1699590 - Intermittent devtools/client/debugger/test/mochitest/browser_dbg-scopes-duplicated.js | A promise chain failed to handle a rejection: Actor 'SpecialPowers' destroyed before query 'Spawn' was resolved - stack: (No stack available.)

Status: RESOLVED FIXED

(DevTools :: Debugger, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=333715826&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/XiLbxeN-SWiTi_9gx2Tejw/runs/0/artifacts/public/logs/live_backing.log

---

[task 2021-03-18T23:48:17.825Z] 23:48:17     INFO - TEST-START | devtools/client/debugger/test/mochitest/browser_dbg-scopes-duplicated.js
[task 2021-03-18T23:48:19.584Z] 23:48:19     INFO - GECKO(3672) | [ACTION] SET_ORIENTATION  - {"type":"SET_ORIENTATION","orientation":"horizontal"}
[task 2021-03-18T23:48:19.671Z] 23:48:19     INFO - GECKO(3672) | [ACTION] CONNECT  - {"type":"CONNECT","mainThreadActorID":"server0.conn48.child4/thread22","isWebExtension":false}
[task 2021-03-18T23:48:19.711Z] 23:48:19     INFO - GECKO(3672) | [ACTION] UPDATE_EVENT_LISTENERS  - {"type":"UPDATE_EVENT_LISTENERS","active":[]}

[task 2021-03-18T23:48:25.731Z] 23:48:25     INFO - TEST-INFO | started process screenshot
[task 2021-03-18T23:48:25.796Z] 23:48:25     INFO - TEST-INFO | screenshot: exit 0
[task 2021-03-18T23:48:25.797Z] 23:48:25     INFO - Buffered messages logged at 23:48:17
[task 2021-03-18T23:48:25.797Z] 23:48:25     INFO - Entering test bound 
[task 2021-03-18T23:48:25.797Z] 23:48:25     INFO - Adding a new tab with URL: http://localhost:57478/
[task 2021-03-18T23:48:25.798Z] 23:48:25     INFO - Buffered messages logged at 23:48:18
[task 2021-03-18T23:48:25.798Z] 23:48:25     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://localhost:57478/" line: 0}]
[task 2021-03-18T23:48:25.799Z] 23:48:25     INFO - Tab added and finished loading
[task 2021-03-18T23:48:25.799Z] 23:48:25     INFO - Opening the toolbox
[task 2021-03-18T23:48:25.800Z] 23:48:25     INFO - Buffered messages logged at 23:48:19
[task 2021-03-18T23:48:25.800Z] 23:48:25     INFO - Toolbox opened and focused
[task 2021-03-18T23:48:25.801Z] 23:48:25     INFO - Waiting for state change: paused
[task 2021-03-18T23:48:25.801Z] 23:48:25     INFO - Waiting for state change: loaded source
[task 2021-03-18T23:48:25.802Z] 23:48:25     INFO - Buffered messages logged at 23:48:20
[task 2021-03-18T23:48:25.802Z] 23:48:25     INFO - Finished waiting for state change: loaded source
[task 2021-03-18T23:48:25.803Z] 23:48:25     INFO - Finished waiting for state change: loaded source
[task 2021-03-18T23:48:25.803Z] 23:48:25     INFO - Buffered messages logged at 23:48:21
[task 2021-03-18T23:48:25.804Z] 23:48:25     INFO - Finished waiting for state change: paused
[task 2021-03-18T23:48:25.804Z] 23:48:25     INFO - Finished waiting for state change: paused
[task 2021-03-18T23:48:25.805Z] 23:48:25     INFO - Waiting for state change: fetched frames
[task 2021-03-18T23:48:25.805Z] 23:48:25     INFO - Finished waiting for state change: fetched frames
[task 2021-03-18T23:48:25.805Z] 23:48:25     INFO - Waiting for state change: selected source
[task 2021-03-18T23:48:25.806Z] 23:48:25     INFO - Finished waiting for state change: selected source
[task 2021-03-18T23:48:25.806Z] 23:48:25     INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-scopes-duplicated.js | got expected scope labels - 
[task 2021-03-18T23:48:25.807Z] 23:48:25     INFO - Expand `x` node
[task 2021-03-18T23:48:25.807Z] 23:48:25     INFO - Toggling node x 
[task 2021-03-18T23:48:25.808Z] 23:48:25     INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-scopes-duplicated.js | got expected scope labels - 
[task 2021-03-18T23:48:25.808Z] 23:48:25     INFO - Expand node `d`
[task 2021-03-18T23:48:25.809Z] 23:48:25     INFO - Toggling node d 
[task 2021-03-18T23:48:25.809Z] 23:48:25     INFO - Buffered messages logged at 23:48:22
[task 2021-03-18T23:48:25.810Z] 23:48:25     INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-scopes-duplicated.js | got expected scope labels - 
[task 2021-03-18T23:48:25.810Z] 23:48:25     INFO - Expand `f` and `e` nodes
[task 2021-03-18T23:48:25.810Z] 23:48:25     INFO - Toggling node f 
[task 2021-03-18T23:48:25.811Z] 23:48:25     INFO - Toggling node e 
[task 2021-03-18T23:48:25.811Z] 23:48:25     INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-scopes-duplicated.js | got expected scope labels - 
[task 2021-03-18T23:48:25.811Z] 23:48:25     INFO - Expand `h`, `g`, `e`, `c`, `b` and `a` nodes
[task 2021-03-18T23:48:25.811Z] 23:48:25     INFO - Toggling node h 
[task 2021-03-18T23:48:25.812Z] 23:48:25     INFO - Toggling node g 
[task 2021-03-18T23:48:25.812Z] 23:48:25     INFO - Toggling node c 
[task 2021-03-18T23:48:25.812Z] 23:48:25     INFO - Toggling node b 
[task 2021-03-18T23:48:25.812Z] 23:48:25     INFO - Toggling node a 
[task 2021-03-18T23:48:25.812Z] 23:48:25     INFO - Buffered messages logged at 23:48:23
[task 2021-03-18T23:48:25.812Z] 23:48:25     INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-scopes-duplicated.js | got expected scope labels - 
[task 2021-03-18T23:48:25.812Z] 23:48:25     INFO - Expand `e`
[task 2021-03-18T23:48:25.812Z] 23:48:25     INFO - Toggling node e 
[task 2021-03-18T23:48:25.813Z] 23:48:25     INFO - Console message: [JavaScript Warning: "MouseEvent.mozPressure is deprecated. Use PointerEvent.pressure instead." {file: "http://localhost:57478/test.js" line: 17}]
[task 2021-03-18T23:48:25.813Z] 23:48:25     INFO - Expand the `target` node
[task 2021-03-18T23:48:25.813Z] 23:48:25     INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-scopes-duplicated.js | Found the target node - 
[task 2021-03-18T23:48:25.813Z] 23:48:25     INFO - Toggling node srcElement 
[task 2021-03-18T23:48:25.813Z] 23:48:25     INFO - Console message: [JavaScript Warning: "onmozfullscreenchange is deprecated." {file: "http://localhost:57478/test.js" line: 17}]
[task 2021-03-18T23:48:25.813Z] 23:48:25     INFO - Console message: [JavaScript Warning: "onmozfullscreenerror is deprecated." {file: "http://localhost:57478/test.js" line: 17}]
[task 2021-03-18T23:48:25.813Z] 23:48:25     INFO - Buffered messages logged at 23:48:24
[task 2021-03-18T23:48:25.814Z] 23:48:25     INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-scopes-duplicated.js | the target node was expanded - 
[task 2021-03-18T23:48:25.814Z] 23:48:25     INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-scopes-duplicated.js | classList is displayed - 
[task 2021-03-18T23:48:25.814Z] 23:48:25     INFO - Leaving test bound 
[task 2021-03-18T23:48:25.814Z] 23:48:25     INFO - Buffered messages logged at 23:48:25
[task 2021-03-18T23:48:25.814Z] 23:48:25     INFO - Removing tab.
[task 2021-03-18T23:48:25.814Z] 23:48:25     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2021-03-18T23:48:25.814Z] 23:48:25     INFO - Got event: 'TabClose' on [object XULElement].
[task 2021-03-18T23:48:25.815Z] 23:48:25     INFO - Tab removed and finished closing
[task 2021-03-18T23:48:25.815Z] 23:48:25     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 2021-03-18T23:48:25.815Z] 23:48:25     INFO - Buffered messages finished
[task 2021-03-18T23:48:25.815Z] 23:48:25     INFO - TEST-UNEXPECTED-FAIL | devtools/client/debugger/test/mochitest/browser_dbg-scopes-duplicated.js | A promise chain failed to handle a rejection: Actor 'SpecialPowers' destroyed before query 'Spawn' was resolved - stack: (No stack available.)
[task 2021-03-18T23:48:25.815Z] 23:48:25     INFO - Rejection date: Thu Mar 18 2021 23:48:25 GMT+0000 (Greenwich Mean Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 285
[task 2021-03-18T23:48:25.815Z] 23:48:25     INFO - Stack trace:
[task 2021-03-18T23:48:25.815Z] 23:48:25     INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:285
[task 2021-03-18T23:48:25.815Z] 23:48:25     INFO - chrome://mochikit/content/browser-test.js:nextTest:631
[task 2021-03-18T23:48:25.815Z] 23:48:25     INFO - chrome://mochikit/content/browser-test.js:testScope/test_finish/<:1550
[task 2021-03-18T23:48:25.815Z] 23:48:25     INFO - chrome://mochikit/content/browser-test.js:run:1465
[task 2021-03-18T23:48:25.816Z] 23:48:25     INFO - Console message: [JavaScript Error: "AbortError: Actor 'SpecialPowers' destroyed before query 'Spawn' was resolved"]
[task 2021-03-18T23:48:25.816Z] 23:48:25     INFO - GECKO(3672) | MEMORY STAT | vsize 2104703MB | vsizeMaxContiguous 66132734MB | residentFast 506MB | heapAllocated 153MB
[task 2021-03-18T23:48:25.816Z] 23:48:25     INFO - TEST-OK | devtools/client/debugger/test/mochitest/browser_dbg-scopes-duplicated.js | took 7942ms
[task 2021-03-18T23:48:25.816Z] 23:48:25     INFO - checking window state```

Comment 1

[Alexandru Michis [:malexandru]]

Alexandre, backfills point to this being caused by the changes in Bug 1698842.
Could you please take a look?

Comment 2

[Intermittent Failures Robot]

22 failures in 670 pushes (0.033 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 14
• try: 5
• mozilla-central: 3

Platform and build breakdown:

• windows10-64: 17
  • asan: 7
  • opt: 7
  • debug: 3
• windows10-64-shippable: 3
  • opt: 3
• windows10-64-devedition: 1
  • opt: 1
• windows10-64-ccov-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1699590&startday=2021-03-19&endday=2021-03-19&tree=all

Comment 3

[Julian Descottes [:jdescottes]]

FWIW backfills point to the push where both Bug 1699432 and Bug 1698842 landed.
I would rather suspect Bug 1699432 here.

Comment 4

[Intermittent Failures Robot]

21 failures in 208 pushes (0.101 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 17
• mozilla-central: 2
• try: 2

Platform and build breakdown:

• windows10-64: 18
  • opt: 7
  • asan: 4
  • debug: 7
• windows10-64-devedition: 1
  • opt: 1
• windows10-64-shippable: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1699590&startday=2021-03-20&endday=2021-03-20&tree=all

Comment 5

[Intermittent Failures Robot]

59 failures in 4257 pushes (0.014 failures/push) were associated with this bug in the last 7 days.

This is the #12 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• mozilla-central: 12
• autoland: 38
• try: 9

Platform and build breakdown:

• windows10-64-ccov-qr: 3
  • opt: 3
• windows10-64: 47
  • asan: 17
  • opt: 17
  • debug: 13
• windows10-64-shippable: 7
  • opt: 7
• windows10-64-devedition: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1699590&startday=2021-03-15&endday=2021-03-21&tree=all

Comment 6

[Alexandre Poirot [:ochameau]]

I'm not able to reproduce locally. Orange factor seems to say it only happens on Windows while I'm on Linux.

But I'll give this a try.

A first try run to assert that it really/still fails on try:
https://treeherder.mozilla.org/jobs?repo=try&revision=3058bd961bd396dc3e2dfb8ab838b7e38966641d

Another try run with a first tentative fix, adding an explicit await resume(dbg) before ending the test. We were not resuming before leaving the test, thus letting the SpecialPowers.spawn promise pending until the end.
https://treeherder.mozilla.org/jobs?repo=try&revision=50288e9781aa281f1e6ed1230721521e4c59a865

And yet another run, with an explicit await of spawn's promise:
https://treeherder.mozilla.org/jobs?repo=try&selectedTaskRun=H0crAWw-T5Sw_680ThUdHQ.0&revision=60156c990f30bbfd24dbfb366f12bbcdeca5f594

Comment 7

[Alexandre Poirot [:ochameau]]

Attachment: Bug 1699590 - Resume page execution before ending browser_dbg-scopes-duplicated.js test.

Comment 8

[Alexandre Poirot [:ochameau]]

(In reply to Alexandre Poirot [:ochameau] from comment #6)

A first try run to assert that it really/still fails on try:
https://treeherder.mozilla.org/jobs?repo=try&revision=3058bd961bd396dc3e2dfb8ab838b7e38966641d

So either this test is not longer failing, or I'm not able to reproduce it with such custom try run...
Because the test is always passing, even with an handful of runs.

Comment 9

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/e3307c3c70a5
Resume page execution before ending browser_dbg-scopes-duplicated.js test. r=nchevobbe

Comment 10

[Bogdan Tara[:bogdan_tara | bogdant]]

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

Comment 11

[Intermittent Failures Robot]

27 failures in 737 pushes (0.037 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-central: 6
• try: 2
• autoland: 14
• mozilla-beta: 5

Platform and build breakdown:

• windows10-64: 17
  • debug: 5
  • opt: 8
  • asan: 4
• windows10-64-shippable: 4
  • opt: 4
• windows10-64-ccov-qr: 2
  • opt: 2
• windows10-64-devedition: 4
  • opt: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1699590&startday=2021-03-22&endday=2021-03-22&tree=all

Comment 12

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/releases/mozilla-beta/rev/cba35b2362a7

Comment 13

[Intermittent Failures Robot]

29 failures in 3967 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 6
• try: 2
• autoland: 14
• mozilla-beta: 7

Platform and build breakdown:

• windows10-64: 18
  • debug: 5
  • opt: 8
  • asan: 5
• windows10-64-shippable: 4
  • opt: 4
• windows10-64-devedition: 5
  • opt: 5
• windows10-64-ccov-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1699590&startday=2021-03-22&endday=2021-03-28&tree=all