1482585 - Intermittent WEBGL Automation Error: mozprocess timed out after 1000 seconds running ['/Users/cltbld/tasks/task_1533926391/build/venv/bin/python', '-u', '/Users/cltbld/tasks/task_1533926391/build/tests/mochitest/runtests.py'

Status: RESOLVED INCOMPLETE

(Core :: Graphics: CanvasWebGL, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: ncsoregi [at] mozilla.com

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

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

11:50:12     INFO - TEST-START | dom/canvas/test/webgl-conf/generated/test_conformance__uniforms__uniform-values-per-program.html
11:50:12     INFO - GECKO(1899) | MEMORY STAT | vsize 4631MB | residentFast 567MB | heapAllocated 46MB
11:50:12     INFO - TEST-OK | dom/canvas/test/webgl-conf/generated/test_conformance__uniforms__uniform-values-per-program.html | took 601ms
11:50:12     INFO - TEST-START | Shutdown
11:50:12     INFO - Passed:  53248
11:50:12     INFO - Failed:  0
11:50:12     INFO - Todo:    0
11:50:12     INFO - Mode:    e10s
11:50:12     INFO - Slowest: 13324ms - /tests/dom/canvas/test/webgl-conf/generated/test_conformance__textures__canvas__tex-2d-rgb-rgb-unsigned_byte.html
11:50:12     INFO - SimpleTest FINISHED
11:50:12     INFO - TEST-INFO | Ran 1 Loops
11:50:12     INFO - SimpleTest FINISHED
11:50:13     INFO - GECKO(1899) | 1533927013069	Marionette	DEBUG	Received observer notification xpcom-will-shutdown
11:50:13     INFO - GECKO(1899) | 1533927013069	Marionette	INFO	Stopped listening on port 2828
11:50:13     INFO - GECKO(1899) | 1533927013069	Marionette	DEBUG	Remote service is inactive
11:50:13     INFO - TEST-INFO | Main app process: exit 0
11:50:13     INFO - runtests.py | Application ran for: 0:07:32.593950
11:50:13     INFO - zombiecheck | Reading PID log: /var/folders/_z/3jk4rgc501x9_nd4ycnrb8xr00000w/T/tmpZnVHinpidlog
11:50:13     INFO - ==> process 1899 launched child process 1903
11:50:13     INFO - ==> process 1899 launched child process 1904
11:50:13     INFO - ==> process 1899 launched child process 1905
11:50:13     INFO - zombiecheck | Checking for orphan process with PID: 1904
11:50:13     INFO - zombiecheck | Checking for orphan process with PID: 1905
11:50:13     INFO - zombiecheck | Checking for orphan process with PID: 1903
11:50:13     INFO - Stopping web server
11:50:13     INFO - Stopping web socket server
11:50:13     INFO - Stopping ssltunnel
11:50:13  WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
11:50:13     INFO - runtests.py | Running tests: end.
11:50:13     INFO - Buffered messages finished
11:50:13     INFO - Running manifest: dom/canvas/test/webgl-mochitest/mochitest.ini
12:06:53     INFO - Automation Error: mozprocess timed out after 1000 seconds running ['/Users/cltbld/tasks/task_1533926391/build/venv/bin/python', '-u', '/Users/cltbld/tasks/task_1533926391/build/tests/mochitest/runtests.py', '--total-chunks', '3', '--this-chunk', '3', '--appname=/Users/cltbld/tasks/task_1533926391/build/application/Firefox Developer Edition.app/Contents/MacOS/firefox', '--utility-path=tests/bin', '--extra-profile-file=tests/bin/plugins', '--symbols-path=https://queue.taskcluster.net/v1/task/JAN6Pn7ETOa5HtJgdwmsGA/artifacts/public/build/target.crashreporter-symbols.zip', '--certificate-path=tests/certs', '--quiet', '--log-raw=/Users/cltbld/tasks/task_1533926391/build/blobber_upload_dir/mochitest-gl_raw.log', '--log-errorsummary=/Users/cltbld/tasks/task_1533926391/build/blobber_upload_dir/mochitest-gl_errorsummary.log', '--screenshot-on-fail', '--cleanup-crashes', '--marionette-startup-timeout=180', '--sandbox-read-whitelist=/Users/cltbld/tasks/task_1533926391/build', '--log-raw=-', '--subsuite=webgl']
12:06:53    ERROR - timed out after 1000 seconds of no output
12:06:53    ERROR - Return code: -15
12:06:53    ERROR - No suite end message was emitted by this harness.
12:06:53     INFO - TinderboxPrint: mochitest-mochitest-gl<br/>1741/0/0
12:06:53    ERROR - # TBPL FAILURE #
12:06:53  WARNING - setting return code to 2
12:06:53    ERROR - The mochitest suite: mochitest-gl ran with return status: FAILURE
12:06:53     INFO - Running post-action listener: _package_coverage_data
12:06:53     INFO - Running post-action listener: _resource_record_post_action
12:06:53     INFO - [mozharness: 2018-08-10 19:06:53.920329Z] Finished run-tests step (success)
12:06:53     INFO - Running post-run listener: _resource_record_post_run
12:06:54     INFO - Validating Perfherder data against /Users/cltbld/tasks/task_1533926391/mozharness/external_tools/performance-artifact-schema.json
12:06:54     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 44.3783468559838}, {"name": "io_write_bytes", "value": 572944896}, {"name": "io.read_bytes", "value": 49199616}, {"name": "io_write_time", "value": 5867}, {"name": "io_read_time", "value": 422}], "extraOptions": ["e10s", "buildbot-unknown"], "name": "mochitest.mochitest-gl.mochitest-gl.3.overall"}, {"subtests": [{"name": "time", "value": 22.571334838867188}, {"name": "cpu_percent", "value": 53.58636363636363}], "name": "mochitest.mochitest-gl.mochitest-gl.3.install"}, {"subtests": [{"name": "time", "value": 0.0004448890686035156}], "name": "mochitest.mochitest-gl.mochitest-gl.3.stage-files"}, {"subtests": [{"name": "time", "value": 1457.868959903717}, {"name": "cpu_percent", "value": 44.2317822802198}], "name": "mochitest.mochitest-gl.mochitest-gl.3.run-tests"}]}
12:06:54     INFO - Total resource usage - Wall time: 1480s; CPU: 44.0%; Read bytes: 49199616; Write bytes: 572944896; Read time: 422; Write time: 5867
12:06:54     INFO - TinderboxPrint: CPU usage<br/>44.2%
12:06:54     INFO - TinderboxPrint: I/O read bytes / time<br/>49,199,616 / 422
12:06:54     INFO - TinderboxPrint: I/O write bytes / time<br/>572,944,896 / 5,867
12:06:54     INFO - TinderboxPrint: CPU idle<br/>3,291.8 (55.6%)
12:06:54     INFO - TinderboxPrint: CPU system<br/>1,400.3 (23.7%)
12:06:54     INFO - TinderboxPrint: CPU user<br/>1,226.2 (20.7%)
12:06:54     INFO - TinderboxPrint: Swap in / out<br/>289,398,784 / 0
12:06:54     INFO - install - Wall time: 23s; CPU: 54.0%; Read bytes: 219336704; Write bytes: 210793984; Read time: 16547; Write time: 451
12:06:54     INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
12:06:54     INFO - run-tests - Wall time: 1458s; CPU: 44.0%; Read bytes: 31900160; Write bytes: 331168768; Read time: 323; Write time: 5321
12:06:54     INFO - Running post-run listener: copy_logs_to_upload_dir
12:06:54     INFO - Copying logs to upload dir...
12:06:54     INFO - mkdir: /Users/cltbld/tasks/task_1533926391/build/upload/logs
12:06:54     INFO - Copying logs to upload dir...
12:06:54  WARNING - returning nonzero exit status 2
[taskcluster 2018-08-10T19:06:54.725Z] Exit Code: 2
[taskcluster 2018-08-10T19:06:54.725Z] === Task Finished ===
[taskcluster 2018-08-10T19:06:54.725Z] Task Duration: 27m0.988734097s
[taskcluster 2018-08-10T19:06:55.126Z] Uploading artifact public/logs/localconfig.json from file logs/localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2019-08-10T17:47:57.705Z
[taskcluster 2018-08-10T19:06:55.817Z] Uploading artifact public/logs/log_critical.log from file logs/log_critical.log with content encoding "gzip", mime type "text/plain" and expiry 2019-08-10T17:47:57.705Z
[taskcluster 2018-08-10T19:06:56.200Z] Uploading artifact public/logs/log_error.log from file logs/log_error.log with content encoding "gzip", mime type "text/plain" and expiry 2019-08-10T17:47:57.705Z
[taskcluster 2018-08-10T19:06:56.651Z] Uploading artifact public/logs/log_fatal.log from file logs/log_fatal.log with content encoding "gzip", mime type "text/plain" and expiry 2019-08-10T17:47:57.705Z
[taskcluster 2018-08-10T19:06:57.013Z] Uploading artifact public/logs/log_info.log from file logs/log_info.log with content encoding "gzip", mime type "text/plain" and expiry 2019-08-10T17:47:57.705Z
[taskcluster 2018-08-10T19:06:58.862Z] Uploading artifact public/logs/log_raw.log from file logs/log_raw.log with content encoding "gzip", mime type "text/plain" and expiry 2019-08-10T17:47:57.705Z
[taskcluster 2018-08-10T19:07:00.751Z] Uploading artifact public/logs/log_warning.log from file logs/log_warning.log with content encoding "gzip", mime type "text/plain" and expiry 2019-08-10T17:47:57.705Z
[taskcluster 2018-08-10T19:07:01.149Z] Uploading artifact public/test_info/manifests.list from file build/blobber_upload_dir/manifests.list with content encoding "gzip", mime type "text/plain; charset=utf-8" and expiry 2019-08-10T17:47:57.705Z
[taskcluster 2018-08-10T19:07:01.522Z] Uploading artifact public/test_info/mochitest-gl_errorsummary.log from file build/blobber_upload_dir/mochitest-gl_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2019-08-10T17:47:57.705Z
[taskcluster 2018-08-10T19:07:02.384Z] Uploading artifact public/test_info/mochitest-gl_raw.log from file build/blobber_upload_dir/mochitest-gl_raw.log with content encoding "gzip", mime type "text/plain" and expiry 2019-08-10T17:47:57.705Z
[taskcluster 2018-08-10T19:07:04.743Z] 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-08-10T17:47:57.705Z
[taskcluster 2018-08-10T19:07:07.662Z] Uploading artifact public/test_info/system-info.log from file build/blobber_upload_dir/system-info.log with content encoding "gzip", mime type "text/plain" and expiry 2019-08-10T17:47:57.705Z
[taskcluster:error] exit status 2

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-beta: 1

Platform breakdown:
* macosx64-devedition: 1

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

Comment 2

[Intermittent Failures Robot]

1 failures in 2672 pushes (0.0 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=1482585&startday=2018-08-13&endday=2018-08-19&tree=all

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1482585&startday=2018-08-27&endday=2018-09-02&tree=all

Comment 4

[Firefox Bug Husbandry Bot]

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