1812318 - Intermittent toolkit/components/cleardata/tests/marionette/[test_name] ServiceWorkerAtShutdownTestCase.test_unregistering_service_worker_when_clearing_data | application crashed [@ NS_DebugBreak]

Status: RESOLVED INVALID

(Core :: DOM: Service Workers, defect)

Description

[Treeherder Bug Filer]

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

---

[task 2023-01-25T12:01:28.832Z] 12:01:28     INFO -  FATAL ERROR: AsyncShutdown timeout in profile-change-teardown Conditions: [{"name":"ServiceWorkerShutdownBlocker: shutting down Service Workers","state":{"shutdownStates":"parent process main thread, ","pendingPromises":1,"acceptingPromises":false},"filename":"/builds/worker/checkouts/gecko/dom/serviceworkers/ServiceWorkerShutdownBlocker.cpp","lineNumber":110,"stack":"Service Workers shutdown"}] At least one completion condition failed to complete within a reasonable amount of time. Causing a crash to ensure that we do not leave the user with an unresponsive process draining resources.
[task 2023-01-25T12:01:28.834Z] 12:01:28     INFO -  [Parent 8824, Main Thread] ###!!! ABORT: file /builds/worker/checkouts/gecko/dom/serviceworkers/ServiceWorkerShutdownBlocker.cpp:110
[task 2023-01-25T12:01:29.095Z] 12:01:29     INFO -  [GFX1-]: Receive IPC cl[osGFe wiX1-]: Receive IPC close with reth raesonason=AbnormalShutdown
[task 2023-01-25T12:01:29.095Z] 12:01:29     INFO -  Exiting due to channel error.
[task 2023-01-25T12:01:29.130Z] 12:01:29     INFO -  =
[task 2023-01-25T12:03:37.977Z] 12:03:37     INFO -  mozcrash Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/c2_AjTyzRwGVSVSDiltkvw/artifacts/public/build/target.crashreporter-symbols.zip
[task 2023-01-25T12:04:02.180Z] 12:04:02     INFO -  mozcrash Copy/paste: Z:/task_167464652668977/fetches\minidump-stackwalk\minidump-stackwalk.exe --symbols-url=https://symbols.mozilla.org/ --human C:\Users\task_167464652668977\AppData\Local\Temp\tmpxy8_w_h1.mozrunner\minidumps\36cb74e8-cb3f-4f59-b08b-4b1ad4d72610.dmp C:\Users\task_167464652668977\AppData\Local\Temp\tmp07d4zkqi
[task 2023-01-25T12:04:11.535Z] 12:04:11     INFO -  mozcrash Saved minidump as Z:\task_167464652668977\build\blobber_upload_dir\36cb74e8-cb3f-4f59-b08b-4b1ad4d72610.dmp
[task 2023-01-25T12:04:11.555Z] 12:04:11     INFO -  mozcrash Saved app info as Z:\task_167464652668977\build\blobber_upload_dir\36cb74e8-cb3f-4f59-b08b-4b1ad4d72610.extra
[task 2023-01-25T12:04:11.566Z] 12:04:11    ERROR -  PROCESS-CRASH | toolkit/components/cleardata/tests/marionette/test_service_worker_at_shutdown.py ServiceWorkerAtShutdownTestCase.test_unregistering_service_worker_when_clearing_data | application crashed [@ NS_DebugBreak(unsigned int, char const*, char const*, char const*, int)]
[task 2023-01-25T12:04:11.576Z] 12:04:11     INFO -  Mozilla crash reason: [Parent 8824, Main Thread] ###!!! ABORT: file /builds/worker/checkouts/gecko/dom/serviceworkers/ServiceWorkerShutdownBlocker.cpp:110
[task 2023-01-25T12:04:11.577Z] 12:04:11     INFO -  Crash dump filename: C:\Users\task_167464652668977\AppData\Local\Temp\tmpxy8_w_h1.mozrunner\minidumps\36cb74e8-cb3f-4f59-b08b-4b1ad4d72610.dmp
[task 2023-01-25T12:04:11.577Z] 12:04:11     INFO -  Operating system: Windows NT
[task 2023-01-25T12:04:11.577Z] 12:04:11     INFO -                    10.0.19041
[task 2023-01-25T12:04:11.577Z] 12:04:11     INFO -  CPU: amd64
[task 2023-01-25T12:04:11.578Z] 12:04:11     INFO -       family 6 model 85 stepping 7
[task 2023-01-25T12:04:11.578Z] 12:04:11     INFO -       8 CPUs
[task 2023-01-25T12:04:11.578Z] 12:04:11     INFO -  Crash reason:  EXCEPTION_BREAKPOINT
[task 2023-01-25T12:04:11.578Z] 12:04:11     INFO -  Crash address: 0x7fff4fa7395c
[task 2023-01-25T12:04:11.579Z] 12:04:11     INFO -  Crashing instruction: `int 0x3`
[task 2023-01-25T12:04:11.580Z] 12:04:11     INFO -  No memory accessed by instruction
[task 2023-01-25T12:04:11.580Z] 12:04:11     INFO -  Process uptime: 64 seconds
[task 2023-01-25T12:04:11.580Z] 12:04:11     INFO -  Thread 0 MainThread (crashed)
[task 2023-01-25T12:04:11.580Z] 12:04:11     INFO -   0  xul.dll!NS_DebugBreak(unsigned int, char const*, char const*, char const*, int) [nsDebugImpl.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 496 + 0x28]
[task 2023-01-25T12:04:11.580Z] 12:04:11     INFO -       rax = 0x00007fff80099e08    rdx = 0x0000000010482040
[task 2023-01-25T12:04:11.580Z] 12:04:11     INFO -       rcx = 0x00007fff550fc878    rbx = 0x0000000000000001
[task 2023-01-25T12:04:11.580Z] 12:04:11     INFO -       rsi = 0x000000240adfced8    rdi = 0x000000240adfc7f0
[task 2023-01-25T12:04:11.580Z] 12:04:11     INFO -       rbp = 0x0000000000000002    rsp = 0x000000240adfc630
[task 2023-01-25T12:04:11.581Z] 12:04:11     INFO -        r8 = 0x0000000000000100     r9 = 0xe5e5e5e5e5e5e5e5
[task 2023-01-25T12:04:11.581Z] 12:04:11     INFO -       r10 = 0x00007fff78290000    r11 = 0x0000019ccbec9e00
[task 2023-01-25T12:04:11.581Z] 12:04:11     INFO -       r12 = 0x0000000000000000    r13 = 0x0000019ccc1ae700
[task 2023-01-25T12:04:11.581Z] 12:04:11     INFO -       r14 = 0x000000240adfcb00    r15 = 0x0000000000000000
[task 2023-01-25T12:04:11.581Z] 12:04:11     INFO -       rip = 0x00007fff4fa7395c
[task 2023-01-25T12:04:11.581Z] 12:04:11     INFO -      Found by: given as instruction pointer in context
[task 2023-01-25T12:04:11.582Z] 12:04:11     INFO -   1  xul.dll!nsDebugImpl::Abort(char const*, int) [nsDebugImpl.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 129 + 0x13]
[task 2023-01-25T12:04:11.582Z] 12:04:11     INFO -       rbx = 0x00007fff549b6f03    rsi = 0x0000000000000002
[task 2023-01-25T12:04:11.582Z] 12:04:11     INFO -       rdi = 0x000000240adfd0f0    rbp = 0x000000240adfd010
[task 2023-01-25T12:04:11.582Z] 12:04:11     INFO -       rsp = 0x000000240adfcfa0    r12 = 0x00007fff549b5640
[task 2023-01-25T12:04:11.583Z] 12:04:11     INFO -       r13 = 0x0000000000000001    r14 = 0x0000000000000002
[task 2023-01-25T12:04:11.583Z] 12:04:11     INFO -       r15 = 0x00007fff549c01a8    rip = 0x00007fff4fa73a2b
[task 2023-01-25T12:04:11.583Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.583Z] 12:04:11     INFO -   2  xul.dll!XPTC__InvokebyIndex + 0x71
[task 2023-01-25T12:04:11.583Z] 12:04:11     INFO -       rbx = 0x00007fff549b6f03    rbp = 0x000000240adfd010
[task 2023-01-25T12:04:11.584Z] 12:04:11     INFO -       rsp = 0x000000240adfcfd0    r12 = 0x00007fff549b5640
[task 2023-01-25T12:04:11.584Z] 12:04:11     INFO -       r13 = 0x0000000000000001    r14 = 0x0000000000000002
[task 2023-01-25T12:04:11.585Z] 12:04:11     INFO -       r15 = 0x00007fff549c01a8    rip = 0x00007fff513191c2
[task 2023-01-25T12:04:11.585Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.585Z] 12:04:11     INFO -   3  xul.dll!NS_InvokeByIndex(nsISupports*, unsigned int, unsigned int, nsXPTCVariant*) [xptcinvoke_x86_64.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 57]
[task 2023-01-25T12:04:11.585Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.586Z] 12:04:11     INFO -   4  xul.dll!CallMethodHelper::Invoke() [XPCWrappedNative.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 1626]
[task 2023-01-25T12:04:11.586Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.586Z] 12:04:11     INFO -   5  xul.dll!CallMethodHelper::Call() [XPCWrappedNative.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 1179]
[task 2023-01-25T12:04:11.586Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.587Z] 12:04:11     INFO -   6  xul.dll!XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode) [XPCWrappedNative.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 1125 + 0x52e]
[task 2023-01-25T12:04:11.587Z] 12:04:11     INFO -       rbx = 0x00007fff549b6f03    rbp = 0x000000240adfd110
[task 2023-01-25T12:04:11.587Z] 12:04:11     INFO -       rsp = 0x000000240adfd020    r12 = 0x00007fff549b5640
[task 2023-01-25T12:04:11.587Z] 12:04:11     INFO -       r13 = 0x0000000000000001    r14 = 0x0000000000000002
[task 2023-01-25T12:04:11.588Z] 12:04:11     INFO -       r15 = 0x00007fff549c01a8    rip = 0x00007fff50d86b89
[task 2023-01-25T12:04:11.588Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.588Z] 12:04:11     INFO -   7  xul.dll!XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) [XPCWrappedNativeJSOps.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 965 + 0x9]
[task 2023-01-25T12:04:11.589Z] 12:04:11     INFO -       rbx = 0x0000019ccb7ccb70    rsi = 0x0000000000000000
[task 2023-01-25T12:04:11.589Z] 12:04:11     INFO -       rdi = 0x0000019ccb7ccae0    rbp = 0x000039afc4f9d970
[task 2023-01-25T12:04:11.589Z] 12:04:11     INFO -       rsp = 0x000000240adfd270    r12 = 0x000000240adfd358
[task 2023-01-25T12:04:11.589Z] 12:04:11     INFO -       r13 = 0x0000019cc6f880c8    r14 = 0x00007fff54abdd70
[task 2023-01-25T12:04:11.589Z] 12:04:11     INFO -       r15 = 0x0000000000000002    rip = 0x00007fff50d88a3c
[task 2023-01-25T12:04:11.590Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.592Z] 12:04:11     INFO -   8  xul.dll!CallJSNative(JSContext*, bool (*)(JSContext*, unsigned int, JS::Value*), js::CallReason, JS::CallArgs const&) [Interpreter.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 459]
[task 2023-01-25T12:04:11.592Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.592Z] 12:04:11     INFO -   9  xul.dll!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [Interpreter.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 547]
[task 2023-01-25T12:04:11.592Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.592Z] 12:04:11     INFO -  10  xul.dll!InternalCall(JSContext*, js::AnyInvokeArgs const&, js::CallReason) [Interpreter.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 614]
[task 2023-01-25T12:04:11.592Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.592Z] 12:04:11     INFO -  11  xul.dll!js::CallFromStack(JSContext*, JS::CallArgs const&, js::CallReason) [Interpreter.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 619]
[task 2023-01-25T12:04:11.592Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.592Z] 12:04:11     INFO -  12  xul.dll!Interpret(JSContext*, js::RunState&) [Interpreter.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 3362 + 0x189]
[task 2023-01-25T12:04:11.592Z] 12:04:11     INFO -       rbx = 0x00007fff50d88840    rsi = 0x0000019cc51a2800
[task 2023-01-25T12:04:11.593Z] 12:04:11     INFO -       rdi = 0xfffc800000000000    rbp = 0xfffdffffffffffff
[task 2023-01-25T12:04:11.593Z] 12:04:11     INFO -       rsp = 0x000000240adfd3d0    r12 = 0x000000000adfd4f6
[task 2023-01-25T12:04:11.593Z] 12:04:11     INFO -       r13 = 0x0000000000000002    r14 = 0x000000240adfd574
[task 2023-01-25T12:04:11.593Z] 12:04:11     INFO -       r15 = 0x0000000000000000    rip = 0x00007fff5114deef
[task 2023-01-25T12:04:11.593Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.594Z] 12:04:11     INFO -  13  xul.dll!js::RunScript(JSContext*, js::RunState&) [Interpreter.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 431]
[task 2023-01-25T12:04:11.594Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.594Z] 12:04:11     INFO -  14  xul.dll!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [Interpreter.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 579]
[task 2023-01-25T12:04:11.594Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.595Z] 12:04:11     INFO -  15  xul.dll!InternalCall(JSContext*, js::AnyInvokeArgs const&, js::CallReason) [Interpreter.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 614]
[task 2023-01-25T12:04:11.595Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.596Z] 12:04:11     INFO -  16  xul.dll!js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) [Interpreter.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 646 + 0xaf]
[task 2023-01-25T12:04:11.596Z] 12:04:11     INFO -       rbx = 0x0000000000000001    rsi = 0x00000bc735fbdbf0
[task 2023-01-25T12:04:11.596Z] 12:04:11     INFO -       rdi = 0x0000000000000008    rbp = 0x0000000000000000
[task 2023-01-25T12:04:11.597Z] 12:04:11     INFO -       rsp = 0x000000240adfd890    r12 = 0x0000000000000000
[task 2023-01-25T12:04:11.597Z] 12:04:11     INFO -       r13 = 0x0000019cc5128400    r14 = 0x0000019cc51a2800
[task 2023-01-25T12:04:11.597Z] 12:04:11     INFO -       r15 = 0x0000000000000000    rip = 0x00007fff50b341fb
[task 2023-01-25T12:04:11.598Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.598Z] 12:04:11     INFO -  17  xul.dll!js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::MutableHandle<JS::Value>) [Interpreter.h:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 116]
[task 2023-01-25T12:04:11.598Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.598Z] 12:04:11     INFO -  18  xul.dll!PromiseReactionJob(JSContext*, unsigned int, JS::Value*) [Promise.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 2240 + 0x77]
[task 2023-01-25T12:04:11.598Z] 12:04:11     INFO -       rbx = 0x0000019cc5128400    rsi = 0x000000240adfdac0
[task 2023-01-25T12:04:11.599Z] 12:04:11     INFO -       rdi = 0x000000240adfdaf8    rbp = 0x000000240adfda70
[task 2023-01-25T12:04:11.599Z] 12:04:11     INFO -       rsp = 0x000000240adfd9c0    r12 = 0x0000019cc51a2800
[task 2023-01-25T12:04:11.599Z] 12:04:11     INFO -       r13 = 0xfff9800000000000    r14 = 0xfffe000000000000
[task 2023-01-25T12:04:11.600Z] 12:04:11     INFO -       r15 = 0x000000240adfda88    rip = 0x00007fff50feb188
[task 2023-01-25T12:04:11.600Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.600Z] 12:04:11     INFO -  19  xul.dll!CallJSNative(JSContext*, bool (*)(JSContext*, unsigned int, JS::Value*), js::CallReason, JS::CallArgs const&) [Interpreter.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 459]
[task 2023-01-25T12:04:11.600Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.601Z] 12:04:11     INFO -  20  xul.dll!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [Interpreter.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 547]
[task 2023-01-25T12:04:11.601Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.601Z] 12:04:11     INFO -  21  xul.dll!InternalCall(JSContext*, js::AnyInvokeArgs const&, js::CallReason) [Interpreter.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 614]
[task 2023-01-25T12:04:11.601Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.602Z] 12:04:11     INFO -  22  xul.dll!js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) [Interpreter.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 646 + 0x201]
[task 2023-01-25T12:04:11.602Z] 12:04:11     INFO -       rbx = 0xfffb000000000000    rsi = 0xffff800000000000
[task 2023-01-25T12:04:11.602Z] 12:04:11     INFO -       rdi = 0xfffc800000000000    rbp = 0x000000240adfdcd8
[task 2023-01-25T12:04:11.602Z] 12:04:11     INFO -       rsp = 0x000000240adfdb50    r12 = 0x0000019cc51a2800
[task 2023-01-25T12:04:11.603Z] 12:04:11     INFO -       r13 = 0x0000019cc5128400    r14 = 0xfffdffffffffffff
[task 2023-01-25T12:04:11.603Z] 12:04:11     INFO -       r15 = 0xfffe000000000000    rip = 0x00007fff50b33ca2
[task 2023-01-25T12:04:11.603Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.605Z] 12:04:11     INFO -  23  xul.dll!JS::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::HandleValueArray const&, JS::MutableHandle<JS::Value>) [CallAndConstruct.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 117 + 0x1f]
[task 2023-01-25T12:04:11.606Z] 12:04:11     INFO -       rbx = 0xfffa800000000000    rsi = 0x0000019cc5128400
[task 2023-01-25T12:04:11.606Z] 12:04:11     INFO -       rdi = 0xfff9800000000000    rbp = 0x0000000000000000
[task 2023-01-25T12:04:11.606Z] 12:04:11     INFO -       rsp = 0x000000240adfdc80    r12 = 0x000000240adfde00
[task 2023-01-25T12:04:11.606Z] 12:04:11     INFO -       r13 = 0x000000240adfdd20    r14 = 0x0000000000000000
[task 2023-01-25T12:04:11.607Z] 12:04:11     INFO -       r15 = 0xfff9800000000000    rip = 0x00007fff50be463f
[task 2023-01-25T12:04:11.607Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.607Z] 12:04:11     INFO -  24  xul.dll!mozilla::dom::PromiseJobCallback::Call(mozilla::dom::BindingCallContext&, JS::Handle<JS::Value>, mozilla::ErrorResult&) [PromiseBinding.cpp: : 83]
[task 2023-01-25T12:04:11.607Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.608Z] 12:04:11     INFO -  25  xul.dll!mozilla::dom::PromiseJobCallback::Call(mozilla::ErrorResult&, char const*, mozilla::dom::CallbackObject::ExceptionHandling, JS::Realm*) [PromiseBinding.h: : 198]
[task 2023-01-25T12:04:11.608Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.608Z] 12:04:11     INFO -  26  xul.dll!mozilla::dom::PromiseJobCallback::Call(char const*) [PromiseBinding.h: : 211]
[task 2023-01-25T12:04:11.608Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.609Z] 12:04:11     INFO -  27  xul.dll!mozilla::PromiseJobRunnable::Run(mozilla::AutoSlowOperation&) [CycleCollectedJSContext.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 213 + 0x163]
[task 2023-01-25T12:04:11.609Z] 12:04:11     INFO -       rbx = 0x000000240adfde48    rsi = 0x0000000000000000
[task 2023-01-25T12:04:11.609Z] 12:04:11     INFO -       rdi = 0x0000019cc9170b40    rbp = 0x0000000000000000
[task 2023-01-25T12:04:11.609Z] 12:04:11     INFO -       rsp = 0x000000240adfddb0    r12 = 0x00007fff514c0000
[task 2023-01-25T12:04:11.610Z] 12:04:11     INFO -       r13 = 0x0000019cccd0c740    r14 = 0x000000240adfe0c8
[task 2023-01-25T12:04:11.610Z] 12:04:11     INFO -       r15 = 0x0000000000000000    rip = 0x00007fff50d297a6
[task 2023-01-25T12:04:11.610Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.611Z] 12:04:11     INFO -  28  xul.dll!mozilla::CycleCollectedJSContext::PerformMicroTaskCheckPoint(bool) [CycleCollectedJSContext.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 676 + 0x20]
[task 2023-01-25T12:04:11.611Z] 12:04:11     INFO -       rbx = 0x0000019cccd0c740    rsi = 0x0000000000000000
[task 2023-01-25T12:04:11.611Z] 12:04:11     INFO -       rdi = 0x0000019cccd0c740    rbp = 0x0000000000000000
[task 2023-01-25T12:04:11.611Z] 12:04:11     INFO -       rsp = 0x000000240adfe080    r12 = 0x00007fff514c0010
[task 2023-01-25T12:04:11.612Z] 12:04:11     INFO -       r13 = 0x0000019cc5b45000    r14 = 0x7fffffffffffffff
[task 2023-01-25T12:04:11.612Z] 12:04:11     INFO -       r15 = 0x000000240adfe0c8    rip = 0x00007fff50b2a53e
[task 2023-01-25T12:04:11.612Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.612Z] 12:04:11     INFO -  29  xul.dll!mozilla::CycleCollectedJSContext::AfterProcessTask(unsigned int) [CycleCollectedJSContext.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 463]
[task 2023-01-25T12:04:11.613Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.613Z] 12:04:11     INFO -  30  xul.dll!XPCJSContext::AfterProcessTask(unsigned int) [XPCJSContext.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 1480]
[task 2023-01-25T12:04:11.613Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.614Z] 12:04:11     INFO -  31  xul.dll!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 1234 + 0x17d]
[task 2023-01-25T12:04:11.614Z] 12:04:11     INFO -       rbx = 0x0000000000000000    rsi = 0x0000019cb8c49d00
[task 2023-01-25T12:04:11.614Z] 12:04:11     INFO -       rdi = 0x0000000000000000    rbp = 0x00007fff7bdf7201
[task 2023-01-25T12:04:11.614Z] 12:04:11     INFO -       rsp = 0x000000240adfe180    r12 = 0x0000000000007908
[task 2023-01-25T12:04:11.615Z] 12:04:11     INFO -       r13 = 0x0000019cc5b45000    r14 = 0x0000019cb8c6b6f0
[task 2023-01-25T12:04:11.615Z] 12:04:11     INFO -       r15 = 0x7fffffffffffffff    rip = 0x00007fff50a6a237
[task 2023-01-25T12:04:11.615Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.615Z] 12:04:11     INFO -  32  xul.dll!XPTC__InvokebyIndex + 0x71
[task 2023-01-25T12:04:11.615Z] 12:04:11     INFO -       rbx = 0x00007fff549b574e    rsi = 0x0000000000000002
[task 2023-01-25T12:04:11.615Z] 12:04:11     INFO -       rdi = 0x000000240adfe640    rbp = 0x000000240adfe560
[task 2023-01-25T12:04:11.616Z] 12:04:11     INFO -       rsp = 0x000000240adfe520    r12 = 0x00007fff549b5640
[task 2023-01-25T12:04:11.616Z] 12:04:11     INFO -       r13 = 0x0000000000000001    r14 = 0x0000000000000002
[task 2023-01-25T12:04:11.616Z] 12:04:11     INFO -       r15 = 0x00007fff549b9860    rip = 0x00007fff513191c2
[task 2023-01-25T12:04:11.617Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.617Z] 12:04:11     INFO -  33  xul.dll!NS_InvokeByIndex(nsISupports*, unsigned int, unsigned int, nsXPTCVariant*) [xptcinvoke_x86_64.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 57]
[task 2023-01-25T12:04:11.617Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.617Z] 12:04:11     INFO -  34  xul.dll!CallMethodHelper::Invoke() [XPCWrappedNative.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 1626]
[task 2023-01-25T12:04:11.618Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.618Z] 12:04:11     INFO -  35  xul.dll!CallMethodHelper::Call() [XPCWrappedNative.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 1179]
[task 2023-01-25T12:04:11.618Z] 12:04:11     INFO -      Found by: inlining
[task 2023-01-25T12:04:11.618Z] 12:04:11     INFO -  36  xul.dll!XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode) [XPCWrappedNative.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 1125 + 0x52e]
[task 2023-01-25T12:04:11.619Z] 12:04:11     INFO -       rbx = 0x00007fff549b574e    rbp = 0x0000000000000001
[task 2023-01-25T12:04:11.619Z] 12:04:11     INFO -       rsp = 0x000000240adfe570    r12 = 0x00007fff549b5640
[task 2023-01-25T12:04:11.619Z] 12:04:11     INFO -       r13 = 0x0000000000000001    r14 = 0x0000000000000002
[task 2023-01-25T12:04:11.619Z] 12:04:11     INFO -       r15 = 0x00007fff549b9860    rip = 0x00007fff50d86b89
[task 2023-01-25T12:04:11.620Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.620Z] 12:04:11     INFO -  37  xul.dll!XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) [XPCWrappedNativeJSOps.cpp:2ac913a38e4cd0c49ceabd0bbd21dd862908f3fb : 965 + 0x9]
[task 2023-01-25T12:04:11.620Z] 12:04:11     INFO -       rbx = 0x0000019ccaa33080    rsi = 0x0000000000000000
[task 2023-01-25T12:04:11.621Z] 12:04:11     INFO -       rdi = 0x0000019ccaa33000    rbp = 0x000028f7fb1f0c40
[task 2023-01-25T12:04:11.621Z] 12:04:11     INFO -       rsp = 0x000000240adfe7c0    r12 = 0x000000240adfe8a8
[task 2023-01-25T12:04:11.621Z] 12:04:11     INFO -       r13 = 0x000000240adfe990    r14 = 0x00007fff54abe1c8
[task 2023-01-25T12:04:11.621Z] 12:04:11     INFO -       r15 = 0x0000000000000001    rip = 0x00007fff50d88a3c
[task 2023-01-25T12:04:11.621Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.622Z] 12:04:11     INFO -  38  0x37ed376285b
[task 2023-01-25T12:04:11.622Z] 12:04:11     INFO -       rbx = 0x000000240adfe980    rsi = 0x0000037ed38667d2
[task 2023-01-25T12:04:11.622Z] 12:04:11     INFO -       rdi = 0x0000019cc5510020    rbp = 0x000000240adfe9a0
[task 2023-01-25T12:04:11.623Z] 12:04:11     INFO -       rsp = 0x000000240adfe920    r12 = 0x0000000000000008
[task 2023-01-25T12:04:11.624Z] 12:04:11     INFO -       r13 = 0x000000240adfef68    r14 = 0x000000240adfec88
[task 2023-01-25T12:04:11.624Z] 12:04:11     INFO -       r15 = 0x0000019cc5128d48    rip = 0x0000037ed376285c
[task 2023-01-25T12:04:11.625Z] 12:04:11     INFO -      Found by: call frame info
[task 2023-01-25T12:04:11.625Z] 12:04:11     INFO -  Thread 1 BrokerEvent

Comment 1

[Andrew McCreight [:mccr8]]

This is some kind of service worker shutdown hang. It doesn't need to be hidden.

Comment 2

[Norisz Fay [:noriszfay]]

This might be a failure similar to this bug. Failure log

Comment 3

[Iulian Moraru]

Hi Jens! Can you please take a look at this? I think this might be something regressed by the recent changes from Bug 1811195.

Backfill range and retriggers.

Please also take a look at Bug 1812492, they seem to have the same issue. Bug 1812492 has this failure line that shows up in treeherder: TEST-UNEXPECTED-ERROR | toolkit/components/cleardata/tests/marionette/test_service_worker_at_shutdown.py ServiceWorkerAtShutdownTestCase.test_unregistering_service_worker_when_clearing_data | marionette_driver.errors.InvalidSessionIdException: Please start a session and a similar line is found in the failure log for this bug here.
Thank you!

Comment 4

[Intermittent Failures Robot]

7 failures in 3914 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2
• autoland: 5

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 3
  • opt: 3
• windows10-64-2004-qr: 2
  • opt: 2
• windows10-32-2004-qr: 2
  • opt: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1812318&startday=2023-01-23&endday=2023-01-29&tree=all

Comment 5

[Jens Stutte [:jstutte]]

[task 2023-01-27T22:35:29.437Z] 22:35:29     INFO -  FATAL ERROR: AsyncShutdown timeout in profile-change-teardown Conditions: [{"name":"ServiceWorkerShutdownBlocker: shutting down Service Workers","state":{"shutdownStates":"parent process main thread, ","pendingPromises":1,"acceptingPromises":false},"filename":"/builds/worker/checkouts/gecko/dom/serviceworkers/ServiceWorkerShutdownBlocker.cpp","lineNumber":110,"stack":"Service Workers shutdown"}] At least one completion condition failed to complete within a reasonable amount of time. Causing a crash to ensure that we do not leave the user with an unresponsive process draining resources.
[task 2023-01-27T22:35:29.439Z] 22:35:29     INFO -  [Parent 876, Main Thread] ###!!! ABORT: file /builds/worker/checkouts/gecko/dom/serviceworkers/ServiceWorkerShutdownBlocker.cpp:110
[task 2023-01-27T22:35:29.661Z] 22:35:29     INFO -  [GPU 6872, IPC I/O Child] WARNING: [FECCE9FF70560480.D68BC888F3F2C5D8]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-01-27T22:35:29.661Z] 22:35:29     INFO -  [GPU 6872, IPC I/O Child] WARNING: [FECCE9FF70560480.D68BC888F3F2C5D8]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-01-27T22:35:29.661Z] 22:35:29     INFO -  [GPU 6872, Main Thread] WARNING: Shutting down GPU process early due to a crash!: file /builds/worker/checkouts/gecko/gfx/ipc/GPUParent.cpp:662
[task 2023-01-27T22:35:29.669Z] 22:35:29     INFO -  [GPU 6872, IPC I/O Child] WARNING: [FECCE9FF70560480.D68BC888F3F2C5D8]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-01-27T22:35:29.670Z] 22:35:29     INFO -  [Child 5996, IPC I/O Child] WARNING: [5E03CF3BA0470F62.BDA94338379BADDB]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:352
[task 2023-01-27T22:35:29.670Z] 22:35:29     INFO -  Exiting due to channel error.
[task 2023-01-27T22:37:38.836Z] 22:37:38     INFO -  mozcrash Copy/paste: Z:/task_167485230236788/fetches\minidump-stackwalk\minidump-stackwalk.exe --symbols-url=https://symbols.mozilla.org/ --cyborg=C:\Users\task_167485230236788\AppData\Local\Temp\tmpv5lvd6l9\420f08dc-db46-4196-b55f-ac64931f8559.trace C:\Users\task_167485230236788\AppData\Local\Temp\tmputhvrf1j.mozrunner\minidumps\420f08dc-db46-4196-b55f-ac64931f8559.dmp Z:\task_167485230236788\build\symbols
[task 2023-01-27T22:37:49.889Z] 22:37:49     INFO -  mozcrash Saved minidump as Z:\task_167485230236788\build\blobber_upload_dir\420f08dc-db46-4196-b55f-ac64931f8559.dmp
[task 2023-01-27T22:37:49.903Z] 22:37:49     INFO -  mozcrash Saved app info as Z:\task_167485230236788\build\blobber_upload_dir\420f08dc-db46-4196-b55f-ac64931f8559.extra
[task 2023-01-27T22:37:49.914Z] 22:37:49    ERROR -  PROCESS-CRASH | toolkit/components/cleardata/tests/marionette/test_service_worker_at_shutdown.py ServiceWorkerAtShutdownTestCase.test_unregistering_service_worker_when_clearing_data | application crashed [@ void __stdcall wil::details::DebugBreak]
[task 2023-01-27T22:37:49.919Z] 22:37:49     INFO -  Crash dump filename: C:\Users\task_167485230236788\AppData\Local\Temp\tmputhvrf1j.mozrunner\minidumps\420f08dc-db46-4196-b55f-ac64931f8559.dmp

There is a delay of ~2min between the message from the async shutdown blocker and the effective crash. And the stack is not very helpful, there might be some relation to bug 1442971, though the stack looks quite different (there the shutdown terminator asks us to crash and then we fail something while handling the crash while here we just crash directly).

Comment 6

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1812318&startday=2023-01-30&endday=2023-02-05&tree=all

Comment 7

[Jens Stutte [:jstutte]]

Seems quiet for a while now.