1516293 - Intermittent Automation Error: mozprocess timed out after 1000 seconds running ['/Users/cltbld/tasks/task_1545682463/build/venv/bin/python', '-u', '/Users/cltbld/tasks/task_1545682463/build/tests/web-platform/runtests.py', '--log-raw=-', '--log-raw=/

Status: RESOLVED INCOMPLETE

(Testing :: General, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: rmaries [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=218709547&repo=mozilla-inbound

https://queue.taskcluster.net/v1/task/AF5ITv1oRvu4WIVPuq8LXg/runs/0/artifacts/public/logs/live_backing.log

13:43:01     INFO - PID 1369 | 1545687781679	Marionette	DEBUG	0 -> [0,143,"WebDriver:SwitchToFrame",{}]
13:43:01     INFO - PID 1369 | 1545687781681	Marionette	DEBUG	0 <- [1,143,null,{"value":null}]
13:43:01     INFO - PID 1369 | 1545687781681	webdriver::server	DEBUG	<- 200 OK {"value":null}
13:43:01     INFO - STDOUT: =============================== warnings summary ===============================
13:43:01     INFO - STDOUT: <undetermined location>
13:43:01     INFO - STDOUT:   Module already imported so cannot be rewritten: mozlog
13:43:01     INFO - STDOUT:   Module already imported so cannot be rewritten: tests.support.fixtures
13:43:01     INFO - STDOUT: -- Docs: http://doc.pytest.org/en/latest/warnings.html
13:43:01     INFO - STDOUT: ===================== 4 passed, 2 warnings in 0.66 seconds =====================
13:43:01     INFO - ....
13:43:01     INFO - TEST-OK | /_mozilla/webdriver/take_full_screenshot/screenshot.py | took 732ms
13:43:01     INFO - No more tests
13:43:01     INFO - Closing logging queue
13:43:01     INFO - queue closed
13:43:01     INFO - Got 0 unexpected results
13:43:01     INFO - SUITE-END | took 808s
13:43:01     INFO - Closing logging queue
13:43:11     INFO - queue closed
13:59:51     INFO - Automation Error: mozprocess timed out after 1000 seconds running ['/Users/cltbld/tasks/task_1545682463/build/venv/bin/python', '-u', '/Users/cltbld/tasks/task_1545682463/build/tests/web-platform/runtests.py', '--log-raw=-', '--log-raw=/Users/cltbld/tasks/task_1545682463/build/blobber_upload_dir/wpt_raw.log', '--log-wptreport=/Users/cltbld/tasks/task_1545682463/build/blobber_upload_dir/wptreport.json', '--log-errorsummary=/Users/cltbld/tasks/task_1545682463/build/blobber_upload_dir/wpt_errorsummary.log', '--binary=/Users/cltbld/tasks/task_1545682463/build/application/Firefox Nightly.app/Contents/MacOS/firefox', '--symbols-path=https://queue.taskcluster.net/v1/task/Z9VLILrXRFijG-lOXoglhQ/artifacts/public/build/target.crashreporter-symbols.zip', '--stackwalk-binary=/Users/cltbld/tasks/task_1545682463/build/macosx64-minidump_stackwalk', '--stackfix-dir=/Users/cltbld/tasks/task_1545682463/build/tests/bin', '--run-by-dir=3', '--no-pause-after-test', '--install-fonts', '--test-type=wdspec', '--test-type=wdspec', '--stylo-threads=4', '--total-chunks=2', '--this-chunk=2', '--webdriver-binary=/Users/cltbld/tasks/task_1545682463/build/tests/bin/geckodriver', '--webdriver-arg=-vv', '--prefs-root=/Users/cltbld/tasks/task_1545682463/build/tests/web-platform/prefs', '--processes=1', '--config=/Users/cltbld/tasks/task_1545682463/build/tests/web-platform/wptrunner.ini', '--ca-cert-path=/Users/cltbld/tasks/task_1545682463/build/tests/web-platform/tests/tools/certs/cacert.pem', '--host-key-path=/Users/cltbld/tasks/task_1545682463/build/tests/web-platform/tests/tools/certs/web-platform.test.key', '--host-cert-path=/Users/cltbld/tasks/task_1545682463/build/tests/web-platform/tests/tools/certs/web-platform.test.pem', '--certutil-binary=/Users/cltbld/tasks/task_1545682463/build/tests/bin/certutil', '--prefs-root=/Users/cltbld/tasks/task_1545682463/build/tests/web-platform/prefs', '--processes=1', '--config=/Users/cltbld/tasks/task_1545682463/build/tests/web-platform/wptrunner.ini', '--ca-cert-path=/Users/cltbld/tasks/task_1545682463/build/tests/web-platform/tests/tools/certs/cacert.pem', '--host-key-path=/Users/cltbld/tasks/task_1545682463/build/tests/web-platform/tests/tools/certs/web-platform.test.key', '--host-cert-path=/Users/cltbld/tasks/task_1545682463/build/tests/web-platform/tests/tools/certs/web-platform.test.pem', '--certutil-binary=/Users/cltbld/tasks/task_1545682463/build/tests/bin/certutil']
13:59:51    ERROR - timed out after 1000 seconds of no output
13:59:51    ERROR - Return code: -15
13:59:51    ERROR - # TBPL FAILURE #
13:59:51  WARNING - setting return code to 2
13:59:51     INFO - Running post-action listener: _package_coverage_data
13:59:51     INFO - Running post-action listener: _resource_record_post_action
13:59:51     INFO - Running post-action listener: process_java_coverage_data
13:59:51     INFO - Running post-action listener: stop_device
13:59:51     INFO - [mozharness: 2018-12-24 21:59:51.922939Z] Finished run-tests step (success)
13:59:51     INFO - Running post-run listener: _resource_record_post_run
13:59:52     INFO - Total resource usage - Wall time: 1862s; CPU: 50.0%; Read bytes: 50841600; Write bytes: 6066832896; Read time: 348; Write time: 20017
13:59:52     INFO - TinderboxPrint: CPU usage<br/>49.6%
13:59:52     INFO - TinderboxPrint: I/O read bytes / time<br/>50,841,600 / 348
13:59:52     INFO - TinderboxPrint: I/O write bytes / time<br/>6,066,832,896 / 20,017
13:59:52     INFO - TinderboxPrint: CPU idle<br/>3,756.2 (50.4%)
13:59:52     INFO - TinderboxPrint: CPU system<br/>1,832.6 (24.6%)
13:59:52     INFO - TinderboxPrint: CPU user<br/>1,857.8 (24.9%)
13:59:52     INFO - TinderboxPrint: Swap in / out<br/>1,695,227,904 / 0
13:59:52     INFO - pull - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
13:59:52     INFO - verify-device - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
13:59:52     INFO - install - Wall time: 24s; CPU: 54.0%; Read bytes: 247478272; Write bytes: 242095616; Read time: 20154; Write time: 508
13:59:52     INFO - run-tests - Wall time: 1838s; CPU: 49.0%; Read bytes: 49874944; Write bytes: 5808476160; Read time: 332; Write time: 19469
13:59:52  WARNING - returning nonzero exit status 2
[taskcluster 2018-12-24T21:59:52.822Z]    Exit Code: 2
[taskcluster 2018-12-24T21:59:52.822Z]    User Time: 14m25.683199s
[taskcluster 2018-12-24T21:59:52.822Z]  Kernel Time: 3m57.362883s
[taskcluster 2018-12-24T21:59:52.822Z]    Wall Time: 32m44.206748023s
[taskcluster 2018-12-24T21:59:52.822Z]       Result: FAILED
[taskcluster 2018-12-24T21:59:52.822Z] === Task Finished ===
[taskcluster 2018-12-24T21:59:52.822Z] Task Duration: 32m44.206924252s
[taskcluster 2018-12-24T21:59:53.513Z] Uploading artifact public/logs/localconfig.json from file logs/localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2019-12-24T20:35:26.003Z
[taskcluster 2018-12-24T21:59:54.014Z] Uploading artifact public/logs/log_critical.log from file logs/log_critical.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-24T20:35:26.003Z
[taskcluster 2018-12-24T21:59:54.421Z] Uploading artifact public/logs/log_error.log from file logs/log_error.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-24T20:35:26.003Z
[taskcluster 2018-12-24T21:59:54.787Z] Uploading artifact public/logs/log_fatal.log from file logs/log_fatal.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-24T20:35:26.003Z
[taskcluster 2018-12-24T21:59:55.141Z] Uploading artifact public/logs/log_info.log from file logs/log_info.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-24T20:35:26.003Z
[taskcluster 2018-12-24T21:59:56.195Z] Uploading artifact public/logs/log_raw.log from file logs/log_raw.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-24T20:35:26.003Z
[taskcluster 2018-12-24T21:59:57.115Z] Uploading artifact public/logs/log_warning.log from file logs/log_warning.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-24T20:35:26.003Z
[taskcluster 2018-12-24T21:59:57.507Z] Uploading artifact public/test_info/resource-usage.json from file build/blobber_upload_dir/resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2019-12-24T20:35:26.003Z
[taskcluster 2018-12-24T21:59:58.137Z] Uploading artifact public/test_info/wpt_errorsummary.log from file build/blobber_upload_dir/wpt_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-24T20:35:26.003Z
[taskcluster 2018-12-24T21:59:59.343Z] Uploading artifact public/test_info/wpt_raw.log from file build/blobber_upload_dir/wpt_raw.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-24T20:35:26.003Z
[taskcluster 2018-12-24T22:00:00.823Z] Uploading artifact public/test_info/wptreport.json from file build/blobber_upload_dir/wptreport.json with content encoding "gzip", mime type "application/json" and expiry 2019-12-24T20:35:26.003Z
[taskcluster:error] exit status 2

Comment 1

[Intermittent Failures Robot]

1 failures in 1008 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1516293&startday=2018-12-24&endday=2018-12-30&tree=all

Comment 2

[Intermittent Failures Robot]

2 failures in 2627 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1
• mozilla-inbound: 1

Platform breakdown:

• osx-10-10: 1
• linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1516293&startday=2019-01-07&endday=2019-01-13&tree=all

Comment 3

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 4

[Razvan Maries]

New occurrence: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=266256540&repo=autoland&lineNumber=7517

Comment 5

[Intermittent Failures Robot]

1 failures in 4637 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• macosx1014-64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1516293&startday=2019-09-09&endday=2019-09-15&tree=all

Comment 6

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 7

[Intermittent Failures Robot]

1 failures in 3801 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1516293&startday=2019-10-07&endday=2019-10-13&tree=all