Closed Bug 1744565 Opened 3 years ago Closed 5 months ago

Intermittent devtools/shared/commands/resource/tests/browser_resources_sources.js | Uncaught exception - at chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:1012 - Error: Failed waitFor(): Got all the sources

Categories

(DevTools :: General, defect, P5)

defect

Tracking

(firefox-esr91 unaffected, firefox95 unaffected, firefox96 unaffected, firefox97 affected)

RESOLVED DUPLICATE of bug 1874227
Tracking Status
firefox-esr91 --- unaffected
firefox95 --- unaffected
firefox96 --- unaffected
firefox97 --- affected

People

(Reporter: intermittent-bug-filer, Assigned: ochameau)

References

(Blocks 1 open bug, Regression)

Details

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

Attachments

(3 files)

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


[task 2021-12-06T17:16:01.569Z] 17:16:01     INFO - TEST-START | devtools/shared/commands/resource/tests/browser_resources_sources.js
[task 2021-12-06T17:16:01.641Z] 17:16:01     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7fb27e86b800 == 2 [pid = 1638] [id = 27]
[task 2021-12-06T17:16:01.643Z] 17:16:01     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 16 (7fb29a87d3c0) [pid = 1638] [serial = 71] [outer = 0]
[task 2021-12-06T17:16:01.644Z] 17:16:01     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 17 (7fb27e86c000) [pid = 1638] [serial = 72] [outer = 7fb29a87d3c0]
[task 2021-12-06T17:16:01.936Z] 17:16:01     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 18 (7fb27e870000) [pid = 1638] [serial = 73] [outer = 7fb29a87d3c0]
[task 2021-12-06T17:16:02.110Z] 17:16:02     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7fb27e871800 == 3 [pid = 1638] [id = 28]
[task 2021-12-06T17:16:02.110Z] 17:16:02     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 19 (7fb29a87d900) [pid = 1638] [serial = 74] [outer = 0]
[task 2021-12-06T17:16:02.111Z] 17:16:02     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 20 (7fb27e872400) [pid = 1638] [serial = 75] [outer = 7fb29a87d900]
[task 2021-12-06T17:16:02.185Z] 17:16:02     INFO - GECKO(1561) | [Child 1638, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1208
[task 2021-12-06T17:16:02.502Z] 17:16:02     INFO - GECKO(1561) | [Child 1777: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (7fbaa3b45800) [pid = 1777] [serial = 41] [outer = 0] [url = about:blank]
[task 2021-12-06T17:16:02.503Z] 17:16:02     INFO - GECKO(1561) | [Child 1777: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7fbaa3b45000 == 1 [pid = 1777] [id = 15] [url = data:text/html,Root Node tests]
[task 2021-12-06T17:16:02.855Z] 17:16:02     INFO - GECKO(1561) | [Child 1777: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 9 (7fbaa3b48800) [pid = 1777] [serial = 39] [outer = 0] [url = about:blank]
[task 2021-12-06T17:16:02.858Z] 17:16:02     INFO - GECKO(1561) | [Child 1777: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 8 (7fbabf97d580) [pid = 1777] [serial = 33] [outer = 0] [url = data:text/html,<div id=div3>]
[task 2021-12-06T17:16:05.056Z] 17:16:05     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7fb2804c0400 == 2 [pid = 1638] [id = 26] [url = about:blank]
[task 2021-12-06T17:16:05.057Z] 17:16:05     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 19 (7fb27e86cc00) [pid = 1638] [serial = 63] [outer = 0] [url = about:blank]
[task 2021-12-06T17:16:05.476Z] 17:16:05     INFO - GECKO(1561) | [Child 1638, Main Thread] WARNING: Unable to get a docShell from the channel!: file /builds/worker/checkouts/gecko/dom/jsurl/nsJSProtocolHandler.cpp:121
[task 2021-12-06T17:16:05.479Z] 17:16:05     INFO - GECKO(1561) | SourceActor threw an exception: [Exception... "Failed to open input source 'javascript:666'"  nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)"  location: "JS frame :: resource://devtools/shared/DevToolsUtils.js :: mainThreadFetch/< :: line 670"  data: yes]
[task 2021-12-06T17:16:05.479Z] 17:16:05     INFO - GECKO(1561) | Stack: mainThreadFetch/<@resource://devtools/shared/DevToolsUtils.js:670:15
[task 2021-12-06T17:16:05.479Z] 17:16:05     INFO - GECKO(1561) | mainThreadFetch@resource://devtools/shared/DevToolsUtils.js:516:10
[task 2021-12-06T17:16:05.479Z] 17:16:05     INFO - GECKO(1561) | _fetchURLContents@resource://devtools/server/actors/utils/sources-manager.js:448:22
[task 2021-12-06T17:16:05.487Z] 17:16:05     INFO - GECKO(1561) | urlContents@resource://devtools/server/actors/utils/sources-manager.js:412:17
[task 2021-12-06T17:16:05.487Z] 17:16:05     INFO - GECKO(1561) | _resurrectSource@resource://devtools/server/actors/thread.js:2101:35
[task 2021-12-06T17:16:05.488Z] 17:16:05     INFO - GECKO(1561) | addAllSources@resource://devtools/server/actors/thread.js:1456:14
[task 2021-12-06T17:16:05.488Z] 17:16:05     INFO - GECKO(1561) | watch@resource://devtools/server/actors/resources/sources.js:49:17
[task 2021-12-06T17:16:05.488Z] 17:16:05     INFO - GECKO(1561) | watchResources@resource://devtools/server/actors/resources/index.js:242:19
[task 2021-12-06T17:16:05.488Z] 17:16:05     INFO - GECKO(1561) | _watchTargetResources@resource://devtools/server/actors/targets/target-actor-mixin.js:150:24
[task 2021-12-06T17:16:05.488Z] 17:16:05     INFO - GECKO(1561) | addSessionDataEntry@resource://devtools/server/actors/targets/target-actor-mixin.js:52:20
[task 2021-12-06T17:16:05.489Z] 17:16:05     INFO - GECKO(1561) | _addSessionDataEntry@resource://devtools/server/connectors/js-window-actor/DevToolsFrameChild.jsm:623:24
[task 2021-12-06T17:16:05.489Z] 17:16:05     INFO - GECKO(1561) | receiveMessage@resource://devtools/server/connectors/js-window-actor/DevToolsFrameChild.jsm:529:21
[task 2021-12-06T17:16:05.489Z] 17:16:05     INFO - GECKO(1561) | JSActor query*addSessionDataEntry@resource://devtools/server/connectors/js-window-actor/DevToolsFrameParent.jsm:83:18
[task 2021-12-06T17:16:05.489Z] 17:16:05     INFO - GECKO(1561) | addSessionDataEntry@resource://devtools/server/actors/watcher/target-helpers/frame-helper.js:232:8
[task 2021-12-06T17:16:05.489Z] 17:16:05     INFO - GECKO(1561) | watchResources@resource://devtools/server/actors/watcher.js:536:32
[task 2021-12-06T17:16:05.490Z] 17:16:05     INFO - GECKO(1561) | async*handler@resource://devtools/shared/protocol/Actor.js:175:37
[task 2021-12-06T17:16:05.492Z] 17:16:05     INFO - GECKO(1561) | onPacket@resource://devtools/server/devtools-server-connection.js:379:58
[task 2021-12-06T17:16:05.493Z] 17:16:05     INFO - GECKO(1561) | send/<@resource://devtools/shared/transport/local-transport.js:68:25
[task 2021-12-06T17:16:05.493Z] 17:16:05     INFO - GECKO(1561) | exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:103:22
[task 2021-12-06T17:16:05.494Z] 17:16:05     INFO - GECKO(1561) | DevToolsUtils.executeSoon*exports.executeSoon@resource://devtools/shared/DevToolsUtils.js:54:21
[task 2021-12-06T17:16:05.494Z] 17:16:05     INFO - GECKO(1561) | send@resource://devtools/shared/transport/local-transport.js:56:21
[task 2021-12-06T17:16:05.500Z] 17:16:05     INFO - GECKO(1561) | send@resource://devtools/shared/protocol/Front.js:276:30
[task 2021-12-06T17:16:05.501Z] 17:16:05     INFO - GECKO(1561) | request@resource://devtools/shared/protocol/Front.js:294:10
[task 2021-12-06T17:16:05.501Z] 17:16:05     INFO - GECKO(1561) | generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol/Front/FrontClassWithSpec.js:46:19
[task 2021-12-06T17:16:05.502Z] 17:16:05     INFO - GECKO(1561) | _startListening@resource://devtools/shared/commands/resource/resource-command.js:932:31
[task 2021-12-06T17:16:05.502Z] 17:16:05     INFO - GECKO(1561) | async*watchResources@resource://devtools/shared/commands/resource/resource-command.js:174:26
[task 2021-12-06T17:16:05.503Z] 17:16:05     INFO - GECKO(1561) | @chrome://mochitests/content/browser/devtools/shared/commands/resource/tests/browser_resources_sources.js:49:25
[task 2021-12-06T17:16:05.503Z] 17:16:05     INFO - GECKO(1561) | Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1091:34
[task 2021-12-06T17:16:05.504Z] 17:16:05     INFO - GECKO(1561) | Tester_execTest@chrome://mochikit/content/browser-test.js:1131:11
[task 2021-12-06T17:16:05.504Z] 17:16:05     INFO - GECKO(1561) | nextTest/<@chrome://mochikit/content/browser-test.js:939:14
[task 2021-12-06T17:16:05.505Z] 17:16:05     INFO - GECKO(1561) | SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1041:13
[task 2021-12-06T17:16:05.505Z] 17:16:05     INFO - GECKO(1561) | Line: 670, column: 0
[task 2021-12-06T17:16:05.506Z] 17:16:05     INFO - GECKO(1561) | console.error: ({})
[task 2021-12-06T17:16:05.546Z] 17:16:05     INFO - GECKO(1561) | [Child 1638, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/base/nsSimpleURI.cpp:618
[task 2021-12-06T17:16:05.546Z] 17:16:05     INFO - GECKO(1561) | [Child 1638, Main Thread] WARNING: NS_ENSURE_TRUE(!doc->IsResourceDoc() && ((!doc->IsLoadedAsData() && aOwner->IsInComposedDoc()) || doc->IsStaticDocument())) failed: file /builds/worker/checkouts/gecko/dom/base/nsFrameLoader.cpp:442
[task 2021-12-06T17:16:05.559Z] 17:16:05     INFO - GECKO(1561) | [Child 1638, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/netwerk/base/nsSimpleURI.cpp:618
[task 2021-12-06T17:16:05.564Z] 17:16:05     INFO - GECKO(1561) | JavaScript error: resource://devtools/shared/DevToolsUtils.js, line 670: NS_ERROR_NOT_AVAILABLE: Failed to open input source 'javascript:666'
[task 2021-12-06T17:16:05.648Z] 17:16:05     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (7fb29a87d200) [pid = 1638] [serial = 69] [outer = 0] [url = about:blank]
[task 2021-12-06T17:16:05.650Z] 17:16:05     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (7fb27fcb4e40) [pid = 1638] [serial = 59] [outer = 0] [url = https://example.org/browser/devtools/shared/commands/resource/tests/sse_frontend_iframe.html]
[task 2021-12-06T17:16:05.651Z] 17:16:05     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (7fb27fcb4200) [pid = 1638] [serial = 58] [outer = 0] [url = https://example.com/browser/devtools/shared/commands/resource/tests/sse_frontend_iframe.html]
[task 2021-12-06T17:16:05.653Z] 17:16:05     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (7fb27fcb4040) [pid = 1638] [serial = 55] [outer = 0] [url = https://example.com/browser/devtools/shared/commands/resource/tests/sse_frontend.html]
[task 2021-12-06T17:16:05.654Z] 17:16:05     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (7fb27fcb4c80) [pid = 1638] [serial = 66] [outer = 0] [url = https://example.org/browser/devtools/shared/commands/resource/tests/sse_frontend_iframe.html]
[task 2021-12-06T17:16:05.655Z] 17:16:05     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 13 (7fb27fcb4ac0) [pid = 1638] [serial = 65] [outer = 0] [url = https://example.com/browser/devtools/shared/commands/resource/tests/sse_frontend_iframe.html]
[task 2021-12-06T17:16:05.657Z] 17:16:05     INFO - GECKO(1561) | [Child 1638: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 12 (7fb27fcb4580) [pid = 1638] [serial = 62] [outer = 0] [url = https://example.com/browser/devtools/shared/commands/resource/tests/sse_frontend.html]
[task 2021-12-06T17:16:06.752Z] 17:16:06     INFO - GECKO(1561) | [Child 1777: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 7 (7fbaa3b45400) [pid = 1777] [serial = 35] [outer = 0] [url = data:text/html,<div id=div1>]
[task 2021-12-06T17:16:06.753Z] 17:16:06     INFO - GECKO(1561) | [Child 1777: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 6 (7fbaa3b47800) [pid = 1777] [serial = 37] [outer = 0] [url = data:text/html,<div id=div3>]
[task 2021-12-06T17:16:06.754Z] 17:16:06     INFO - GECKO(1561) | [Child 1777: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (7fbaa3b44400) [pid = 1777] [serial = 34] [outer = 0] [url = about:blank]
[task 2021-12-06T17:16:06.755Z] 17:16:06     INFO - GECKO(1561) | [Child 1777: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (7fbaa3b47000) [pid = 1777] [serial = 36] [outer = 0] [url = data:text/html,<div id=div1>]
[task 2021-12-06T17:16:06.893Z] 17:16:06     INFO - GECKO(1561) | [Child 1777: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (7fbabf97dc80) [pid = 1777] [serial = 40] [outer = 0] [url = data:text/html,Root Node tests]
[task 2021-12-06T17:16:07.473Z] 17:16:07     INFO - GECKO(1561) | [Child 1829: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7ff2931e5800 == 0 [pid = 1829] [id = 3] [url = https://example.org/document-builder.sjs?html=org]
[task 2021-12-06T17:16:07.573Z] 17:16:07     INFO - GECKO(1561) | [Child 1829: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (7ff2ad57d200) [pid = 1829] [serial = 10] [outer = 0] [url = https://example.org/document-builder.sjs?html=org]
[task 2021-12-06T17:16:11.267Z] 17:16:11     INFO - TEST-INFO | started process screentopng
[task 2021-12-06T17:16:11.577Z] 17:16:11     INFO - TEST-INFO | screentopng: exit 0
[task 2021-12-06T17:16:11.577Z] 17:16:11     INFO - Buffered messages logged at 17:16:01
[task 2021-12-06T17:16:11.578Z] 17:16:11     INFO - Entering test bound 
[task 2021-12-06T17:16:11.579Z] 17:16:11     INFO - Adding a new tab with URL: https://example.com/browser/devtools/shared/commands/resource/tests/sources.html
[task 2021-12-06T17:16:11.579Z] 17:16:11     INFO - Buffered messages logged at 17:16:02
[task 2021-12-06T17:16:11.580Z] 17:16:11     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "about:blank" line: 0}]
[task 2021-12-06T17:16:11.580Z] 17:16:11     INFO - Tab added and finished loading
[task 2021-12-06T17:16:11.581Z] 17:16:11     INFO - Buffered messages logged at 17:16:05
[task 2021-12-06T17:16:11.581Z] 17:16:11     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_sources.js | Got expected number of targets - 
[task 2021-12-06T17:16:11.582Z] 17:16:11     INFO - Check already available resources
[task 2021-12-06T17:16:11.582Z] 17:16:11     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
[task 2021-12-06T17:16:11.583Z] 17:16:11     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
[task 2021-12-06T17:16:11.584Z] 17:16:11     INFO - Console message: [JavaScript Warning: "‘src’ attribute of <script> element is not a valid URI: “sources.js”" {file: "moz-nullprincipal:{3a19a035-844b-4939-a6ed-833debd72a15}" line: 1}]
[task 2021-12-06T17:16:11.584Z] 17:16:11     INFO - Console message: [JavaScript Error: "NS_ERROR_NOT_AVAILABLE: Failed to open input source 'javascript:666'" {file: "resource://devtools/shared/DevToolsUtils.js" line: 670}]
[task 2021-12-06T17:16:11.585Z] 17:16:11     INFO - Buffered messages finished
[task 2021-12-06T17:16:11.588Z] 17:16:11     INFO - TEST-UNEXPECTED-FAIL | devtools/shared/commands/resource/tests/browser_resources_sources.js | Uncaught exception - at chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:1012 - Error: Failed waitFor(): Got all the sources
[task 2021-12-06T17:16:11.589Z] 17:16:11     INFO - Failed condition: () => availableResources.length >= expectedExistingResources.length
[task 2021-12-06T17:16:11.589Z] 17:16:11     INFO - 
[task 2021-12-06T17:16:11.589Z] 17:16:11     INFO - Stack trace:
[task 2021-12-06T17:16:11.590Z] 17:16:11     INFO - waitFor@chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:1012:11
[task 2021-12-06T17:16:11.590Z] 17:16:11     INFO - async*@chrome://mochitests/content/browser/devtools/shared/commands/resource/tests/browser_resources_sources.js:227:9
[task 2021-12-06T17:16:11.591Z] 17:16:11     INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1091:34
[task 2021-12-06T17:16:11.591Z] 17:16:11     INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1131:11
[task 2021-12-06T17:16:11.592Z] 17:16:11     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:939:14
[task 2021-12-06T17:16:11.592Z] 17:16:11     INFO - SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1041:13
[task 2021-12-06T17:16:11.593Z] 17:16:11     INFO - Leaving test bound 
[task 2021-12-06T17:16:11.594Z] 17:16:11     INFO - Removing tab.
[task 2021-12-06T17:16:11.595Z] 17:16:11     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2021-12-06T17:16:11.596Z] 17:16:11     INFO - Got event: 'TabClose' on [object XULElement].
[task 2021-12-06T17:16:11.597Z] 17:16:11     INFO - Tab removed and finished closing
[task 2021-12-06T17:16:11.734Z] 17:16:11     INFO - GECKO(1561) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'
[task 2021-12-06T17:16:11.736Z] 17:16:11     INFO - GECKO(1561) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'
[task 2021-12-06T17:16:11.756Z] 17:16:11     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2021-12-06T17:16:11.759Z] 17:16:11     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2021-12-06T17:16:11.761Z] 17:16:11     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_sources.js | The main process DevToolsServer has no pending connection when the test ends - 
[task 2021-12-06T17:16:11.769Z] 17:16:11     INFO - GECKO(1561) | MEMORY STAT | vsize 3291MB | residentFast 548MB | heapAllocated 235MB
[task 2021-12-06T17:16:11.770Z] 17:16:11     INFO - TEST-OK | devtools/shared/commands/resource/tests/browser_resources_sources.js | took 10201ms

Alexandre, could you please take a look?

Flags: needinfo?(poirot.alex)

I'm looking at that. I understand what is going on and have a local patch.
I'm polishing it before asking for review.

Assignee: nobody → poirot.alex
Flags: needinfo?(poirot.alex)

In this test, we weren't setting breakpoints, nor watching fot thread states.
So nothing was "attaching" the thread actor and so we would miss all sources created
after calling SourceWatcher.watch. (we only catched already existing sources)

Thus leading to many intermittents.

But the miss of target attaching wasn't the sole reason why it fails.
The resurrectSource function is still failing for javascriptURL and domTimer sources.
I'm also seeing exception about not being unable to load sources.js, but that doesn't seem to break anything in this test.

So I'm forking this test in two. One, as before, which will assert that we
catch absolutely all the sources when we reload the page after we started watching.
And a new test, which ensure testing GC-ed sources and better highlights
which are the one that we fail resurrecting.

(I'm also removing target related assertions as they aren't really relevant for this test)
(And migrate to CommandsFactory to simplify the test a bit)

Set release status flags based on info from the regressing bug 1743044

Pushed by apoirot@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/6f7405b4fb5c [devtools] Attach the thread actor to intercept future sources when watching for sources. r=bomsy https://hg.mozilla.org/integration/autoland/rev/66f56bc9fae3 [devtools] Fork browser_resources_sources.js to test GC-ed sources explicitely. r=bomsy
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → 97 Branch
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Target Milestone: 97 Branch → ---
Whiteboard: [stockwell disable-recommended] → [stockwell needswork:owner]

There are 27 total failures in the last 7 days on

[task 2022-01-15T16:20:38.393Z] 16:20:38     INFO - TEST-START | devtools/shared/commands/resource/tests/browser_resources_sources.js
[task 2022-01-15T16:20:38.427Z] 16:20:38     INFO - GECKO(3927) | [Child 4123: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7ffa3e487c00 == 2 [pid = 4123] [id = 20]
[task 2022-01-15T16:20:38.429Z] 16:20:38     INFO - GECKO(3927) | [Child 4123: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (7ffa3e403580) [pid = 4123] [serial = 53] [outer = 0]
[task 2022-01-15T16:20:38.430Z] 16:20:38     INFO - GECKO(3927) | [Child 4123: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (7ffa3e488c00) [pid = 4123] [serial = 54] [outer = 7ffa3e403580]
[task 2022-01-15T16:20:38.482Z] 16:20:38     INFO - GECKO(3927) | [Child 4123, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, false) failed with result 0x804B0050 (NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS): file /builds/worker/checkouts/gecko/toolkit/components/antitracking/URLQueryStringStripper.cpp:129
[task 2022-01-15T16:20:38.594Z] 16:20:38     INFO - GECKO(3927) | [Child 4123: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (7ffa3e484400) [pid = 4123] [serial = 55] [outer = 7ffa3e403580]
[task 2022-01-15T16:20:40.048Z] 16:20:40     INFO - GECKO(3927) | [Child 4004: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7fb94545f800 == 1 [pid = 4004] [id = 21] [url = data:text/html,Root Node tests]
[task 2022-01-15T16:20:40.049Z] 16:20:40     INFO - GECKO(3927) | [Child 4004: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (7fb94545fc00) [pid = 4004] [serial = 58] [outer = 0] [url = about:blank]
[task 2022-01-15T16:20:40.393Z] 16:20:40     INFO - GECKO(3927) | [Child 4123: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 6 (7ffa3e48c800) [pid = 4123] [serial = 56] [outer = 7ffa3e403580]
[task 2022-01-15T16:20:40.425Z] 16:20:40     INFO - GECKO(3927) | [Child 4004: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (7fb9467653c0) [pid = 4004] [serial = 57] [outer = 0] [url = data:text/html,Root Node tests]
[task 2022-01-15T16:20:40.427Z] 16:20:40     INFO - GECKO(3927) | [Child 4004: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (7fb945464800) [pid = 4004] [serial = 56] [outer = 0] [url = about:blank]
[task 2022-01-15T16:20:40.874Z] 16:20:40     INFO - GECKO(3927) | [Child 4123: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7ffa3e490000 == 3 [pid = 4123] [id = 21]
[task 2022-01-15T16:20:40.875Z] 16:20:40     INFO - GECKO(3927) | [Child 4123: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 7 (7ffa3e434740) [pid = 4123] [serial = 57] [outer = 0]
[task 2022-01-15T16:20:40.877Z] 16:20:40     INFO - GECKO(3927) | [Child 4123: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 8 (7ffa3e490400) [pid = 4123] [serial = 58] [outer = 7ffa3e434740]
[task 2022-01-15T16:20:40.913Z] 16:20:40     INFO - GECKO(3927) | [Child 4123, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1180
[task 2022-01-15T16:20:42.136Z] 16:20:42     INFO - GECKO(3927) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'
[task 2022-01-15T16:20:42.138Z] 16:20:42     INFO - GECKO(3927) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'
[task 2022-01-15T16:20:42.172Z] 16:20:42     INFO - GECKO(3927) | [Child 4152: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f4406d69c00 == 2 [pid = 4152] [id = 20]
[task 2022-01-15T16:20:42.174Z] 16:20:42     INFO - GECKO(3927) | [Child 4152: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (7f4406d9a200) [pid = 4152] [serial = 62] [outer = 0]
[task 2022-01-15T16:20:42.175Z] 16:20:42     INFO - GECKO(3927) | [Child 4152: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (7f4406d6a000) [pid = 4152] [serial = 63] [outer = 7f4406d9a200]
[task 2022-01-15T16:20:42.321Z] 16:20:42     INFO - GECKO(3927) | [Child 4152: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 6 (7f4406d6c000) [pid = 4152] [serial = 64] [outer = 7f4406d9a200]
[task 2022-01-15T16:20:42.408Z] 16:20:42     INFO - GECKO(3927) | [Parent 3927, Main Thread] WARNING: NS_ENSURE_TRUE(reg) failed: file /builds/worker/checkouts/gecko/dom/serviceworkers/ServiceWorkerProxy.cpp:47
[task 2022-01-15T16:20:42.487Z] 16:20:42     INFO - GECKO(3927) | [Child 4152: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f4406d6f400 == 3 [pid = 4152] [id = 21]
[task 2022-01-15T16:20:42.488Z] 16:20:42     INFO - GECKO(3927) | [Child 4152: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 7 (7f440d66e3c0) [pid = 4152] [serial = 65] [outer = 0]
[task 2022-01-15T16:20:42.489Z] 16:20:42     INFO - GECKO(3927) | [Child 4152: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 8 (7f4406d6f800) [pid = 4152] [serial = 66] [outer = 7f440d66e3c0]
[task 2022-01-15T16:20:42.509Z] 16:20:42     INFO - GECKO(3927) | [Parent 3927, Main Thread] WARNING: NS_ENSURE_TRUE(registration->GetActive()) failed: file /builds/worker/checkouts/gecko/dom/serviceworkers/ServiceWorkerManager.cpp:1259
[task 2022-01-15T16:20:42.624Z] 16:20:42     INFO - GECKO(3927) | [Child 4152, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1180
[task 2022-01-15T16:20:43.359Z] 16:20:43     INFO - GECKO(3927) | [Child 4152: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 7 (7f4406d67c00) [pid = 4152] [serial = 60] [outer = 0] [url = about:blank]
[task 2022-01-15T16:20:43.361Z] 16:20:43     INFO - GECKO(3927) | [Child 4152: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f4406d67000 == 2 [pid = 4152] [id = 19] [url = https://example.com/document-builder.sjs?html=com]
[task 2022-01-15T16:20:43.381Z] 16:20:43     INFO - GECKO(3927) | [Child 4152: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 6 (7f4406d9a040) [pid = 4152] [serial = 59] [outer = 0] [url = https://example.com/document-builder.sjs?html=com]
[task 2022-01-15T16:20:45.310Z] 16:20:45     INFO - GECKO(3927) | [Child 4177: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f4e2aaeb400 == 0 [pid = 4177] [id = 3] [url = https://example.org/document-builder.sjs?html=org]
[task 2022-01-15T16:20:45.639Z] 16:20:45     INFO - GECKO(3927) | [Child 4177: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (7f4e2a31d200) [pid = 4177] [serial = 10] [outer = 0] [url = https://example.org/document-builder.sjs?html=org]
[task 2022-01-15T16:20:45.712Z] 16:20:45     INFO - GECKO(3927) | [Child 4004: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (7fb945460c00) [pid = 4004] [serial = 59] [outer = 0] [url = data:text/html,Root Node tests]
[task 2022-01-15T16:20:46.369Z] 16:20:46     INFO - GECKO(3927) | [Child 4152: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (7f4406d69400) [pid = 4152] [serial = 61] [outer = 0] [url = https://example.com/document-builder.sjs?html=com]
[task 2022-01-15T16:20:46.371Z] 16:20:46     INFO - GECKO(3927) | [Child 4152: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (7f4406d6a000) [pid = 4152] [serial = 63] [outer = 0] [url = about:blank]
[task 2022-01-15T16:20:46.730Z] 16:20:46     INFO - GECKO(3927) | [Child 4123: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7ffa3e485800 == 2 [pid = 4123] [id = 19] [url = about:blank]
[task 2022-01-15T16:20:46.875Z] 16:20:46     INFO - GECKO(3927) | [Child 4123: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 7 (7ffa3e403040) [pid = 4123] [serial = 51] [outer = 0] [url = about:blank]
[task 2022-01-15T16:20:50.966Z] 16:20:50     INFO - GECKO(3927) | [Child 4177: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (7f4e2aaeb800) [pid = 4177] [serial = 11] [outer = 0] [url = about:blank]
[task 2022-01-15T16:20:50.966Z] 16:20:50     INFO - GECKO(3927) | [Child 4177: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (7f4e2aaecc00) [pid = 4177] [serial = 12] [outer = 0] [url = https://example.org/document-builder.sjs?html=org]
[task 2022-01-15T16:20:52.073Z] 16:20:52     INFO - GECKO(3927) | [Child 4123: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 6 (7ffa3e485c00) [pid = 4123] [serial = 52] [outer = 0] [url = about:blank]
[task 2022-01-15T16:20:52.074Z] 16:20:52     INFO - GECKO(3927) | [Child 4123: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (7ffa3e488c00) [pid = 4123] [serial = 54] [outer = 0] [url = about:blank]
[task 2022-01-15T16:20:52.602Z] 16:20:52     INFO - TEST-INFO | started process screentopng
[task 2022-01-15T16:20:52.814Z] 16:20:52     INFO - TEST-INFO | screentopng: exit 0

[task 2022-01-15T16:20:52.977Z] 16:20:52     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_sources.js | The value of extensionName is correct for "#service worker script" - 
[task 2022-01-15T16:20:52.978Z] 16:20:52     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2022-01-15T16:20:52.980Z] 16:20:52     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2022-01-15T16:20:52.981Z] 16:20:52     INFO - Leaving test bound testSourcesOnload
[task 2022-01-15T16:20:52.982Z] 16:20:52     INFO - Entering test bound testGarbagedCollectedSources
[task 2022-01-15T16:20:52.983Z] 16:20:52     INFO - Assert SOURCES on an already loaded page with some sources that have been GC-ed
[task 2022-01-15T16:20:52.984Z] 16:20:52     INFO - Adding a new tab with URL: https://example.com/browser/devtools/shared/commands/resource/tests/sources.html
[task 2022-01-15T16:20:52.986Z] 16:20:52     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "about:blank" line: 0}]
[task 2022-01-15T16:20:52.986Z] 16:20:52     INFO - Tab added and finished loading
[task 2022-01-15T16:20:52.987Z] 16:20:52     INFO - Force some GC to free some sources
[task 2022-01-15T16:20:52.989Z] 16:20:52     INFO - Buffered messages logged at 16:20:46
[task 2022-01-15T16:20:52.990Z] 16:20:52     INFO - Check already available resources
[task 2022-01-15T16:20:52.991Z] 16:20:52     INFO - Buffered messages finished
[task 2022-01-15T16:20:52.992Z] 16:20:52     INFO - TEST-UNEXPECTED-FAIL | devtools/shared/commands/resource/tests/browser_resources_sources.js | Uncaught exception - at chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:1018 - Error: Failed waitFor(): Got all the sources
[task 2022-01-15T16:20:52.993Z] 16:20:52     INFO - Failed condition: () => availableResources.length >= expectedResources.length
[task 2022-01-15T16:20:52.993Z] 16:20:52     INFO - 
[task 2022-01-15T16:20:52.994Z] 16:20:52     INFO - Stack trace:
[task 2022-01-15T16:20:52.995Z] 16:20:52     INFO - waitFor@chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:1018:11
[task 2022-01-15T16:20:52.996Z] 16:20:52     INFO - async*testGarbagedCollectedSources@chrome://mochitests/content/browser/devtools/shared/commands/resource/tests/browser_resources_sources.js:266:9
[task 2022-01-15T16:20:52.997Z] 16:20:52     INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1130:34
[task 2022-01-15T16:20:52.998Z] 16:20:52     INFO - async*Tester_execTest@chrome://mochikit/content/browser-test.js:1170:11
[task 2022-01-15T16:20:52.999Z] 16:20:52     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:978:14
[task 2022-01-15T16:20:53.000Z] 16:20:52     INFO - SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1041:13
[task 2022-01-15T16:20:53.001Z] 16:20:53     INFO - Leaving test bound testGarbagedCollectedSources
[task 2022-01-15T16:20:53.001Z] 16:20:53     INFO - Entering test bound testParentProcessPrivilegedSources
[task 2022-01-15T16:20:54.186Z] 16:20:54     INFO - Check already available resources
[task 2022-01-15T16:20:56.933Z] 16:20:56     INFO - GECKO(3927) | [Child 4123: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (7ffa3e484400) [pid = 4123] [serial = 55] [outer = 0] [url = about:blank]
[task 2022-01-15T16:20:58.277Z] 16:20:58     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
[task 2022-01-15T16:20:58.278Z] 16:20:58     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
[task 2022-01-15T16:20:58.283Z] 16:20:58     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
[task 2022-01-15T16:20:58.302Z] 16:20:58     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
[task 2022-01-15T16:20:58.306Z] 16:20:58     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
[task 2022-01-15T16:20:58.315Z] 16:20:58     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
[task 2022-01-15T16:20:58.317Z] 16:20:58     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
[task 2022-01-15T16:20:58.516Z] 16:20:58     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_sources.js | We get many sources reported from a multiprocess command - 
[task 2022-01-15T16:20:58.531Z] 16:20:58     INFO - Wait for the sandbox source
[task 2022-01-15T16:20:58.593Z] 16:20:58     INFO - TEST-PASS | devtools/shared/commands/resource/tests/browser_resources_sources.js | Length of existing resources is correct at initial - 

Alexandre, are you still working on this?

Flags: needinfo?(poirot.alex)
Whiteboard: [stockwell unknown] → [stockwell needswork:owner]
Has Regression Range: --- → yes
Keywords: leave-open
Whiteboard: [stockwell needswork:owner] → [stockwell needswork:owner][stockwell disabled]
Pushed by apavel@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/093dca59b0ff disable browser_resources_sources.js on linux64 and win10_2004 opt r=intermittent-reviewers,jmaher DONTBUILD

Let's try to unify all bugs around this test failures.

Status: REOPENED → RESOLVED
Closed: 3 years ago5 months ago
Duplicate of bug: 1874227
Flags: needinfo?(poirot.alex)
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: