Closed Bug 1900433 Opened 1 year ago Closed 1 year ago

Intermittent devtools/client/memory/test/browser/browser_memory_dominator_trees_01.js (finished) | single tracking bug

Categories

(DevTools :: Memory, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, intermittent-testcase)

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


[task 2024-06-03T17:26:32.618Z] 17:26:32     INFO - TEST-OK | devtools/client/memory/test/browser/browser_memory_dominator_trees_01.js | took 8042ms
[task 2024-06-03T17:26:32.627Z] 17:26:32     INFO - GECKO(1798) | [Child 1802: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 113915800 == 1 [pid = 1802] [id = 2]
[task 2024-06-03T17:26:32.627Z] 17:26:32     INFO - GECKO(1798) | [Child 1802: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (10e944200) [pid = 1802] [serial = 5] [outer = 0]
[task 2024-06-03T17:26:32.628Z] 17:26:32     INFO - GECKO(1798) | [Child 1802: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (113916000) [pid = 1802] [serial = 6] [outer = 10e944200]
[task 2024-06-03T17:26:32.650Z] 17:26:32     INFO - checking window state
[task 2024-06-03T17:26:32.650Z] 17:26:32     INFO - GECKO(1798) | must wait for focus
[task 2024-06-03T17:26:33.449Z] 17:26:33     INFO - GECKO(1798) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/40/r3s4v7650l5_ctg0b7p2x2_r000014/T/tmp2cdxs3gl.mozrunner/runtests_leaks_tab_pid1830.log
[task 2024-06-03T17:26:33.497Z] 17:26:33     INFO - GECKO(1798) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/40/r3s4v7650l5_ctg0b7p2x2_r000014/T/tmp2cdxs3gl.mozrunner/runtests_leaks_tab_pid1831.log
[task 2024-06-03T17:26:33.543Z] 17:26:33     INFO - GECKO(1798) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/40/r3s4v7650l5_ctg0b7p2x2_r000014/T/tmp2cdxs3gl.mozrunner/runtests_leaks_tab_pid1832.log
[task 2024-06-03T17:26:36.436Z] 17:26:36     INFO - GECKO(1798) | [Parent 1798: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (12ed32c00) [pid = 1798] [serial = 24] [outer = 0] [url = about:devtools-toolbox]
[task 2024-06-03T17:26:36.436Z] 17:26:36     INFO - GECKO(1798) | [Parent 1798: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (14038b000) [pid = 1798] [serial = 26] [outer = 0] [url = about:blank]
[task 2024-06-03T17:26:36.976Z] 17:26:36     INFO - GECKO(1798) | [Parent 1798: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 13 (1371ed3e0) [pid = 1798] [serial = 27] [outer = 0] [url = about:devtools-toolbox]
[task 2024-06-03T17:26:36.976Z] 17:26:36     INFO - GECKO(1798) | [Parent 1798: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 12 (1373384c0) [pid = 1798] [serial = 30] [outer = 0] [url = chrome://devtools/content/memory/index.xhtml]
[task 2024-06-03T17:26:40.288Z] 17:26:40     INFO - GECKO(1798) | [Child 1799, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2024-06-03T17:26:40.402Z] 17:26:40     INFO - GECKO(1798) | [Child 1799: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 12a82ec00 == 5 [pid = 1799] [id = 3] [url = moz-extension://5b0e0345-3dbf-4e14-967b-3f216b2c05e6/_generated_background_page.html]
[task 2024-06-03T17:26:41.102Z] 17:26:41     INFO - GECKO(1798) | [Child 1800: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 123715800 == 0 [pid = 1800] [id = 2] [url = about:blank]
[task 2024-06-03T17:26:41.485Z] 17:26:41     INFO - GECKO(1798) | [Parent 1798: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 11 (14038f000) [pid = 1798] [serial = 31] [outer = 0] [url = about:blank]
[task 2024-06-03T17:26:41.486Z] 17:26:41     INFO - GECKO(1798) | [Parent 1798: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (138746000) [pid = 1798] [serial = 29] [outer = 0] [url = about:devtools-toolbox]
[task 2024-06-03T17:26:45.870Z] 17:26:45     INFO - GECKO(1798) | [Child 1800: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (108d44200) [pid = 1800] [serial = 7] [outer = 0] [url = about:blank]
[task 2024-06-03T17:26:49.027Z] 17:26:49     INFO - GECKO(1798) | [Child 1799: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 11 (10fe44f20) [pid = 1799] [serial = 7] [outer = 0] [url = moz-extension://5b0e0345-3dbf-4e14-967b-3f216b2c05e6/_generated_background_page.html]
[task 2024-06-03T17:26:50.380Z] 17:26:50     INFO - GECKO(1798) | [Child 1800: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (123716000) [pid = 1800] [serial = 8] [outer = 0] [url = about:blank]
[task 2024-06-03T17:26:53.537Z] 17:26:53     INFO - GECKO(1798) | [Child 1799: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (12b0b6800) [pid = 1799] [serial = 14] [outer = 0] [url = moz-extension://5b0e0345-3dbf-4e14-967b-3f216b2c05e6/_generated_background_page.html]
[task 2024-06-03T17:33:03.611Z] 17:33:03     INFO - TEST-UNEXPECTED-TIMEOUT | devtools/client/memory/test/browser/browser_memory_dominator_trees_01.js (finished) | application timed out after 370 seconds with no output
[task 2024-06-03T17:33:03.611Z] 17:33:03     INFO - TEST-INFO 
[task 2024-06-03T17:33:03.611Z] 17:33:03     INFO - Buffered messages finished
[task 2024-06-03T17:33:03.611Z] 17:33:03  WARNING - Force-terminating active process(es).
[task 2024-06-03T17:33:03.612Z] 17:33:03     INFO - Determining child pids from psutil...
[task 2024-06-03T17:33:03.613Z] 17:33:03     INFO - [1799, 1800, 1801, 1802, 1804, 1830, 1831, 1832]
[task 2024-06-03T17:33:03.613Z] 17:33:03     INFO - ==> process 1798 launched child process 1799
[task 2024-06-03T17:33:03.614Z] 17:33:03     INFO - ==> process 1798 launched child process 1800
[task 2024-06-03T17:33:03.614Z] 17:33:03     INFO - ==> process 1798 launched child process 1801
[task 2024-06-03T17:33:03.614Z] 17:33:03     INFO - ==> process 1798 launched child process 1802
[task 2024-06-03T17:33:03.615Z] 17:33:03     INFO - ==> process 1798 launched child process 1803
[task 2024-06-03T17:33:03.615Z] 17:33:03     INFO - ==> process 1798 launched child process 1804
[task 2024-06-03T17:33:03.615Z] 17:33:03     INFO - ==> process 1798 launched child process 1805
[task 2024-06-03T17:33:03.615Z] 17:33:03     INFO - ==> process 1798 launched child process 1810
[task 2024-06-03T17:33:03.616Z] 17:33:03     INFO - ==> process 1798 launched child process 1811
[task 2024-06-03T17:33:03.616Z] 17:33:03     INFO - ==> process 1798 launched child process 1812
[task 2024-06-03T17:33:03.616Z] 17:33:03     INFO - ==> process 1798 launched child process 1813
[task 2024-06-03T17:33:03.617Z] 17:33:03     INFO - ==> process 1798 launched child process 1814
[task 2024-06-03T17:33:03.617Z] 17:33:03     INFO - ==> process 1798 launched child process 1815
[task 2024-06-03T17:33:03.617Z] 17:33:03     INFO - ==> process 1798 launched child process 1816
[task 2024-06-03T17:33:03.617Z] 17:33:03     INFO - ==> process 1798 launched child process 1817
[task 2024-06-03T17:33:03.618Z] 17:33:03     INFO - ==> process 1798 launched child process 1822
[task 2024-06-03T17:33:03.618Z] 17:33:03     INFO - ==> process 1798 launched child process 1830
[task 2024-06-03T17:33:03.618Z] 17:33:03     INFO - ==> process 1798 launched child process 1831
[task 2024-06-03T17:33:03.618Z] 17:33:03     INFO - ==> process 1798 launched child process 1832
[task 2024-06-03T17:33:03.619Z] 17:33:03     INFO - Found child pids: {1799, 1800, 1801, 1802, 1803, 1804, 1805, 1810, 1811, 1812, 1813, 1814, 1815, 1816, 1817, 1822, 1830, 1831, 1832}
[task 2024-06-03T17:33:03.619Z] 17:33:03     INFO - Failed to get child procs
[task 2024-06-03T17:33:03.619Z] 17:33:03     INFO - Killing process: 1799
[task 2024-06-03T17:33:03.619Z] 17:33:03     INFO - TEST-INFO | started process screencapture
[task 2024-06-03T17:33:03.733Z] 17:33:03     INFO - TEST-INFO | screencapture: exit 0
[task 2024-06-03T17:33:03.734Z] 17:33:03     INFO - Killing process: 1800
[task 2024-06-03T17:33:03.734Z] 17:33:03     INFO - Not taking screenshot here: see the one that was previously logged
<...>
[task 2024-06-03T17:33:04.068Z] 17:33:04     INFO - psutil found pid 1798 dead
[task 2024-06-03T17:49:44.260Z] 17:49:44     INFO - Automation Error: mozharness timed out after 1000 seconds running ['/opt/worker/tasks/task_171743427941879/build/venv/bin/python', '-u', '/opt/worker/tasks/task_171743427941879/build/tests/mochitest/runtests.py', 'devtools/client/aboutdebugging/test/browser/browser.toml', 'devtools/client/framework/test/browser.toml', 'devtools/client/inspector/fonts/test/browser.toml', 'devtools/client/memory/test/browser/browser.toml', 'devtools/client/shared/sourceeditor/test/browser.toml', 'devtools/server/tracer/tests/browser/browser.toml', 'devtools/shared/commands/target/tests/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_171743427941879/build/application/Firefox NightlyDebug.app/Contents/MacOS/firefox', '--utility-path=tests/bin', '--extra-profile-file=tests/bin/plugins', '--symbols-path=/opt/worker/tasks/task_171743427941879/build/symbols', '--certificate-path=tests/certs', '--quiet', '--log-errorsummary=/opt/worker/tasks/task_171743427941879/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_171743427941879/build', '--log-raw=-', '--flavor=browser', '--subsuite=devtools', '--chunk-by-runtime']
[task 2024-06-03T17:49:44.262Z] 17:49:44     INFO - Return code: -9
[task 2024-06-03T17:49:44.263Z] 17:49:44  WARNING - Got 1 unexpected statuses
[task 2024-06-03T17:49:44.263Z] 17:49:44    ERROR - No suite end message was emitted by this harness.
[task 2024-06-03T17:49:44.263Z] 17:49:44     INFO - TinderboxPrint: mochitest-mochitest-devtools-chrome<br/>226/<em class="testfail">1</em>/0
[task 2024-06-03T17:49:44.263Z] 17:49:44  WARNING - setting return code to 2
[task 2024-06-03T17:49:44.263Z] 17:49:44     INFO - The mochitest suite: mochitest-devtools-chrome ran with return status: FAILURE
[task 2024-06-03T17:49:44.263Z] 17:49:44     INFO - Running post-action listener: _package_coverage_data
[task 2024-06-03T17:49:44.263Z] 17:49:44     INFO - Running post-action listener: _resource_record_post_action
[task 2024-06-03T17:49:44.263Z] 17:49:44     INFO - Running post-action listener: process_java_coverage_data
[task 2024-06-03T17:49:44.263Z] 17:49:44     INFO - [mozharness: 2024-06-03 17:49:44.263492Z] Finished run-tests step (success)
[task 2024-06-03T17:49:44.263Z] 17:49:44     INFO - [mozharness: 2024-06-03 17:49:44.263531Z] Running uninstall step.
[task 2024-06-03T17:49:44.263Z] 17:49:44     INFO - Running pre-action listener: _resource_record_pre_action
[task 2024-06-03T17:49:44.263Z] 17:49:44     INFO - Running main action method: uninstall
[task 2024-06-03T17:49:44.263Z] 17:49:44     INFO - Skipping uninstall for non-MSIX test
[task 2024-06-03T17:49:44.263Z] 17:49:44     INFO - Running post-action listener: _resource_record_post_action
[task 2024-06-03T17:49:44.263Z] 17:49:44     INFO - [mozharness: 2024-06-03 17:49:44.263696Z] Finished uninstall step (success)
[task 2024-06-03T17:49:44.263Z] 17:49:44     INFO - Running post-run listener: _resource_record_post_run
[task 2024-06-03T17:49:45.138Z] 17:49:45     INFO - instance_metadata.json not found; unable to determine instance type
[task 2024-06-03T17:49:45.188Z] 17:49:45     INFO - Validating Perfherder data against /opt/worker/tasks/task_171743427941879/mozharness/external_tools/performance-artifact-schema.json
[task 2024-06-03T17:49:45.190Z] 17:49:45     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": "mochitest.mochitest-devtools-chrome.overall", "extraOptions": ["e10s", "buildbot-unknown"], "subtests": [{"name": "cpu_percent", "value": 15.335744595527078}, {"name": "io_write_bytes", "value": 852328448}, {"name": "io.read_bytes", "value": 198819840}, {"name": "io_write_time", "value": 4051}, {"name": "io_read_time", "value": 2823}]}, {"name": "mochitest.mochitest-devtools-chrome.start-pulseaudio", "subtests": [{"name": "time", "value": 0.00026572800000224106}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-devtools-chrome.install", "subtests": [{"name": "time", "value": 27.515111419000007}, {"name": "cpu_percent", "value": 13.70350529100529}]}, {"name": "mochitest.mochitest-devtools-chrome.stage-files", "subtests": [{"name": "time", "value": 0.00020465300002570075}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-devtools-chrome.run-tests", "subtests": [{"name": "time", "value": 2597.056016493}, {"name": "cpu_percent", "value": 15.358996007870598}]}, {"name": "mochitest.mochitest-devtools-chrome.uninstall", "subtests": [{"name": "time", "value": 0.00010347899979024078}, {"name": "cpu_percent", "value": 0}]}]}
[task 2024-06-03T17:49:45.190Z] 17:49:45     INFO - Total resource usage - Wall time: 2625s; CPU: Can't collect data; Read bytes: 198819840; Write bytes: 852328448; Read time: 2823; Write time: 4051
[task 2024-06-03T17:49:45.190Z] 17:49:45     INFO - TinderboxPrint: I/O read bytes / time<br/>198,819,840 / 2,823
[task 2024-06-03T17:49:45.190Z] 17:49:45     INFO - TinderboxPrint: I/O write bytes / time<br/>852,328,448 / 4,051
[task 2024-06-03T17:49:45.190Z] 17:49:45     INFO - TinderboxPrint: CPU idle<br/>26,859.8 (85.3%)
[task 2024-06-03T17:49:45.190Z] 17:49:45     INFO - TinderboxPrint: CPU system<br/>418.5 (1.3%)
[task 2024-06-03T17:49:45.190Z] 17:49:45     INFO - TinderboxPrint: CPU user<br/>4,214.7 (13.4%)
[task 2024-06-03T17:49:45.190Z] 17:49:45     INFO - TinderboxPrint: Swap in / out<br/>681,349,120 / 0
[task 2024-06-03T17:49:45.194Z] 17:49:45     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-06-03T17:49:45.199Z] 17:49:45     INFO - install - Wall time: 28s; CPU: 14%; Read bytes: 365368832; Write bytes: 366489600; Read time: 25607; Write time: 639
[task 2024-06-03T17:49:45.202Z] 17:49:45     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-06-03T17:49:45.338Z] 17:49:45     INFO - run-tests - Wall time: 2597s; CPU: 15%; Read bytes: 188895232; Write bytes: 485818368; Read time: 2732; Write time: 3412
[task 2024-06-03T17:49:45.345Z] 17:49:45     INFO - uninstall - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-06-03T17:49:49.408Z] 17:49:49  WARNING - returning nonzero exit status 2
[taskcluster 2024-06-03T17:49:49.597Z]    Exit Code: 2
[taskcluster 2024-06-03T17:49:49.597Z]    User Time: 45m58.428241s
[taskcluster 2024-06-03T17:49:49.597Z]  Kernel Time: 1m42.785327s
[taskcluster 2024-06-03T17:49:49.597Z]    Wall Time: 45m8.212827s
[taskcluster 2024-06-03T17:49:49.597Z]       Result: FAILED
[taskcluster 2024-06-03T17:49:49.597Z] === Task Finished ===
[taskcluster 2024-06-03T17:49:49.597Z] Task Duration: 45m8.218245s
[taskcluster 2024-06-03T17:49:49.839Z] Uploading artifact public/logs/localconfig.json from file /opt/worker/tasks/task_171743427941879/logs/localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2025-06-03T16:37:29.527Z
[taskcluster 2024-06-03T17:49:50.132Z] Uploading artifact public/test_info/manifests.list from file /opt/worker/tasks/task_171743427941879/build/blobber_upload_dir/manifests.list with content encoding "gzip", mime type "text/plain; charset=utf-8" and expiry 2025-06-03T16:37:29.527Z
[taskcluster 2024-06-03T17:49:50.379Z] Uploading artifact public/test_info/mochitest-devtools-chrome_errorsummary.log from file /opt/worker/tasks/task_171743427941879/build/blobber_upload_dir/mochitest-devtools-chrome_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2025-06-03T16:37:29.527Z
[taskcluster 2024-06-03T17:49:50.633Z] Uploading artifact public/test_info/mozilla-test-fail-screenshot_00b3pts6.png from file /opt/worker/tasks/task_171743427941879/build/blobber_upload_dir/mozilla-test-fail-screenshot_00b3pts6.png with content encoding "identity", mime type "image/png" and expiry 2025-06-03T16:37:29.527Z
[taskcluster 2024-06-03T17:49:50.897Z] Uploading artifact public/test_info/profile_resource-usage.json from file /opt/worker/tasks/task_171743427941879/build/blobber_upload_dir/profile_resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2025-06-03T16:37:29.527Z
[taskcluster 2024-06-03T17:49:51.266Z] Uploading artifact public/test_info/resource-usage.json from file /opt/worker/tasks/task_171743427941879/build/blobber_upload_dir/resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2025-06-03T16:37:29.527Z
[taskcluster 2024-06-03T17:49:52.060Z] Uploading artifact public/test_info/system-info.log from file /opt/worker/tasks/task_171743427941879/build/blobber_upload_dir/system-info.log with content encoding "gzip", mime type "text/plain" and expiry 2025-06-03T16:37:29.527Z
[taskcluster 2024-06-03T17:49:52.303Z] Uploading link artifact public/logs/live.log to artifact public/logs/live_backing.log with expiry 2025-06-03T16:37:29.527Z
[taskcluster:error] exit status 2
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.