Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=251982960&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/YfH3Gc-MTkyll198z2UJRw/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/YfH3Gc-MTkyll198z2UJRw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2019-06-15T00:57:29.729Z] 00:57:29 INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js | foo -
[task 2019-06-15T00:57:29.729Z] 00:57:29 INFO - Toggling node var_weakset
[task 2019-06-15T00:57:29.730Z] 00:57:29 INFO - Buffered messages finished
[task 2019-06-15T00:57:29.730Z] 00:57:29 INFO - TEST-UNEXPECTED-FAIL | devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js | A promise chain failed to handle a rejection: Connection closed, pending request to server1.conn3.child1/workerTarget21/context1, type removeBreakpoint failed
[task 2019-06-15T00:57:29.730Z] 00:57:29 INFO -
[task 2019-06-15T00:57:29.730Z] 00:57:29 INFO - Request stack:
[task 2019-06-15T00:57:29.732Z] 00:57:29 INFO - request@resource://devtools/shared/protocol.js:1386:14
[task 2019-06-15T00:57:29.733Z] 00:57:29 INFO - generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol.js:1510:19
[task 2019-06-15T00:57:29.734Z] 00:57:29 INFO - removeBreakpoint/<@resource://devtools/client/debugger/src/client/firefox/commands.js:208:46
[task 2019-06-15T00:57:29.734Z] 00:57:29 INFO - forEachWorkerThread/promises<@resource://devtools/client/debugger/src/client/firefox/commands.js:92:60
[task 2019-06-15T00:57:29.735Z] 00:57:29 INFO - forEachWorkerThread@resource://devtools/client/debugger/src/client/firefox/commands.js:92:46
[task 2019-06-15T00:57:29.736Z] 00:57:29 INFO - removeBreakpoint@resource://devtools/client/debugger/src/client/firefox/commands.js:208:9
[task 2019-06-15T00:57:29.737Z] 00:57:29 INFO - clientRemoveBreakpoint@resource://devtools/client/debugger/src/actions/breakpoints/modify.js:54:17
[task 2019-06-15T00:57:29.738Z] 00:57:29 INFO - removeBreakpoint/<@resource://devtools/client/debugger/src/actions/breakpoints/modify.js:152:69
[task 2019-06-15T00:57:29.738Z] 00:57:29 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-06-15T00:57:29.739Z] 00:57:29 INFO - bindActionCreator/<@resource://devtools/client/shared/vendor/redux.js:644:12
[task 2019-06-15T00:57:29.740Z] 00:57:29 INFO - removeBreakpoint@chrome://mochitests/content/browser/devtools/client/debugger/test/mochitest/helpers.js:960:22
[task 2019-06-15T00:57:29.740Z] 00:57:29 INFO - @chrome://mochitests/content/browser/devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js:47:9
[task 2019-06-15T00:57:29.741Z] 00:57:29 INFO - AsyncTester_execTest/<@chrome://mochikit/content/browser-test.js:1115:34
[task 2019-06-15T00:57:29.742Z] 00:57:29 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1143:12
[task 2019-06-15T00:57:29.742Z] 00:57:29 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:999:14
[task 2019-06-15T00:57:29.743Z] 00:57:29 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:803:59
[task 2019-06-15T00:57:29.744Z] 00:57:29 INFO - - stack: destroy@resource://devtools/shared/protocol.js:1299:23
[task 2019-06-15T00:57:29.744Z] 00:57:29 INFO - TargetMixin/destroy/this._destroyer<@resource://devtools/shared/fronts/targets/target-mixin.js:539:23
[task 2019-06-15T00:57:29.745Z] 00:57:29 INFO - asyncdestroy@resource://devtools/shared/fronts/targets/target-mixin.js:573:9
[task 2019-06-15T00:57:29.746Z] 00:57:29 INFO - newListener@resource://devtools/shared/event-emitter.js:145:22
[task 2019-06-15T00:57:29.747Z] 00:57:29 INFO - emit@resource://devtools/shared/event-emitter.js:186:24
[task 2019-06-15T00:57:29.747Z] 00:57:29 INFO - emit@resource://devtools/shared/event-emitter.js:267:18
[task 2019-06-15T00:57:29.748Z] 00:57:29 INFO - onPacket@resource://devtools/shared/protocol.js:1424:13
[task 2019-06-15T00:57:29.749Z] 00:57:29 INFO - onPacket@resource://devtools/shared/client/debugger-client.js:560:13
[task 2019-06-15T00:57:29.749Z] 00:57:29 INFO - send/<@resource://devtools/shared/transport/local-transport.js:64:23
[task 2019-06-15T00:57:29.750Z] 00:57:29 INFO - exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:109:22
[task 2019-06-15T00:57:29.750Z] 00:57:29 INFO - DevToolsUtils.executeSoonexports.executeSoon@resource://devtools/shared/DevToolsUtils.js:55:21
[task 2019-06-15T00:57:29.751Z] 00:57:29 INFO - send@resource://devtools/shared/transport/local-transport.js:58:21
[task 2019-06-15T00:57:29.751Z] 00:57:29 INFO - send@resource://devtools/server/main.js:1023:20
[task 2019-06-15T00:57:29.752Z] 00:57:29 INFO - receiveMessage@resource://devtools/shared/transport/child-transport.js:66:16
[task 2019-06-15T00:57:29.753Z] 00:57:29 INFO - MessageListener.receiveMessage_addListener@resource://devtools/shared/transport/child-transport.js:40:14
[task 2019-06-15T00:57:29.753Z] 00:57:29 INFO - ready@resource://devtools/shared/transport/child-transport.js:57:10
[task 2019-06-15T00:57:29.753Z] 00:57:29 INFO - connectToFrame/</onActorCreated<@resource://devtools/server/main.js:730:24
[task 2019-06-15T00:57:29.753Z] 00:57:29 INFO - exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:109:22
[task 2019-06-15T00:57:29.754Z] 00:57:29 INFO - MessageListener.receiveMessage*trackMessageManager@resource://devtools/server/main.js:612:14
[task 2019-06-15T00:57:29.754Z] 00:57:29 INFO - connectToFrame/<@resource://devtools/server/main.js:825:7
[task 2019-06-15T00:57:29.754Z] 00:57:29 INFO - connectToFrame@resource://devtools/server/main.js:601:12
[task 2019-06-15T00:57:29.755Z] 00:57:29 INFO - connect@resource://devtools/server/actors/targets/frame-proxy.js:57:36

Hi Yulia, looks like this started as a TV failure when bug 1494796 landed then moved on to tier1 failures.

There are 26 failures in the last 3 days on linux64 asan, linux64-shippable, macosx1014-64-shippable, windows7-32-shippable opt builds

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=252114696&repo=mozilla-inbound&lineNumber=12666

[task 2019-06-16T19:57:14.570Z] 19:57:14 INFO - TEST-START | devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js
[task 2019-06-16T19:57:15.461Z] 19:57:15 INFO - GECKO(1077) | [ACTION] SET_ORIENTATION - {"type":"SET_ORIENTATION","orientation":"horizontal"}
[task 2019-06-16T19:57:15.528Z] 19:57:15 INFO - GECKO(1077) | [ACTION] RECEIVE_EVENT_LISTENER_TYPES - {"type":"RECEIVE_EVENT_LISTENER_TYPES"}

[task 2019-06-16T19:57:18.564Z] 19:57:18 INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js | bar -
[task 2019-06-16T19:57:18.565Z] 19:57:18 INFO - Toggling node var_weakmap
[task 2019-06-16T19:57:18.565Z] 19:57:18 INFO - Toggling node var_weakset
[task 2019-06-16T19:57:18.567Z] 19:57:18 INFO - Toggling node <entries>
[task 2019-06-16T19:57:18.567Z] 19:57:18 INFO - Toggling node 0
[task 2019-06-16T19:57:18.569Z] 19:57:18 INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js | foo -
[task 2019-06-16T19:57:18.570Z] 19:57:18 INFO - Toggling node var_weakset
[task 2019-06-16T19:57:18.570Z] 19:57:18 INFO - Buffered messages finished
[task 2019-06-16T19:57:18.581Z] 19:57:18 INFO - TEST-UNEXPECTED-FAIL | devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js | A promise chain failed to handle a rejection: Connection closed, pending request to server1.conn107.child1/workerTarget21/context1, type removeBreakpoint failed

Yulia, I'm happy to help investigate. This test is a good bellweather for breakpoint and specifically breakpoints in worker threads.

[ACTION] REMOVE_BREAKPOINT [start] - {}
[ACTION] IN_SCOPE_LINES  - {}
[ACTION] MAP_SCOPES [done] - {}
[ACTION] EVALUATE_EXPRESSIONS  - {"type":"EVALUATE_EXPRESSIONS","cx":{"navigateCounter":0,"thread":"server1.conn107.child1/workerTarget24/context1","isPaused":true,"pauseCounter":1},"inputs":[],"results":[]}
[ACTION] SET_VIEWPORT  - {"type":"SET_VIEWPORT","viewport":{"start":{"line":3,"column":0},"end":{"line":14,"column":91}}}
JavaScript error: resource://devtools/shared/protocol.js, line 1299: Error: Connection closed, pending request to server1.conn107.child1/workerTarget21/context1, type removeBreakpoint failed
Request stack:
  request@resource://devtools/shared/protocol.js:1386:14
  generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol.js:1510:19
  removeBreakpoint/<@resource://devtools/client/debugger/src/client/firefox/commands.js:208:46
  forEachWorkerThread/promises<@resource://devtools/client/debugger/src/client/firefox/commands.js:92:60
  forEachWorkerThread@resource://devtools/client/debugger/src/client/firefox/commands.js:92:46
  removeBreakpoint@resource://devtools/client/debugger/src/client/firefox/commands.js:208:9
  clientRemoveBreakpoint@resource://devtools/client/debugger/src/actions/breakpoints/modify.js:54:17
  removeBreakpoint/<@resource://devtools/client/debugger/src/actions/breakpoints/modify.js:152:69
  thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
  bindActionCreator/<@resource://devtools/client/shared/vendor/redux.js:644:12
  removeBreakpoint@chrome://mochitests/content/browser/devtools/client/debugger/test/mochitest/helpers.js:960:22
  @chrome://mochitests/content/browser/devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js:47:9
  Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1115:34
  Tester_execTest@chrome://mochikit/content/browser-test.js:1143:12
  nextTest/<@chrome://mochikit/content/browser-test.js:1004:14
  SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:803:59
[ACTION] REMOVE_BREAKPOINT [done] - {}
[ACTION] NODE_EXPAND  - {}
[ACTION] REMOVE_SOURCE_ACTORS  - {"type":"REMOVE_SOURCE_ACTORS","items":[{"id":"server1.conn107.child1/workerTarget21/source4","actor":"server1.conn107.child1/workerTarget21/source4","thread":"server1.conn107.child1/workerTarget21/context1","source":"sourceURL-http://example.com/browser/devtools/client/debugger/test/mochitest/examples/scopes-worker.js","isBlackBoxed":false,"sourceMapURL":null,"url":"http://example.com/browser/devtools/client/debugger/test/mochitest/examples/scopes-worker.js","introductionUrl":null}]}
[ACTION] REMOVE_WORKERS  - {"type":"REMOVE_WORKERS","cx":{"navigateCounter":0},"workers":["server1.conn107.child1/workerTarget21/context1"]}
[ACTION] SET_EXPANDED_STATE  - {"type":"SET_EXPANDED_STATE","expanded":{}}
[ACTION] SET_EXPANDED_STATE  - {"type":"SET_EXPANDED_STATE","expanded":{}}
console.warn: "Error while detaching target: undefined"
[ACTION] NODE_PROPERTIES_LOADED  - {}

Here's an interesting extract from the logs. We can see that during the remove breakpoint action, it seems we lose the worker source. The corresponding source actor is removed, and the connection to the worker thread is lost. It seems this issue is not linked to pending requests not cleaned before navigation as we've had in other tests.

Taking a look at the high frequency intermittent Bug 1531493, the failures seem to also have this unexpected "REMOVE_SOURCE_ACTORS" action. Maybe the ThreadClient refactor only made the issue result in a pending request failure rather than in a test timeout. I think this is the same intermittent, but with a different output. Understanding why workers are lost midway through the test would probably fix most of the intermittents currently logged for this test.

The older failures also have interesting error messages that could relate to why the worker is lost:

20:46:21     INFO - GECKO(6112) | [Parent 5440, Gecko_IOThread] WARNING: pipe error: 109: file z:/task_1560449260/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
20:46:21     INFO - GECKO(6112) | JavaScript error: resource://devtools/shared/transport/worker-transport.js, line 37: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIWorkerDebugger.postMessage]

I looked into this test when I was working on the thread client refactor. I thin julian is right, it might be that the failure is the same, but the test now says that it is the breakpoints (https://searchfox.org/mozilla-central/source/devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js#48). If the test runs correctly, then we have code that explicitly waits on the breakpoints before continuing. The underlying behaviour did not change. I also spoke with jason and this looks like it is related to a pre-existing intermittent.

In the last 7 days, there have been 51 failures. The failures are on linux64, linux64-shippable, macosx1014-64, windows10-64, windows10-64-shippable, windows7-32 and windows7-32-shippable platforms. The affected build types are: opt, asan and debug.

An example of a recent log file: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=253081216&repo=mozilla-central&lineNumber=14883

And the relevant part of the log:

10:59:09 INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js | foo -
10:59:09 INFO - Toggling node var_weakset
10:59:09 INFO - Buffered messages finished
10:59:09 INFO - TEST-UNEXPECTED-FAIL | devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js | A promise chain failed to handle a rejection: Connection closed, pending request to server1.conn110.child1/workerTarget21/context1, type removeBreakpoint failed
10:59:09 INFO -
10:59:09 INFO - Request stack:
10:59:09 INFO - request@resource://devtools/shared/protocol.js:1386:14
10:59:09 INFO - generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol.js:1510:19
10:59:09 INFO - removeBreakpoint/<@resource://devtools/client/debugger/src/client/firefox/commands.js:209:46
10:59:09 INFO - forEachWorkerThread/promises<@resource://devtools/client/debugger/src/client/firefox/commands.js:93:60
10:59:09 INFO - forEachWorkerThread@resource://devtools/client/debugger/src/client/firefox/commands.js:93:46
10:59:09 INFO - removeBreakpoint@resource://devtools/client/debugger/src/client/firefox/commands.js:209:9
10:59:09 INFO - clientRemoveBreakpoint@resource://devtools/client/debugger/src/actions/breakpoints/modify.js:54:17
10:59:09 INFO - removeBreakpoint/<@resource://devtools/client/debugger/src/actions/breakpoints/modify.js:152:69
10:59:09 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
10:59:09 INFO - bindActionCreator/<@resource://devtools/client/shared/vendor/redux.js:644:12
10:59:09 INFO - removeBreakpoint@chrome://mochitests/content/browser/devtools/client/debugger/test/mochitest/helpers.js:960:22
10:59:09 INFO - @chrome://mochitests/content/browser/devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js:47:9
10:59:09 INFO - AsyncTester_execTest/<@chrome://mochikit/content/browser-test.js:1115:34
10:59:09 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1143:12
10:59:09 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:1004:14
10:59:09 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:803:59
10:59:09 INFO - - stack: destroy@resource://devtools/shared/protocol.js:1299:23
10:59:09 INFO - TargetMixin/destroy/this._destroyer<@resource://devtools/shared/fronts/targets/target-mixin.js:539:23
10:59:09 INFO - asyncdestroy@resource://devtools/shared/fronts/targets/target-mixin.js:573:9
10:59:09 INFO - newListener@resource://devtools/shared/event-emitter.js:145:22
10:59:09 INFO - emit@resource://devtools/shared/event-emitter.js:186:24
10:59:09 INFO - emit@resource://devtools/shared/event-emitter.js:267:18
10:59:09 INFO - onPacket@resource://devtools/shared/protocol.js:1424:13
10:59:09 INFO - onPacket@resource://devtools/shared/client/debugger-client.js:560:13
10:59:09 INFO - send/<@resource://devtools/shared/transport/local-transport.js:64:23
10:59:09 INFO - exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:109:22
10:59:09 INFO - DevToolsUtils.executeSoonexports.executeSoon@resource://devtools/shared/DevToolsUtils.js:55:21
10:59:09 INFO - send@resource://devtools/shared/transport/local-transport.js:58:21
10:59:09 INFO - send@resource://devtools/server/main.js:1023:20
10:59:09 INFO - receiveMessage@resource://devtools/shared/transport/child-transport.js:66:16
10:59:09 INFO - MessageListener.receiveMessage_addListener@resource://devtools/shared/transport/child-transport.js:40:14
10:59:09 INFO - ready@resource://devtools/shared/transport/child-transport.js:57:10
10:59:09 INFO - connectToFrame/</onActorCreated<@resource://devtools/server/main.js:730:24
10:59:09 INFO - exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:109:22
10:59:09 INFO - MessageListener.receiveMessage*trackMessageManager@resource://devtools/server/main.js:612:14
10:59:09 INFO - connectToFrame/<@resource://devtools/server/main.js:825:7

Jason, as you are the triage owner of this component, could you please take a look at this?
Thank you!

This started to perma fail with the landing of Bug 1561216.
https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&resultStatus=pending%2Crunning%2Csuccess%2Ctestfailed%2Cbusted%2Cexception%2Crunnable&searchStr=linux%2Cx64%2Casan%2Cmochitests%2Ctest-linux64-asan%2Fopt-mochitest-devtools-chrome-e10s-4%2Cm%28dt4%29&fromchange=1e28a064d7be5feec7ae99f5e5b17012d512c421

:njn , could you please take a look?

I looked at this. Some observations:

• After a few more hours of pushes one can see that it's not a permafail -- there have been multiple successful runs of that job since.
• The failure rate definitely took a jump yesterday, but it wasn't due to bug 1561216's patches. I triggered a bunch of re-runs before and after bug 1561216's patches landed, and the problem started happening earlier.

Jason can you assign someone to take a look at this?

I can look into it, but I would appreciate help hunting down which commit regressed it. This was a flakey test that got much worse recently

Please see Comment 2 : https://hg.mozilla.org/integration/autoland/rev/0013565e760d8347c984427b2589969c24e5a5c5

This bug was created 13 days ago after landing the ThreadClient refactor.

At that point my analysis was that this new intermittent was just a different manifestation of Bug 1531493. I think the root cause of both issues is that the worker gets destroyed midway through the test. It's very clear from the logs. Before the ThreadClient refactor, this issue always ended up in a test timeout. After the ThreadClient refactor it can also lead to this intermittent "rejection: Connection closed".

Recently it spiked on linux asan, and again if you open the logs, you will see the extra REMOVE_SOURCE_ACTORS action in this test. So I guess some change made the issue more frequent on linux asan, but now you need to figure out why.

You can start by doing retriggers around the recent spike. Take the treeherder pages for central, inbound, autoland, and retrigger the job on linux 64 asan several times until you can confidently identify which changeset caused the spike. Maybe this will help you understand what is causing this worker to be destroyed.

I started a bunch of retriggers on autoland at https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&resultStatus=pending%2Crunning%2Csuccess%2Ctestfailed%2Cbusted%2Cexception%2Crunnable&searchStr=linux%2Cx64%2Casan%2Cmochitests%2Ctest-linux64-asan%2Fopt-mochitest-devtools-chrome-e10s-4%2Cm%28dt4%29&fromchange=a8c21ee98a4c2f683335b8358c11b2fceb863f05&tochange=b91b32c55b199626595ef97e3ae6c6319f826644

(I am forwarding the ni? to Jason again because I guess it was the initial intent)

Ah, yes, it was. Still, thanks for looking even though you were ni by mistake.

Also, I mentioned comment 2 because even before the spike, the failure rate was still high enough for this to be looked at and fixed.

We'll post retrigger results later this shift.

I just realized that for pushes on inbound before 53c79fdf66930a1ab892051b0edcf404bc1670e6, the test was running in dt5, not in dt4, so we need to take that into account when doing the retriggers.

And for autoland, all pushes before ec36c52abdd5068d6297d10d40e60e00ef82e7f0 were also running the test in dt5 instead of dt4

https://hg.mozilla.org/mozilla-central/rev/325164bff59a

dt4 retrigger range: https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=linux%2Cx64%2Casan%2Cmochitests%2Ctest-linux64-asan%2Fopt-mochitest-devtools-chrome-e10s-4%2Cm%28dt4%29&tochange=69e31119cd489a611246119fb1109d4012b4e43f&fromchange=9737fcd4ec9257efb8e7d3e5bb52275b7b3f7396&group_state=expanded&selectedJob=253856163

dt5 retrigger range: https://treeherder.mozilla.org/#/jobs?repo=autoland&group_state=expanded&searchStr=linux%2Cx64%2Casan%2Cmochitests%2Ctest-linux64-asan%2Fopt-mochitest-devtools-chrome-e10s-5%2Cm%28dt5%29&tochange=303b1fcafdeb3d31f045e5d26278956bf643871b&fromchange=ee39c2c54d6b0a5e582af26d04edd17dff8fc591&selectedJob=253847101

I wonder if it would be worth trying to isolate browser_dbg-worker-scopes.js in a separate browser.ini. This will force this test to run in a fresh browser instance.

In the last 7 days, there have been 49 failures. This test was disabled on linux asan, but the failures are affecting macosx1014-64-shippable, macosx1014-64, linux64-shippable, linux64, windows10-64-shippable, windows7-32-shippable platforms.
Affected build types: debug, opt.

An example of a recent log file:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=255036125&repo=autoland&lineNumber=12511

And the relevant part of the log:
0:10:59 INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js | foo -
00:10:59 INFO - Toggling node var_weakset
00:10:59 INFO - Buffered messages finished
00:10:59 INFO - TEST-UNEXPECTED-FAIL | devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js | A promise chain failed to handle a rejection: Connection closed, pending request to server1.conn111.child1/workerTarget21/context1, type removeBreakpoint failed
00:10:59 INFO -
00:10:59 INFO - Request stack:
00:10:59 INFO - request@resource://devtools/shared/protocol/Front.js:162:14
00:10:59 INFO - generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol/Front/FrontClassWithSpec.js:49:19
00:10:59 INFO - removeBreakpoint/<@resource://devtools/client/debugger/src/client/firefox/commands.js:209:46
00:10:59 INFO - forEachWorkerThread/promises<@resource://devtools/client/debugger/src/client/firefox/commands.js:93:60
00:10:59 INFO - forEachWorkerThread@resource://devtools/client/debugger/src/client/firefox/commands.js:93:46
00:10:59 INFO - removeBreakpoint@resource://devtools/client/debugger/src/client/firefox/commands.js:209:9
00:10:59 INFO - clientRemoveBreakpoint@resource://devtools/client/debugger/src/actions/breakpoints/modify.js:54:17
00:10:59 INFO - removeBreakpoint/<@resource://devtools/client/debugger/src/actions/breakpoints/modify.js:152:69
00:10:59 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
00:10:59 INFO - bindActionCreator/<@resource://devtools/client/shared/vendor/redux.js:644:12
00:10:59 INFO - removeBreakpoint@chrome://mochitests/content/browser/devtools/client/debugger/test/mochitest/helpers.js:960:22
00:10:59 INFO - @chrome://mochitests/content/browser/devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js:47:9
00:10:59 INFO - AsyncTester_execTest/<@chrome://mochikit/content/browser-test.js:1346:34
00:10:59 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1381:11
00:10:59 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:1209:14
00:10:59 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:803:59
00:10:59 INFO - - stack: destroy@resource://devtools/shared/protocol/Front.js:69:23
00:10:59 INFO - TargetMixin/destroy/this._destroyer<@resource://devtools/shared/fronts/targets/target-mixin.js:564:23
00:10:59 INFO - asyncdestroy@resource://devtools/shared/fronts/targets/target-mixin.js:598:9
00:10:59 INFO - newListener@resource://devtools/shared/event-emitter.js:149:22
00:10:59 INFO - emit@resource://devtools/shared/event-emitter.js:190:24
00:10:59 INFO - emit@resource://devtools/shared/event-emitter.js:271:18
00:10:59 INFO - onPacket@resource://devtools/shared/protocol/Front.js:200:13
00:10:59 INFO - onPacket@resource://devtools/shared/client/debugger-client.js:593:13
00:10:59 INFO - send/<@resource://devtools/shared/transport/local-transport.js:70:25
00:10:59 INFO - exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:111:22
00:10:59 INFO - DevToolsUtils.executeSoonexports.executeSoon@resource://devtools/shared/DevToolsUtils.js:62:21
00:10:59 INFO - send@resource://devtools/shared/transport/local-transport.js:58:21
00:10:59 INFO - send@resource://devtools/server/main.js:1108:20
00:10:59 INFO - receiveMessage@resource://devtools/shared/transport/child-transport.js:66:16
00:10:59 INFO - MessageListener.receiveMessage_addListener@resource://devtools/shared/transport/child-transport.js:40:14
00:10:59 INFO - ready@resource://devtools/shared/transport/child-transport.js:57:10
00:10:59 INFO - connectToFrame/</onActorCreated<@resource://devtools/server/main.js:800:24
00:10:59 INFO - exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:111:22
00:10:59 INFO - MessageListener.receiveMessage*trackMessageManager@resource://devtools/server/main.js:668:14
00:10:59 INFO - connectToFrame/<@resource://devtools/server/main.js:900:7
00:10:59 INFO - connectToFrame@resource://devtools/server/main.js:654:12

Jason, can you please take a look?
Thank you!

(In reply to Julian Descottes [:jdescottes] from comment #29)

I wonder if it would be worth trying to isolate browser_dbg-worker-scopes.js in a separate browser.ini. This will force this test to run in a fresh browser instance.

Just wanted to report that I tried to do that and sadly it doesn't help.

There are 47 total failures in the last 7 days: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-07-10&endday=2019-07-17&tree=trunk&bug=1559547

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=257010935&repo=autoland&lineNumber=13132

[task 2019-07-17T19:35:48.713Z] 19:35:48 INFO - TEST-START | devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js
[task 2019-07-17T19:35:52.675Z] 19:35:52 INFO - TEST-UNEXPECTED-FAIL | devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js | A promise chain failed to handle a rejection: Connection closed, pending request to server1.conn110.child1/workerTarget21/thread1, type setBreakpoint failed
[task 2019-07-17T19:35:52.676Z] 19:35:52 INFO -
[task 2019-07-17T19:35:52.676Z] 19:35:52 INFO - Request stack:
[task 2019-07-17T19:35:52.677Z] 19:35:52 INFO - request@resource://devtools/shared/protocol/Front.js:162:14
[task 2019-07-17T19:35:52.677Z] 19:35:52 INFO - generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol/Front/FrontClassWithSpec.js:49:19
[task 2019-07-17T19:35:52.677Z] 19:35:52 INFO - setBreakpoint/<@resource://devtools/client/debugger/src/client/firefox/commands.js:192:41
[task 2019-07-17T19:35:52.677Z] 19:35:52 INFO - forEachThread/workerPromises<@resource://devtools/client/debugger/src/client/firefox/commands.js:99:7
[task 2019-07-17T19:35:52.679Z] 19:35:52 INFO - forEachThread@resource://devtools/client/debugger/src/client/firefox/commands.js:97:51
[task 2019-07-17T19:35:52.680Z] 19:35:52 INFO - setBreakpoint@resource://devtools/client/debugger/src/client/firefox/commands.js:192:10
[task 2019-07-17T19:35:52.681Z] 19:35:52 INFO - clientSetBreakpoint@resource://devtools/client/debugger/src/actions/breakpoints/modify.js:47:17
[task 2019-07-17T19:35:52.681Z] 19:35:52 INFO - addBreakpoint/<@resource://devtools/client/debugger/src/actions/breakpoints/modify.js:127:102
[task 2019-07-17T19:35:52.681Z] 19:35:52 INFO - asyncthunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-07-17T19:35:52.681Z] 19:35:52 INFO - dispatch@resource://devtools/client/shared/vendor/redux.js:755:18
[task 2019-07-17T19:35:52.682Z] 19:35:52 INFO - loadSourceTextPromise@resource://devtools/client/debugger/src/actions/sources/loadSourceText.js:94:13
[task 2019-07-17T19:35:52.683Z] 19:35:52 INFO - asyncaction@resource://devtools/client/debugger/src/actions/sources/loadSourceText.js:118:42
[task 2019-07-17T19:35:52.684Z] 19:35:52 INFO - memoizeableAction/</</<@resource://devtools/client/debugger/src/utils/memoizableAction.js:54:17
[task 2019-07-17T19:35:52.684Z] 19:35:52 INFO - memoizeableAction/</<@resource://devtools/client/debugger/src/utils/memoizableAction.js:60:9
[task 2019-07-17T19:35:52.684Z] 19:35:52 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-07-17T19:35:52.685Z] 19:35:52 INFO - dispatch@resource://devtools/client/shared/vendor/redux.js:755:18
[task 2019-07-17T19:35:52.685Z] 19:35:52 INFO - doSetSymbols@resource://devtools/client/debugger/src/actions/sources/symbols.js:17:9
[task 2019-07-17T19:35:52.686Z] 19:35:52 INFO - action@resource://devtools/client/debugger/src/actions/sources/symbols.js:41:42
[task 2019-07-17T19:35:52.686Z] 19:35:52 INFO - memoizeableAction/</</<@resource://devtools/client/debugger/src/utils/memoizableAction.js:54:17
[task 2019-07-17T19:35:52.687Z] 19:35:52 INFO - memoizeableAction/</<@resource://devtools/client/debugger/src/utils/memoizableAction.js:60:9
[task 2019-07-17T19:35:52.687Z] 19:35:52 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-07-17T19:35:52.687Z] 19:35:52 INFO - dispatch@resource://devtools/client/shared/vendor/redux.js:755:18
[task 2019-07-17T19:35:52.687Z] 19:35:52 INFO - updateFrameSymbols/<@resource://devtools/client/debugger/src/actions/pause/mapFrames.js:149:12
[task 2019-07-17T19:35:52.688Z] 19:35:52 INFO - updateFrameSymbols@resource://devtools/client/debugger/src/actions/pause/mapFrames.js:147:28
[task 2019-07-17T19:35:52.688Z] 19:35:52 INFO - mapFrames/<@resource://devtools/client/debugger/src/actions/pause/mapFrames.js:171:11
[task 2019-07-17T19:35:52.688Z] 19:35:52 INFO - asyncthunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-07-17T19:35:52.689Z] 19:35:52 INFO - dispatch@resource://devtools/client/shared/vendor/redux.js:755:18
[task 2019-07-17T19:35:52.689Z] 19:35:52 INFO - paused/<@resource://devtools/client/debugger/src/actions/pause/paused.js:49:11
[task 2019-07-17T19:35:52.690Z] 19:35:52 INFO - thunk/</</<@resource://devtools/client/debugger/src/actions/utils/middleware/thunk.js:21:45
[task 2019-07-17T19:35:52.690Z] 19:35:52 INFO - bindActionCreator/<@resource://devtools/client/shared/vendor/redux.js:644:12
[task 2019-07-17T19:35:52.690Z] 19:35:52 INFO - paused@resource://devtools/client/debugger/src/client/firefox/events.js:64:13
[task 2019-07-17T19:35:52.690Z] 19:35:52 INFO - Asyncemit@resource://devtools/shared/event-emitter.js:190:24
[task 2019-07-17T19:35:52.690Z] 19:35:52 INFO - emit@resource://devtools/shared/event-emitter.js:271:18
[task 2019-07-17T19:35:52.691Z] 19:35:52 INFO - onPacket@resource://devtools/shared/protocol/Front.js:200:13
[task 2019-07-17T19:35:52.691Z] 19:35:52 INFO - onPacket@resource://devtools/shared/client/debugger-client.js:593:13
[task 2019-07-17T19:35:52.691Z] 19:35:52 INFO - - stack: destroy@resource://devtools/shared/protocol/Front.js:69:23
[task 2019-07-17T19:35:52.691Z] 19:35:52 INFO - TargetMixin/destroy/this._destroyer<@resource://devtools/shared/fronts/targets/target-mixin.js:564:23
[task 2019-07-17T19:35:52.692Z] 19:35:52 INFO - asyncdestroy@resource://devtools/shared/fronts/targets/target-mixin.js:603:9
[task 2019-07-17T19:35:52.692Z] 19:35:52 INFO - newListener@resource://devtools/shared/event-emitter.js:149:22
[task 2019-07-17T19:35:52.694Z] 19:35:52 INFO - emit@resource://devtools/shared/event-emitter.js:190:24
[task 2019-07-17T19:35:52.694Z] 19:35:52 INFO - emit@resource://devtools/shared/event-emitter.js:271:18
[task 2019-07-17T19:35:52.694Z] 19:35:52 INFO - onPacket@resource://devtools/shared/protocol/Front.js:200:13
[task 2019-07-17T19:35:52.694Z] 19:35:52 INFO - onPacket@resource://devtools/shared/client/debugger-client.js:593:13
[task 2019-07-17T19:35:52.695Z] 19:35:52 INFO - send/<@resource://devtools/shared/transport/local-transport.js:70:25
[task 2019-07-17T19:35:52.695Z] 19:35:52 INFO - exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:111:22
[task 2019-07-17T19:35:52.696Z] 19:35:52 INFO - DevToolsUtils.executeSoonexports.executeSoon@resource://devtools/shared/DevToolsUtils.js:62:21
[task 2019-07-17T19:35:52.696Z] 19:35:52 INFO - send@resource://devtools/shared/transport/local-transport.js:58:21
[task 2019-07-17T19:35:52.696Z] 19:35:52 INFO - send@resource://devtools/server/main.js:1108:20
[task 2019-07-17T19:35:52.696Z] 19:35:52 INFO - receiveMessage@resource://devtools/shared/transport/child-transport.js:66:16
[task 2019-07-17T19:35:52.696Z] 19:35:52 INFO - MessageListener.receiveMessage*_addListener@resource://devtools/shared/transport/child-transport.js:40:14
[task 2019-07-17T19:35:52.696Z] 19:35:52 INFO - ready@resource://devtools/shared/transport/child-transport.js:57:10
[task 2019-07-17T19:35:52.696Z] 19:35:52 INFO - connectToFrame/</onActorCreated<@resource://devtools/server/main.js:800:24
[task 2019-07-17T19:35:52.697Z] 19:35:52 INFO - exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:111:22
[task 2019-07-17T19:35:52.697Z] 19:35:52 INFO - MessageListener.receiveMessagetrackMessageManager@resource://devtools/server/main.js:668:14
[task 2019-07-17T19:35:52.697Z] 19:35:52 INFO - connectToFrame/<@resource://devtools/server/main.js:900:7
[task 2019-07-17T19:35:52.697Z] 19:35:52 INFO - connectToFrame@resource://devtools/server/main.js:654:12
[task 2019-07-17T19:35:52.697Z] 19:35:52 INFO - connect@resource://devtools/server/actors/targets/frame-proxy.js:62:36
[task 2019-07-17T19:35:52.697Z] 19:35:52 INFO - asyncBrowserTabList.prototype._getActorForBrowser@resource://devtools/server/actors/webbrowser.js:370:16
[task 2019-07-17T19:35:52.697Z] 19:35:52 INFO - BrowserTabList.prototype.getTab@resource://devtools/server/actors/webbrowser.js:412:21
[task 2019-07-17T19:35:52.697Z] 19:35:52 INFO - onGetTab@resource://devtools/server/actors/root.js:369:35
[task 2019-07-17T19:35:52.697Z] 19:35:52 INFO - onPacket@resource://devtools/server/main.js:1402:58
[task 2019-07-17T19:35:52.697Z] 19:35:52 INFO - send/<@resource://devtools/shared/transport/local-transport.js:70:25
[task 2019-07-17T19:35:52.698Z] 19:35:52 INFO - exports.makeInfallible/<@resource://devtools/shared/ThreadSafeDevToolsUtils.js:111:22
[task 2019-07-17T19:35:52.699Z] 19:35:52 INFO - DevToolsUtils.executeSoonexports.executeSoon@resource://devtools/shared/DevToolsUtils.js:62:21
[task 2019-07-17T19:35:52.700Z] 19:35:52 INFO - send@resource://devtools/shared/transport/local-transport.js:58:21
[task 2019-07-17T19:35:52.701Z] 19:35:52 INFO - send@resource://devtools/shared/protocol/Front.js:146:30
[task 2019-07-17T19:35:52.702Z] 19:35:52 INFO - request@resource://devtools/shared/protocol/Front.js:164:10
[task 2019-07-17T19:35:52.703Z] 19:35:52 INFO - generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol/Front/FrontClassWithSpec.js:49:19
[task 2019-07-17T19:35:52.704Z] 19:35:52 INFO - getTab@resource://devtools/shared/fronts/root.js:252:18
[task 2019-07-17T19:35:52.705Z] 19:35:52 INFO - createTargetForTab@resource://devtools/client/framework/target.js:90:28
[task 2019-07-17T19:35:52.706Z] 19:35:52 INFO - asyncforTab@resource://devtools/client/framework/target.js:35:26
[task 2019-07-17T19:35:52.706Z] 19:35:52 INFO - openToolboxForTab@chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:436:38
[task 2019-07-17T19:35:52.706Z] 19:35:52 INFO - openNewTabAndToolbox@chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:468:10
[task 2019-07-17T19:35:52.707Z] 19:35:52 INFO - asyncinitDebugger@chrome://mochitests/content/browser/devtools/client/debugger/test/mochitest/helpers.js:537:25
[task 2019-07-17T19:35:52.707Z] 19:35:52 INFO - async@chrome://mochitests/content/browser/devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js:39:21
[task 2019-07-17T19:35:52.707Z] 19:35:52 INFO - Tester_execTest/<@chrome://mochikit/content/browser-test.js:1346:34
[task 2019-07-17T19:35:52.707Z] 19:35:52 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1381:11
[task 2019-07-17T19:35:52.707Z] 19:35:52 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:1209:14
[task 2019-07-17T19:35:52.707Z] 19:35:52 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:803:59
[task 2019-07-17T19:35:52.707Z] 19:35:52 INFO - Rejection date: Wed Jul 17 2019 19:35:50 GMT+0000 (Coordinated Universal Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 263
[task 2019-07-17T19:35:52.707Z] 19:35:52 INFO - Stack trace:
[task 2019-07-17T19:35:52.707Z] 19:35:52 INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:263
[task 2019-07-17T19:35:52.707Z] 19:35:52 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1377
[task 2019-07-17T19:35:52.707Z] 19:35:52 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1381
[task 2019-07-17T19:35:52.707Z] 19:35:52 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1209
[task 2019-07-17T19:35:52.707Z] 19:35:52 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:803
[task 2019-07-17T19:35:52.707Z] 19:35:52 INFO - Leaving test bound
[task 2019-07-17T19:35:52.765Z] 19:35:52 INFO - Removing tab.
[task 2019-07-17T19:35:52.767Z] 19:35:52 INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2019-07-17T19:35:52.786Z] 19:35:52 INFO - Got event: 'TabClose' on [object XULElement].
[task 2019-07-17T19:35:52.805Z] 19:35:52 INFO - Tab removed and finished closing
[task 2019-07-17T19:35:52.866Z] 19:35:52 INFO - GECKO(1077) | MEMORY STAT | vsize 3716MB | residentFast 463MB | heapAllocated 130MB
[task 2019-07-17T19:35:52.867Z] 19:35:52 INFO - TEST-OK | devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js | took 4158ms
[task 2019-07-17T19:35:52.904Z] 19:35:52 INFO - checking window state
[task 2019-07-17T19:35:52.907Z] 19:35:52 INFO - GECKO(1077) | JavaScript error: resource://testing-common/PromiseTestUtils.jsm, line 112: uncaught exception: Object

Brian, would you be able to look into this. I spent a bunch of time investigating it earlier this week and have a hunch that there is a platform issue that is triggering the worker to pre-maturely destroy itself.

It looks like the removeBreakpoint packet does not get returned because the worker unexpectedly is destroyed here. Note the worker destroyed event happens right before the Front throws an exception...

• fail log
• passing log

It's funny how writing something down sometimes helps unblock you...

I just put this patch together that might be a reasonable fix because we want the debugger to be resilient to shutdowns.
https://gist.github.com/jasonLaster/d8d009e1790c5d1f364255f45370bcb4

I'll kick off some test runs and see if this helps

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

Jason, is this something we can safely backport to Beta to fix the oranges there too?