Closed Bug 1689101 Opened 3 years ago Closed 2 years ago

Intermittent devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Uncaught exception - at chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:700 - Error: Failed waitFor():

Categories

(DevTools :: Console, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED DUPLICATE of bug 1767727

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [stockwell disabled])

Attachments

(3 files)

Filed by: smolnar [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=327957479&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/dm58qLniTeG8BVS2p-NEzQ/runs/2/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/dm58qLniTeG8BVS2p-NEzQ/runs/2/artifacts/public/logs/live_backing.log&only_show_unexpected=1


TEST-START | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js
[task 2021-01-27T11:12:04.520Z] 11:12:04     INFO - GECKO(3066) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp98Th0x.mozrunner/runtests_leaks_tab_pid3259.log
[task 2021-01-27T11:12:04.520Z] 11:12:04     INFO - GECKO(3066) | [3259, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2021-01-27T11:12:04.638Z] 11:12:04     INFO - GECKO(3066) | [Child 3259, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:629
[task 2021-01-27T11:12:05.017Z] 11:12:05     INFO - GECKO(3066) | [Child 3259: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f395cc04800 == 1 [pid = 3259] [id = 0]
[task 2021-01-27T11:12:05.078Z] 11:12:05     INFO - GECKO(3066) | [Child 3259: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f3979462e40) [pid = 3259] [serial = 1] [outer = (nil)]
[task 2021-01-27T11:12:05.078Z] 11:12:05     INFO - GECKO(3066) | [Child 3259: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f397942f800) [pid = 3259] [serial = 2] [outer = 0x7f3979462e40]
[task 2021-01-27T11:12:05.160Z] 11:12:05     INFO - GECKO(3066) | [Child 3259, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2021-01-27T11:12:05.195Z] 11:12:05     INFO - GECKO(3066) | [Child 3259: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7f395cca7800) [pid = 3259] [serial = 3] [outer = 0x7f3979462e40]
[task 2021-01-27T11:12:05.649Z] 11:12:05     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f0b0269ec00 == 8 [pid = 3066] [id = 7]
[task 2021-01-27T11:12:05.651Z] 11:12:05     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 16 (0x7f0b0d8ee200) [pid = 3066] [serial = 16] [outer = (nil)]
[task 2021-01-27T11:12:05.658Z] 11:12:05     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 17 (0x7f0b026aa000) [pid = 3066] [serial = 17] [outer = 0x7f0b0d8ee200]
[task 2021-01-27T11:12:05.679Z] 11:12:05     INFO - GECKO(3066) | [Child 3259, Main Thread] WARNING: Scrolled rect smaller than scrollport?: file /builds/worker/checkouts/gecko/layout/generic/nsGfxScrollFrame.cpp:6958
[task 2021-01-27T11:12:05.760Z] 11:12:05     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 18 (0x7f0b026a3800) [pid = 3066] [serial = 18] [outer = 0x7f0b0d8ee200]
[task 2021-01-27T11:12:05.868Z] 11:12:05     INFO - GECKO(3066) | [Parent 3066, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/dom/base/nsContentUtils.cpp:3909
[task 2021-01-27T11:12:06.045Z] 11:12:06     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f0b026a7400 == 9 [pid = 3066] [id = 8]
[task 2021-01-27T11:12:06.045Z] 11:12:06     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 19 (0x7f0b02a0e3c0) [pid = 3066] [serial = 19] [outer = (nil)]
[task 2021-01-27T11:12:06.045Z] 11:12:06     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 20 (0x7f0b02a42000) [pid = 3066] [serial = 20] [outer = 0x7f0b02a0e3c0]
[task 2021-01-27T11:12:06.264Z] 11:12:06     INFO - GECKO(3066) | [Parent 3066, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1298
[task 2021-01-27T11:12:06.566Z] 11:12:06     INFO - GECKO(3066) | [Parent 3066, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A (NS_ERROR_MALFORMED_URI): file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp:46
[task 2021-01-27T11:12:06.567Z] 11:12:06     INFO - GECKO(3066) | [Parent 3066, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp:58
[task 2021-01-27T11:12:07.940Z] 11:12:07     INFO - GECKO(3066) | [Child 3121: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f7b217ed000 == 0 [pid = 3121] [id = 0] [url = about:blank]
[task 2021-01-27T11:12:08.764Z] 11:12:08     INFO - GECKO(3066) | [Child 3138: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f48c332e800 == 3 [pid = 3138] [id = 1] [url = moz-extension://1855813a-cf94-4514-b119-afcd1a4f46d3/_generated_background_page.html]
[task 2021-01-27T11:12:08.764Z] 11:12:08     INFO - GECKO(3066) | [Child 3138: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 11 (0x7f48adaa9200) [pid = 3138] [serial = 3] [outer = (nil)] [url = moz-extension://1855813a-cf94-4514-b119-afcd1a4f46d3/_generated_background_page.html]
[task 2021-01-27T11:12:11.951Z] 11:12:11     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 19 (0x7f0b058e4900) [pid = 3066] [serial = 10] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:12.067Z] 11:12:12     INFO - GECKO(3066) | [Child 3121: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (0x7f7b21804000) [pid = 3121] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:12.107Z] 11:12:12     INFO - GECKO(3066) | [Child 3121: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f7b37c62e40) [pid = 3121] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:12.713Z] 11:12:12     INFO - GECKO(3066) | [Child 3138: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (0x7f48a6d74800) [pid = 3138] [serial = 10] [outer = (nil)] [url = moz-extension://1855813a-cf94-4514-b119-afcd1a4f46d3/_generated_background_page.html]
[task 2021-01-27T11:12:12.713Z] 11:12:12     INFO - GECKO(3066) | [Child 3138: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 9 (0x7f48c3333000) [pid = 3138] [serial = 8] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:12.714Z] 11:12:12     INFO - GECKO(3066) | [Child 3138: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 8 (0x7f48c3331c00) [pid = 3138] [serial = 6] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:12.715Z] 11:12:12     INFO - GECKO(3066) | [Child 3138: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 7 (0x7f48c332fc00) [pid = 3138] [serial = 4] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:12.716Z] 11:12:12     INFO - GECKO(3066) | [Child 3138: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 6 (0x7f48c332d800) [pid = 3138] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:14.932Z] 11:12:14     INFO - GECKO(3066) | [Child 3199: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f2edd604c00) [pid = 3199] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:15.932Z] 11:12:15     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (0x7f0b0b15c800) [pid = 3066] [serial = 8] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:15.933Z] 11:12:15     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (0x7f0b026aa000) [pid = 3066] [serial = 17] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:15.933Z] 11:12:15     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (0x7f0b0c527000) [pid = 3066] [serial = 12] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:15.954Z] 11:12:15     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f0b05885000 == 8 [pid = 3066] [id = 4] [url = about:blank]
[task 2021-01-27T11:12:15.955Z] 11:12:15     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f0b05886c00 == 7 [pid = 3066] [id = 5] [url = about:blank]
INFO - GECKO(3066) | [Child 3121: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7f7b37c31800) [pid = 3121] [serial = 3] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:16.134Z] 11:12:16     INFO - GECKO(3066) | [Child 3121: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f7b217ef800) [pid = 3121] [serial = 4] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:16.512Z] 11:12:16     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (0x7f0b058e4ac0) [pid = 3066] [serial = 11] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:17.526Z] 11:12:17     INFO - GECKO(3066) | [Child 3259: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f397942f800) [pid = 3259] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:17.883Z] 11:12:17     INFO - GECKO(3066) | [Parent 3066: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (0x7f0b0c52c400) [pid = 3066] [serial = 13] [outer = (nil)] [url = about:blank]
[task 2021-01-27T11:12:21.160Z] 11:12:21     INFO - TEST-INFO | started process screentopng
[task 2021-01-27T11:12:21.426Z] 11:12:21     INFO - TEST-INFO | screentopng: exit 0
[task 2021-01-27T11:12:21.427Z] 11:12:21     INFO - Buffered messages logged at 11:12:04
[task 2021-01-27T11:12:21.428Z] 11:12:21     INFO - Entering test bound task
[task 2021-01-27T11:12:21.429Z] 11:12:21     INFO - Adding a new tab with URL: https://example.com/browser/devtools/client/webconsole/test/browser/test-network-request.html
[task 2021-01-27T11:12:21.429Z] 11:12:21     INFO - Buffered messages logged at 11:12:05
[task 2021-01-27T11:12:21.431Z] 11:12:21     INFO - Tab added and finished loading
[task 2021-01-27T11:12:21.431Z] 11:12:21     INFO - Opening the toolbox
[task 2021-01-27T11:12:21.432Z] 11:12:21     INFO - Buffered messages logged at 11:12:06
[task 2021-01-27T11:12:21.434Z] 11:12:21     INFO - Toolbox opened and focused
[task 2021-01-27T11:12:21.434Z] 11:12:21     INFO - Test "headers" panel
[task 2021-01-27T11:12:21.435Z] 11:12:21     INFO - Buffered messages logged at 11:12:07
[task 2021-01-27T11:12:21.436Z] 11:12:21     INFO - Wait for https://example.com/browser/devtools/client/webconsole/test/browser/sjs_slow-response-test-server.sjs message
[task 2021-01-27T11:12:21.436Z] 11:12:21     INFO - Console message: [JavaScript Error: "Unknown Collection "main/partitioning-exempt-urls"" {file: "resource://services-settings/RemoteSettingsClient.jsm" line: 160}]
[task 2021-01-27T11:12:21.437Z] 11:12:21     INFO - UnknownCollectionError@resource://services-settings/RemoteSettingsClient.jsm:160:5
[task 2021-01-27T11:12:21.437Z] 11:12:21     INFO - sync@resource://services-settings/RemoteSettingsClient.jsm:470:13
[task 2021-01-27T11:12:21.437Z] 11:12:21     INFO - async*get/this._importingPromise<@resource://services-settings/RemoteSettingsClient.jsm:370:26
[task 2021-01-27T11:12:21.438Z] 11:12:21     INFO - async*get@resource://services-settings/RemoteSettingsClient.jsm:372:13
[task 2021-01-27T11:12:21.438Z] 11:12:21     INFO - async*lazyInit@resource://gre/modules/PartitioningExceptionListService.jsm:111:26
[task 2021-01-27T11:12:21.439Z] 11:12:21     INFO - registerAndRunExceptionListObserver@resource://gre/modules/PartitioningExceptionListService.jsm:135:10
...
INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Response tab is available - 
[task 2021-01-27T11:12:21.516Z] 11:12:21     INFO - Buffered messages finished
[task 2021-01-27T11:12:21.517Z] 11:12:21     INFO - TEST-UNEXPECTED-FAIL | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Uncaught exception - at chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:700 - Error: Failed waitFor(): 
[task 2021-01-27T11:12:21.517Z] 11:12:21     INFO - Failed condition: () =>
[task 2021-01-27T11:12:21.517Z] 11:12:21     INFO -     responsePanel.querySelector("#responsePayload-header")
[task 2021-01-27T11:12:21.518Z] 11:12:21     INFO - 
[task 2021-01-27T11:12:21.518Z] 11:12:21     INFO - Stack trace:
[task 2021-01-27T11:12:21.519Z] 11:12:21     INFO - waitFor@chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:700:11
[task 2021-01-27T11:12:21.519Z] 11:12:21     INFO - async*testResponse@chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js:225:39
[task 2021-01-27T11:12:21.520Z] 11:12:21     INFO - openRequestBeforeUpdates@chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js:118:13
[task 2021-01-27T11:12:21.520Z] 11:12:21     INFO - async*task@chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js:72:11
[task 2021-01-27T11:12:21.520Z] 11:12:21     INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1088:34
[task 2021-01-27T11:12:21.521Z] 11:12:21     INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1128:11
[task 2021-01-27T11:12:21.521Z] 11:12:21     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:948:14
[task 2021-01-27T11:12:21.521Z] 11:12:21     INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1037:23
[task 2021-01-27T11:12:21.521Z] 11:12:21     INFO - Leaving test bound task
[task 2021-01-27T11:12:22.512Z] 11:12:22     INFO - Removing tab.
[task 2021-01-27T11:12:22.513Z] 11:12:22     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2021-01-27T11:12:22.535Z] 11:12:22     INFO - Got event: 'TabClose' on [object XULElement].
[task 2021-01-27T11:12:22.556Z] 11:12:22     INFO - GECKO(3066) | console.warn: "IGNORED REDUX ACTION:" "AUTOCOMPLETE_CLEAR"
[task 2021-01-27T11:12:22.557Z] 11:12:22     INFO - GECKO(3066) | [Child 3259, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:327
[task 2021-01-27T11:12:22.558Z] 11:12:22     INFO - GECKO(3066) | [Child 3259, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:327
[task 2021-01-27T11:12:22.561Z] 11:12:22     INFO - GECKO(3066) | [Parent 3066, Main Thread] WARNING: NS_ENSURE_TRUE(uri) failed: file /builds/worker/checkouts/gecko/caps/BasePrincipal.cpp:1327
[task 2021-01-27T11:12:22.561Z] 11:12:22     INFO - GECKO(3066) | [Parent 3066, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:181
[task 2021-01-27T11:12:22.568Z] 11:12:22     INFO - Tab removed and finished closing
[task 2021-01-27T11:12:22.644Z] 11:12:22     INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | The main process DevToolsServer has no pending connection when the test ends - ```

Tier1 failure log: https://treeherder.mozilla.org/logviewer?job_id=328004018&repo=autoland&lineNumber=8460

[task 2021-01-27T19:09:38.370Z] 19:09:38 INFO - TEST-START | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js
[task 2021-01-27T19:09:38.406Z] 19:09:38 INFO - GECKO(1546) | [Child 1778: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f8dacf0c400 == 1 [pid = 1778] [id = 51]
[task 2021-01-27T19:09:38.407Z] 19:09:38 INFO - GECKO(1546) | [Child 1778: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f8daee79580) [pid = 1778] [serial = 162] [outer = (nil)]
[task 2021-01-27T19:09:38.408Z] 19:09:38 INFO - GECKO(1546) | [Child 1778: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f8dacf0d800) [pid = 1778] [serial = 163] [outer = 0x7f8daee79580]
[task 2021-01-27T19:09:38.585Z] 19:09:38 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (0x7f2d767143c0) [pid = 1546] [serial = 665] [outer = (nil)] [url = about:devtools-toolbox]
[task 2021-01-27T19:09:38.585Z] 19:09:38 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (0x7f2d8f2d4e40) [pid = 1546] [serial = 668] [outer = (nil)] [url = chrome://devtools/content/webconsole/index.html]
[task 2021-01-27T19:09:38.586Z] 19:09:38 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f2d75fc0400 == 7 [pid = 1546] [id = 274] [url = chrome://devtools/content/webconsole/index.html]
[task 2021-01-27T19:09:38.605Z] 19:09:38 INFO - GECKO(1546) | [Child 1778: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7f8dad7b3c00) [pid = 1778] [serial = 164] [outer = 0x7f8daee79580]
[task 2021-01-27T19:09:38.866Z] 19:09:38 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f2d714ce400 == 8 [pid = 1546] [id = 277]
[task 2021-01-27T19:09:38.866Z] 19:09:38 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 18 (0x7f2d767143c0) [pid = 1546] [serial = 675] [outer = (nil)]
[task 2021-01-27T19:09:38.867Z] 19:09:38 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 19 (0x7f2d75fc5000) [pid = 1546] [serial = 676] [outer = 0x7f2d767143c0]
[task 2021-01-27T19:09:38.890Z] 19:09:38 INFO - GECKO(1546) | [Child 1778, Main Thread] WARNING: Scrolled rect smaller than scrollport?: file /builds/worker/checkouts/gecko/layout/generic/nsGfxScrollFrame.cpp:6958
[task 2021-01-27T19:09:38.931Z] 19:09:38 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 20 (0x7f2d75fc6c00) [pid = 1546] [serial = 677] [outer = 0x7f2d767143c0]
[task 2021-01-27T19:09:39.019Z] 19:09:39 INFO - GECKO(1546) | [Parent 1546, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/dom/base/nsContentUtils.cpp:3909
[task 2021-01-27T19:09:39.122Z] 19:09:39 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f2d75fc3400 == 9 [pid = 1546] [id = 278]
[task 2021-01-27T19:09:39.125Z] 19:09:39 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 21 (0x7f2d8f2d4e40) [pid = 1546] [serial = 678] [outer = (nil)]
[task 2021-01-27T19:09:39.126Z] 19:09:39 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 22 (0x7f2d76763000) [pid = 1546] [serial = 679] [outer = 0x7f2d8f2d4e40]
[task 2021-01-27T19:09:39.316Z] 19:09:39 INFO - GECKO(1546) | [Parent 1546, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1298
[task 2021-01-27T19:09:39.574Z] 19:09:39 INFO - GECKO(1546) | [Child 1606: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (0x7f36fc07c800) [pid = 1606] [serial = 212] [outer = (nil)] [url = about:blank]
[task 2021-01-27T19:09:39.576Z] 19:09:39 INFO - GECKO(1546) | [Child 1606: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (0x7f36fc086c00) [pid = 1606] [serial = 215] [outer = (nil)] [url = http://example.com/browser/devtools/client/webconsole/test/browser/test-console.html]
[task 2021-01-27T19:09:39.577Z] 19:09:39 INFO - GECKO(1546) | [Child 1606: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (0x7f36fcd96400) [pid = 1606] [serial = 216] [outer = (nil)] [url = http://example.com/browser/devtools/client/webconsole/test/browser/test-console.html]
[task 2021-01-27T19:09:39.578Z] 19:09:39 INFO - GECKO(1546) | [Child 1606: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f36fc07f800) [pid = 1606] [serial = 214] [outer = (nil)] [url = about:blank]
[task 2021-01-27T19:09:39.579Z] 19:09:39 INFO - GECKO(1546) | [Child 1606: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f36fc082c00 == 0 [pid = 1606] [id = 85] [url = about:blank]
[task 2021-01-27T19:09:39.580Z] 19:09:39 INFO - GECKO(1546) | [Parent 1546, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A (NS_ERROR_MALFORMED_URI): file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp:46
[task 2021-01-27T19:09:39.581Z] 19:09:39 INFO - GECKO(1546) | [Parent 1546, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp:58
[task 2021-01-27T19:09:39.675Z] 19:09:39 INFO - GECKO(1546) | [Child 1606: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7f36fdf7dc80) [pid = 1606] [serial = 217] [outer = (nil)] [url = about:blank]
[task 2021-01-27T19:09:40.207Z] 19:09:40 INFO - GECKO(1546) | [Child 1714: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f5190dc6c00 == 1 [pid = 1714] [id = 82] [url = https://example.com/browser/devtools/client/webconsole/test/browser/test-network-request.html]
[task 2021-01-27T19:09:40.208Z] 19:09:40 INFO - GECKO(1546) | [Child 1714: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (0x7f5190dc9000) [pid = 1714] [serial = 221] [outer = (nil)] [url = about:blank]
[task 2021-01-27T19:09:40.208Z] 19:09:40 INFO - GECKO(1546) | [Child 1714: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (0x7f5190de8400) [pid = 1714] [serial = 219] [outer = (nil)] [url = about:blank]
[task 2021-01-27T19:09:40.337Z] 19:09:40 INFO - GECKO(1546) | [Child 1714: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (0x7f51923c93c0) [pid = 1714] [serial = 220] [outer = (nil)] [url = https://example.com/browser/devtools/client/webconsole/test/browser/test-network-request.html]
[task 2021-01-27T19:09:41.552Z] 19:09:41 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f2d75fc4c00 == 8 [pid = 1546] [id = 275] [url = about:devtools-toolbox]
[task 2021-01-27T19:09:42.639Z] 19:09:42 INFO - GECKO(1546) | [Child 1714: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f5190df2c00) [pid = 1714] [serial = 222] [outer = (nil)] [url = https://example.com/browser/devtools/client/webconsole/test/browser/test-network-request.html]
[task 2021-01-27T19:09:43.702Z] 19:09:43 INFO - GECKO(1546) | [Child 1606: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f36fc085400) [pid = 1606] [serial = 218] [outer = (nil)] [url = about:blank]
[task 2021-01-27T19:09:45.295Z] 19:09:45 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 21 (0x7f2d75fc1400) [pid = 1546] [serial = 671] [outer = (nil)] [url = about:blank]
[task 2021-01-27T19:09:45.296Z] 19:09:45 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 20 (0x7f2d76765400) [pid = 1546] [serial = 669] [outer = (nil)] [url = about:blank]
[task 2021-01-27T19:09:45.297Z] 19:09:45 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 19 (0x7f2d76767800) [pid = 1546] [serial = 667] [outer = (nil)] [url = about:devtools-toolbox]
[task 2021-01-27T19:09:47.228Z] 19:09:47 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f2d75fc7800 == 7 [pid = 1546] [id = 276] [url = chrome://devtools/content/webconsole/index.html]
[task 2021-01-27T19:09:47.229Z] 19:09:47 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (0x7f2d8f2d4740) [pid = 1546] [serial = 673] [outer = (nil)] [url = chrome://devtools/content/webconsole/index.html]
[task 2021-01-27T19:09:47.230Z] 19:09:47 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (0x7f2d76714900) [pid = 1546] [serial = 670] [outer = (nil)] [url = about:devtools-toolbox]
[task 2021-01-27T19:09:50.163Z] 19:09:50 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (0x7f2d75fc5000) [pid = 1546] [serial = 676] [outer = (nil)] [url = about:blank]
[task 2021-01-27T19:09:50.183Z] 19:09:50 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (0x7f2d76761800) [pid = 1546] [serial = 672] [outer = (nil)] [url = about:devtools-toolbox]
[task 2021-01-27T19:09:50.183Z] 19:09:50 INFO - GECKO(1546) | [Parent 1546: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (0x7f2d7676c000) [pid = 1546] [serial = 674] [outer = (nil)] [url = about:blank]
[task 2021-01-27T19:09:51.155Z] 19:09:51 INFO - GECKO(1546) | [Child 1778: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f8dacf0d800) [pid = 1778] [serial = 163] [outer = (nil)] [url = about:blank]
[task 2021-01-27T19:09:54.043Z] 19:09:54 INFO - TEST-INFO | started process screentopng
[task 2021-01-27T19:09:54.345Z] 19:09:54 INFO - TEST-INFO | screentopng: exit 0

[task 2021-01-27T19:09:54.408Z] 19:09:54 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Security tab is available -
[task 2021-01-27T19:09:54.409Z] 19:09:54 INFO - Buffered messages logged at 19:09:48
[task 2021-01-27T19:09:54.409Z] 19:09:54 INFO - Test "response" panel
[task 2021-01-27T19:09:54.410Z] 19:09:54 INFO - Wait for https://example.com/browser/devtools/client/webconsole/test/browser/sjs_slow-response-test-server.sjs message
[task 2021-01-27T19:09:54.411Z] 19:09:54 INFO - Matched a message with text: "https://example.com/browser/devtools/client/webconsole/test/browser/sjs_slow-response-test-server.sjs", all messages received.
[task 2021-01-27T19:09:54.413Z] 19:09:54 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Network message found. -
[task 2021-01-27T19:09:54.413Z] 19:09:54 INFO - Click on XHR message and wait for the network detail panel to be displayed
[task 2021-01-27T19:09:54.414Z] 19:09:54 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | The correct tab is selected -
[task 2021-01-27T19:09:54.415Z] 19:09:54 INFO - Test that the tab is empty
[task 2021-01-27T19:09:54.415Z] 19:09:54 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Cookies tab is empty -
[task 2021-01-27T19:09:54.416Z] 19:09:54 INFO - Test content of the default tab
[task 2021-01-27T19:09:54.417Z] 19:09:54 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Response tab is available -
[task 2021-01-27T19:09:54.417Z] 19:09:54 INFO - Buffered messages finished
[task 2021-01-27T19:09:54.418Z] 19:09:54 INFO - TEST-UNEXPECTED-FAIL | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Uncaught exception - at chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:700 - Error: Failed waitFor():
[task 2021-01-27T19:09:54.419Z] 19:09:54 INFO - Failed condition: () =>
[task 2021-01-27T19:09:54.419Z] 19:09:54 INFO - responsePanel.querySelector("#responsePayload-header")
[task 2021-01-27T19:09:54.420Z] 19:09:54 INFO -
[task 2021-01-27T19:09:54.420Z] 19:09:54 INFO - Stack trace:
[task 2021-01-27T19:09:54.421Z] 19:09:54 INFO - waitFor@chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:700:11
[task 2021-01-27T19:09:54.422Z] 19:09:54 INFO - asynctestResponse@chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js:225:39
[task 2021-01-27T19:09:54.422Z] 19:09:54 INFO - openRequestBeforeUpdates@chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js:118:13
[task 2021-01-27T19:09:54.423Z] 19:09:54 INFO - async
task@chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js:72:11
[task 2021-01-27T19:09:54.423Z] 19:09:54 INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1088:34
[task 2021-01-27T19:09:54.424Z] 19:09:54 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1128:11
[task 2021-01-27T19:09:54.425Z] 19:09:54 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:948:14
[task 2021-01-27T19:09:54.425Z] 19:09:54 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1037:23
[task 2021-01-27T19:09:54.426Z] 19:09:54 INFO - Leaving test bound task
[task 2021-01-27T19:09:55.614Z] 19:09:55 INFO - Removing tab.
[task 2021-01-27T19:09:55.614Z] 19:09:55 INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2021-01-27T19:09:55.630Z] 19:09:55 INFO - Got event: 'TabClose' on [object XULElement].
[task 2021-01-27T19:09:55.634Z] 19:09:55 INFO - GECKO(1546) | console.warn: "IGNORED REDUX ACTION:" "AUTOCOMPLETE_CLEAR"
[task 2021-01-27T19:09:55.650Z] 19:09:55 INFO - GECKO(1546) | [Child 1778, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:327
[task 2021-01-27T19:09:55.651Z] 19:09:55 INFO - GECKO(1546) | [Child 1778, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:327
[task 2021-01-27T19:09:55.652Z] 19:09:55 INFO - GECKO(1546) | [Parent 1546, Main Thread] WARNING: NS_ENSURE_TRUE(uri) failed: file /builds/worker/checkouts/gecko/caps/BasePrincipal.cpp:1327
[task 2021-01-27T19:09:55.653Z] 19:09:55 INFO - GECKO(1546) | [Parent 1546, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:181
[task 2021-01-27T19:09:55.662Z] 19:09:55 INFO - Tab removed and finished closing
[task 2021-01-27T19:09:55.722Z] 19:09:55 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | The main process DevToolsServer has no pending connection when the test ends -
[task 2021-01-27T19:09:55.749Z] 19:09:55 INFO - GECKO(1546) | MEMORY STAT | vsize 3736MB | residentFast 491MB | heapAllocated 158MB
[task 2021-01-27T19:09:55.750Z] 19:09:55 INFO - TEST-OK | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | took 17376ms
[task 2021-01-27T19:09:55.765Z] 19:09:55 INFO - GECKO(1546) | [Child 1606: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f36fc07c000 == 1 [pid = 1606] [id = 86]
[task 2021-01-27T19:09:55.766Z] 19:09:55 INFO - GECKO(1546) | [Child 1606: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f36fdf7d740) [pid = 1606] [serial = 219] [outer = (nil)]
[task 2021-01-27T19:09:55.767Z] 19:09:55 INFO - GECKO(1546) | [Child 1606: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f36fc07dc00) [pid = 1606] [serial = 220] [outer = 0x7f36fdf7d740]
[task 2021-01-27T19:09:55.806Z] 19:09:55 INFO - checking window state

Regressed by: 1438979
Has Regression Range: --- → yes
Summary: Intermittent TV devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Uncaught exception - at chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:700 - Error: Failed waitFor(): → Intermittent devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Uncaught exception - at chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:700 - Error: Failed waitFor():

There are 22 total failures in the last 7 days on

  • linux1804-64 debug and opt
  • linux1804-64-shippable opt
  • windows10-64 opt
  • windows10-64-shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=329805699&repo=autoland&lineNumber=9483

[task 2021-02-12T17:51:25.099Z] 17:51:25 INFO - TEST-START | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js
[task 2021-02-12T17:51:25.203Z] 17:51:25 INFO - GECKO(1532) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpFG9N1C.mozrunner/runtests_leaks_tab_pid3739.log
[task 2021-02-12T17:51:25.203Z] 17:51:25 INFO - GECKO(1532) | [3739, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2021-02-12T17:51:25.259Z] 17:51:25 INFO - GECKO(1532) | [Child 3714: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f8b75363c80) [pid = 3714] [serial = 1] [outer = (nil)] [url = https://example.com/browser/devtools/client/webconsole/test/browser/test-network-request.html]
[task 2021-02-12T17:51:25.259Z] 17:51:25 INFO - GECKO(1532) | [Child 3714: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7f8b58b0b400) [pid = 3714] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2021-02-12T17:51:25.259Z] 17:51:25 INFO - GECKO(1532) | [Child 3714: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f8b58bccc00) [pid = 3714] [serial = 3] [outer = (nil)] [url = https://example.com/browser/devtools/client/webconsole/test/browser/test-network-request.html]
[task 2021-02-12T17:51:25.315Z] 17:51:25 INFO - GECKO(1532) | [Child 3714, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3365
[task 2021-02-12T17:51:25.351Z] 17:51:25 INFO - GECKO(1532) | [Child 3714, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4381
[task 2021-02-12T17:51:25.381Z] 17:51:25 INFO - GECKO(1532) | [Child 3739, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:619
[task 2021-02-12T17:51:25.619Z] 17:51:25 INFO - GECKO(1532) | [Child 3739: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7fd0b0104800 == 1 [pid = 3739] [id = 0]

[task 2021-02-12T17:51:41.777Z] 17:51:41 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Security tab is available -
[task 2021-02-12T17:51:41.777Z] 17:51:41 INFO - Test "response" panel
[task 2021-02-12T17:51:41.777Z] 17:51:41 INFO - Wait for https://example.com/browser/devtools/client/webconsole/test/browser/sjs_slow-response-test-server.sjs message
[task 2021-02-12T17:51:41.778Z] 17:51:41 INFO - Matched a message with text: "https://example.com/browser/devtools/client/webconsole/test/browser/sjs_slow-response-test-server.sjs", all messages received.
[task 2021-02-12T17:51:41.778Z] 17:51:41 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Network message found. -
[task 2021-02-12T17:51:41.779Z] 17:51:41 INFO - Click on XHR message and wait for the network detail panel to be displayed
[task 2021-02-12T17:51:41.780Z] 17:51:41 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | The correct tab is selected -
[task 2021-02-12T17:51:41.780Z] 17:51:41 INFO - Test that the tab is empty
[task 2021-02-12T17:51:41.780Z] 17:51:41 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Cookies tab is empty -
[task 2021-02-12T17:51:41.780Z] 17:51:41 INFO - Test content of the default tab
[task 2021-02-12T17:51:41.781Z] 17:51:41 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Response tab is available -
[task 2021-02-12T17:51:41.781Z] 17:51:41 INFO - Buffered messages finished
[task 2021-02-12T17:51:41.785Z] 17:51:41 INFO - TEST-UNEXPECTED-FAIL | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Uncaught exception - at chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:687 - Error: Failed waitFor():
[task 2021-02-12T17:51:41.785Z] 17:51:41 INFO - Failed condition: () =>
[task 2021-02-12T17:51:41.786Z] 17:51:41 INFO - responsePanel.querySelector("#responsePayload-header")
[task 2021-02-12T17:51:41.786Z] 17:51:41 INFO -
[task 2021-02-12T17:51:41.786Z] 17:51:41 INFO - Stack trace:
[task 2021-02-12T17:51:41.786Z] 17:51:41 INFO - waitFor@chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:687:11
[task 2021-02-12T17:51:41.787Z] 17:51:41 INFO - asynctestResponse@chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js:225:39
[task 2021-02-12T17:51:41.791Z] 17:51:41 INFO - openRequestBeforeUpdates@chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js:118:13
[task 2021-02-12T17:51:41.792Z] 17:51:41 INFO - async
task@chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js:72:11
[task 2021-02-12T17:51:41.792Z] 17:51:41 INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1088:34
[task 2021-02-12T17:51:41.793Z] 17:51:41 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1128:11
[task 2021-02-12T17:51:41.793Z] 17:51:41 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:948:14
[task 2021-02-12T17:51:41.793Z] 17:51:41 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1037:23
[task 2021-02-12T17:51:41.794Z] 17:51:41 INFO - Leaving test bound task
[task 2021-02-12T17:51:42.891Z] 17:51:42 INFO - Removing tab.
[task 2021-02-12T17:51:42.891Z] 17:51:42 INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2021-02-12T17:51:42.910Z] 17:51:42 INFO - Got event: 'TabClose' on [object XULElement].
[task 2021-02-12T17:51:42.918Z] 17:51:42 INFO - GECKO(1532) | console.warn: "IGNORED REDUX ACTION:" "AUTOCOMPLETE_CLEAR"
[task 2021-02-12T17:51:42.929Z] 17:51:42 INFO - GECKO(1532) | [Child 3739, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:327
[task 2021-02-12T17:51:42.930Z] 17:51:42 INFO - GECKO(1532) | [Parent 1532, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:181
[task 2021-02-12T17:51:42.931Z] 17:51:42 INFO - GECKO(1532) | [Child 3739, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:327
[task 2021-02-12T17:51:42.932Z] 17:51:42 INFO - Tab removed and finished closing
[task 2021-02-12T17:51:42.994Z] 17:51:42 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | The main process DevToolsServer has no pending connection when the test ends -
[task 2021-02-12T17:51:43.029Z] 17:51:43 INFO - GECKO(1532) | MEMORY STAT | vsize 3564MB | residentFast 482MB | heapAllocated 159MB
[task 2021-02-12T17:51:43.030Z] 17:51:43 INFO - TEST-OK | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | took 17933ms
[task 2021-02-12T17:51:43.050Z] 17:51:43 INFO - GECKO(1532) | [Child 1604: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f6ba8686400 == 1 [pid = 1604] [id = 67]
[task 2021-02-12T17:51:43.051Z] 17:51:43 INFO - GECKO(1532) | [Child 1604: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f6ba7e99200) [pid = 1604] [serial = 161] [outer = (nil)]
[task 2021-02-12T17:51:43.052Z] 17:51:43 INFO - GECKO(1532) | [Child 1604: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f6ba8688000) [pid = 1604] [serial = 162] [outer = 0x7f6ba7e99200]
[task 2021-02-12T17:51:43.134Z] 17:51:43 INFO - checking window state
Nicolas, please take a look.

Flags: needinfo?(nchevobbe)
Whiteboard: [stockwell needswork:owner]

There have been a total of 32 failures in the past 7 days on:

  • linux1804-64 debug
  • macosx1014-64-qr debug
  • windows10-64 opt and debug
  • windows10-64-shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=333386035&repo=autoland&lineNumber=28969

Assignee: nobody → abutkovits
Status: NEW → ASSIGNED
Pushed by abutkovits@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/06dec8e12c2f
disable browser_webconsole_network_messages_expand_before_updates.js on Windows for frequent failures. r=intermittent-reviewers,jmaher DONTBUILD
Keywords: leave-open
Whiteboard: [stockwell unknown] → [stockwell disabled]
Assignee: abutkovits → nobody
Status: ASSIGNED → NEW
Flags: needinfo?(jdescottes)

Was not able to get any confirmation about the impact of this change with try pushes.
However all the failures seem related to random waitFor calls in this test, without any regular pattern.
I suspect that our waitFor delay might be too short in some cases, increasing the interval will allow to verify this assumption.

Flags: needinfo?(nchevobbe)
Flags: needinfo?(jdescottes)
Pushed by jdescottes@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/f0477710867c
[devtools] Increase waitFor interval in browser_webconsole_network_messages_expand_before_updates r=nchevobbe

Looks like increasing the interval didn't actually solve this, even though I had a promising try push at https://treeherder.mozilla.org/jobs?repo=try&revision=d7e349df8606582bdce826bb6ffc04f1f3933bd6&searchStr=dt11 (all oranges are infra related)

I am wondering if we should increase the interval even more to fully rule out the waitFor timeout suspicion.

Update:
There have been 33 failures within the last 7 days:
• 1 failures on Linux 18.04 x64 WebRender asan opt
• 4 failures on Linux 18.04 x64 WebRender opt
• 22 failures on Linux 18.04 x64 WebRender debug
• 1 failures on Linux 18.04 x64 WebRender Shippable opt
• 1 failures on OS X 10.15 WebRender opt
• 4 failures on OS X 10.15 WebRender debug
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=347720002&repo=autoland&lineNumber=8666

[task 2021-08-07T05:49:37.819Z] 05:49:37     INFO - TEST-START | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js
[task 2021-08-07T05:49:37.874Z] 05:49:37     INFO - GECKO(1547) | [Child 1619: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f8ce5c1f000 == 2 [pid = 1619] [id = 95]
[task 2021-08-07T05:49:37.876Z] 05:49:37     INFO - GECKO(1547) | [Child 1619: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (7f8ce53183c0) [pid = 1619] [serial = 255] [outer = 0]
[task 2021-08-07T05:49:37.881Z] 05:49:37     INFO - GECKO(1547) | [Child 1619: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (7f8ce5c20c00) [pid = 1619] [serial = 256] [outer = 7f8ce53183c0]
[task 2021-08-07T05:49:38.096Z] 05:49:38     INFO - GECKO(1547) | [Parent 1547: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f3527327000 == 8 [pid = 1547] [id = 277] [url = chrome://devtools/content/webconsole/index.html]
<...>
[task 2021-08-07T05:50:14.063Z] 05:50:14     INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Response tab is available - 
[task 2021-08-07T05:50:14.064Z] 05:50:14     INFO - Buffered messages finished
[task 2021-08-07T05:50:14.066Z] 05:50:14     INFO - TEST-UNEXPECTED-FAIL | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | Uncaught exception - at chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:763 - Error: Failed waitFor(): 
[task 2021-08-07T05:50:14.066Z] 05:50:14     INFO - Failed condition: () =>
[task 2021-08-07T05:50:14.067Z] 05:50:14     INFO -     responsePanel.querySelector(".data-header")
[task 2021-08-07T05:50:14.067Z] 05:50:14     INFO - 
[task 2021-08-07T05:50:14.068Z] 05:50:14     INFO - Stack trace:
[task 2021-08-07T05:50:14.068Z] 05:50:14     INFO - waitFor@chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:763:11
[task 2021-08-07T05:50:14.068Z] 05:50:14     INFO - async*testResponse@chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js:226:39
[task 2021-08-07T05:50:14.069Z] 05:50:14     INFO - openRequestBeforeUpdates@chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js:119:13
[task 2021-08-07T05:50:14.069Z] 05:50:14     INFO - async*task@chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js:73:11
[task 2021-08-07T05:50:14.069Z] 05:50:14     INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1098:34
[task 2021-08-07T05:50:14.070Z] 05:50:14     INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1138:11
[task 2021-08-07T05:50:14.070Z] 05:50:14     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:946:14
[task 2021-08-07T05:50:14.071Z] 05:50:14     INFO - SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1041:13
[task 2021-08-07T05:50:14.071Z] 05:50:14     INFO - Leaving test bound task
[task 2021-08-07T05:50:15.242Z] 05:50:15     INFO - Removing tab.
[task 2021-08-07T05:50:15.244Z] 05:50:15     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2021-08-07T05:50:15.267Z] 05:50:15     INFO - Got event: 'TabClose' on [object XULElement].
[task 2021-08-07T05:50:15.273Z] 05:50:15     INFO - GECKO(1547) | console.warn: "IGNORED REDUX ACTION:" "AUTOCOMPLETE_CLEAR"
[task 2021-08-07T05:50:15.284Z] 05:50:15     INFO - GECKO(1547) | [Child 1619, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:327
[task 2021-08-07T05:50:15.285Z] 05:50:15     INFO - GECKO(1547) | [Parent 1547, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:184
[task 2021-08-07T05:50:15.286Z] 05:50:15     INFO - GECKO(1547) | [Child 1619, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:327
[task 2021-08-07T05:50:15.295Z] 05:50:15     INFO - Tab removed and finished closing
[task 2021-08-07T05:50:15.332Z] 05:50:15     INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | The main process DevToolsServer has no pending connection when the test ends - 
[task 2021-08-07T05:50:15.682Z] 05:50:15     INFO - GECKO(1547) | MEMORY STAT | vsize 3816MB | residentFast 611MB | heapAllocated 272MB
[task 2021-08-07T05:50:15.682Z] 05:50:15     INFO - TEST-OK | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_expand_before_updates.js | took 37862ms
[task 2021-08-07T05:50:15.692Z] 05:50:15     INFO - GECKO(1547) | [Child 1619: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f8ce5c1d800 == 2 [pid = 1619] [id = 96]
[task 2021-08-07T05:50:15.694Z] 05:50:15     INFO - GECKO(1547) | [Child 1619: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (7f8ce5318580) [pid = 1619] [serial = 258] [outer = 0]
[task 2021-08-07T05:50:15.696Z] 05:50:15     INFO - GECKO(1547) | [Child 1619: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (7f8ce5c21000) [pid = 1619] [serial = 259] [outer = 7f8ce5318580]
[task 2021-08-07T05:50:15.732Z] 05:50:15     INFO - checking window state
[task 2021-08-07T05:50:15.750Z] 05:50:15     INFO - TEST-START | devtools/client/webconsole/test/browser/browser_webconsole_network_messages_openinnet.js
Whiteboard: [stockwell disabled] → [stockwell disabled][stockwell needswork:owner]

Nicolas, as the owner of this component, could you help us assign it to someone?
Thank you.

Flags: needinfo?(nchevobbe)

I think bomsy was going to look into that :)

Flags: needinfo?(nchevobbe) → needinfo?(hmanilla)
Pushed by abutkovits@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/c8aa1ced6aaa
disable browser_webconsole_network_messages_expand_before_updates.js on Linux_64_QR for frequent failures. r=intermittent-reviewers,jmaher DONTBUILD
Whiteboard: [stockwell disabled][stockwell needswork:owner] → [stockwell disabled]
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → DUPLICATE
Flags: needinfo?(hmanilla)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: