Open Bug 1779029 Opened 2 years ago Updated 1 year ago

Intermittent damp | toolbox/browser-toolbox.js: Test timed out

Categories

(DevTools :: Console, defect, P5)

defect

Tracking

(firefox-esr91 unaffected, firefox-esr102 unaffected, firefox102 unaffected, firefox103 unaffected, firefox104 wontfix, firefox105 wontfix)

Tracking Status
firefox-esr91 --- unaffected
firefox-esr102 --- unaffected
firefox102 --- unaffected
firefox103 --- unaffected
firefox104 --- wontfix
firefox105 --- wontfix

People

(Reporter: intermittent-bug-filer, Unassigned, NeedInfo)

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [retriggered])

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


[task 2022-07-11T16:18:54.760Z] 16:18:54     INFO -  PID 18668 | Close toolbox on 'custom.netmonitor'
[task 2022-07-11T16:18:55.797Z] 16:18:55     INFO -  PID 18668 | Garbage collect
[task 2022-07-11T16:18:56.111Z] 16:18:56     INFO -  PID 18668 | netmonitor/custom.js took 6991ms.
[task 2022-07-11T16:18:56.111Z] 16:18:56     INFO -  PID 18668 | Loading test 'toolbox/panels-in-background.js'
[task 2022-07-11T16:18:56.111Z] 16:18:56     INFO -  PID 18668 | Executing test 'toolbox/panels-in-background.js'
[task 2022-07-11T16:18:56.121Z] 16:18:56     INFO -  PID 18668 | Wait for a pageshow event for browsing context 95
[task 2022-07-11T16:18:56.304Z] 16:18:56     INFO -  PID 18668 | Received pageshow event for 95
[task 2022-07-11T16:18:56.499Z] 16:18:56     INFO -  PID 18668 | Open toolbox on 'webconsole'
[task 2022-07-11T16:18:56.504Z] 16:18:56     INFO -  PID 18668 | Open toolbox - Call showToolboxForTab
[task 2022-07-11T16:18:56.509Z] 16:18:56     INFO -  PID 18668 | Open toolbox - Wait for "toolbox-created"
[task 2022-07-11T16:18:56.685Z] 16:18:56     INFO -  PID 18668 | Open toolbox - Wait for showToolbox to resolve
[task 2022-07-11T16:18:57.244Z] 16:18:57     INFO -  PID 18668 | Reload page on 'panelsInBackground'
[task 2022-07-11T16:18:57.244Z] 16:18:57     INFO -  PID 18668 | Wait for a pageshow event for browsing context 95
[task 2022-07-11T16:18:57.610Z] 16:18:57     INFO -  PID 18668 | Received pageshow event for 95
[task 2022-07-11T16:18:57.610Z] 16:18:57     INFO -  PID 18668 | Wait for pending paints on 'panelsInBackground.reload'
[task 2022-07-11T16:18:57.610Z] 16:18:57     INFO -  PID 18668 | 'panelsInBackground.reload.settle.DAMP' took 0.06508100000064587ms.
[task 2022-07-11T16:18:59.302Z] 16:18:59     INFO -  PID 18668 | Garbage collect
[task 2022-07-11T16:18:59.697Z] 16:18:59     INFO -  PID 18668 | toolbox/panels-in-background.js took 3586ms.
[task 2022-07-11T16:18:59.697Z] 16:18:59     INFO -  PID 18668 | Loading test 'toolbox/screenshot.js'
[task 2022-07-11T16:18:59.697Z] 16:18:59     INFO -  PID 18668 | Executing test 'toolbox/screenshot.js'
[task 2022-07-11T16:18:59.706Z] 16:18:59     INFO -  PID 18668 | Wait for a pageshow event for browsing context 102
[task 2022-07-11T16:18:59.998Z] 16:18:59     INFO -  PID 18668 | console.warn: LoginHelper(Content): "Couldn't parse specified uri httpdisabled://www.bild.de/suche.bild.html?type=article&query=&resultsStart=0&resultsPerPage=0 with error NS_ERROR_FAILURE"
[task 2022-07-11T16:19:00.017Z] 16:19:00     INFO -  PID 18668 | console.warn: LoginHelper(Content): "Couldn't parse specified uri httpdisabled://tarifvergleich.bild.de/strom/strom.php?phpurl=stromrechner.php with error NS_ERROR_FAILURE"
[task 2022-07-11T16:19:00.164Z] 16:19:00     INFO -  PID 18668 | Received pageshow event for 102
[task 2022-07-11T16:19:00.266Z] 16:19:00     INFO -  PID 18668 | Open toolbox on 'webconsole'
[task 2022-07-11T16:19:00.267Z] 16:19:00     INFO -  PID 18668 | Open toolbox - Call showToolboxForTab
[task 2022-07-11T16:19:00.268Z] 16:19:00     INFO -  PID 18668 | Open toolbox - Wait for "toolbox-created"
[task 2022-07-11T16:19:00.281Z] 16:19:00     INFO -  PID 18668 | Open toolbox - Wait for showToolbox to resolve
[task 2022-07-11T16:19:01.408Z] 16:19:01     INFO -  PID 18668 | [Parent 18668, MediaDecoderStateMachine #1] WARNING: 7f0cd76fe3a0 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:281
[task 2022-07-11T16:19:01.408Z] 16:19:01     INFO -  PID 18668 | [Parent 18668, MediaDecoderStateMachine #1] WARNING: Decoder=7f0cfa643a00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3979
[task 2022-07-11T16:19:01.408Z] 16:19:01     INFO -  PID 18668 | [Parent 18668, MediaDecoderStateMachine #1] WARNING: Decoder=7f0cfa643a00 Decode error: NS_ERROR_DOM_MEDIA_MEDIASINK_ERR (0x806e000b) - OnMediaSinkAudioError: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachineBase.cpp:151
[task 2022-07-11T16:19:01.665Z] 16:19:01     INFO -  PID 18668 | console.warn: "IGNORED REDUX ACTION:" "AUTOCOMPLETE_CLEAR"
[task 2022-07-11T16:19:01.671Z] 16:19:01     INFO -  PID 18668 | Garbage collect
[task 2022-07-11T16:19:02.106Z] 16:19:02     INFO -  PID 18668 | toolbox/screenshot.js took 2409ms.
[task 2022-07-11T16:19:02.107Z] 16:19:02     INFO -  PID 18668 | Loading test 'toolbox/browser-toolbox.js'
[task 2022-07-11T16:19:02.107Z] 16:19:02     INFO -  PID 18668 | Executing test 'toolbox/browser-toolbox.js'
[task 2022-07-11T16:19:02.118Z] 16:19:02     INFO -  PID 18668 | Wait for a pageshow event for browsing context 107
[task 2022-07-11T16:19:02.137Z] 16:19:02     INFO -  PID 18668 | Received pageshow event for 107
[task 2022-07-11T16:19:02.260Z] 16:19:02     INFO -  PID 18668 | DevTools Server for Browser Toolbox listening on port: 43141
[task 2022-07-11T16:19:02.269Z] 16:19:02     INFO -  PID 18668 | Starting Browser Toolbox /home/cltbld/tasks/task_165755063928602/build/application/firefox/firefox-bin -no-remote -foreground -profile /tmp/tmpeu7lhqi0/profile/chrome_debugger_profile -chrome chrome://devtools/content/framework/browser-toolbox/window.html
[task 2022-07-11T16:19:04.087Z] 16:19:04     INFO -  PID 18668 | 22018> Wait for debugger to initializeJavaScript error: resource://devtools/client/fronts/targets/target-mixin.js, line 322: Error: Target already destroyed, unable to fetch children fronts
[task 2022-07-11T16:19:04.197Z] 16:19:04     INFO -  PID 18668 | 22018> console.error: (new Error("Target already destroyed, unable to fetch children fronts", "resource://devtools/client/fronts/targets/target-mixin.js", 322))
[task 2022-07-11T16:24:02.108Z] 16:24:02     INFO -  PID 18668 | TEST-UNEXPECTED-FAIL | damp | toolbox/browser-toolbox.js: Test timed out
[task 2022-07-11T16:24:02.119Z] 16:24:02     INFO -  Terminating psutil.Process(pid=18668, name='firefox-bin', started='16:18:25')
[task 2022-07-11T16:24:02.119Z] 16:24:02     INFO -  PID 18668 | [DampLoad helper] Unregister DampLoad actors
[task 2022-07-11T16:24:02.133Z] 16:24:02     INFO -  PID 18668 | Exiting due to channel error.
[task 2022-07-11T16:24:02.133Z] 16:24:02     INFO -  PID 18668 | Exiting due to channel error.
[task 2022-07-11T16:24:02.133Z] 16:24:02     INFO -  PID 18668 | Exiting due to channel error.
[task 2022-07-11T16:24:02.134Z] 16:24:02     INFO -  PID 18668 | Exiting due to channel error.
[task 2022-07-11T16:24:02.134Z] 16:24:02     INFO -  PID 18668 | Exiting due to channel error.
[task 2022-07-11T16:24:02.134Z] 16:24:02     INFO -  PID 18668 | Exiting due to channel error.
[task 2022-07-11T16:24:02.246Z] 16:24:02     INFO -  mozcrash checking /tmp/tmpeu7lhqi0/profile/minidumps for minidumps...
[task 2022-07-11T16:24:02.247Z] 16:24:02     INFO -  TEST-UNEXPECTED-ERROR | damp | unexpected error
[task 2022-07-11T16:24:02.247Z] 16:24:02    ERROR -  Traceback (most recent call last):
[task 2022-07-11T16:24:02.247Z] 16:24:02     INFO -    File "/home/cltbld/tasks/task_165755063928602/build/tests/talos/talos/run_tests.py", line 341, in run_tests
[task 2022-07-11T16:24:02.247Z] 16:24:02     INFO -      talos_results.add(mytest.runTest(browser_config, test))
[task 2022-07-11T16:24:02.247Z] 16:24:02     INFO -    File "/home/cltbld/tasks/task_165755063928602/build/tests/talos/talos/ttest.py", line 65, in runTest
[task 2022-07-11T16:24:02.248Z] 16:24:02     INFO -      return self._runTest(browser_config, test_config, setup)
[task 2022-07-11T16:24:02.248Z] 16:24:02     INFO -    File "/home/cltbld/tasks/task_165755063928602/build/tests/talos/talos/ttest.py", line 209, in _runTest
[task 2022-07-11T16:24:02.248Z] 16:24:02     INFO -      debugger_args=browser_config["debugger_args"],
[task 2022-07-11T16:24:02.248Z] 16:24:02     INFO -    File "/home/cltbld/tasks/task_165755063928602/build/tests/talos/talos/talos_process.py", line 191, in run_browser
[task 2022-07-11T16:24:02.249Z] 16:24:02     INFO -      raise TalosError("unexpected error")
[task 2022-07-11T16:24:02.249Z] 16:24:02     INFO -  talos.utils.TalosError: unexpected error
[task 2022-07-11T16:24:02.249Z] 16:24:02     INFO -  TEST-INFO took 990037ms
[task 2022-07-11T16:24:02.249Z] 16:24:02     INFO -  SUITE-END | took 990s
Component: Talos → Console
Product: Testing → DevTools

Hi Alexandre! Can you please take a look at this? It seems that this is regressed by your recent changes in Bug 1778274.
Thank you!

Flags: needinfo?(poirot.alex)

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

This might related to a zombie target while opening the browser toolbox and preventing it from opening:

[task 2022-07-21T22:21:22.715Z] 22:21:22     INFO -  PID 2458 | DevTools Server for Browser Toolbox listening on port: 35481
[task 2022-07-21T22:21:22.725Z] 22:21:22     INFO -  PID 2458 | Starting Browser Toolbox /home/cltbld/tasks/task_165843124990944/build/application/firefox/firefox-bin -no-remote -foreground -profile /tmp/tmpl5_dbum7/profile/chrome_debugger_profile -chrome chrome://devtools/content/framework/browser-toolbox/window.html
[task 2022-07-21T22:21:24.448Z] 22:21:24     INFO -  PID 2458 | 5870> Wait for debugger to initializeJavaScript error: resource://devtools/client/fronts/targets/target-mixin.js, line 322: Error: Target already destroyed, unable to fetch children fronts
[task 2022-07-21T22:21:24.558Z] 22:21:24     INFO -  PID 2458 | 5870> console.error: (new Error("Target already destroyed, unable to fetch children fronts", "resource://devtools/client/fronts/targets/target-mixin.js", 322))
[task 2022-07-21T22:26:22.560Z] 22:26:22     INFO -  PID 2458 | TEST-UNEXPECTED-FAIL | damp | toolbox/browser-toolbox.js: Test timed out

It is worth investigating as it might probably happen in production.

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

There have been 41 failures in the last 7 days.

Happens on:
-linux1804-64-shippable-qr opt
-macosx1015-64-shippable-qr opt
-windows10-64-shippable-qr opt.

Recent failure log

Flags: needinfo?(jdescottes)
You need to log in before you can comment on or make changes to this bug.