1762929 - Intermittent TV devtools/client/debugger/test/mochitest/browser_dbg-features-source-tree.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. -

Status: NEW

(DevTools :: Debugger, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: nfay [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=373282385&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/WiQ40G5EQ6yUg0l57zGyUw/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://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/WiQ40G5EQ6yUg0l57zGyUw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

[task 2022-04-04T14:14:15.537Z] 14:14:15     INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-features-source-tree.js | Source is focused - 
[task 2022-04-04T14:14:15.537Z] 14:14:15     INFO - Buffered messages logged at 14:14:11
[task 2022-04-04T14:14:15.540Z] 14:14:15     INFO - Console message: [JavaScript Error: "TypeError: can't access property "notifyTargetDestroyed", watcher is undefined" {file: "resource://devtools/server/connectors/js-window-actor/DevToolsFrameParent.jsm" line: 217}]
[task 2022-04-04T14:14:15.540Z] 14:14:15     INFO - receiveMessage@resource://devtools/server/connectors/js-window-actor/DevToolsFrameParent.jsm:217:11
[task 2022-04-04T14:14:15.540Z] 14:14:15     INFO - JSActor query*_createTargetActor/<@resource://devtools/server/connectors/js-window-actor/DevToolsFrameChild.jsm:246:14
[task 2022-04-04T14:14:15.540Z] 14:14:15     INFO - newListener@resource://devtools/shared/event-emitter.js:169:27
[task 2022-04-04T14:14:15.540Z] 14:14:15     INFO - _emit@resource://devtools/shared/event-emitter.js:242:32
[task 2022-04-04T14:14:15.540Z] 14:14:15     INFO - emit@resource://devtools/shared/event-emitter.js:186:18
[task 2022-04-04T14:14:15.540Z] 14:14:15     INFO - emit@resource://devtools/shared/event-emitter.js:330:18
[task 2022-04-04T14:14:15.540Z] 14:14:15     INFO - destroy@resource://devtools/server/actors/targets/window-global.js:726:10
[task 2022-04-04T14:14:15.540Z] 14:14:15     INFO - module.exports/proto.destroy@resource://devtools/server/actors/targets/target-actor-mixin.js:253:30
[task 2022-04-04T14:14:15.540Z] 14:14:15     INFO - onTransportClosed/<@resource://devtools/server/devtools-server-connection.js:493:34
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - onTransportClosed@resource://devtools/server/devtools-server-connection.js:493:19
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - close@resource://devtools/shared/transport/js-window-actor-transport.js:41:18
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - close@resource://devtools/server/devtools-server-connection.js:94:23
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - _destroyTargetActor@resource://devtools/server/connectors/js-window-actor/DevToolsFrameChild.jsm:307:31
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - receiveMessage@resource://devtools/server/connectors/js-window-actor/DevToolsFrameChild.jsm:461:21
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - JSActor query*destroyTarget@resource://devtools/server/connectors/js-window-actor/DevToolsFrameParent.jsm:72:10
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - destroyTargets@resource://devtools/server/actors/watcher/target-helpers/frame-helper.js:178:8
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - unwatchTargets@resource://devtools/server/actors/watcher.js:282:24
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - destroy@resource://devtools/server/actors/watcher.js:173:12
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - destroy@resource://devtools/shared/protocol/Pool.js:211:17
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - destroy@resource://devtools/shared/protocol/Actor.js:76:11
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - destroy@resource://devtools/server/actors/descriptors/tab.js:245:29
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - destroy@resource://devtools/shared/protocol/Pool.js:211:17
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - destroy@resource://devtools/server/actors/root.js:201:36
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - destroy@resource://devtools/shared/protocol/Pool.js:211:17
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - onTransportClosed/<@resource://devtools/server/devtools-server-connection.js:493:34
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - onTransportClosed@resource://devtools/server/devtools-server-connection.js:493:19
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - close@resource://devtools/shared/transport/local-transport.js:170:22
[task 2022-04-04T14:14:15.541Z] 14:14:15     INFO - close@resource://devtools/shared/transport/local-transport.js:165:13
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - close@resource://devtools/client/devtools-client.js:131:23
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - destroy@resource://devtools/client/fronts/descriptors/descriptor-mixin.js:71:22
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - async*destroy@resource://devtools/client/fronts/descriptors/tab.js:97:11
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - _emit@resource://devtools/shared/event-emitter.js:242:32
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - emit@resource://devtools/shared/event-emitter.js:186:18
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - emit@resource://devtools/shared/event-emitter.js:330:18
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - destroy@resource://devtools/client/fronts/descriptors/tab.js:92:12
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - _destroyToolbox/onceDestroyed</<@resource://devtools/client/framework/toolbox.js:4127:41
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - promise callback*_destroyToolbox/onceDestroyed<@resource://devtools/client/framework/toolbox.js:4088:12
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - _destroyToolbox@resource://devtools/client/framework/toolbox.js:4084:27
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - destroy@resource://devtools/client/framework/toolbox.js:3948:10
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - closeToolbox@resource://devtools/client/framework/toolbox.js:3924:16
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - testSourceTreeWithWebExtensionContentScript@chrome://mochitests/content/browser/devtools/client/debugger/test/mochitest/browser_dbg-features-source-tree.js:353:21
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - Async*handleTask@chrome://mochikit/content/browser-test.js:989:26
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - _runTaskBasedTest@chrome://mochikit/content/browser-test.js:1061:18
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - async*Tester_execTest@chrome://mochikit/content/browser-test.js:1189:14
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:972:14
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1041:13
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - 
[task 2022-04-04T14:14:15.542Z] 14:14:15     INFO - Buffered messages logged at 14:14:12
[task 2022-04-04T14:14:15.543Z] 14:14:15     INFO - Leaving test bound testSourceTreeWithWebExtensionContentScript
[task 2022-04-04T14:14:15.543Z] 14:14:15     INFO - Removing tab.
[task 2022-04-04T14:14:15.544Z] 14:14:15     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2022-04-04T14:14:15.544Z] 14:14:15     INFO - Got event: 'TabClose' on [object XULElement].
[task 2022-04-04T14:14:15.544Z] 14:14:15     INFO - Tab removed and finished closing
[task 2022-04-04T14:14:15.545Z] 14:14:15     INFO - Removing tab.
[task 2022-04-04T14:14:15.545Z] 14:14:15     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2022-04-04T14:14:15.545Z] 14:14:15     INFO - Got event: 'TabClose' on [object XULElement].
[task 2022-04-04T14:14:15.546Z] 14:14:15     INFO - Tab removed and finished closing
[task 2022-04-04T14:14:15.546Z] 14:14:15     INFO - Buffered messages logged at 14:14:13
[task 2022-04-04T14:14:15.546Z] 14:14:15     INFO - Removing tab.
[task 2022-04-04T14:14:15.547Z] 14:14:15     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2022-04-04T14:14:15.547Z] 14:14:15     INFO - Got event: 'TabClose' on [object XULElement].
[task 2022-04-04T14:14:15.547Z] 14:14:15     INFO - Tab removed and finished closing
[task 2022-04-04T14:14:15.548Z] 14:14:15     INFO - Console message: [JavaScript Error: "TypeError: can't access property "notifyTargetDestroyed", watcher is undefined" {file: "resource://devtools/server/connectors/js-window-actor/DevToolsFrameParent.jsm" line: 217}]
[task 2022-04-04T14:14:15.548Z] 14:14:15     INFO - receiveMessage@resource://devtools/server/connectors/js-window-actor/DevToolsFrameParent.jsm:217:11
[task 2022-04-04T14:14:15.548Z] 14:14:15     INFO - 
[task 2022-04-04T14:14:15.549Z] 14:14:15     INFO - Buffered messages logged at 14:14:14
[task 2022-04-04T14:14:15.549Z] 14:14:15     INFO - Removing tab.
[task 2022-04-04T14:14:15.549Z] 14:14:15     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2022-04-04T14:14:15.550Z] 14:14:15     INFO - Got event: 'TabClose' on [object XULElement].
[task 2022-04-04T14:14:15.550Z] 14:14:15     INFO - Tab removed and finished closing
[task 2022-04-04T14:14:15.551Z] 14:14:15     INFO - Console message: [JavaScript Error: "TypeError: can't access property "notifyTargetDestroyed", watcher is undefined" {file: "resource://devtools/server/connectors/js-window-actor/DevToolsFrameParent.jsm" line: 217}]
[task 2022-04-04T14:14:15.551Z] 14:14:15     INFO - receiveMessage@resource://devtools/server/connectors/js-window-actor/DevToolsFrameParent.jsm:217:11
[task 2022-04-04T14:14:15.551Z] 14:14:15     INFO - 
[task 2022-04-04T14:14:15.552Z] 14:14:15     INFO - Buffered messages logged at 14:14:15
[task 2022-04-04T14:14:15.552Z] 14:14:15     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2022-04-04T14:14:15.553Z] 14:14:15     INFO - TEST-PASS | devtools/client/debugger/test/mochitest/browser_dbg-features-source-tree.js | The main process DevToolsServer has no pending connection when the test ends - 
[task 2022-04-04T14:14:15.553Z] 14:14:15     INFO - Buffered messages finished
[task 2022-04-04T14:14:15.554Z] 14:14:15     INFO - TEST-UNEXPECTED-FAIL | devtools/client/debugger/test/mochitest/browser_dbg-features-source-tree.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. - 
[task 2022-04-04T14:14:15.554Z] 14:14:15     INFO - GECKO(3110) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2022-04-04T14:14:15.555Z] 14:14:15     INFO - GECKO(3110) | MEMORY STAT | vsize 16242MB | residentFast 431MB | heapAllocated 153MB
[task 2022-04-04T14:14:15.555Z] 14:14:15     INFO - TEST-OK | devtools/client/debugger/test/mochitest/browser_dbg-features-source-tree.js | took 61320ms
[task 2022-04-04T14:14:15.556Z] 14:14:15     INFO - checking window state
[task 2022-04-04T14:14:15.556Z] 14:14:15     INFO - GECKO(3110) | Completed ShutdownLeaks collections in process 3110
[task 2022-04-04T14:14:15.557Z] 14:14:15     INFO - TEST-START | Shutdown
[task 2022-04-04T14:14:15.557Z] 14:14:15     INFO - Browser Chrome Test Summary
[task 2022-04-04T14:14:15.557Z] 14:14:15     INFO - Passed:  30
[task 2022-04-04T14:14:15.558Z] 14:14:15     INFO - Failed:  1
[task 2022-04-04T14:14:15.558Z] 14:14:15     INFO - Todo:    0
[task 2022-04-04T14:14:15.558Z] 14:14:15     INFO - Mode:    e10s
[task 2022-04-04T14:14:15.559Z] 14:14:15     INFO - *** End BrowserChrome Test Results ***

Comment 1

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1761368

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

:ochameau, since you are the author of the regressor, bug 1761368, could you take a look?
For more information, please visit auto_nag documentation.

Comment 3

[Intermittent Failures Robot]

2 failures in 2922 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• macosx1015-64-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1762929&startday=2022-04-04&endday=2022-04-10&tree=all

Comment 4

[Intermittent Failures Robot]

1 failures in 3159 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1762929&startday=2022-04-18&endday=2022-04-24&tree=all

Comment 5

[Intermittent Failures Robot]

1 failures in 3289 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1762929&startday=2022-04-25&endday=2022-05-01&tree=all