Intermittent Automation Error: mozprocess timed out after 600 seconds running ['/usr/bin/python2.7', '-u', '/builds/worker/workspace/mozharness/external_tools/tooltool.py', '--url', 'http://relengapi/tooltool/', 'fetch', '-m', '/builds/worker/workspace
Categories
(Release Engineering :: Applications: MozharnessCore, defect, P5)
Tracking
(Not tracked)
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
| Comment hidden (Intermittent Failures Robot) |
Comment 2•8 years ago
|
||
Comment 3•8 years ago
|
||
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 10•8 years ago
|
||
Comment 11•8 years ago
|
||
Comment 12•8 years ago
|
||
| Comment hidden (Intermittent Failures Robot) |
Comment 14•8 years ago
|
||
| Comment hidden (Intermittent Failures Robot) |
Comment 16•7 years ago
|
||
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=222133727&repo=autoland&lineNumber=916
[task 2019-01-16T03:56:17.410Z] 03:56:17 INFO - retry: Calling run_command with args: (['/usr/bin/python2.7', '-u', '/builds/worker/workspace/mozharness/external_tools/tooltool.py', '--url', 'http://relengapi/tooltool/', 'fetch', '-m', '/builds/worker/workspace/build/hostutils/releng.manifest', '-o', '-c', '/builds/worker/tooltool-cache'],), kwargs: {'output_timeout': 600, 'error_list': [{'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x7f9c8b5f9408>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x7f9c8c2ffc48>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x7f9c8c26a510>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/worker/workspace/build/hostutils', 'privileged': False}, attempt #1
[task 2019-01-16T03:56:17.410Z] 03:56:17 INFO - Running command: ['/usr/bin/python2.7', '-u', '/builds/worker/workspace/mozharness/external_tools/tooltool.py', '--url', 'http://relengapi/tooltool/', 'fetch', '-m', '/builds/worker/workspace/build/hostutils/releng.manifest', '-o', '-c', '/builds/worker/tooltool-cache'] in /builds/worker/workspace/build/hostutils
[task 2019-01-16T03:56:17.410Z] 03:56:17 INFO - Copy/paste: /usr/bin/python2.7 -u /builds/worker/workspace/mozharness/external_tools/tooltool.py --url http://relengapi/tooltool/ fetch -m /builds/worker/workspace/build/hostutils/releng.manifest -o -c /builds/worker/tooltool-cache
[task 2019-01-16T03:56:17.411Z] 03:56:17 INFO - Calling ['/usr/bin/python2.7', '-u', '/builds/worker/workspace/mozharness/external_tools/tooltool.py', '--url', 'http://relengapi/tooltool/', 'fetch', '-m', '/builds/worker/workspace/build/hostutils/releng.manifest', '-o', '-c', '/builds/worker/tooltool-cache'] with output_timeout 600
[task 2019-01-16T03:56:17.461Z] 03:56:17 INFO - INFO - File host-utils-66.0a1.en-US.linux-x86_64.tar.gz not present in local cache folder /builds/worker/tooltool-cache
[task 2019-01-16T03:56:17.461Z] 03:56:17 INFO - INFO - Attempting to fetch from 'http://relengapi/tooltool/'...
[task 2019-01-16T04:06:17.491Z] 04:06:17 INFO - Automation Error: mozprocess timed out after 600 seconds running ['/usr/bin/python2.7', '-u', '/builds/worker/workspace/mozharness/external_tools/tooltool.py', '--url', 'http://relengapi/tooltool/', 'fetch', '-m', '/builds/worker/workspace/build/hostutils/releng.manifest', '-o', '-c', '/builds/worker/tooltool-cache']
[task 2019-01-16T04:06:17.522Z] 04:06:17 ERROR - timed out after 600 seconds of no output
[task 2019-01-16T04:06:17.522Z] 04:06:17 ERROR - Return code: -15
[task 2019-01-16T04:06:17.522Z] 04:06:17 INFO - retry: Failed, sleeping 60 seconds before retrying
| Comment hidden (Intermittent Failures Robot) |
Comment 18•7 years ago
|
||
Comment 19•7 years ago
|
||
Comment 20•7 years ago
|
||
Recent log failure:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=241795433&repo=mozilla-beta&lineNumber=825
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 26•7 years ago
|
||
Comment 27•6 years ago
|
||
| Comment hidden (Intermittent Failures Robot) |
Comment 29•6 years ago
|
||
Comment 30•6 years ago
|
||
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 39•5 years ago
•
|
||
Looks like this failure is present also on green runs: https://treeherder.mozilla.org/logviewer?job_id=332646144&repo=autoland&lineNumber=964 so it's not relevant for the classified failures here. Gonna re-classify. Failures were all Bug 1589796.
Comment 40•5 years ago
|
||
Andrew, looks like these timeouts started occurring after Bug 1369784 and Bug 1646161 landed here. Could you have a look over these?
Comment 41•5 years ago
|
||
It should be impossible for a change in mozlint (lint infrastructure) to affect tests like mochitest. Likely further retriggers will show another push is the culprit or the error is due to some external factor and that push happened to be at the wrong place at the wrong time.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 45•4 years ago
|
||
These failures have started appearing recently starting with this merge . So far they are only failing on Android 8 as tier 2.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 48•4 years ago
|
||
This is also happening on our tier-3 G5 and Pixel 2 perf tests: https://treeherder.mozilla.org/jobs?repo=mozilla-central&tier=1%2C2%2C3&searchStr=browsertime%2Cchrome%2Candroid&revision=0d591d3bc99786bdb3cb057203a3831110d00800&selectedTaskRun=TB4zOTdQQFGMS4JT3dThGQ.1
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 55•3 years ago
|
||
These failures are almost exclusively on android-hw, when downloading host-utils from tooltool. Most android-hw and android-em test tasks download host-utils this way.
host-utils is about 100 MB in size. For android-em tasks, host-utils is typically downloaded and extracted in a few seconds. On android-hw, host-utils downloads typically take 4 to 6 minutes. In many of the failure logs for this bug, tooltool runs for 10 minutes, times out, retries, might run tooltool and timeout again after 10 minutes, eventually succeeds, but then the task exceeds its max-run-time (having run perhaps 30 minutes extra downloading host-utils).
At first I thought a shorter tooltool timeout might be helpful: retry sooner, might succeed sooner if tooltool is hung. But, as the timeout is an output timeout, and tooltool doesn't produce any progress output, and typical android-hw downloads take 4-6 minutes anyway, there's not much room to reduce the timeout, and doing so might cause more retries / more failures.
Increasing the tooltool timeout might be helpful, if those timed-out downloads are actually progressing but just needed more time. But if those tooltool sessions are actually hung, increasing the timeout will make things worse.
Overall, I think the 10 minute tooltool timeout is sensible in this case.
Another solution would be to increase the android-hw mochitest and reftest (and maybe other) max-run-time: In case it takes several attempts and 30+ minutes to download host-utils, allow the tasks to run that much longer.
Ideally, it would be nice to remove this reliance on tooltool; can we use a fetch instead; would that work any better?
| Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Comment 57•3 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Description
•