Closed Bug 1669114 Opened 4 years ago Closed 3 years ago

Intermittent devtools/client/framework/test/browser_toolbox_options_disable_js.js | A promise chain failed to handle a rejection: can't access property "get", this._containers is null - stack: getContainer@resource://devtools/client/inspector/markup/marku

Categories

(DevTools :: Framework, defect, P5)

defect

Tracking

(firefox87 fixed)

RESOLVED FIXED
87 Branch
Tracking Status
firefox87 --- fixed

People

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

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

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


[task 2020-10-04T20:21:40.382Z] 20:21:40     INFO - TEST-START | devtools/client/framework/test/browser_toolbox_options_disable_js.js
[task 2020-10-04T20:21:40.786Z] 20:21:40     INFO - GECKO(2424) | console.log: "[DISPATCH] action type:" "UPDATE_GRIDS"
[task 2020-10-04T20:21:40.822Z] 20:21:40     INFO - GECKO(2424) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
[task 2020-10-04T20:21:40.868Z] 20:21:40     INFO - GECKO(2424) | console.log: "[DISPATCH] action type:" "UPDATE_GRIDS"
[task 2020-10-04T20:21:40.909Z] 20:21:40     INFO - GECKO(2424) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
[task 2020-10-04T20:21:40.911Z] 20:21:40     INFO - GECKO(2424) | console.log: "[DISPATCH] action type:" "UPDATE_OFFSET_PARENT"
[task 2020-10-04T20:21:40.911Z] 20:21:40     INFO - GECKO(2424) | console.log: "[DISPATCH] action type:" "UPDATE_LAYOUT"
[task 2020-10-04T20:21:41.193Z] 20:21:41     INFO - GECKO(2424) | console.error: (new TypeError("can't access property \"button\", this.nodeHierarchy[this.currentIndex] is undefined", "resource://devtools/client/inspector/breadcrumbs.js", 805))
[task 2020-10-04T20:21:41.266Z] 20:21:41     INFO - GECKO(2424) | JavaScript error: resource://devtools/client/inspector/markup/markup.js, line 742: TypeError: can't access property "get", this._containers is null
[task 2020-10-04T20:21:42.377Z] 20:21:42     INFO - TEST-INFO | started process screencapture
[task 2020-10-04T20:21:42.512Z] 20:21:42     INFO - TEST-INFO | screencapture: exit 0
[task 2020-10-04T20:21:42.512Z] 20:21:42     INFO - Buffered messages logged at 20:21:40
[task 2020-10-04T20:21:42.513Z] 20:21:42     INFO - Entering test bound 
[task 2020-10-04T20:21:42.513Z] 20:21:42     INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/framework/test/browser_toolbox_options_disable_js.html
[task 2020-10-04T20:21:42.515Z] 20:21:42     INFO - Tab added and finished loading
[task 2020-10-04T20:21:42.515Z] 20:21:42     INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_options_disable_js.js | Toolbox selected via selectTool method - 
[task 2020-10-04T20:21:42.515Z] 20:21:42     INFO - Testing that JS is enabled
[task 2020-10-04T20:21:42.516Z] 20:21:42     INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_options_disable_js.js | Output is "JavaScript Enabled" - "JavaScript Enabled" == "JavaScript Enabled" - 
[task 2020-10-04T20:21:42.516Z] 20:21:42     INFO - Testing that JS is enabled in the iframe
[task 2020-10-04T20:21:42.516Z] 20:21:42     INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_options_disable_js.js | Output is "JavaScript Enabled" in iframe - "JavaScript Enabled" == "JavaScript Enabled" - 
[task 2020-10-04T20:21:42.516Z] 20:21:42     INFO - Checking checkbox to disable JS
[task 2020-10-04T20:21:42.516Z] 20:21:42     INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_options_disable_js.js | BrowsingContextTargetFront's configureOptions is correct before the toggle - 
[task 2020-10-04T20:21:42.518Z] 20:21:42     INFO - Buffered messages logged at 20:21:41
[task 2020-10-04T20:21:42.518Z] 20:21:42     INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_options_disable_js.js | BrowsingContextTargetFront's configureOptions is correctly updated - 
[task 2020-10-04T20:21:42.519Z] 20:21:42     INFO - Testing that JS is disabled
[task 2020-10-04T20:21:42.519Z] 20:21:42     INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_options_disable_js.js | output is not "JavaScript Disabled" - true == true - 
[task 2020-10-04T20:21:42.519Z] 20:21:42     INFO - Testing that JS is disabled in the iframe
[task 2020-10-04T20:21:42.519Z] 20:21:42     INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_options_disable_js.js | output is not "JavaScript Disabled" in iframe - true == true - 
[task 2020-10-04T20:21:42.519Z] 20:21:42     INFO - Clearing checkbox to re-enable JS
[task 2020-10-04T20:21:42.523Z] 20:21:42     INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_options_disable_js.js | BrowsingContextTargetFront's configureOptions is correct before the toggle - 
[task 2020-10-04T20:21:42.524Z] 20:21:42     INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_options_disable_js.js | BrowsingContextTargetFront's configureOptions is correctly updated - 
[task 2020-10-04T20:21:42.524Z] 20:21:42     INFO - Testing that JS is enabled
[task 2020-10-04T20:21:42.524Z] 20:21:42     INFO - Console message: [JavaScript Error: "TypeError: can't access property "get", this._containers is null" {file: "resource://devtools/client/inspector/markup/markup.js" line: 742}]
[task 2020-10-04T20:21:42.524Z] 20:21:42     INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_options_disable_js.js | Output is "JavaScript Enabled" - "JavaScript Enabled" == "JavaScript Enabled" - 
[task 2020-10-04T20:21:42.525Z] 20:21:42     INFO - Testing that JS is enabled in the iframe
[task 2020-10-04T20:21:42.525Z] 20:21:42     INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_options_disable_js.js | Output is "JavaScript Enabled" in iframe - "JavaScript Enabled" == "JavaScript Enabled" - 
[task 2020-10-04T20:21:42.525Z] 20:21:42     INFO - Buffered messages finished
[task 2020-10-04T20:21:42.526Z] 20:21:42     INFO - TEST-UNEXPECTED-FAIL | devtools/client/framework/test/browser_toolbox_options_disable_js.js | A promise chain failed to handle a rejection: can't access property "get", this._containers is null - stack: getContainer@resource://devtools/client/inspector/markup/markup.js:742:5
[task 2020-10-04T20:21:42.526Z] 20:21:42     INFO - _onResourceAvailable@resource://devtools/client/inspector/markup/markup.js:1390:30
[task 2020-10-04T20:21:42.526Z] 20:21:42     INFO - _notifyWatchers@resource://devtools/shared/resources/resource-watcher.js:557:24
[task 2020-10-04T20:21:42.526Z] 20:21:42     INFO - throttle/<@resource://devtools/shared/throttle.js:45:21
[task 2020-10-04T20:21:42.526Z] 20:21:42     INFO - _onResourceAvailable@resource://devtools/shared/resources/resource-watcher.js:370:10
[task 2020-10-04T20:21:42.526Z] 20:21:42     INFO - module.exports/<@resource://devtools/shared/resources/legacy-listeners/root-node.js:54:12
[task 2020-10-04T20:21:42.526Z] 20:21:42     INFO - _emit@resource://devtools/shared/event-emitter.js:226:34
[task 2020-10-04T20:21:42.526Z] 20:21:42     INFO - emit@resource://devtools/shared/event-emitter.js:172:18
[task 2020-10-04T20:21:42.526Z] 20:21:42     INFO - emit@resource://devtools/shared/event-emitter.js:324:18
[task 2020-10-04T20:21:42.526Z] 20:21:42     INFO - onPacket@resource://devtools/shared/protocol/Front.js:312:13
[task 2020-10-04T20:21:42.526Z] 20:21:42     INFO - onPacket@resource://devtools/client/devtools-client.js:492:13
[task 2020-10-04T20:21:42.526Z] 20:21:42     INFO - send/<@resource://devtools/shared/transport/local-transport.js:68:25
[task 2020-10-04T20:21:42.526Z] 20:21:42     INFO - exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:103:22
[task 2020-10-04T20:21:42.527Z] 20:21:42     INFO - DevToolsUtils.executeSoon*exports.executeSoon@resource://devtools/shared/DevToolsUtils.js:54:21
[task 2020-10-04T20:21:42.527Z] 20:21:42     INFO - send@resource://devtools/shared/transport/local-transport.js:56:21
[task 2020-10-04T20:21:42.527Z] 20:21:42     INFO - send@resource://devtools/server/devtools-server-connection.js:99:20
[task 2020-10-04T20:21:42.527Z] 20:21:42     INFO - receiveMessage@resource://devtools/shared/transport/child-transport.js:66:16
[task 2020-10-04T20:21:42.527Z] 20:21:42     INFO - MessageListener.receiveMessage*_addListener@resource://devtools/shared/transport/child-transport.js:40:14
[task 2020-10-04T20:21:42.527Z] 20:21:42     INFO - ready@resource://devtools/shared/transport/child-transport.js:57:10
[task 2020-10-04T20:21:42.527Z] 20:21:42     INFO - connectToFrame/</onActorCreated<@resource://devtools/server/connectors/frame-connector.js:183:22
[task 2020-10-04T20:21:42.527Z] 20:21:42     INFO - exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:103:22
[task 2020-10-04T20:21:42.527Z] 20:21:42     INFO - MessageListener.receiveMessage*trackMessageManager@resource://devtools/server/connectors/frame-connector.js:55:12
[task 2020-10-04T20:21:42.527Z] 20:21:42     INFO - connectToFrame/<@resource://devtools/server/connectors/frame-connector.js:283:5
[task 2020-10-04T20:21:42.528Z] 20:21:42     INFO - connectToFrame@resource://devtools/server/connectors/frame-connector.js:41:10
[task 2020-10-04T20:21:42.529Z] 20:21:42     INFO - getTarget/<@resource://devtools/server/actors/descriptors/tab.js:159:35
[task 2020-10-04T20:21:42.529Z] 20:21:42     INFO - getTarget@resource://devtools/server/actors/descriptors/tab.js:143:12
[task 2020-10-04T20:21:42.529Z] 20:21:42     INFO - handler@resource://devtools/shared/protocol/Actor.js:172:37
[task 2020-10-04T20:21:42.530Z] 20:21:42     INFO - onPacket@resource://devtools/server/devtools-server-connection.js:379:58
[task 2020-10-04T20:21:42.530Z] 20:21:42     INFO - send/<@resource://devtools/shared/transport/local-transport.js:68:25
[task 2020-10-04T20:21:42.530Z] 20:21:42     INFO - exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:103:22
[task 2020-10-04T20:21:42.530Z] 20:21:42     INFO - DevToolsUtils.executeSoon*exports.executeSoon@resource://devtools/shared/DevToolsUtils.js:54:21```

I think most of the browser_toolbox_options_disable_js.js intermittents are related to a race condition between the watchResources/unwatchResources calls made by the markup view.

MarkupView calls watchResources from its constructor, and unwatchResources from its destroy.
The issue is that watchResources is async, and will only populate the internal _watchers array of ResourceWatcher at the end of the method. If unwatchResource is called before watchResources could resolve then the entry will not be purged from the resourceWatcher.

In this case this means that a destroyed MarkupView instance will keep receive resource available notifications, which will fail in various ways, leading to unhandled promise rejections.

Several thoughts on how to fix this:

  • the test could open on the options panel directly and not involve the inspector at all
  • resource watcher could support calls to unwatchResources happening before watchResources resolved (need a new map to keep track of things but doable)
  • markup view should properly wait on its watchResources call (but it wouldn't fix anything here, the inspector is just a panel loaded in the background)
  • markup view should add some logic to unwatchResources only after watchResources was called

Obviously I'll go for the first option here as the others require more discussion.

Assignee: nobody → jdescottes
Status: NEW → ASSIGNED
Blocks: 1692995
Pushed by jdescottes@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/57fd0943cb50
[devtools] Do not involve the inspector in browser_toolbox_options_disable_js r=nchevobbe
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → 87 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: