Perma [tier2] devtools/client/framework/test/browser_tab_descriptor_fission.js | A promise chain failed to handle a rejection: Connection closed, pending request to server0.conn24.child22/consoleActor3, type getCachedMessages/startListeners failed
Categories
(DevTools :: Framework, defect, P5)
Tracking
(firefox80 fixed)
Tracking | Status | |
---|---|---|
firefox80 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: jdescottes)
References
Details
(Keywords: intermittent-failure)
Attachments
(2 files)
Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=309121627&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/CdCcSBuzQcuSFnNbSpUq9Q/runs/2/artifacts/public/logs/live_backing.log
[task 2020-07-09T11:17:37.401Z] 11:17:37 INFO - TEST-START | devtools/client/framework/test/browser_tab_descriptor_fission.js
[task 2020-07-09T11:17:39.789Z] 11:17:39 INFO - GECKO(3860) | JavaScript error: resource://devtools/shared/protocol/Front.js, line 77: Error: Connection closed, pending request to server0.conn24.child22/consoleActor3, type getCachedMessages failed
[task 2020-07-09T11:17:39.790Z] 11:17:39 INFO - GECKO(3860) | Request stack:
[task 2020-07-09T11:17:39.790Z] 11:17:39 INFO - GECKO(3860) | request@resource://devtools/shared/protocol/Front.js:256:14
[task 2020-07-09T11:17:39.790Z] 11:17:39 INFO - GECKO(3860) | generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol/Front/FrontClassWithSpec.js:47:19
[task 2020-07-09T11:17:39.790Z] 11:17:39 INFO - GECKO(3860) | getCachedMessages@resource://devtools/client/fronts/webconsole.js:312:34
[task 2020-07-09T11:17:39.790Z] 11:17:39 INFO - GECKO(3860) | module.exports@resource://devtools/shared/resources/legacy-listeners/platform-messages.js:34:44
[task 2020-07-09T11:17:39.790Z] 11:17:39 INFO - GECKO(3860) | async*_watchResourcesForTarget@resource://devtools/shared/resources/resource-watcher.js:371:41
[task 2020-07-09T11:17:39.790Z] 11:17:39 INFO - GECKO(3860) | _onTargetAvailable@resource://devtools/shared/resources/resource-watcher.js:193:18
[task 2020-07-09T11:17:39.793Z] 11:17:39 INFO - GECKO(3860) | Async*_emit@resource://devtools/shared/event-emitter.js:226:34
[task 2020-07-09T11:17:39.794Z] 11:17:39 INFO - GECKO(3860) | emitAsync@resource://devtools/shared/event-emitter.js:176:25
[task 2020-07-09T11:17:39.795Z] 11:17:39 INFO - GECKO(3860) | emitAsync@resource://devtools/shared/event-emitter.js:328:25
[task 2020-07-09T11:17:39.795Z] 11:17:39 INFO - GECKO(3860) | _onTargetAvailable@resource://devtools/shared/resources/target-list.js:169:33
[task 2020-07-09T11:17:39.796Z] 11:17:39 INFO - GECKO(3860) | switchToTarget@resource://devtools/shared/resources/target-list.js:508:16
[task 2020-07-09T11:17:39.797Z] 11:17:39 INFO - GECKO(3860) | onLocalTabRemotenessChange@resource://devtools/shared/resources/target-list.js:491:10
[task 2020-07-09T11:17:39.797Z] 11:17:39 INFO - GECKO(3860) | Async*_emit@resource://devtools/shared/event-emitter.js:226:34
[task 2020-07-09T11:17:39.798Z] 11:17:39 INFO - GECKO(3860) | emit@resource://devtools/shared/event-emitter.js:172:18
[task 2020-07-09T11:17:39.798Z] 11:17:39 INFO - GECKO(3860) | emit@resource://devtools/shared/event-emitter.js:324:18
[task 2020-07-09T11:17:39.798Z] 11:17:39 INFO - GECKO(3860) | _onRemotenessChange@resource://devtools/client/fronts/targets/local-tab.js:132:12
[task 2020-07-09T11:17:39.798Z] 11:17:39 INFO - GECKO(3860) | _handleTabEvent@resource://devtools/client/fronts/targets/local-tab.js:98:14
[task 2020-07-09T11:17:39.801Z] 11:17:39 INFO - GECKO(3860) | didChange@chrome://browser/content/tabbrowser.js:5717:15
[task 2020-07-09T11:17:39.801Z] 11:17:39 INFO - GECKO(3860) | finishChangeRemoteness@chrome://global/content/elements/browser-custom-element.js:1900:12
[task 2020-07-09T11:17:39.801Z] 11:17:39 INFO - GECKO(3860) | getInterfaceProxy/get/<@chrome://global/content/customElements.js:696:35
[task 2020-07-09T11:17:39.808Z] 11:17:39 INFO - TEST-INFO | started process screentopng
[task 2020-07-09T11:17:40.153Z] 11:17:40 INFO - TEST-INFO | screentopng: exit 0
[task 2020-07-09T11:17:40.173Z] 11:17:40 INFO - TEST-PASS | devtools/client/framework/test/browser_tab_descriptor_fission.js | The main process DevToolsServer has no pending connection when the test ends -
[task 2020-07-09T11:17:40.176Z] 11:17:40 INFO - Console message: [JavaScript Error: "Error: Connection closed, pending request to server0.conn24.child22/consoleActor3, type getCachedMessages failed
[task 2020-07-09T11:17:40.177Z] 11:17:40 INFO -
[task 2020-07-09T11:17:40.177Z] 11:17:40 INFO - Request stack:
[task 2020-07-09T11:17:40.178Z] 11:17:40 INFO - request@resource://devtools/shared/protocol/Front.js:256:14
[task 2020-07-09T11:17:40.179Z] 11:17:40 INFO - generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol/Front/FrontClassWithSpec.js:47:19
[task 2020-07-09T11:17:40.179Z] 11:17:40 INFO - getCachedMessages@resource://devtools/client/fronts/webconsole.js:312:34
[task 2020-07-09T11:17:40.180Z] 11:17:40 INFO - module.exports@resource://devtools/shared/resources/legacy-listeners/platform-messages.js:34:44
[task 2020-07-09T11:17:40.180Z] 11:17:40 INFO - async*_watchResourcesForTarget@resource://devtools/shared/resources/resource-watcher.js:371:41
[task 2020-07-09T11:17:40.181Z] 11:17:40 INFO - _onTargetAvailable@resource://devtools/shared/resources/resource-watcher.js:193:18
[task 2020-07-09T11:17:40.181Z] 11:17:40 INFO - Async*_emit@resource://devtools/shared/event-emitter.js:226:34
[task 2020-07-09T11:17:40.182Z] 11:17:40 INFO - emitAsync@resource://devtools/shared/event-emitter.js:176:25
[task 2020-07-09T11:17:40.182Z] 11:17:40 INFO - emitAsync@resource://devtools/shared/event-emitter.js:328:25
[task 2020-07-09T11:17:40.183Z] 11:17:40 INFO - _onTargetAvailable@resource://devtools/shared/resources/target-list.js:169:33
[task 2020-07-09T11:17:40.183Z] 11:17:40 INFO - switchToTarget@resource://devtools/shared/resources/target-list.js:508:16
[task 2020-07-09T11:17:40.184Z] 11:17:40 INFO - onLocalTabRemotenessChange@resource://devtools/shared/resources/target-list.js:491:10
[task 2020-07-09T11:17:40.184Z] 11:17:40 INFO - Async*_emit@resource://devtools/shared/event-emitter.js:226:34
[task 2020-07-09T11:17:40.185Z] 11:17:40 INFO - emit@resource://devtools/shared/event-emitter.js:172:18
[task 2020-07-09T11:17:40.185Z] 11:17:40 INFO - emit@resource://devtools/shared/event-emitter.js:324:18
[task 2020-07-09T11:17:40.186Z] 11:17:40 INFO - _onRemotenessChange@resource://devtools/client/fronts/targets/local-tab.js:132:12
[task 2020-07-09T11:17:40.187Z] 11:17:40 INFO - _handleTabEvent@resource://devtools/client/fronts/targets/local-tab.js:98:14
[task 2020-07-09T11:17:40.187Z] 11:17:40 INFO - didChange@chrome://browser/content/tabbrowser.js:5717:15
[task 2020-07-09T11:17:40.188Z] 11:17:40 INFO - finishChangeRemoteness@chrome://global/content/elements/browser-custom-element.js:1900:12
[task 2020-07-09T11:17:40.188Z] 11:17:40 INFO - getInterfaceProxy/get/<@chrome://global/content/customElements.js:696:35
[task 2020-07-09T11:17:40.189Z] 11:17:40 INFO - " {file: "resource://devtools/shared/protocol/Front.js" line: 77}]
[task 2020-07-09T11:17:40.189Z] 11:17:40 INFO - Buffered messages finished
[task 2020-07-09T11:17:40.191Z] 11:17:40 INFO - TEST-UNEXPECTED-FAIL | devtools/client/framework/test/browser_tab_descriptor_fission.js | A promise chain failed to handle a rejection: Connection closed, pending request to server0.conn24.child22/consoleActor3, type getCachedMessages failed
[task 2020-07-09T11:17:40.193Z] 11:17:40 INFO -
[task 2020-07-09T11:17:40.193Z] 11:17:40 INFO - Request stack:
[task 2020-07-09T11:17:40.194Z] 11:17:40 INFO - request@resource://devtools/shared/protocol/Front.js:256:14
[task 2020-07-09T11:17:40.195Z] 11:17:40 INFO - generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol/Front/FrontClassWithSpec.js:47:19
[task 2020-07-09T11:17:40.195Z] 11:17:40 INFO - getCachedMessages@resource://devtools/client/fronts/webconsole.js:312:34
[task 2020-07-09T11:17:40.196Z] 11:17:40 INFO - module.exports@resource://devtools/shared/resources/legacy-listeners/platform-messages.js:34:44
[task 2020-07-09T11:17:40.197Z] 11:17:40 INFO - async*_watchResourcesForTarget@resource://devtools/shared/resources/resource-watcher.js:371:41
[task 2020-07-09T11:17:40.197Z] 11:17:40 INFO - _onTargetAvailable@resource://devtools/shared/resources/resource-watcher.js:193:18
[task 2020-07-09T11:17:40.198Z] 11:17:40 INFO - Async*_emit@resource://devtools/shared/event-emitter.js:226:34
[task 2020-07-09T11:17:40.198Z] 11:17:40 INFO - emitAsync@resource://devtools/shared/event-emitter.js:176:25
[task 2020-07-09T11:17:40.199Z] 11:17:40 INFO - emitAsync@resource://devtools/shared/event-emitter.js:328:25
[task 2020-07-09T11:17:40.199Z] 11:17:40 INFO - _onTargetAvailable@resource://devtools/shared/resources/target-list.js:169:33
[task 2020-07-09T11:17:40.200Z] 11:17:40 INFO - switchToTarget@resource://devtools/shared/resources/target-list.js:508:16
[task 2020-07-09T11:17:40.201Z] 11:17:40 INFO - onLocalTabRemotenessChange@resource://devtools/shared/resources/target-list.js:491:10
[task 2020-07-09T11:17:40.202Z] 11:17:40 INFO - Async*_emit@resource://devtools/shared/event-emitter.js:226:34
[task 2020-07-09T11:17:40.221Z] 11:17:40 INFO - emit@resource://devtools/shared/event-emitter.js:172:18
[task 2020-07-09T11:17:40.227Z] 11:17:40 INFO - emit@resource://devtools/shared/event-emitter.js:324:18
[task 2020-07-09T11:17:40.228Z] 11:17:40 INFO - _onRemotenessChange@resource://devtools/client/fronts/targets/local-tab.js:132:12
[task 2020-07-09T11:17:40.229Z] 11:17:40 INFO - _handleTabEvent@resource://devtools/client/fronts/targets/local-tab.js:98:14
[task 2020-07-09T11:17:40.229Z] 11:17:40 INFO - didChange@chrome://browser/content/tabbrowser.js:5717:15
[task 2020-07-09T11:17:40.230Z] 11:17:40 INFO - finishChangeRemoteness@chrome://global/content/elements/browser-custom-element.js:1900:12
[task 2020-07-09T11:17:40.230Z] 11:17:40 INFO - getInterfaceProxy/get/<@chrome://global/content/customElements.js:696:35
[task 2020-07-09T11:17:40.231Z] 11:17:40 INFO - - stack: destroy@resource://devtools/shared/protocol/Front.js:77:23
[task 2020-07-09T11:17:40.232Z] 11:17:40 INFO - destroy@resource://devtools/client/fronts/webconsole.js:615:18
[task 2020-07-09T11:17:40.233Z] 11:17:40 INFO - _destroyTarget@resource://devtools/client/fronts/targets/target-mixin.js:565:15
[task 2020-07-09T11:17:40.233Z] 11:17:40 INFO - destroy@resource://devtools/client/fronts/targets/target-mixin.js:550:12
[task 2020-07-09T11:17:40.234Z] 11:17:40 INFO - destroy@resource://devtools/client/fronts/targets/browsing-context.js:129:27
[task 2020-07-09T11:17:40.234Z] 11:17:40 INFO - _destroyToolbox/onceDestroyed</<@resource://devtools/client/framework/toolbox.js:3784:32
[task 2020-07-09T11:17:40.235Z] 11:17:40 INFO - Rejection date: Thu Jul 09 2020 11:17:39 GMT+0000 (Coordinated Universal Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 265
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 3•4 years ago
|
||
This changed into "startListeners failed" starting with: https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&group_state=expanded&searchStr=windows%2C10%2Cx64%2Copt%2Cmochitests%2Cwith%2Cfission%2Cenabled%2Ctest-windows10-64%2Fopt-mochitest-devtools-chrome-fis-e10s%2Cdt4&revision=3dfec4ecf5a5a93c53541beeb70b52a9a23403e5&selectedTaskRun=KJKVNeRTQ-ySemPtwmsA6A.0
Log: https://treeherder.mozilla.org/logviewer.html#?job_id=309658775&repo=mozilla-central
Assignee | ||
Comment 4•4 years ago
|
||
The issue here is that the local-tab target fires a remoteness-change event while we destroy the toolbox during the test shutdown.
I guess the remoteness change event could be triggered when closing a tab?
But our cleanup code is supposed to first destroy the toolbox and then only close the tabs:
https://searchfox.org/mozilla-central/rev/82c04b9cad5b98bdf682bd477f2b1e3071b004ad/devtools/client/shared/test/shared-head.js#784-795
So in theory the local-tab target should be destroyed before we try to close the tab.
Is the remoteness-change event triggered by something else?
Ignoring that, we probably start seeing this intermittent only now because the target-list will unconditionally call onTargetAvailable when receiving the remoteness-change event on its current localtab-target. The toolbox destroy calls TargetList::stopListener, but this won't cleanup the listener on remoteness-change.
Assignee | ||
Comment 5•4 years ago
|
||
Actually it's much simpler than this. The remoteness event which triggers the failure is the one we explicitly perform in the test. But one of our resource watchers doesn't properly await on startListeners
Assignee | ||
Updated•4 years ago
|
Assignee | ||
Comment 6•4 years ago
|
||
Pushed by jdescottes@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/44a40788841e Wait for webConsoleFront.startListeners in legacy network-event resource watcher r=nchevobbe
Comment 8•4 years ago
|
||
Backed out for dt failures on browser_webconsole_stubs_network_event.js
Backout link: https://hg.mozilla.org/integration/autoland/rev/ac00f620614c25daef81e30b7cfa19b005f7a903
Log link: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=309967346&repo=autoland&lineNumber=4200
Assignee | ||
Comment 9•4 years ago
|
||
Depends on D83703
Comment 10•4 years ago
|
||
Pushed by jdescottes@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/beecfe21a94e Wait for webConsoleFront.startListeners in legacy network-event resource watcher r=nchevobbe https://hg.mozilla.org/integration/autoland/rev/5959e2315836 Update stubs for browser_webconsole_stubs_network_event.js r=nchevobbe
Assignee | ||
Comment 11•4 years ago
|
||
Sorry about that, we had to regenerate stubs.
Comment 12•4 years ago
|
||
bugherder |
https://hg.mozilla.org/mozilla-central/rev/beecfe21a94e
https://hg.mozilla.org/mozilla-central/rev/5959e2315836
Comment hidden (Intermittent Failures Robot) |
Description
•