Intermittent Assertion failure: false (Try to init HttpHandler after shutdown), at /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpHandler.cpp:333
Categories
(Core :: DOM: Workers, defect, P5)
Tracking
()
Tracking | Status | |
---|---|---|
firefox-esr102 | --- | unaffected |
firefox109 | --- | unaffected |
firefox110 | --- | unaffected |
firefox111 | --- | wontfix |
firefox112 | --- | wontfix |
firefox113 | --- | wontfix |
firefox114 | --- | wontfix |
People
(Reporter: intermittent-bug-filer, Unassigned)
References
(Regression)
Details
(Keywords: assertion, intermittent-failure, regression, Whiteboard: [retriggered])
Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=403860204&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/V9oqaFKdQa6HrUkUHV1oiQ/runs/0/artifacts/public/logs/live_backing.log
[task 2023-01-28T23:42:35.041Z] 23:42:35 INFO - TEST-START | browser/components/shell/test/browser_headless_screenshot_4.js
<...>
[task 2023-01-28T23:42:46.703Z] 23:42:46 INFO - GECKO(4593) | [Parent 7280, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/toolkit/xre/nsXREDirProvider.cpp:478
[task 2023-01-28T23:42:46.719Z] 23:42:46 INFO - GECKO(4593) | >>> expected format: --window-size width[,height]
[task 2023-01-28T23:42:47.136Z] 23:42:47 INFO - GECKO(4593) | [Child 4685: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (7f3e5037c090) [pid = 4685] [serial = 9] [outer = 0] [url = about:blank]
[task 2023-01-28T23:42:47.180Z] 23:42:47 INFO - GECKO(4593) | [Parent 7280, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/toolkit/xre/nsXREDirProvider.cpp:478
[task 2023-01-28T23:42:47.349Z] 23:42:47 INFO - GECKO(4593) | [WARN rkv::backend::impl_safe::environment] `load_ratio()` is irrelevant for this storage backend.
[task 2023-01-28T23:42:47.379Z] 23:42:47 INFO - GECKO(4593) | >>> console.error: (new Error("IndexedDB: main/cookie-banner-rules-list getLastModified() IndexedDB: execute() The application is shutting down", "resource://services-settings/IDBHelpers.jsm", 18))
[task 2023-01-28T23:42:47.540Z] 23:42:47 INFO - GECKO(4593) | Assertion failure: false (Try to init HttpHandler after shutdown), at /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpHandler.cpp:333
[task 2023-01-28T23:42:47.547Z] 23:42:47 INFO - Initializing stack-fixing for the first stack frame, this may take a while...
[task 2023-01-28T23:43:11.732Z] 23:43:11 INFO - GECKO(4593) | #01: mozilla::net::nsHttpHandler::Init() [netwerk/protocol/http/nsHttpHandler.cpp:333]
[task 2023-01-28T23:43:11.733Z] 23:43:11 INFO - GECKO(4593) | #02: mozilla::net::nsHttpHandler::GetInstance() [netwerk/protocol/http/nsHttpHandler.cpp:197]
[task 2023-01-28T23:43:11.735Z] 23:43:11 INFO - GECKO(4593) | #03: mozCreateComponent<mozilla::net::nsHttpHandler>() [netwerk/build/nsNetModule.cpp:65]
[task 2023-01-28T23:43:11.737Z] 23:43:11 INFO - GECKO(4593) | #04: mozilla::xpcom::CreateInstanceImpl(mozilla::xpcom::ModuleID, nsID const&, void**) [s3:gecko-generated-sources:5251d764dd33ae83b21ba504fdc534268f0eea28725cb5fbd495aa230c58264497a65e6cee3656986235d23829552e49f9d9ae3330e2af227a5bb5e59e3883a8/xpcom/components/StaticComponents.cpp::10686]
[task 2023-01-28T23:43:11.739Z] 23:43:11 INFO - GECKO(4593) | #05: nsComponentManagerImpl::GetServiceLocked(mozilla::Maybe<mozilla::detail::BaseMonitorAutoLock<mozilla::Monitor> >&, (anonymous namespace)::EntryWrapper&, nsID const&, void**) [xpcom/components/nsComponentManager.cpp:975]
[task 2023-01-28T23:43:11.740Z] 23:43:11 INFO - GECKO(4593) | #06: nsComponentManagerImpl::GetServiceByContractID(char const*, nsID const&, void**) [xpcom/components/nsComponentManager.cpp:1164]
[task 2023-01-28T23:43:11.742Z] 23:43:11 INFO - GECKO(4593) | #07: nsGetServiceByContractIDWithError::operator()(nsID const&, void**) const [xpcom/components/nsComponentManagerUtils.cpp:251]
[task 2023-01-28T23:43:11.743Z] 23:43:11 INFO - GECKO(4593) | #08: nsCOMPtr<nsIHttpProtocolHandler>::assign_from_gs_contractid_with_error(nsGetServiceByContractIDWithError const&, nsID const&) [xpcom/base/nsCOMPtr.h:1244]
[task 2023-01-28T23:43:11.745Z] 23:43:11 INFO - GECKO(4593) | #09: mozilla::dom::Navigator::GetAppVersion(nsTSubstring<char16_t>&, mozilla::dom::Document*, bool) [dom/base/Navigator.cpp:2009]
[task 2023-01-28T23:43:11.747Z] 23:43:11 INFO - GECKO(4593) | #10: mozilla::dom::workerinternals::RuntimeService::RegisterWorker(mozilla::dom::WorkerPrivate&) [dom/workers/RuntimeService.cpp:1177]
[task 2023-01-28T23:43:11.748Z] 23:43:11 INFO - GECKO(4593) | #11: mozilla::dom::WorkerPrivate::Constructor(JSContext*, nsTSubstring<char16_t> const&, bool, mozilla::dom::WorkerKind, mozilla::dom::RequestCredentials, mozilla::dom::WorkerType, nsTSubstring<char16_t> const&, nsTSubstring<char> const&, mozilla::dom::WorkerLoadInfo*, mozilla::ErrorResult&, nsTString<char16_t>) [dom/workers/WorkerPrivate.cpp:2649]
[task 2023-01-28T23:43:11.750Z] 23:43:11 INFO - GECKO(4593) | #12: mozilla::dom::ChromeWorker::Constructor(mozilla::dom::GlobalObject const&, nsTSubstring<char16_t> const&, mozilla::ErrorResult&) [dom/workers/ChromeWorker.cpp:22]
[task 2023-01-28T23:43:11.751Z] 23:43:11 INFO - GECKO(4593) | #13: mozilla::dom::ChromeWorker_Binding::_constructor(JSContext*, unsigned int, JS::Value*) [s3:gecko-generated-sources:96fd512ceda46a08eabed8213d3d855ae74fba26af77b3d2c438a7da441d3105b50a8561f08c44986c9d87e5f29cc5ea075ab3cfce271686f5ffb76034e5d2b8/dom/bindings/WorkerBinding.cpp::313]
[task 2023-01-28T23:43:11.753Z] 23:43:11 INFO - GECKO(4593) | #14: CallJSNative(JSContext*, bool (*)(JSContext*, unsigned int, JS::Value*), js::CallReason, JS::CallArgs const&) [js/src/vm/Interpreter.cpp:459]
[task 2023-01-28T23:43:11.755Z] 23:43:11 INFO - GECKO(4593) | #15: CallJSNativeConstructor(JSContext*, bool (*)(JSContext*, unsigned int, JS::Value*), JS::CallArgs const&) [js/src/vm/Interpreter.cpp:475]
[task 2023-01-28T23:43:11.757Z] 23:43:11 INFO - GECKO(4593) | #16: InternalConstruct(JSContext*, js::AnyConstructArgs const&, js::CallReason) [js/src/vm/Interpreter.cpp:0]
[task 2023-01-28T23:43:11.758Z] 23:43:11 INFO - GECKO(4593) | #17: Interpret(JSContext*, js::RunState&) [js/src/vm/Interpreter.cpp:3347]
[task 2023-01-28T23:43:11.760Z] 23:43:11 INFO - GECKO(4593) | #18: js::RunScript(JSContext*, js::RunState&) [js/src/vm/Interpreter.cpp:431]
[task 2023-01-28T23:43:11.761Z] 23:43:11 INFO - GECKO(4593) | #19: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [js/src/vm/Interpreter.cpp:0]
[task 2023-01-28T23:43:11.763Z] 23:43:11 INFO - GECKO(4593) | #20: js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) [js/src/vm/Interpreter.cpp:646]
[task 2023-01-28T23:43:11.765Z] 23:43:11 INFO - GECKO(4593) | #21: js::CallSelfHostedFunction(JSContext*, JS::Handle<js::PropertyName*>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>) [js/src/vm/SelfHosting.cpp:1489]
[task 2023-01-28T23:43:11.766Z] 23:43:11 INFO - GECKO(4593) | #22: js::jit::InterpretResume(JSContext*, JS::Handle<JSObject*>, JS::Value*, JS::MutableHandle<JS::Value>) [js/src/jit/VMFunctions.cpp:1088]
[task 2023-01-28T23:43:11.767Z] 23:43:11 INFO - GECKO(4593) | #23: ??? (???:???)
[task 2023-01-28T23:43:11.769Z] 23:43:11 INFO - GECKO(4593) | ExceptionHandler::GenerateDump cloned child 7332
[task 2023-01-28T23:43:11.770Z] 23:43:11 INFO - GECKO(4593) | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2023-01-28T23:43:11.772Z] 23:43:11 INFO - GECKO(4593) | ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2023-01-28T23:43:11.773Z] 23:43:11 INFO - TEST-INFO | started process screentopng
[task 2023-01-28T23:43:12.057Z] 23:43:12 INFO - TEST-INFO | screentopng: exit 0
[task 2023-01-28T23:43:12.059Z] 23:43:12 INFO - Buffered messages logged at 23:42:35
[task 2023-01-28T23:43:12.060Z] 23:43:12 INFO - Entering test bound
[task 2023-01-28T23:43:12.061Z] 23:43:12 INFO - Buffered messages logged at 23:42:38
[task 2023-01-28T23:43:12.062Z] 23:43:12 INFO - TEST-PASS | browser/components/shell/test/browser_headless_screenshot_4.js | Firefox process should exit with code 0 -
[task 2023-01-28T23:43:12.065Z] 23:43:12 INFO - TEST-PASS | browser/components/shell/test/browser_headless_screenshot_4.js | A screenshot should be saved in the tmp directory -
[task 2023-01-28T23:43:12.066Z] 23:43:12 INFO - TEST-PASS | browser/components/shell/test/browser_headless_screenshot_4.js | Screenshot should be 800 pixels wide -
[task 2023-01-28T23:43:12.067Z] 23:43:12 INFO - TEST-PASS | browser/components/shell/test/browser_headless_screenshot_4.js | Screenshot should be 600 pixels tall -
[task 2023-01-28T23:43:12.069Z] 23:43:12 INFO - Buffered messages logged at 23:42:42
[task 2023-01-28T23:43:12.073Z] 23:43:12 INFO - TEST-PASS | browser/components/shell/test/browser_headless_screenshot_4.js | Firefox process should exit with code 0 -
[task 2023-01-28T23:43:12.074Z] 23:43:12 INFO - TEST-PASS | browser/components/shell/test/browser_headless_screenshot_4.js | A screenshot should be saved in the tmp directory -
[task 2023-01-28T23:43:12.075Z] 23:43:12 INFO - TEST-PASS | browser/components/shell/test/browser_headless_screenshot_4.js | Screenshot should be 1234 pixels wide -
[task 2023-01-28T23:43:12.076Z] 23:43:12 INFO - Buffered messages logged at 23:42:46
[task 2023-01-28T23:43:12.077Z] 23:43:12 INFO - TEST-PASS | browser/components/shell/test/browser_headless_screenshot_4.js | Firefox process should exit with code 0 -
[task 2023-01-28T23:43:12.078Z] 23:43:12 INFO - TEST-PASS | browser/components/shell/test/browser_headless_screenshot_4.js | A screenshot should not be saved -
[task 2023-01-28T23:43:12.079Z] 23:43:12 INFO - Buffered messages finished
[task 2023-01-28T23:43:12.080Z] 23:43:12 INFO - TEST-UNEXPECTED-FAIL | browser/components/shell/test/browser_headless_screenshot_4.js | Firefox process should exit with code 0 - Got 11, expected +0
[task 2023-01-28T23:43:12.081Z] 23:43:12 INFO - Stack trace:
[task 2023-01-28T23:43:12.082Z] 23:43:12 INFO - chrome://mochikit/content/browser-test.js:test_is:1484
[task 2023-01-28T23:43:12.083Z] 23:43:12 INFO - chrome://mochitests/content/browser/browser/components/shell/test/head.js:runFirefox:44
[task 2023-01-28T23:43:12.089Z] 23:43:12 INFO - TEST-PASS | browser/components/shell/test/browser_headless_screenshot_4.js | A screenshot should not be saved -
[task 2023-01-28T23:43:12.090Z] 23:43:12 INFO - Leaving test bound
[task 2023-01-28T23:43:12.092Z] 23:43:12 INFO - GECKO(4593) | MEMORY STAT | vsize 3036MB | residentFast 427MB | heapAllocated 181MB
[task 2023-01-28T23:43:12.093Z] 23:43:12 INFO - TEST-OK | browser/components/shell/test/browser_headless_screenshot_4.js | took 12627ms
[task 2023-01-28T23:43:12.095Z] 23:43:12 INFO - GECKO(4593) | [Child 4685: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f3e4b123c00 == 1 [pid = 4685] [id = 4]
[task 2023-01-28T23:43:12.096Z] 23:43:12 INFO - GECKO(4593) | [Child 4685: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (7f3e5037c090) [pid = 4685] [serial = 11] [outer = 0]
[task 2023-01-28T23:43:12.098Z] 23:43:12 INFO - GECKO(4593) | [Child 4685: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (7f3e4b124400) [pid = 4685] [serial = 12] [outer = 7f3e5037c090]
[task 2023-01-28T23:43:12.099Z] 23:43:12 INFO - checking window state
[task 2023-01-28T23:43:12.100Z] 23:43:12 INFO - TEST-START | browser/components/shell/test/browser_headless_screenshot_cross_origin.js
Comment hidden (Intermittent Failures Robot) |
Comment 2•2 years ago
|
||
First range of retriggers and backfills were inconclusive.
Kershaw, this might be related to Bug 1802910.
Do you have a bit of time to look at this?
Thank you.
Comment 3•2 years ago
|
||
Set release status flags based on info from the regressing bug 1802910
Comment hidden (Intermittent Failures Robot) |
Comment 5•2 years ago
|
||
Looks like we are trying to create a worker during shutdown.
[task 2023-01-28T23:43:11.745Z] 23:43:11 INFO - GECKO(4593) | #09: mozilla::dom::Navigator::GetAppVersion(nsTSubstring<char16_t>&, mozilla::dom::Document*, bool) [dom/base/Navigator.cpp:2009]
[task 2023-01-28T23:43:11.747Z] 23:43:11 INFO - GECKO(4593) | #10: mozilla::dom::workerinternals::RuntimeService::RegisterWorker(mozilla::dom::WorkerPrivate&) [dom/workers/RuntimeService.cpp:1177]
[task 2023-01-28T23:43:11.748Z] 23:43:11 INFO - GECKO(4593) | #11: mozilla::dom::WorkerPrivate::Constructor(JSContext*, nsTSubstring<char16_t> const&, bool, mozilla::dom::WorkerKind, mozilla::dom::RequestCredentials, mozilla::dom::WorkerType, nsTSubstring<char16_t> const&, nsTSubstring<char> const&, mozilla::dom::WorkerLoadInfo*, mozilla::ErrorResult&, nsTString<char16_t>) [dom/workers/WorkerPrivate.cpp:2649]
[task 2023-01-28T23:43:11.750Z] 23:43:11 INFO - GECKO(4593) | #12: mozilla::dom::ChromeWorker::Constructor(mozilla::dom::GlobalObject const&, nsTSubstring<char16_t> const&, mozilla::ErrorResult&) [dom/workers/ChromeWorker.cpp:22]
Jens, could you find someone to take a look? Thanks.
Comment 6•2 years ago
|
||
Set release status flags based on info from the regressing bug 1802910
Updated•2 years ago
|
Comment 7•2 years ago
•
|
||
Joshua, would you mind to take a look? Even if it is not frequent, the stack might be interesting enough to look at.
Updated•2 years ago
|
Comment 8•2 years ago
|
||
Just a bit if context:
nsHttpHandler
is doing a AppShutdown::IsInOrBeyond(ShutdownPhase::AppShutdown)
check. The stack passes through WorkerPrivate::Constructor
and probably we should not allow the creation of new workers after we entered shutdown in general.
I assume that if we let the Constructor
return nullptr
the calling JS will throw and we might have a chance to see who was actually calling us here. And/or we could print out the JS stack when this happens.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•2 years ago
|
Updated•2 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment 12•1 year ago
|
||
So bug 1827207 now gives us:
[task 2023-05-08T18:32:25.827Z] 18:32:25 INFO - GECKO(20087) | >>> 0 _execute(method = ""importJSONDump"", args = "main,anti-tracking-url-decoration", options = "[object Object]") ["resource://services-settings/RemoteSettingsWorker.sys.mjs":70:20]
[task 2023-05-08T18:32:25.828Z] 18:32:25 INFO - GECKO(20087) | this = [object Object]
[task 2023-05-08T18:32:25.829Z] 18:32:25 INFO - GECKO(20087) | 1 importJSONDump(bucket = ""main"", collection = ""anti-tracking-url-decoration"") ["resource://services-settings/RemoteSettingsWorker.sys.mjs":171:16]
[task 2023-05-08T18:32:25.830Z] 18:32:25 INFO - GECKO(20087) | this = [object Object]
[task 2023-05-08T18:32:25.831Z] 18:32:25 INFO - GECKO(20087) | 2 _importJSONDump() ["resource://services-settings/RemoteSettingsClient.sys.mjs":966:51]
[task 2023-05-08T18:32:25.832Z] 18:32:25 INFO - GECKO(20087) | this = [object Object]
[task 2023-05-08T18:32:25.833Z] 18:32:25 INFO - GECKO(20087) | 3 get/this._importingPromise<() ["resource://services-settings/RemoteSettingsClient.sys.mjs":457:27]
[task 2023-05-08T18:32:25.834Z] 18:32:25 INFO - GECKO(20087) | 4 get() ["resource://services-settings/RemoteSettingsClient.sys.mjs":472:12]
[task 2023-05-08T18:32:25.835Z] 18:32:25 INFO - GECKO(20087) | 5 InterpretGeneratorResume(gen = "[object Object]", val = "null", kind = ""next"") ["self-hosted":1359:33]
[task 2023-05-08T18:32:25.836Z] 18:32:25 INFO - GECKO(20087) | 6 AsyncFunctionNext(val = "null") ["self-hosted":756:26]
[task 2023-05-08T18:32:25.837Z] 18:32:25 INFO - GECKO(20087) | this = [object Object]
[task 2023-05-08T18:32:25.838Z] 18:32:25 INFO - GECKO(20087) | 7 observe("null", ""profile-before-change"", "null") ["resource://gre/modules/AsyncShutdown.sys.mjs":575:16]
[task 2023-05-08T18:32:25.838Z] 18:32:25 INFO - GECKO(20087) | this = [object Object]
coming from this async operation in RemoteSettingsClient
. Could it be that we miss a shutdown blocker here?
Updated•1 year ago
|
Comment 13•1 year ago
|
||
Mathieu knows this code better than me.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 17•6 months ago
|
||
This intermittent looks pretty moot now, but every few months it shows up. I filed bug 1890278 for the remote settings piece.
Comment 18•5 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Reporter | ||
Comment 19•5 months ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=459791566&repo=autoland
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 23•3 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Reporter | ||
Comment 24•3 months ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=465797685&repo=mozilla-central
Comment hidden (Intermittent Failures Robot) |
Comment 26•2 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Description
•