Intermittent devtools/client/framework/test/browser_toolbox_hosts.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. -
Categories
(DevTools :: Framework, defect, P3)
Tracking
(firefox99 fixed)
Tracking | Status | |
---|---|---|
firefox99 | --- | fixed |
People
(Reporter: bogdan_tara, Assigned: ochameau)
References
Details
(Keywords: intermittent-failure, Whiteboard: [stockwell disable-recommended])
Attachments
(3 files)
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 47•3 years ago
|
||
Update:
There have been 89 failures within the last 7 days, all on Linux 18.04 x64 WebRender debug.
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=366851379&repo=autoland&lineNumber=10548
[task 2022-02-05T21:39:37.417Z] 21:39:37 INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_hosts.js | The previous host is correct -
[task 2022-02-05T21:39:37.418Z] 21:39:37 INFO - Buffered messages logged at 21:39:36
[task 2022-02-05T21:39:37.419Z] 21:39:37 INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2022-02-05T21:39:37.419Z] 21:39:37 INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2022-02-05T21:39:37.421Z] 21:39:37 INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2022-02-05T21:39:37.422Z] 21:39:37 INFO - Leaving test bound runNonFissionWindowTest
[task 2022-02-05T21:39:37.422Z] 21:39:37 INFO - TEST-PASS | devtools/client/framework/test/browser_toolbox_hosts.js | The main process DevToolsServer has no pending connection when the test ends -
[task 2022-02-05T21:39:37.423Z] 21:39:37 INFO - Buffered messages finished
[task 2022-02-05T21:39:37.425Z] 21:39:37 INFO - TEST-UNEXPECTED-FAIL | devtools/client/framework/test/browser_toolbox_hosts.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-02-05T21:39:37.426Z] 21:39:37 INFO - GECKO(1558) | MEMORY STAT | vsize 3956MB | residentFast 733MB | heapAllocated 336MB
[task 2022-02-05T21:39:37.427Z] 21:39:37 INFO - TEST-OK | devtools/client/framework/test/browser_toolbox_hosts.js | took 92209ms
[task 2022-02-05T21:39:37.433Z] 21:39:37 INFO - GECKO(1558) | [Child 1993: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7ff7e8a8dc00 == 2 [pid = 1993] [id = 27]
[task 2022-02-05T21:39:37.434Z] 21:39:37 INFO - GECKO(1558) | [Child 1993: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (7ff7e3df83c0) [pid = 1993] [serial = 67] [outer = 0]
[task 2022-02-05T21:39:37.435Z] 21:39:37 INFO - GECKO(1558) | [Child 1993: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (7ff7e8a8e000) [pid = 1993] [serial = 68] [outer = 7ff7e3df83c0]
[task 2022-02-05T21:39:37.436Z] 21:39:37 INFO - GECKO(1558) | [Parent 1558, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, false) failed with result 0x804B0050 (NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS): file /builds/worker/checkouts/gecko/toolkit/components/antitracking/URLQueryStringStripper.cpp:129
[task 2022-02-05T21:39:37.436Z] 21:39:37 INFO - GECKO(1558) | [Child 1993, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, false) failed with result 0x804B0050 (NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS): file /builds/worker/checkouts/gecko/toolkit/components/antitracking/URLQueryStringStripper.cpp:129
[task 2022-02-05T21:39:37.437Z] 21:39:37 INFO - checking window state
[task 2022-02-05T21:39:37.438Z] 21:39:37 INFO - GECKO(1558) | [Child 1993, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, false) failed with result 0x804B0050 (NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS): file /builds/worker/checkouts/gecko/toolkit/components/antitracking/URLQueryStringStripper.cpp:129
[task 2022-02-05T21:39:37.439Z] 21:39:37 INFO - GECKO(1558) | [Child 1993: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7ff7e8a8ac00 == 1 [pid = 1993] [id = 26] [url = about:blank]
[task 2022-02-05T21:39:37.440Z] 21:39:37 INFO - GECKO(1558) | [Parent 1558: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 66 (7fb5a0154040) [pid = 1558] [serial = 434] [outer = 0] [url = about:blank]
[task 2022-02-05T21:39:37.440Z] 21:39:37 INFO - GECKO(1558) | [Parent 1558: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 65 (7fb5a0154200) [pid = 1558] [serial = 431] [outer = 0] [url = about:blank]
[task 2022-02-05T21:39:37.441Z] 21:39:37 INFO - GECKO(1558) | [Parent 1558: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 64 (7fb599f28580) [pid = 1558] [serial = 428] [outer = 0] [url = about:blank]
[task 2022-02-05T21:39:37.442Z] 21:39:37 INFO - GECKO(1558) | [Parent 1558: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 63 (7fb5c06e83c0) [pid = 1558] [serial = 445] [outer = 0] [url = about:blank]
[task 2022-02-05T21:39:37.443Z] 21:39:37 INFO - TEST-START | devtools/client/framework/test/browser_toolbox_hosts_size.js
Comment 48•3 years ago
|
||
Hi Alexandre! Can you please take a look at this? Maybe you could help us assign it to someone.
Thank you!
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 51•3 years ago
|
||
This history middleware is bad as it forces leaking all action until firefox is closed.
This doesn't seem to be enough to reduce the runtime of browser_toolbox_hosts.js,
but this may help free more objects in test and reduce intermittent and timeouts.
I suspect that there is some other leaks happening in this toolbox host test.
Updated•3 years ago
|
Assignee | ||
Comment 52•3 years ago
|
||
Opening and closing toolbox allocate lots of objects
and the GC pauses between each task takes some time.
In addition to that, there is some leaked memory, which slow things down.
So that the test takes too much time to run on DEBUG builds.
Updated•3 years ago
|
Assignee | ||
Comment 53•3 years ago
|
||
We were trying to process style actor that did not relate to any stylesheet.
This ended up trying to create stylesheet resources with no stylesheet object,
and various exception because of that.
Comment hidden (Intermittent Failures Robot) |
Comment 55•3 years ago
|
||
Comment 56•3 years ago
|
||
Backed out for causing multiple xpcshell failures.
Failure log for when it first fails on test_action-clear-snapshots_XX.js
Failure log for when it first fails on test_action-export-snapshot.js
Failure log for when it first fails on test_action-import-snapshot-and-census.js
[task 2022-02-10T11:55:38.904Z] 11:55:38 INFO - TEST-START | netwerk/test/unit_ipc/test_trr_httpssvc_wrap.js
[task 2022-02-10T11:55:39.607Z] 11:55:39 INFO - TEST-PASS | netwerk/test/unit_ipc/test_trackingProtection_annotateChannels_wrap2.js | took 5707ms
[task 2022-02-10T11:55:39.647Z] 11:55:39 INFO - TEST-PASS | netwerk/test/unit_ipc/test_trackingProtection_annotateChannels_wrap1.js | took 6107ms
[task 2022-02-10T11:55:40.147Z] 11:55:40 INFO - TEST-PASS | netwerk/test/unit_ipc/test_multipart_streamconv_wrap.js | took 4255ms
[task 2022-02-10T11:55:40.361Z] 11:55:40 INFO - TEST-PASS | netwerk/test/unit_ipc/test_channel_priority_wrap.js | took 4706ms
[task 2022-02-10T11:55:40.739Z] 11:55:40 INFO - TEST-PASS | netwerk/test/unit_ipc/test_alt-data_cross_process_wrap.js | took 3637ms
[task 2022-02-10T11:55:40.834Z] 11:55:40 INFO - TEST-PASS | netwerk/test/unit_ipc/test_httpcancel_wrap.js | took 3549ms
[task 2022-02-10T11:55:42.758Z] 11:55:42 INFO - TEST-PASS | netwerk/test/unit_ipc/test_dns_by_type_resolve_wrap.js | took 4425ms
[task 2022-02-10T11:55:43.278Z] 11:55:43 INFO - TEST-PASS | netwerk/test/unit_ipc/test_trr_httpssvc_wrap.js | took 4375ms
[task 2022-02-10T11:55:43.281Z] 11:55:43 INFO - Retrying tests that failed when run in parallel.
[task 2022-02-10T11:55:43.284Z] 11:55:43 INFO - TEST-START | devtools/client/memory/test/xpcshell/test_action-clear-snapshots_01.js
[task 2022-02-10T11:55:44.009Z] 11:55:44 WARNING - TEST-UNEXPECTED-FAIL | devtools/client/memory/test/xpcshell/test_action-clear-snapshots_01.js | xpcshell return code: 0
[task 2022-02-10T11:55:44.009Z] 11:55:44 INFO - TEST-INFO took 725ms
[task 2022-02-10T11:55:44.010Z] 11:55:44 INFO - >>>>>>>
[task 2022-02-10T11:55:44.010Z] 11:55:44 INFO - PID 7460 | [Parent 7460, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file /builds/worker/checkouts/gecko/toolkit/crashreporter/nsExceptionHandler.cpp:2965
[task 2022-02-10T11:55:44.011Z] 11:55:44 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2022-02-10T11:55:44.011Z] 11:55:44 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2022-02-10T11:55:44.011Z] 11:55:44 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2022-02-10T11:55:44.012Z] 11:55:44 INFO - running event loop
[task 2022-02-10T11:55:44.013Z] 11:55:44 INFO - devtools/client/memory/test/xpcshell/test_action-clear-snapshots_01.js | Starting
[task 2022-02-10T11:55:44.014Z] 11:55:44 INFO - (xpcshell/head.js) | test pending (2)
[task 2022-02-10T11:55:44.014Z] 11:55:44 INFO - PID 7460 | [Parent 7460, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, kKnownEsrVersion) failed with result 0x80004002 (NS_NOINTERFACE): file /builds/worker/checkouts/gecko/toolkit/components/resistfingerprinting/nsRFPService.cpp:560
[task 2022-02-10T11:55:44.014Z] 11:55:44 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2022-02-10T11:55:44.015Z] 11:55:44 INFO - "Waiting for snapshots' censuses to be of state: tree-map-state-saved"
[task 2022-02-10T11:55:44.015Z] 11:55:44 INFO - "Waiting for state predicate "() => {
[task 2022-02-10T11:55:44.015Z] 11:55:44 INFO - const snapshots = store.getState().snapshots;
[task 2022-02-10T11:55:44.015Z] 11:55:44 INFO - info(
[task 2022-02-10T11:55:44.015Z] 11:55:44 INFO - "Current census state:" +
[task 2022-02-10T11:55:44.019Z] 11:55:44 INFO - snapshots.map(x => (getCensus(x) ? getCensus(x).state : null))
[task 2022-02-10T11:55:44.019Z] 11:55:44 INFO - );
[task 2022-02-10T11:55:44.019Z] 11:55:44 INFO - return (
[task 2022-02-10T11:55:44.019Z] 11:55:44 INFO - snapshots.length === expected.length &&
[task 2022-02-10T11:55:44.019Z] 11:55:44 INFO - expected.every((state, i) => {
[task 2022-02-10T11:55:44.020Z] 11:55:44 INFO - const census = getCensus(snapshots[i]);
[task 2022-02-10T11:55:44.020Z] 11:55:44 INFO - return (
[task 2022-02-10T11:55:44.021Z] 11:55:44 INFO - state === "*" ||
[task 2022-02-10T11:55:44.024Z] 11:55:44 INFO - (!census && !state) ||
[task 2022-02-10T11:55:44.024Z] 11:55:44 INFO - (census && census.state === state)
[task 2022-02-10T11:55:44.024Z] 11:55:44 INFO - );
[task 2022-02-10T11:55:44.024Z] 11:55:44 INFO - })
[task 2022-02-10T11:55:44.024Z] 11:55:44 INFO - );
[task 2022-02-10T11:55:44.024Z] 11:55:44 INFO - }""
[task 2022-02-10T11:55:44.024Z] 11:55:44 INFO - "Current census state:"
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - "Current census state:"
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - "Current census state:"
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - "Current census state:"
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - "Current census state:tree-map-state-saving"
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - "Current census state:tree-map-state-saved"
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - "Found state predicate "() => {
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - const snapshots = store.getState().snapshots;
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - info(
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - "Current census state:" +
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - snapshots.map(x => (getCensus(x) ? getCensus(x).state : null))
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - );
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - return (
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - snapshots.length === expected.length &&
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - expected.every((state, i) => {
[task 2022-02-10T11:55:44.025Z] 11:55:44 INFO - const census = getCensus(snapshots[i]);
[task 2022-02-10T11:55:44.026Z] 11:55:44 INFO - return (
[task 2022-02-10T11:55:44.026Z] 11:55:44 INFO - state === "*" ||
[task 2022-02-10T11:55:44.026Z] 11:55:44 INFO - (!census && !state) ||
[task 2022-02-10T11:55:44.026Z] 11:55:44 INFO - (census && census.state === state)
[task 2022-02-10T11:55:44.026Z] 11:55:44 INFO - );
[task 2022-02-10T11:55:44.026Z] 11:55:44 INFO - })
[task 2022-02-10T11:55:44.026Z] 11:55:44 INFO - );
[task 2022-02-10T11:55:44.026Z] 11:55:44 INFO - }""
[task 2022-02-10T11:55:44.026Z] 11:55:44 INFO - TEST-PASS | devtools/client/memory/test/xpcshell/test_action-clear-snapshots_01.js | - snapshot created - true == true
[task 2022-02-10T11:55:44.026Z] 11:55:44 INFO - TEST-PASS | devtools/client/memory/test/xpcshell/test_action-clear-snapshots_01.js | - dispatch clearSnapshots action - true == true
[task 2022-02-10T11:55:44.026Z] 11:55:44 INFO - Unexpected exception ReferenceError: waitForDispatch is not defined at /builds/worker/workspace/build/tests/xpcshell/tests/devtools/client/memory/test/xpcshell/test_action-clear-snapshots_01.js:28
[task 2022-02-10T11:55:44.026Z] 11:55:44 INFO - @/builds/worker/workspace/build/tests/xpcshell/tests/devtools/client/memory/test/xpcshell/test_action-clear-snapshots_01.js:28:5
[task 2022-02-10T11:55:44.026Z] 11:55:44 INFO - _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:240:6
[task 2022-02-10T11:55:44.027Z] 11:55:44 INFO - _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:604:5
[task 2022-02-10T11:55:44.027Z] 11:55:44 INFO - @-e:1:1
[task 2022-02-10T11:55:44.027Z] 11:55:44 INFO - exiting test
[task 2022-02-10T11:55:44.027Z] 11:55:44 INFO - TEST-PASS | devtools/client/memory/test/xpcshell/test_action-clear-snapshots_01.js | - Should have had the expected number of DevToolsUtils.assert() failures. - 0 == 0
[task 2022-02-10T11:55:44.027Z] 11:55:44 INFO - PID 7460 | [Parent 7460, Main Thread] WARNING: A runnable was posted to a worker that is already shutting down!: file /builds/worker/checkouts/gecko/dom/workers/WorkerPrivate.cpp:1497
[task 2022-02-10T11:55:44.027Z] 11:55:44 INFO - PID 7460 | [Parent 7460, Main Thread] WARNING: Failed to dispatch offline status change event!: file /builds/worker/checkouts/gecko/dom/workers/WorkerPrivate.cpp:1974
[task 2022-02-10T11:55:44.027Z] 11:55:44 INFO - PID 7460 | [Parent 7460, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3354
[task 2022-02-10T11:55:44.027Z] 11:55:44 INFO - PID 7460 | [Parent 7460, Main Thread] WARNING: OOPDeinit() without successful OOPInit(): file /builds/worker/checkouts/gecko/toolkit/crashreporter/nsExceptionHandler.cpp:3421
[task 2022-02-10T11:55:44.027Z] 11:55:44 INFO - PID 7460 | [Parent 7460, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4460
[task 2022-02-10T11:55:44.027Z] 11:55:44 INFO - PID 7460 | [Parent 7460, Main Thread] WARNING: XPCOM object PerThreadData destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:206
[task 2022-02-10T11:55:44.028Z] 11:55:44 INFO - PID 7460 | [Parent 7460, Main Thread] WARNING: XPCOM object MasterList destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:206
[task 2022-02-10T11:55:44.028Z] 11:55:44 INFO - <<<<<<<
[task 2022-02-10T11:55:44.029Z] 11:55:44 INFO - TEST-START | devtools/client/memory/test/xpcshell/test_action-clear-snapshots_03.js
Updated•3 years ago
|
Updated•3 years ago
|
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 58•3 years ago
|
||
I broke xpcshell because of now missing waitForDispatch
in them.
I'll duplicate this method in xpcshell's head.js and followup to start sharing shared-head.js to xpcshell tests.
Assignee | ||
Comment 59•3 years ago
|
||
Comment 60•3 years ago
|
||
Comment 61•3 years ago
|
||
bugherder |
https://hg.mozilla.org/mozilla-central/rev/84dc675069c3
https://hg.mozilla.org/mozilla-central/rev/ea82e7cfdb12
https://hg.mozilla.org/mozilla-central/rev/e7cfbaa85de1
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Description
•