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

[task 2020-06-13T02:40:00.798Z] 02:40:00 INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-scopes-duplicated.js | The main process DevToolsServer has no pending connection when the test ends -
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - Console message: [JavaScript Error: "Error: Can not send request 'getNodeActorFromObjectActor' because front 'domwalker' is already destroyed." {file: "resource://devtools/shared/protocol/Front/FrontClassWithSpec.js" line: 29}]
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - Buffered messages finished
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - TEST-UNEXPECTED-FAIL | devtools/client/debugger/test/mochitest/browser_dbg-scopes-duplicated.js | A promise chain failed to handle a rejection: Can not send request 'getNodeActorFromObjectActor' because front 'domwalker' is already destroyed. - stack: generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol/Front/FrontClassWithSpec.js:29:15
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - gripToNodeFront@resource://devtools/client/fronts/walker.js:156:33
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - getNodeFrontFromNodeGrip@resource://devtools/client/fronts/inspector.js:163:26
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - getHighlighter/highlight/pendingHighlight<@resource://devtools/client/framework/toolbox.js:3529:46
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - async*highlight@resource://devtools/client/framework/toolbox.js:3539:11
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - highlightDomElement@resource://devtools/client/debugger/panel.js:157:17
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - highlightDomElement/<@resource://devtools/client/debugger/src/actions/toolbox.js:57:18
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:29:45
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - bindActionCreator/<@resource://devtools/client/shared/vendor/redux.js:520:12
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - onDOMNodeMouseOver@resource://devtools/client/debugger/src/components/SecondaryPanes/Scopes.js:188:56
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - onMouseOver@resource://devtools/client/shared/components/reps/reps.js:7081:45
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - invokeGuardedCallbackImpl@resource://devtools/client/shared/vendor/react-dom.js:74:10
[task 2020-06-13T02:40:00.799Z] 02:40:00 INFO - invokeGuardedCallback@resource://devtools/client/shared/vendor/react-dom.js:111:29
[task 2020-06-13T02:40:00.800Z] 02:40:00 INFO - invokeGuardedCallbackAndCatchFirstError@resource://devtools/client/shared/vendor/react-dom.js:125:25
[task 2020-06-13T02:40:00.800Z] 02:40:00 INFO - executeDispatch@resource://devtools/client/shared/vendor/react-dom.js:346:42
[task 2020-06-13T02:40:00.800Z] 02:40:00 INFO - executeDispatchesInOrder@resource://devtools/client/shared/vendor/react-dom.js:365:20
[task 2020-06-13T02:40:00.800Z] 02:40:00 INFO - executeDispatchesAndRelease@resource://devtools/client/shared/vendor/react-dom.js:462:29
[task 2020-06-13T02:40:00.800Z] 02:40:00 INFO - executeDispatchesAndReleaseTopLevel@resource://devtools/client/shared/vendor/react-dom.js:470:10
[task 2020-06-13T02:40:00.800Z] 02:40:00 INFO - forEachAccumulated@resource://devtools/client/shared/vendor/react-dom.js:444:8
[task 2020-06-13T02:40:00.800Z] 02:40:00 INFO - runEventsInBatch@resource://devtools/client/shared/vendor/react-dom.js:598:21
[task 2020-06-13T02:40:00.800Z] 02:40:00 INFO - runExtractedEventsInBatch@resource://devtools/client/shared/vendor/react-dom.js:606:19

Based on https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=Windows%2C7%2Cdebug%2CMochitests%2Ctest-windows7-32%2Fdebug-mochitest-devtools-chrome-e10s-4%2CM%28dt4%29&fromchange=99ea9e6229cbb44a344afc83b572a0450777aac9&tochange=308399471b6e70a047951712e4cb8e91bfc795a8&selectedTaskRun=Gb96CyX_Qb2fg1dKNXjulw.0 I think bug 1644669 is the culprit.

Marco, could you take a look?

My push from bug 1644669 didn't touch any of that code. So I don't see how this intermittent could be related. Someone more familiar with the Debugger tests should look at this.

Continued retriggers: https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=windows%2C7%2Cdebug%2Cmochitests%2Ctest-windows7-32%2Fdebug-mochitest-devtools-chrome-e10s-4%2Cm%28dt4%29&fromchange=0b4d785bd7a16c1ccbac06957ee784d3f5c49750&tochange=308399471b6e70a047951712e4cb8e91bfc795a8

Continued retriggers and backfills: https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=windows%2C7%2Cdebug%2Cmochitests%2Ctest-windows7-32%2Fdebug-mochitest-devtools-chrome-e10s-4%2Cm%28dt4%29&fromchange=ca053f5829f0856d66291432ebfe55722bc7c066&tochange=308399471b6e70a047951712e4cb8e91bfc795a8&group_state=expanded&selectedTaskRun=Ts8WJexRSympnyP8RrR7Sg.0

Moving to another chunk found so far: https://treeherder.mozilla.org/#/jobs?repo=autoland&group_state=expanded&searchStr=Windows%2C10%2Cx64%2Casan%2CMochitests%2Ctest-windows10-64-asan%2Fopt-mochitest-devtools-chrome-e10s-8%2CM%28dt8%29&fromchange=ca053f5829f0856d66291432ebfe55722bc7c066&tochange=308399471b6e70a047951712e4cb8e91bfc795a8&selectedTaskRun=TAAa568KRjq4Al_OGZJolQ.0

Could it be Bug 1594467?

Can you check what started this frequent failure, please?

aryx: Did you mean to close this one as duplicate? The two bugs don't seem related.

Julian, this bug is on our disable-recommended filter. Are there any updates?

https://hg.mozilla.org/mozilla-central/rev/ca79c56a0a1b

Here's what I could gather. We can focus on this part of the stack:

gripToNodeFront@resource://devtools/client/fronts/walker.js:156:33
getNodeFrontFromNodeGrip@resource://devtools/client/fronts/inspector.js:163:26
getHighlighter/highlight/pendingHighlight<@resource://devtools/client/framework/toolbox.js:3529:46
async*highlight@resource://devtools/client/framework/toolbox.js:3539:11
highlightDomElement@resource://devtools/client/debugger/panel.js:157:17
highlightDomElement/<@resource://devtools/client/debugger/src/actions/toolbox.js:57:18
thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:29:45
bindActionCreator/<@resource://devtools/client/shared/vendor/redux.js:520:12
onDOMNodeMouseOver@resource://devtools/client/debugger/src/components/SecondaryPanes/Scopes.js:188:56
onMouseOver@resource://devtools/client/shared/components/reps/reps.js:7081:45

The Scopes pane can show small "highlight" icons next to DOM nodes. What seems to happen here is that a call to the highlighters is triggered at the end of the test, because the mouse cursor was over one of those "highlight icons". However, the test itself is not asserting anything related to mouse events.

Testing locally, I managed to get the same failure by leaving my mouse cursor exactly where one of those icons would show up, and running with --verify. Even then,it only failed pretty rarely.

Anyway, my guess is that either a previous test is moving the mouse in a wrong spot, or maybe this is the default position of the mouse on this platform. As far as fixing this, we could either:

• wait for requests to settle at the end of the test
• or move the mouse somewhere else at the beginning of the test
• update Toolbox::highlight to catch errors occurring after toolbox destroy

None of those fixes are really satisfactory as they just address the symptoms in various ways. The root cause is that we don't have a solution to handle async calls that are fired around the time of a toolbox destroy. I wish we had a way to cancel all devtools generated promises when the toolbox is destroyed.

We very often have to introduce a pattern in our async methods in order to "swallow"
async errors if a panel was destroyed, if the toolbox was destroyed etc...

This is not an issue in a regular usage of the toolbox, but it can lead to many intermittent failures.
One solution could be to always wait for all requests to be completed before shutting down tests.
Another approach is to have an easy way of swallowing errors when a certain condition is true.

The helper added here will run the provide method in a try catch, and will only bubble up errors if the provided check fails.

Depends on D81675

This should fix the intermittents related to pending highlight requests when toolbox is destroyed.
See https://bugzilla.mozilla.org/show_bug.cgi?id=1645563#c21 for additional context

Depends on D81676

Depends on D81677

We recently introduced a modification to updateWorkers in order to swallow errors after destroy.
Since I am suggesting to add a helper to take care of a similar issue in Toolbox::highlight I think we could also apply it here.

https://hg.mozilla.org/mozilla-central/rev/59f5ba699cc7
https://hg.mozilla.org/mozilla-central/rev/6c62392d88f7
https://hg.mozilla.org/mozilla-central/rev/948201d152d3
https://hg.mozilla.org/mozilla-central/rev/fc8c959faac2

The new failures are for a different error message, which is tracked by Bug 1699590 (A promise chain failed to handle a rejection: Actor 'SpecialPowers' destroyed before query 'Spawn' was resolved).