New issue
Advanced search Search tips

Issue 713903 link

Starred by 1 user

Issue metadata

Status: WontFix
Owner: ----
Closed: Sep 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

autoupdate_endtoendtest fails with unknown error

Project Member Reported by semenzato@chromium.org, Apr 20 2017

Issue description

The cause of failure for PaygenTestDev in this build:

https://uberchromegw.corp.google.com/i/chromeos/builders/wizpig-release/builds/1056

is hard to determine.  The stdio reports a test failure:

https://uberchromegw.corp.google.com/i/chromeos/builders/wizpig-release/builds/1056/steps/PaygenTestDev/logs/stdio


04-20-2017 [11:01:27] Suite job is finished.
04-20-2017 [11:01:27] Start collectint test results and dump them to json.
Suite job                                     [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_delta   [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_full    [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_delta   [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_full    [ PASSED ]
autoupdate_EndToEndTest.paygen_au_dev_full    [ FAILED ]
autoupdate_EndToEndTest.paygen_au_dev_full      ABORT: None
autoupdate_EndToEndTest.paygen_au_dev_full      retry_count: 1


so first of all, the "None" above is suspicious.  The bucket is

https://pantheon.corp.google.com/storage/browser/chromeos-autotest-results/113507434-chromeos-test/chromeos6-row2-rack20-host1/debug/

and autoserv.DEBUG is confusing.  First there is this:

04/20 09:44:44.719 INFO |       autoupdater:0302| Updating image via: /usr/bin/update_engine_client --update --omaha_url=http://100.115.185.227:33117/update
04/20 09:44:44.719 DEBUG|          ssh_host:0284| Running (ssh) '/usr/bin/update_engine_client --update --omaha_url=http://100.115.185.227:33117/update'
04/20 09:44:44.900 ERROR|        base_utils:0280| [stderr] [0420/094444:INFO:update_engine_client.cc(471)] Forcing an update by setting app_version to ForcedUpdate.
04/20 09:44:44.901 ERROR|        base_utils:0280| [stderr] [0420/094444:INFO:update_engine_client.cc(473)] Initiating update check and install.
04/20 09:44:44.978 ERROR|        base_utils:0280| [stderr] [0420/094444:INFO:update_engine_client.cc(502)] Waiting for update to complete.
04/20 09:50:43.773 ERROR|        base_utils:0280| [stderr] [0420/095043:INFO:update_engine_client.cc(224)] Update succeeded -- reboot needed.
04/20 09:50:43.857 WARNI|       autoupdater:0315| Unable to parse build name /update for metrics. Continuing anyway.
04/20 09:50:43.857 DEBUG|          ssh_host:0284| Running (ssh) '/usr/bin/update_engine_client -status | grep CURRENT_OP'
04/20 09:50:44.178 ERROR|        base_utils:0280| [stderr] [0420/095043:INFO:update_engine_client.cc(493)] Querying Update Engine status...
04/20 09:50:44.255 DEBUG|        base_utils:0280| [stdout] CURRENT_OP=UPDATE_STATUS_UPDATED_NEED_REBOOT
04/20 09:50:44.258 INFO |       autoupdater:0521| Updating stateful partition...
04/20 09:50:44.258 DEBUG|      abstract_ssh:0448| send_file. source: /usr/local/google/chromeos/src/platform/dev/stateful_update, dest: /tmp/stateful_update, delete_dest: True,preserve_symlinks:False
04/20 09:50:44.258 DEBUG|          ssh_host:0284| Running (ssh) 'rsync --version'

Those lines marked with ERROR, are they errors or not?  The messages don't look like errors.

There are a few more. (Why would "Querying Update Engine status" be logged as an error?)

04/20 09:54:02.990 DEBUG|        base_utils:0280| [stdout] CURRENT_OP=UPDATE_STATUS_IDLE
04/20 09:54:02.991 ERROR|        base_utils:0280| [stderr] [0420/095402:INFO:update_engine_client.cc(493)] Querying Update Engine status...
04/20 09:54:02.992 INFO |       autoupdater:0253| Triggering update via: /usr/bin/update_engine_client --check_for_update --omaha_url=http://100.115.185.227:46439/update
04/20 09:54:02.992 DEBUG|          ssh_host:0284| Running (ssh) '/usr/bin/update_engine_client --check_for_update --omaha_url=http://100.115.185.227:46439/update'
04/20 09:54:03.190 ERROR|        base_utils:0280| [stderr] [0420/095402:INFO:update_engine_client.cc(473)] Initiating update check and install.
04/20 09:54:03.191 WARNI|       autoupdater:0266| Unable to parse build name /update for metrics. Continuing anyway.

then there are the errors from the TKO parser:

04/20 10:47:51.299 INFO | get_network_stats:0048| get_network_stats: at-start RXbytes 15583273 TXbytes 933352
04/20 10:47:51.301 ERROR|   logging_manager:0626| tko parser: {'aborted_by': 'autotest_system', 'job_started': 1492706563, 'parent_job_id': 113497744, 'user': 'chromeos-test', 'aborted_on': 1492710462, 'builds': "{'cros-version': 'wizpig-release/R60-9479.0.0'}", 'job_finished': 1492710462, 'hostname': 'chromeos6-row2-rack20-host1', 'status_version': 1, 'label': 'wizpig-release/R60-9479.0.0/paygen_au_dev/autoupdate_EndToEndTest_paygen_au_dev_full_9449.0.0', 'drone': 'chromeos-server82.cbf.corp.google.com', 'build': 'wizpig-release/R60-9479.0.0', 'suite': 'paygen_au_dev', 'retry_original_job_id': 113497829, 'experimental': 'False', 'job_queued': 1492706327}
04/20 10:47:51.302 ERROR|   logging_manager:0626| tko parser: MACHINE NAME: chromeos6-row2-rack20-host1
04/20 10:47:51.302 ERROR|   logging_manager:0626| tko parser: MACHINE GROUP: wizpig
04/20 10:47:51.302 ERROR|   logging_manager:0626| tko parser: parsing partial test ---- SERVER_JOB
04/20 10:47:51.302 ERROR|   logging_manager:0626| tko parser: parsing partial test autoupdate_EndToEndTest.paygen_au_dev_full autoupdate_EndToEndTest.paygen_au_dev_full
04/20 10:47:51.302 ERROR|   logging_manager:0626| tko parser: RUNNING: RUNNING
04/20 10:47:51.302 ERROR|   logging_manager:0626| Subdir: autoupdate_EndToEndTest.paygen_au_dev_full
04/20 10:47:51.303 ERROR|   logging_manager:0626| Testname: autoupdate_EndToEndTest.paygen_au_dev_full
04/20 10:47:51.303 ERROR|   logging_manager:0626| 
04/20 10:47:51.303 ERROR|   logging_manager:0626| tko parser: Unexpected indent: aborting log parse
04/20 10:47:51.303 ERROR|   logging_manager:0626| tko parser: parsing test autoupdate_EndToEndTest.paygen_au_dev_full autoupdate_EndToEndTest.paygen_au_dev_full
04/20 10:47:51.303 ERROR|   logging_manager:0626| tko parser: ADD: ABORT
04/20 10:47:51.304 ERROR|   logging_manager:0626| Subdir: autoupdate_EndToEndTest.paygen_au_dev_full
04/20 10:47:51.304 ERROR|   logging_manager:0626| Testname: autoupdate_EndToEndTest.paygen_au_dev_full
04/20 10:47:51.304 ERROR|   logging_manager:0626| None
04/20 10:47:51.304 DEBUG|          ssh_host:0284| Running (ssh) 'grep -q CHROMEOS /etc/lsb-release && ! test -f /mnt/stateful_partition/.android_tester && ! grep -q moblab /etc/lsb-release'
04/20 10:47:51.304 ERROR|   logging_manager:0626| tko parser: parsing test ---- SERVER_JOB
04/20 10:47:51.311 INFO |      abstract_ssh:0809| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_rjzxFissh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmps1x9Af -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 chromeos6-row2-rack20-host1'

and finally these:

04/20 10:47:54.209 INFO | site_crashcollect:0111| Generating stack trace using devserver for /usr/local/autotest/results/113507434-chromeos-test/chromeos6-row2-rack20-host1/sysinfo/var/spool/crash/chrome.20170420.094209.14714.dmp
04/20 10:47:56.573 DEBUG|        dev_server:0294| RPC call get_load has timed out on devserver 172.25.61.81.
04/20 10:47:56.574 ERROR|        dev_server:0428| Devserver call failed: "http://172.25.61.81:8082/check_health?", timeout: 2.0 seconds, Error: retry exception (label="get_load"), timeout = 2s
04/20 10:47:56.599 DEBUG|        dev_server:0294| RPC call get_load has timed out on devserver 172.25.66.216.
04/20 10:47:56.600 ERROR|        dev_server:0428| Devserver call failed: "http://172.25.66.216:8082/check_health?", timeout: 2.0 seconds, Error: retry exception (label="get_load"), timeout = 2s
04/20 10:47:56.617 DEBUG|             retry:0155| Converted retries value: 0 -> Retry(total=0, connect=None, read=None, redirect=0)
04/20 10:47:56.617 INFO |    connectionpool:0188| Starting new HTTP connection (1): 100.108.1.59
04/20 10:48:38.422 DEBUG|    connectionpool:0362| "POST /symbolicate_dump?archive_url=gs://chromeos-image-archive/wizpig-release/R60-9479.0.0 HTTP/1.1" 500 1643
04/20 10:48:38.425 INFO | site_crashcollect:0128| Failed to generate stack trace on devserver for dump /usr/local/autotest/results/113507434-chromeos-test/chromeos6-row2-rack20-host1/sysinfo/var/spool/crash/chrome.20170420.094209.14714.dmp:
DevServerException('\n\n\n    \n    500 Internal Server Error\n    \n    #powered_by {\n        margin-top: 20px;\n        border-top: 2px solid black;\n        font-style: italic;\n    }\n\n    #traceback {\n        color: red;\n    }\n    \n\n    \n        500 Internal Server Error\n        The server encountered an unexpected condition which prevented it from fulfilling the request.\n        Traceback (most recent call last):\n  File "/usr/lib/python2.7/dist-packages/cherrypy/_cprequest.py", line 656, in respond\n    response.body = self.handler()\n  File "/usr/lib/python2.7/dist-packages/cherrypy/lib/encoding.py", line 188, in __call__\n    self.body = self.oldhandler(*args, **kwargs)\n  File "/usr/lib/python2.7/dist-packages/cherrypy/_cpdispatch.py", line 34, in __call__\n    return self.callable(*self.args, **self.kwargs)\n  File "/usr/local/google/home/chromeos-test/chromiumos/src/platform/dev/devserver.py", line 1112, in symbolicate_dump\n    stdout=subprocess.PIPE, stderr=subprocess.PIPE)\n  File "/usr/lib/python2.7/subprocess.py", line 710, in __init__\n    errread, errwrite)\n  File "/usr/lib/python2.7/subprocess.py", line 1327, in _execute_child\n    raise child_exception\nOSError: [Errno 2] No such file or directory\n\n    \n    Powered by CherryPy 3.2.2\n    \n    \n\n',)
04/20 10:48:38.425 WARNI| site_crashcollect:0132| Failed to generate stack trace for /usr/local/autotest/results/113507434-chromeos-test/chromeos6-row2-rack20-host1/sysinfo/var/spool/crash/chrome.20170420.094209.14714.dmp (see info logs)

So where's the error??????????????

 
Cc: hidehiko@chromium.org

Comment 2 by aut...@google.com, Jun 2 2017

Status: Unconfirmed (was: Untriaged)
Labels: FixedByAURewrite
Status: WontFix (was: Unconfirmed)
Obsolete with AU test rewrite 

Sign in to add a comment