1703300 - Intermittent browser_rules_color_scheme_simulation.js | A promise chain failed to handle a rejection: can't access property "on", walker is undefined - stack: registerWalkerListeners@resource://devtools/client/framework/actions/dom-mutation-breakpoints.js

Reporter

Description

•

3 years ago

treeherder

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

...
...
...
[task 2021-04-06T16:29:49.691Z] 16:29:49     INFO - Select the top level div again
[task 2021-04-06T16:29:49.691Z] 16:29:49     INFO - Selecting the node for 'div'
[task 2021-04-06T16:29:49.692Z] 16:29:49     INFO - Click the light button simulate light mode
[task 2021-04-06T16:29:49.692Z] 16:29:49     INFO - TEST-PASS | devtools/client/inspector/rules/test/browser_rules_color_scheme_simulation.js | The button has the expected light state - 
[task 2021-04-06T16:29:49.692Z] 16:29:49     INFO - TEST-PASS | devtools/client/inspector/rules/test/browser_rules_color_scheme_simulation.js | the dark button was unchecked when enabling light mode - 
[task 2021-04-06T16:29:49.692Z] 16:29:49     INFO - Click the light button to disable simulation
[task 2021-04-06T16:29:49.693Z] 16:29:49     INFO - TEST-PASS | devtools/client/inspector/rules/test/browser_rules_color_scheme_simulation.js | The button isn't checked anymore - 
[task 2021-04-06T16:29:49.693Z] 16:29:49     INFO - TEST-PASS | devtools/client/inspector/rules/test/browser_rules_color_scheme_simulation.js | We're not simulating color-scheme anymore - 
[task 2021-04-06T16:29:49.693Z] 16:29:49     INFO - Select the node from the remote iframe again
[task 2021-04-06T16:29:49.694Z] 16:29:49     INFO - Loop through all frame selectors
[task 2021-04-06T16:29:49.694Z] 16:29:49     INFO - Find the frame element for selector iframe in http://example.com/browser/devtools/client/inspector/rules/test/doc_media_queries.html
[task 2021-04-06T16:29:49.694Z] 16:29:49     INFO - Selecting the node for '[Front for domnode/server0.conn24.child4/domnode28]'
[task 2021-04-06T16:29:49.694Z] 16:29:49     INFO - Connect to remote frame and retrieve the targetFront
[task 2021-04-06T16:29:49.695Z] 16:29:49     INFO - Selecting the node for '[Front for domnode/server0.conn24.windowGlobal23622320129/domnode27]'
[task 2021-04-06T16:29:49.695Z] 16:29:49     INFO - Buffered messages logged at 16:29:44
[task 2021-04-06T16:29:49.695Z] 16:29:49     INFO - TEST-PASS | devtools/client/inspector/rules/test/browser_rules_color_scheme_simulation.js | The simulation stopped on the remote iframe as well - 
[task 2021-04-06T16:29:49.696Z] 16:29:49     INFO - Check that reloading keep the selected simulation
[task 2021-04-06T16:29:49.696Z] 16:29:49     INFO - Selecting the node for 'div'
[task 2021-04-06T16:29:49.696Z] 16:29:49     INFO - Load document "http://example.com/browser/devtools/client/inspector/rules/test/doc_media_queries.html"
[task 2021-04-06T16:29:49.696Z] 16:29:49     INFO - Waiting for page to be loaded…
[task 2021-04-06T16:29:49.697Z] 16:29:49     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.com/browser/devtools/client/inspector/rules/test/doc_media_queries.html" line: 0}]
[task 2021-04-06T16:29:49.697Z] 16:29:49     INFO - Buffered messages logged at 16:29:45
[task 2021-04-06T16:29:49.697Z] 16:29:49     INFO - → page loaded
[task 2021-04-06T16:29:49.698Z] 16:29:49     INFO - Waiting for inspector to be reloaded…
[task 2021-04-06T16:29:49.698Z] 16:29:49     INFO - Waiting for markup view to load after navigation.
[task 2021-04-06T16:29:49.699Z] 16:29:49     INFO - Waiting for new root.
[task 2021-04-06T16:29:49.699Z] 16:29:49     INFO - Waiting for inspector to update after new-root event.
[task 2021-04-06T16:29:49.699Z] 16:29:49     INFO - Waiting for inspector updates after page reload
[task 2021-04-06T16:29:49.700Z] 16:29:49     INFO - → panel reloaded
[task 2021-04-06T16:29:49.700Z] 16:29:49     INFO - Waiting for target 'navigate' event…
[task 2021-04-06T16:29:49.700Z] 16:29:49     INFO - → 'navigate' emitted
[task 2021-04-06T16:29:49.707Z] 16:29:49     INFO - Selecting the node for 'div'
[task 2021-04-06T16:29:49.707Z] 16:29:49     INFO - TEST-PASS | devtools/client/inspector/rules/test/browser_rules_color_scheme_simulation.js | dark mode is still simulated after reloading the page - 
[task 2021-04-06T16:29:49.707Z] 16:29:49     INFO - Loop through all frame selectors
[task 2021-04-06T16:29:49.707Z] 16:29:49     INFO - Find the frame element for selector iframe in http://example.com/browser/devtools/client/inspector/rules/test/doc_media_queries.html
[task 2021-04-06T16:29:49.708Z] 16:29:49     INFO - Selecting the node for '[Front for domnode/server0.conn24.child4/domnode57]'
[task 2021-04-06T16:29:49.708Z] 16:29:49     INFO - Buffered messages logged at 16:29:46
[task 2021-04-06T16:29:49.708Z] 16:29:49     INFO - Connect to remote frame and retrieve the targetFront
[task 2021-04-06T16:29:49.709Z] 16:29:49     INFO - Console message: [JavaScript Error: "TypeError: can't access property "on", walker is undefined" {file: "resource://devtools/client/framework/actions/dom-mutation-breakpoints.js" line: 14}]
[task 2021-04-06T16:29:49.709Z] 16:29:49     INFO - Selecting the node for '[Front for domnode/server0.conn24.windowGlobal25769803777/domnode26]'
[task 2021-04-06T16:29:49.709Z] 16:29:49     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
[task 2021-04-06T16:29:49.710Z] 16:29:49     INFO - TEST-PASS | devtools/client/inspector/rules/test/browser_rules_color_scheme_simulation.js | simulation is still applied to the iframe after reloading - 
[task 2021-04-06T16:29:49.710Z] 16:29:49     INFO - Check that closing DevTools reset the simulation
[task 2021-04-06T16:29:49.710Z] 16:29:49     INFO - Buffered messages logged at 16:29:49
[task 2021-04-06T16:29:49.710Z] 16:29:49     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2021-04-06T16:29:49.711Z] 16:29:49     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2021-04-06T16:29:49.711Z] 16:29:49     INFO - TEST-PASS | devtools/client/inspector/rules/test/browser_rules_color_scheme_simulation.js | color scheme simulation is disabled after closing DevTools - 
[task 2021-04-06T16:29:49.711Z] 16:29:49     INFO - Buffered messages finished
[task 2021-04-06T16:29:49.712Z] 16:29:49     INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/rules/test/browser_rules_color_scheme_simulation.js | A promise chain failed to handle a rejection: can't access property "on", walker is undefined - stack: registerWalkerListeners@resource://devtools/client/framework/actions/dom-mutation-breakpoints.js:14:3
[task 2021-04-06T16:29:49.712Z] 16:29:49     INFO - _onTargetAvailable/<@resource://devtools/client/framework/toolbox.js:710:30
[task 2021-04-06T16:29:49.712Z] 16:29:49     INFO - watchFronts@resource://devtools/shared/protocol/Front.js:194:22
[task 2021-04-06T16:29:49.712Z] 16:29:49     INFO - _onTargetAvailable@resource://devtools/client/framework/toolbox.js:709:17
[task 2021-04-06T16:29:49.712Z] 16:29:49     INFO - _emit@resource://devtools/shared/event-emitter.js:226:34
[task 2021-04-06T16:29:49.712Z] 16:29:49     INFO - emitAsync@resource://devtools/shared/event-emitter.js:176:25
[task 2021-04-06T16:29:49.712Z] 16:29:49     INFO - emitAsync@resource://devtools/shared/event-emitter.js:328:25
[task 2021-04-06T16:29:49.712Z] 16:29:49     INFO - _onTargetAvailable@resource://devtools/shared/commands/target/target-command.js:187:33
[task 2021-04-06T16:29:49.712Z] 16:29:49     INFO - Async*_emit@resource://devtools/shared/event-emitter.js:226:34
[task 2021-04-06T16:29:49.712Z] 16:29:49     INFO - emit@resource://devtools/shared/event-emitter.js:172:18
[task 2021-04-06T16:29:49.712Z] 16:29:49     INFO - emit@resource://devtools/shared/event-emitter.js:324:18
[task 2021-04-06T16:29:49.712Z] 16:29:49     INFO - _onTargetAvailable@resource://devtools/client/fronts/watcher.js:60:10
[task 2021-04-06T16:29:49.713Z] 16:29:49     INFO - _emit@resource://devtools/shared/event-emitter.js:226:34
[task 2021-04-06T16:29:49.713Z] 16:29:49     INFO - emit@resource://devtools/shared/event-emitter.js:172:18
[task 2021-04-06T16:29:49.713Z] 16:29:49     INFO - emit@resource://devtools/shared/event-emitter.js:324:18
[task 2021-04-06T16:29:49.713Z] 16:29:49     INFO - onPacket@resource://devtools/shared/protocol/Front.js:329:13
[task 2021-04-06T16:29:49.713Z] 16:29:49     INFO - onPacket@resource://devtools/client/devtools-client.js:482:13
[task 2021-04-06T16:29:49.713Z] 16:29:49     INFO - send/<@resource://devtools/shared/transport/local-transport.js:68:25
[task 2021-04-06T16:29:49.713Z] 16:29:49     INFO - exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:103:22
[task 2021-04-06T16:29:49.714Z] 16:29:49     INFO - DevToolsUtils.executeSoon*exports.executeSoon@resource://devtools/shared/DevToolsUtils.js:54:21
[task 2021-04-06T16:29:49.714Z] 16:29:49     INFO - send@resource://devtools/shared/transport/local-transport.js:56:21
[task 2021-04-06T16:29:49.714Z] 16:29:49     INFO - send@resource://devtools/server/devtools-server-connection.js:99:20
[task 2021-04-06T16:29:49.714Z] 16:29:49     INFO - _sendEvent@resource://devtools/shared/protocol/Actor.js:72:15
[task 2021-04-06T16:29:49.714Z] 16:29:49     INFO - initialize/<@resource://devtools/shared/protocol/Actor.js:46:16
[task 2021-04-06T16:29:49.714Z] 16:29:49     INFO - _emit@resource://devtools/shared/event-emitter.js:226:34
[task 2021-04-06T16:29:49.715Z] 16:29:49     INFO - emit@resource://devtools/shared/event-emitter.js:172:18
[task 2021-04-06T16:29:49.715Z] 16:29:49     INFO - emit@resource://devtools/shared/event-emitter.js:324:18
[task 2021-04-06T16:29:49.715Z] 16:29:49     INFO - notifyTargetAvailable@resource://devtools/server/actors/watcher.js:240:10
[task 2021-04-06T16:29:49.715Z] 16:29:49     INFO - connectFromContent@resource://devtools/server/connectors/js-window-actor/DevToolsFrameParent.jsm:156:13
[task 2021-04-06T16:29:49.715Z] 16:29:49     INFO - receiveMessage@resource://devtools/server/connectors/js-window-actor/DevToolsFrameParent.jsm:221:21
[task 2021-04-06T16:29:49.715Z] 16:29:49     INFO - JSActor query*_createTargetActor@resource://devtools/server/connectors/js-window-actor/DevToolsFrameChild.jsm:251:10
[task 2021-04-06T16:29:49.715Z] 16:29:49     INFO - instantiate@resource://devtools/server/connectors/js-window-actor/DevToolsFrameChild.jsm:174:14
[task 2021-04-06T16:29:49.716Z] 16:29:49     INFO - handleEvent@resource://devtools/server/connectors/js-window-actor/DevToolsFrameChild.jsm:483:12
[task 2021-04-06T16:29:49.716Z] 16:29:49     INFO - Rejection date: Tue Apr 06 2021 16:29:46 GMT+0000 (Greenwich Mean Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 285
[task 2021-04-06T16:29:49.716Z] 16:29:49     INFO - Stack trace:
[task 2021-04-06T16:29:49.716Z] 16:29:49     INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:285
[task 2021-04-06T16:29:49.716Z] 16:29:49     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1120
[task 2021-04-06T16:29:49.716Z] 16:29:49     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1129
[task 2021-04-06T16:29:49.717Z] 16:29:49     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:949
[task 2021-04-06T16:29:49.717Z] 16:29:49     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:1037
[task 2021-04-06T16:29:49.717Z] 16:29:49     INFO - Leaving test bound 
[task 2021-04-06T16:29:49.717Z] 16:29:49     INFO - GECKO(1342) | [Parent 1342, Main Thread] WARNING: Failed to update worker context options!: file /builds/worker/checkouts/gecko/dom/workers/WorkerPrivate.cpp:1868
[task 2021-04-06T16:29:49.718Z] 16:29:49     INFO - Removing tab.
[task 2021-04-06T16:29:49.718Z] 16:29:49     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2021-04-06T16:29:49.718Z] 16:29:49     INFO - Got event: 'TabClose' on [object XULElement].
[task 2021-04-06T16:29:49.718Z] 16:29:49     INFO - Tab removed and finished closing
[task 2021-04-06T16:29:49.719Z] 16:29:49     INFO - GECKO(1342) | [Child 1391: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (116156200) [pid = 1391] [serial = 6] [outer = 0] [url = about:blank]
[task 2021-04-06T16:29:49.719Z] 16:29:49     INFO - TEST-PASS | devtools/client/inspector/rules/test/browser_rules_color_scheme_simulation.js | The main process DevToolsServer has no pending connection when the test ends - 
[task 2021-04-06T16:29:49.719Z] 16:29:49     INFO - GECKO(1342) | [Child 1391, Main Thread] WARNING: nsAppShell::Exit() called redundantly: file /builds/worker/checkouts/gecko/widget/cocoa/nsAppShell.mm:751
[task 2021-04-06T16:29:49.720Z] 16:29:49     INFO - GECKO(1342) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-04-06T16:29:49.723Z] 16:29:49     INFO - GECKO(1342) | MEMORY STAT | vsize 8025MB | residentFast 489MB | heapAllocated 162MB
[task 2021-04-06T16:29:49.735Z] 16:29:49     INFO - GECKO(1342) | [Child 1393, Main Thread] WARNING: nsAppShell::Exit() called redundantly: file /builds/worker/checkouts/gecko/widget/cocoa/nsAppShell.mm:751
[task 2021-04-06T16:29:49.735Z] 16:29:49     INFO - TEST-OK | devtools/client/inspector/rules/test/browser_rules_color_scheme_simulation.js | took 9352ms```

Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)

Updated

•

3 years ago

status-firefox87: --- → unaffected

status-firefox88: --- → unaffected

status-firefox89: --- → affected

status-firefox-esr78: --- → unaffected

Flags: needinfo?(nchevobbe)

Keywords: regression

Regressed by: 1702217

BMO Automation

Updated

•

3 years ago

Has Regression Range: --- → yes

Nicolas Chevobbe [:nchevobbe]

Comment 1

•

3 years ago

jdescottes already performed some investigation on this (see https://phabricator.services.mozilla.com/D110515#inline-618502), and I was looking at this.

Flags: needinfo?(nchevobbe)

Julian Descottes [:jdescottes]

Assignee

Comment 2

•

3 years ago

I managed to reproduce locally in debug mode with --repeat 20, and the fix I started suggesting in https://phabricator.services.mozilla.com/D110515#inline-618502 works.

diff --git a/devtools/shared/protocol/Front.js b/devtools/shared/protocol/Front.js
--- a/devtools/shared/protocol/Front.js
+++ b/devtools/shared/protocol/Front.js
@@ -136,16 +136,17 @@ class Front extends Pool {
       );
     }
 
     super.manage(front);
 
     if (typeof front.initialize == "function") {
       await front.initialize();
     }
+    front._initializeResolved = true;
 
     // Ensure calling form() *before* notifying about this front being just created.
     // We exprect the front to be fully initialized, especially via its form attributes.
     // But do that *after* calling manage() so that the front is already registered
     // in Pools and can be fetched by its ID, in case a child actor, created in form()
     // tries to get a reference to its parent via the actor ID.
     if (form) {
       front.form(form, ctx);
@@ -185,17 +186,17 @@ class Front extends Pool {
           `already destroyed front '${this.typeName}'.`
       );
       return;
     }
 
     if (onAvailable) {
       // First fire the callback on already instantiated fronts
       for (const front of this.poolChildren()) {
-        if (front.typeName == typeName) {
+        if (front.typeName == typeName && front._initializeResolved) {
           onAvailable(front);
         }
       }
 
       // Then register the callback for fronts instantiated in the future
       this._frontCreationListeners.on(typeName, onAvailable);
     }

Another way to look at this would be to try to swap super.manage(front); and await front.initialize();, I think it's not the first time that managing un-initialized Fronts creates problems. But I'm afraid that doing this will create its own class of new issues. Whereas the flag approach should be quite safe.

Julian Descottes [:jdescottes]

Assignee

Comment 3

•

3 years ago

Attached file Bug 1703300 - [devtools] Do not notify about uninitialized fronts in Front::watchFronts — Details

Phabricator Automation

Updated

•

3 years ago

Assignee: nobody → jdescottes

Status: NEW → ASSIGNED

Julian Descottes [:jdescottes]

Assignee

Comment 4

•

3 years ago

Attached file Bug 1703300 - [devtools] Remove guard against undefined walker in registerWalkerListeners — Details

Depends on D111093

Pulsebot

Comment 5

•

3 years ago

Pushed by jdescottes@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/4167d230af41
[devtools] Do not notify about uninitialized fronts in Front::watchFronts r=nchevobbe
https://hg.mozilla.org/integration/autoland/rev/fcc7dd8098a7
[devtools] Remove guard against undefined walker in registerWalkerListeners r=nchevobbe

Atila Butkovits

Comment 6

•

3 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/4167d230af41
https://hg.mozilla.org/mozilla-central/rev/fcc7dd8098a7

Status: ASSIGNED → RESOLVED

Closed: 3 years ago

status-firefox89: affected → fixed

Resolution: --- → FIXED

Target Milestone: --- → 89 Branch

Comment hidden (Intermittent Failures Robot)

Bug 1703300 - [devtools] Do not notify about uninitialized fronts in Front::watchFronts 3 years ago Julian Descottes [:jdescottes] 48 bytes, text/x-phabricator-request		Details \| Review
Bug 1703300 - [devtools] Remove guard against undefined walker in registerWalkerListeners 3 years ago Julian Descottes [:jdescottes] 48 bytes, text/x-phabricator-request		Details \| Review

Bugzilla

Quick Search

Intermittent browser_rules_color_scheme_simulation.js | A promise chain failed to handle a rejection: can't access property "on", walker is undefined - stack: registerWalkerListeners@resource://devtools/client/framework/actions/dom-mutation-breakpoints.js

Categories

(DevTools :: Inspector: Rules, defect, P5)

Tracking

(firefox-esr78 unaffected, firefox87 unaffected, firefox88 unaffected, firefox89 fixed)

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Crash Data

Security

(public)

User Story

Attachments

(2 files)

Description

Updated

Updated

Comment 1

Comment 2

Comment 3

Updated

Comment 4

Comment 5

Comment 6

Comment 7

Attachment

General

Description

File Name

Content Type