Closed Bug 1888787 Opened 2 years ago Closed 1 year ago

Intermittent devtools/client/webconsole/test/browser/browser_toolbox_console_new_process.js (finished) | single tracking bug

Categories

(DevTools :: Console, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, intermittent-testcase)

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


[task 2024-03-30T20:49:47.032Z] 20:49:47     INFO - TEST-OK | devtools/client/webconsole/test/browser/browser_toolbox_console_new_process.js | took 9500ms
[task 2024-03-30T20:49:47.032Z] 20:49:47     INFO - checking window state
[task 2024-03-30T20:49:47.032Z] 20:49:47     INFO - GECKO(1848) | must wait for focus
[task 2024-03-30T20:55:57.011Z] 20:55:57     INFO - TEST-UNEXPECTED-TIMEOUT | devtools/client/webconsole/test/browser/browser_toolbox_console_new_process.js (finished) | application timed out after 370 seconds with no output
[task 2024-03-30T20:55:57.011Z] 20:55:57     INFO - TEST-INFO 
[task 2024-03-30T20:55:57.011Z] 20:55:57     INFO - Buffered messages finished
[task 2024-03-30T20:55:57.011Z] 20:55:57  WARNING - Force-terminating active process(es).
[task 2024-03-30T20:55:57.012Z] 20:55:57     INFO - Determining child pids from psutil...
[task 2024-03-30T20:55:57.013Z] 20:55:57     INFO - [1849, 1850, 1851, 1852, 1853, 1869, 1943, 1944, 1945]
[task 2024-03-30T20:55:57.014Z] 20:55:57     INFO - ==> process 1848 launched child process 1849
[task 2024-03-30T20:55:57.014Z] 20:55:57     INFO - ==> process 1848 launched child process 1850
[task 2024-03-30T20:55:57.014Z] 20:55:57     INFO - ==> process 1848 launched child process 1851
[task 2024-03-30T20:55:57.015Z] 20:55:57     INFO - ==> process 1848 launched child process 1852
[task 2024-03-30T20:55:57.015Z] 20:55:57     INFO - ==> process 1848 launched child process 1853
[task 2024-03-30T20:55:57.015Z] 20:55:57     INFO - ==> process 1848 launched child process 1854
[task 2024-03-30T20:55:57.015Z] 20:55:57     INFO - ==> process 1848 launched child process 1859
[task 2024-03-30T20:55:57.016Z] 20:55:57     INFO - ==> process 1848 launched child process 1868
[task 2024-03-30T20:55:57.016Z] 20:55:57     INFO - ==> process 1848 launched child process 1869
[task 2024-03-30T20:55:57.016Z] 20:55:57     INFO - ==> process 1848 launched child process 1903
[task 2024-03-30T20:55:57.016Z] 20:55:57     INFO - ==> process 1848 launched child process 1923
[task 2024-03-30T20:55:57.017Z] 20:55:57     INFO - ==> process 1848 launched child process 1924
[task 2024-03-30T20:55:57.017Z] 20:55:57     INFO - ==> process 1848 launched child process 1925
[task 2024-03-30T20:55:57.017Z] 20:55:57     INFO - ==> process 1848 launched child process 1926
[task 2024-03-30T20:55:57.018Z] 20:55:57     INFO - ==> process 1848 launched child process 1927
[task 2024-03-30T20:55:57.018Z] 20:55:57     INFO - ==> process 1848 launched child process 1932
[task 2024-03-30T20:55:57.018Z] 20:55:57     INFO - ==> process 1848 launched child process 1939
[task 2024-03-30T20:55:57.018Z] 20:55:57     INFO - ==> process 1848 launched child process 1943
[task 2024-03-30T20:55:57.019Z] 20:55:57     INFO - ==> process 1848 launched child process 1944
[task 2024-03-30T20:55:57.019Z] 20:55:57     INFO - ==> process 1848 launched child process 1945
[task 2024-03-30T20:55:57.019Z] 20:55:57     INFO - Found child pids: {1923, 1924, 1925, 1926, 1927, 1932, 1939, 1943, 1944, 1945, 1849, 1850, 1851, 1852, 1853, 1854, 1859, 1868, 1869, 1903}
[task 2024-03-30T20:55:57.020Z] 20:55:57     INFO - Failed to get child procs
[task 2024-03-30T20:55:57.020Z] 20:55:57     INFO - Killing process: 1923
[task 2024-03-30T20:55:57.020Z] 20:55:57     INFO - TEST-INFO | started process screencapture
[task 2024-03-30T20:55:57.292Z] 20:55:57     INFO - TEST-INFO | screencapture: exit 0
[task 2024-03-30T20:55:57.292Z] 20:55:57     INFO - Can't trigger Breakpad, process no longer exists
[task 2024-03-30T20:55:57.293Z] 20:55:57     INFO - Killing process: 1924
<...>
[task 2024-03-30T20:55:57.309Z] 20:55:57     INFO - Can't trigger Breakpad, process no longer exists
[task 2024-03-30T20:55:57.310Z] 20:55:57     INFO - Killing process: 1848
[task 2024-03-30T20:55:57.310Z] 20:55:57     INFO - Not taking screenshot here: see the one that was previously logged
[task 2024-03-30T20:55:57.731Z] 20:55:57     INFO - psutil found pid 1848 dead
[task 2024-03-30T21:12:37.799Z] 21:12:37     INFO - Automation Error: mozharness timed out after 1000 seconds running ['/opt/worker/tasks/task_171183013973095/build/venv/bin/python', '-u', '/opt/worker/tasks/task_171183013973095/build/tests/mochitest/runtests.py', 'devtools/client/application/test/browser/browser.toml', 'devtools/client/framework/test/allocations/browser_allocations_browser_console.toml', 'devtools/client/framework/test/allocations/browser_allocations_reload_debugger.toml', 'devtools/client/framework/test/allocations/browser_allocations_reload_inspector.toml', 'devtools/client/framework/test/allocations/browser_allocations_reload_netmonitor.toml', 'devtools/client/framework/test/allocations/browser_allocations_reload_no_devtools.toml', 'devtools/client/framework/test/allocations/browser_allocations_reload_webconsole.toml', 'devtools/client/framework/test/allocations/browser_allocations_target.toml', 'devtools/client/framework/test/allocations/browser_allocations_toolbox.toml', 'devtools/client/framework/test/browser-telemetry-startup.toml', 'devtools/client/framework/test/metrics/browser_metrics_debugger.toml', 'devtools/client/framework/test/metrics/browser_metrics_inspector.toml', 'devtools/client/framework/test/metrics/browser_metrics_netmonitor.toml', 'devtools/client/framework/test/metrics/browser_metrics_webconsole.toml', 'devtools/client/inspector/changes/test/browser.toml', 'devtools/client/inspector/fonts/test/browser.toml', 'devtools/client/inspector/shared/test/browser.toml', 'devtools/client/netmonitor/src/har/test/browser.toml', 'devtools/client/netmonitor/test/browser_http3.toml', 'devtools/client/shared/components/test/node/stubs/reps/stubs.toml', 'devtools/client/shared/source-map-loader/test/browser/browser.toml', 'devtools/client/webconsole/test/browser/_browser_console.toml', 'devtools/client/webconsole/test/node/fixtures/stubs/stubs.toml', 'devtools/shared/commands/inspected-window/tests/browser.toml', 'devtools/shared/commands/script/tests/browser.toml', 'devtools/shared/test-helpers/browser.toml', '--setpref=layout.css.stylo-threads=4', '--setpref=media.peerconnection.mtransport_process=false', '--setpref=network.process.enabled=false', '--setpref=layers.d3d11.enable-blacklist=false', '--appname=/opt/worker/tasks/task_171183013973095/build/application/Firefox.app/Contents/MacOS/firefox', '--utility-path=tests/bin', '--extra-profile-file=tests/bin/plugins', '--symbols-path=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/HTyfDk2MSDaV1gVql8n-8g/artifacts/public/build/target.crashreporter-symbols.zip', '--certificate-path=tests/certs', '--quiet', '--log-errorsummary=/opt/worker/tasks/task_171183013973095/build/blobber_upload_dir/mochitest-devtools-chrome_errorsummary.log', '--screenshot-on-fail', '--cleanup-crashes', '--marionette-startup-timeout=180', '--sandbox-read-whitelist=/opt/worker/tasks/task_171183013973095/build', '--log-raw=-', '--flavor=browser', '--subsuite=devtools', '--chunk-by-runtime']
[task 2024-03-30T21:12:37.802Z] 21:12:37     INFO - Return code: -9
[task 2024-03-30T21:12:37.802Z] 21:12:37  WARNING - Got 1 unexpected statuses
[task 2024-03-30T21:12:37.802Z] 21:12:37    ERROR - No suite end message was emitted by this harness.
[task 2024-03-30T21:12:37.802Z] 21:12:37     INFO - TinderboxPrint: mochitest-mochitest-devtools-chrome<br/>132/<em class="testfail">1</em>/0
[task 2024-03-30T21:12:37.802Z] 21:12:37  WARNING - setting return code to 2
[task 2024-03-30T21:12:37.802Z] 21:12:37     INFO - The mochitest suite: mochitest-devtools-chrome ran with return status: FAILURE
[task 2024-03-30T21:12:37.802Z] 21:12:37     INFO - Running post-action listener: _package_coverage_data
[task 2024-03-30T21:12:37.802Z] 21:12:37     INFO - Running post-action listener: _resource_record_post_action
[task 2024-03-30T21:12:37.802Z] 21:12:37     INFO - Running post-action listener: process_java_coverage_data
[task 2024-03-30T21:12:37.802Z] 21:12:37     INFO - [mozharness: 2024-03-30 21:12:37.802923Z] Finished run-tests step (success)
[task 2024-03-30T21:12:37.803Z] 21:12:37     INFO - [mozharness: 2024-03-30 21:12:37.802964Z] Running uninstall step.
[task 2024-03-30T21:12:37.803Z] 21:12:37     INFO - Running pre-action listener: _resource_record_pre_action
[task 2024-03-30T21:12:37.803Z] 21:12:37     INFO - Running main action method: uninstall
[task 2024-03-30T21:12:37.803Z] 21:12:37     INFO - Skipping uninstall for non-MSIX test
[task 2024-03-30T21:12:37.803Z] 21:12:37     INFO - Running post-action listener: _resource_record_post_action
[task 2024-03-30T21:12:37.803Z] 21:12:37     INFO - [mozharness: 2024-03-30 21:12:37.803171Z] Finished uninstall step (success)
[task 2024-03-30T21:12:37.803Z] 21:12:37     INFO - Running post-run listener: _resource_record_post_run
[task 2024-03-30T21:12:38.374Z] 21:12:38     INFO - instance_metadata.json not found; unable to determine instance type
[task 2024-03-30T21:12:38.406Z] 21:12:38     INFO - Validating Perfherder data against /opt/worker/tasks/task_171183013973095/mozharness/external_tools/performance-artifact-schema.json
[task 2024-03-30T21:12:38.408Z] 21:12:38     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": "mochitest.mochitest-devtools-chrome.overall", "extraOptions": ["e10s", "buildbot-unknown"], "subtests": [{"name": "cpu_percent", "value": 10.375996432888154}, {"name": "io_write_bytes", "value": 1008500736}, {"name": "io.read_bytes", "value": 124981248}, {"name": "io_write_time", "value": 4828}, {"name": "io_read_time", "value": 3321}]}, {"name": "mochitest.mochitest-devtools-chrome.start-pulseaudio", "subtests": [{"name": "time", "value": 0.00026683999999477237}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-devtools-chrome.install", "subtests": [{"name": "time", "value": 30.99458313199989}, {"name": "cpu_percent", "value": 13.030976430976432}]}, {"name": "mochitest.mochitest-devtools-chrome.stage-files", "subtests": [{"name": "time", "value": 0.00023100899989003665}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-devtools-chrome.run-tests", "subtests": [{"name": "time", "value": 1741.527614447}, {"name": "cpu_percent", "value": 10.32884407634135}]}, {"name": "mochitest.mochitest-devtools-chrome.uninstall", "subtests": [{"name": "time", "value": 0.00013723699976253556}, {"name": "cpu_percent", "value": 0}]}]}
[task 2024-03-30T21:12:38.408Z] 21:12:38     INFO - Total resource usage - Wall time: 1773s; CPU: Can't collect data; Read bytes: 124981248; Write bytes: 1008500736; Read time: 3321; Write time: 4828
[task 2024-03-30T21:12:38.408Z] 21:12:38     INFO - TinderboxPrint: I/O read bytes / time<br/>124,981,248 / 3,321
[task 2024-03-30T21:12:38.408Z] 21:12:38     INFO - TinderboxPrint: I/O write bytes / time<br/>1,008,500,736 / 4,828
[task 2024-03-30T21:12:38.408Z] 21:12:38     INFO - TinderboxPrint: CPU idle<br/>19,134.2 (90.0%)
[task 2024-03-30T21:12:38.408Z] 21:12:38     INFO - TinderboxPrint: CPU user<br/>2,005.0 (9.4%)
[task 2024-03-30T21:12:38.408Z] 21:12:38     INFO - TinderboxPrint: Swap in / out<br/>429,740,032 / 0
[task 2024-03-30T21:12:38.411Z] 21:12:38     INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-03-30T21:12:38.414Z] 21:12:38     INFO - install - Wall time: 31s; CPU: 13%; Read bytes: 389309952; Write bytes: 386420736; Read time: 28668; Write time: 968
[task 2024-03-30T21:12:38.417Z] 21:12:38     INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-03-30T21:12:38.504Z] 21:12:38     INFO - run-tests - Wall time: 1742s; CPU: 10%; Read bytes: 114036736; Write bytes: 622059520; Read time: 2983; Write time: 3860
[task 2024-03-30T21:12:38.508Z] 21:12:38     INFO - uninstall - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-03-30T21:12:41.145Z] 21:12:41  WARNING - returning nonzero exit status 2
[taskcluster 2024-03-30T21:12:41.277Z]    Exit Code: 2
[taskcluster 2024-03-30T21:12:41.277Z]    User Time: 7m34.113886s
[taskcluster 2024-03-30T21:12:41.277Z]  Kernel Time: 1m1.529792s
[taskcluster 2024-03-30T21:12:41.277Z]    Wall Time: 30m59.398648s
[taskcluster 2024-03-30T21:12:41.277Z]       Result: FAILED
[taskcluster 2024-03-30T21:12:41.278Z] === Task Finished ===
[taskcluster 2024-03-30T21:12:41.278Z] Task Duration: 30m59.403432s
[taskcluster 2024-03-30T21:12:42.636Z] Uploading artifact public/logs/localconfig.json from file /opt/worker/tasks/task_171183013973095/logs/localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2024-06-28T18:47:04.654Z
[taskcluster 2024-03-30T21:12:42.936Z] Uploading artifact public/test_info/manifests.list from file /opt/worker/tasks/task_171183013973095/build/blobber_upload_dir/manifests.list with content encoding "gzip", mime type "text/plain; charset=utf-8" and expiry 2024-06-28T18:47:04.654Z
[taskcluster 2024-03-30T21:12:43.202Z] Uploading artifact public/test_info/mochitest-devtools-chrome_errorsummary.log from file /opt/worker/tasks/task_171183013973095/build/blobber_upload_dir/mochitest-devtools-chrome_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2024-06-28T18:47:04.654Z
[taskcluster 2024-03-30T21:12:43.458Z] Uploading artifact public/test_info/mozilla-test-fail-screenshot_rp_w5yq0.png from file /opt/worker/tasks/task_171183013973095/build/blobber_upload_dir/mozilla-test-fail-screenshot_rp_w5yq0.png with content encoding "identity", mime type "image/png" and expiry 2024-06-28T18:47:04.654Z
[taskcluster 2024-03-30T21:12:43.723Z] Uploading artifact public/test_info/profile_resource-usage.json from file /opt/worker/tasks/task_171183013973095/build/blobber_upload_dir/profile_resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2024-06-28T18:47:04.654Z
[taskcluster 2024-03-30T21:12:44.045Z] Uploading artifact public/test_info/resource-usage.json from file /opt/worker/tasks/task_171183013973095/build/blobber_upload_dir/resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2024-06-28T18:47:04.654Z
[taskcluster 2024-03-30T21:12:44.622Z] Uploading artifact public/test_info/system-info.log from file /opt/worker/tasks/task_171183013973095/build/blobber_upload_dir/system-info.log with content encoding "gzip", mime type "text/plain" and expiry 2024-06-28T18:47:04.654Z
[taskcluster 2024-03-30T21:12:44.888Z] Uploading link artifact public/logs/live.log to artifact public/logs/live_backing.log with expiry 2024-06-28T18:47:04.654Z
[taskcluster:error] exit status 2
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 1 year ago1 year ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.