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

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

Merge: https://hg.mozilla.org/mozilla-central/pushloghtml?changeset=3dfec4ecf5a5a93c53541beeb70b52a9a23403e5

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.

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

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

Depends on D83703

Sorry about that, we had to regenerate stubs.

https://hg.mozilla.org/mozilla-central/rev/beecfe21a94e
https://hg.mozilla.org/mozilla-central/rev/5959e2315836