1757278 - Intermittent TEST-UNEXPECTED-TIMEOUT | devtools/client/debugger/test/mochitest/browser_dbg-preview-getter.js | application timed out after 370 seconds with no output

Status: RESOLVED INCOMPLETE

(DevTools :: Debugger, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: mlaza [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=369303377&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/cTGlHpQnTBCQyXNnUGf9JQ/runs/0/artifacts/public/logs/live_backing.log

---

[task 2022-02-26T10:52:42.947Z] 10:52:42     INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-preview-getter.js | Getters were invoked and three object values are displayed as expected. - 
[task 2022-02-26T10:52:49.746Z] 10:52:49     INFO - Get token at 5, 7
[task 2022-02-26T10:52:55.484Z] 10:52:54     INFO - Buffered messages logged at 10:38:08
[task 2022-02-26T10:53:01.868Z] 10:53:01     INFO - CodeMirror line 5
[task 2022-02-26T10:53:08.176Z] 10:53:07     INFO - Buffered messages logged at 10:38:10
[task 2022-02-26T10:53:14.963Z] 10:53:14     INFO - Leaving test bound 
[task 2022-02-26T10:53:21.568Z] 10:53:20     INFO - Buffered messages finished
[task 2022-02-26T10:53:26.254Z] 10:53:25    ERROR - TEST-UNEXPECTED-TIMEOUT | devtools/client/debugger/test/mochitest/browser_dbg-preview-getter.js | application timed out after 370 seconds with no output
[task 2022-02-26T10:53:27.373Z] 10:53:26    ERROR - Force-terminating active process(es).
[task 2022-02-26T10:53:33.096Z] 10:53:32     INFO - Determining child pids from psutil...
[task 2022-02-26T10:54:12.961Z] 10:54:12     INFO - [1711, 1729, 1813, 1849, 1869, 2105]
[task 2022-02-26T10:54:28.505Z] 10:54:27     INFO - ==> process 1603 launched child process 1624
[task 2022-02-26T10:54:35.983Z] 10:54:35     INFO - ==> process 1603 launched child process 1711
[task 2022-02-26T10:54:42.350Z] 10:54:41     INFO - ==> process 1603 launched child process 1729
[task 2022-02-26T10:54:55.069Z] 10:54:54     INFO - ==> process 1603 launched child process 1813
[task 2022-02-26T10:55:06.627Z] 10:55:06     INFO - ==> process 1603 launched child process 1849
[task 2022-02-26T10:55:17.786Z] 10:55:17     INFO - ==> process 1603 launched child process 1869
[task 2022-02-26T10:55:29.342Z] 10:55:28     INFO - ==> process 1603 launched child process 2105
[task 2022-02-26T10:55:39.928Z] 10:55:39     INFO - Found child pids: {1729, 1869, 1711, 1813, 1624, 1849, 2105}
[task 2022-02-26T10:56:01.222Z] 10:56:00     INFO - Failed to get child procs
[task 2022-02-26T10:56:14.017Z] 10:56:13     INFO - Killing process: 1729
[task 2022-02-26T10:56:43.948Z] 10:56:43     INFO - TEST-INFO | started process screentopng
[task 2022-02-26T11:13:23.954Z] 11:13:23     INFO - Automation Error: mozprocess timed out after 1000 seconds running ['/builds/worker/workspace/build/venv/bin/python', '-u', '/builds/worker/workspace/build/tests/mochitest/runtests.py', 'devtools/client/debugger/test/mochitest/browser.ini', '--setpref=fission.autostart=false', '--setpref=media.peerconnection.mtransport_process=false', '--setpref=network.process.enabled=false', '--setpref=layers.d3d11.enable-blacklist=false', '--appname=/builds/worker/workspace/build/application/firefox/firefox', '--utility-path=tests/bin', '--extra-profile-file=tests/bin/plugins', '--symbols-path=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/YtvlyX5XTKKi1boC8KLRYg/artifacts/public/build/target.crashreporter-symbols.zip', '--certificate-path=tests/certs', '--setpref=webgl.force-enabled=true', '--quiet', '--log-raw=/builds/worker/workspace/build/blobber_upload_dir/mochitest-devtools-chrome_raw.log', '--log-errorsummary=/builds/worker/workspace/build/blobber_upload_dir/mochitest-devtools-chrome_errorsummary.log', '--use-test-media-devices', '--screenshot-on-fail', '--cleanup-crashes', '--marionette-startup-timeout=180', '--sandbox-read-whitelist=/builds/worker/workspace/build', '--log-raw=-', '--flavor=browser', '--subsuite=devtools', '--chunk-by-runtime']
[task 2022-02-26T11:13:23.961Z] 11:13:23    ERROR - timed out after 1000 seconds of no output
[task 2022-02-26T11:13:23.961Z] 11:13:23    ERROR - Return code: -15
[task 2022-02-26T11:13:23.962Z] 11:13:23    ERROR - No suite end message was emitted by this harness.
[task 2022-02-26T11:13:23.962Z] 11:13:23     INFO - TinderboxPrint: mochitest-mochitest-devtools-chrome<br/>125/0/0
[task 2022-02-26T11:13:23.962Z] 11:13:23    ERROR - # TBPL FAILURE #
[task 2022-02-26T11:13:23.962Z] 11:13:23  WARNING - setting return code to 2
[task 2022-02-26T11:13:23.962Z] 11:13:23    ERROR - The mochitest suite: mochitest-devtools-chrome ran with return status: FAILURE
[task 2022-02-26T11:13:23.962Z] 11:13:23     INFO - Running post-action listener: _package_coverage_data
[task 2022-02-26T11:13:23.963Z] 11:13:23     INFO - Running post-action listener: _resource_record_post_action
[task 2022-02-26T11:13:23.963Z] 11:13:23     INFO - Running post-action listener: process_java_coverage_data
[task 2022-02-26T11:13:23.963Z] 11:13:23     INFO - [mozharness: 2022-02-26 11:13:23.963095Z] Finished run-tests step (success)
[task 2022-02-26T11:13:23.963Z] 11:13:23     INFO - Running post-run listener: _resource_record_post_run
[task 2022-02-26T11:13:25.218Z] 11:13:25     INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2022-02-26T11:13:25.227Z] 11:13:25     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": "mochitest.mochitest-devtools-chrome.overall", "extraOptions": ["e10s", "taskcluster-c5.xlarge"], "subtests": [{"name": "cpu_percent", "value": 40.58099730458224}, {"name": "io_write_bytes", "value": 3692339200}, {"name": "io.read_bytes", "value": 741093011456}, {"name": "io_write_time", "value": 434132}, {"name": "io_read_time", "value": 56485924}]}, {"name": "mochitest.mochitest-devtools-chrome.start-pulseaudio", "subtests": [{"name": "time", "value": 0.01779317855834961}]}, {"name": "mochitest.mochitest-devtools-chrome.install", "subtests": [{"name": "time", "value": 49.229451417922974}, {"name": "cpu_percent", "value": 25.239583333333332}]}, {"name": "mochitest.mochitest-devtools-chrome.stage-files", "subtests": [{"name": "time", "value": 0.0002598762512207031}]}, {"name": "mochitest.mochitest-devtools-chrome.run-tests", "subtests": [{"name": "time", "value": 2976.6681563854218}, {"name": "cpu_percent", "value": 41.30244590780813}]}]}
[task 2022-02-26T11:13:25.227Z] 11:13:25     INFO - Total resource usage - Wall time: 3026s; CPU: 41%; Read bytes: 741093011456; Write bytes: 3692339200; Read time: 56485924; Write time: 434132
[task 2022-02-26T11:13:25.227Z] 11:13:25     INFO - TinderboxPrint: CPU usage<br/>41.3%
[task 2022-02-26T11:13:25.227Z] 11:13:25     INFO - TinderboxPrint: I/O read bytes / time<br/>741,093,011,456 / 56,485,924
[task 2022-02-26T11:13:25.227Z] 11:13:25     INFO - TinderboxPrint: I/O write bytes / time<br/>3,692,339,200 / 434,132
[task 2022-02-26T11:13:25.227Z] 11:13:25     INFO - TinderboxPrint: CPU idle<br/>2,679.4 (22.3%)
[task 2022-02-26T11:13:25.227Z] 11:13:25     INFO - TinderboxPrint: CPU iowait<br/>7,242.4 (60.3%)
[task 2022-02-26T11:13:25.227Z] 11:13:25     INFO - TinderboxPrint: CPU system<br/>409.6 (3.4%)
[task 2022-02-26T11:13:25.227Z] 11:13:25     INFO - TinderboxPrint: CPU user<br/>1,680.3 (14.0%)
[task 2022-02-26T11:13:25.227Z] 11:13:25     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2022-02-26T11:13:25.227Z] 11:13:25     INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2022-02-26T11:13:25.227Z] 11:13:25     INFO - install - Wall time: 49s; CPU: 25%; Read bytes: 200704; Write bytes: 1955381248; Read time: 8; Write time: 227560
[task 2022-02-26T11:13:25.227Z] 11:13:25     INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2022-02-26T11:13:25.230Z] 11:13:25     INFO - run-tests - Wall time: 2977s; CPU: 41%; Read bytes: 741090123776; Write bytes: 1731465216; Read time: 56485716; Write time: 204524
[task 2022-02-26T11:13:25.448Z] 11:13:25  WARNING - returning nonzero exit status 2

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1757278&startday=2022-02-21&endday=2022-02-27&tree=all

Comment 2

[BugBot [:suhaib / :marco]]

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