Closed Bug 1535221 Opened 6 years ago Closed 6 years ago

Dead lock with a11y's mscom and mozilla::dom::LSObject

Categories

(Core :: Storage: localStorage & sessionStorage, defect, P1)

Product:
Core
Component:
Storage: localStorage & sessionStorage
Platform:
Unspecified
Windows
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla68
Tracking Flags:
Tracking Status
firefox67 --- wontfix
firefox68 --- fixed

People

(Reporter: m_kato, Assigned: janv)

References

(Blocks 1 open bug)

Details

Attachments

(3 files)

Bug 1535221 - Add infrastructure for hang debugging; r=asuth
47 bytes, text/x-phabricator-request
Details | Review
Bug 1535221 - Add more robust logging including more detailed logging for CheckClosingDatastore and DirectoryOpenPending state; r=asuth
47 bytes, text/x-phabricator-request
Details | Review
Bug 1535221 - Dead lock with a11y's mscom and mozilla::dom::LSObject; r=asuth
47 bytes, text/x-phabricator-request
Details | Review

When using Firefox 67 (build ID: 20190312214352), I hit the following deak lock. But I don't know how to reproduce this and regression range. I guess that one reason may be mozilla::dom::LSObject uses event loop

chrome process

0:086> ~0k
Child-SP          RetAddr           Call Site
000000c9`15ff8ac8 00007ff9`f2d0e4e2 win32u!NtUserPeekMessage+0x14
000000c9`15ff8ad0 00007ff9`f2d0e3be user32!_PeekMessage+0x42
000000c9`15ff8b40 00007ff9`f278d1aa user32!PeekMessageW+0x9e
000000c9`15ff8bb0 00007ff9`f278d11d combase!CCliModalLoop::MyPeekMessage+0x52
000000c9`15ff8c20 00007ff9`f278d55a combase!CCliModalLoop::PeekRPCAndDDEMessage+0x49
000000c9`15ff8c90 00007ff9`f278bf51 combase!CCliModalLoop::FindMessage+0x42
000000c9`15ff8d00 00007ff9`f278caf1 combase!CCliModalLoop::HandleWakeForMsg+0x51
000000c9`15ff8da0 00007ff9`f278c801 combase!CCliModalLoop::BlockFn+0x2ad
000000c9`15ff8e20 00007ff9`f277d913 combase!ModalLoop+0xb5
000000c9`15ff8e90 00007ff9`f277d088 combase!ThreadSendReceive+0x2a3
(Inline Function) --------`-------- combase!CSyncClientCall::SwitchAptAndDispatchCall+0x96
000000c9`15ff9480 00007ff9`f278c5a8 combase!CSyncClientCall::SendReceive2+0x178
(Inline Function) --------`-------- combase!SyncClientCallRetryContext::SendReceiveWithRetry+0x25
(Inline Function) --------`-------- combase!CSyncClientCall::SendReceiveInRetryContext+0x25
000000c9`15ff9670 00007ff9`f277c55d combase!ClassicSTAThreadSendReceive+0xa8
000000c9`15ff97a0 00007ff9`f2750a54 combase!CSyncClientCall::SendReceive+0x12d
000000c9`15ff99d0 00007ff9`f27ac54e combase!CClientChannel::SendReceive+0x84
000000c9`15ff9a40 00007ff9`f23ca009 combase!NdrExtpProxySendReceive+0x4e
000000c9`15ff9a70 00007ff9`f27aad7b RPCRT4!NdrpClientCall3+0x8e9
000000c9`15ff9e20 00007ff9`f281ce92 combase!ObjectStublessClient+0x13b
000000c9`15ffa1b0 00007ff9`f27b2471 combase!ObjectStubless+0x42
000000c9`15ffa200 00007ff9`f27235b6 combase!CStdMarshal::Begin_RemQIAndUnmarshal2+0x111
(Inline Function) --------`-------- combase!CStdMarshal::Begin_RemQIAndUnmarshal+0x1ef
(Inline Function) --------`-------- combase!CStdMarshal::Begin_QueryRemoteInterfaces+0x266
000000c9`15ffa2d0 00007ff9`f275945b combase!CStdMarshal::QueryRemoteInterfaces+0x30e
(Inline Function) --------`-------- combase!CStdIdentity::CInternalUnk::QueryMultipleInterfaces+0x145
000000c9`15ffa410 00007ff9`f27bd8f0 combase!CStdIdentity::CInternalUnk::QueryInterface+0x18b
000000c9`15ffa4d0 00007ff9`f274a967 combase!CAggId::QueryInterface+0x40
(Inline Function) --------`-------- combase!ShouldMarshalByValue+0x1f1
000000c9`15ffa500 00007ff9`f274a6d0 combase!CDestObjectWrapper::GetMarshalSizeMaxEx+0x24f
000000c9`15ffa620 00007ff9`f274aa05 combase!CoGetMarshalSizeMaxEx+0x11c
000000c9`15ffa6c0 00007ff9`f27dcd71 combase!CoGetMarshalSizeMax+0x35
000000c9`15ffa710 00007ff9`f3045a24 combase!WdtpInterfacePointer_UserSize+0x41
000000c9`15ffa750 00007ff9`f233900d OLEAUT32!VARIANT_UserSize+0x19344
000000c9`15ffa790 00007ff9`f2304538 RPCRT4!NdrUserMarshalBufferSize+0x11d
000000c9`15ffa810 00007ff9`f23453f3 RPCRT4!NdrStubCall2+0x5f8
000000c9`15ffae40 00007ff9`f27ac473 RPCRT4!NdrStubCall3+0xe3
000000c9`15ffaea0 00007ff9`f234978b combase!CStdStubBuffer_Invoke+0x73
000000c9`15ffaee0 00007ff9`f271f203 RPCRT4!CStdStubBuffer_Invoke+0x3b
(Inline Function) --------`-------- combase!InvokeStubWithExceptionPolicyAndTracing::__l6::<lambda_76d9e92c799d246a4afbe64a2bf5673d>::operator()+0x18
000000c9`15ffaf10 00007ff9`f271eff4 combase!ObjectMethodExceptionHandlingAction<<lambda_76d9e92c799d246a4afbe64a2bf5673d> >+0x43
(Inline Function) --------`-------- combase!InvokeStubWithExceptionPolicyAndTracing+0xa8
000000c9`15ffaf70 00007ff9`f27b2df6 combase!DefaultStubInvoke+0x1c4
(Inline Function) --------`-------- combase!SyncStubCall::Invoke+0x22
000000c9`15ffb0c0 00007ff9`f2752e55 combase!SyncServerCall::StubInvoke+0x26
(Inline Function) --------`-------- combase!StubInvoke+0x265
000000c9`15ffb100 00007ff9`f277ded2 combase!ServerCall::ContextInvoke+0x435
(Inline Function) --------`-------- combase!CServerChannel::ContextInvoke+0x79
(Inline Function) --------`-------- combase!DefaultInvokeInApartment+0x92
000000c9`15ffb510 00007ff9`f27647a0 combase!ReentrantSTAInvokeInApartment+0x1a2
000000c9`15ffb590 00007ff9`f2764064 combase!AppInvoke+0x200
000000c9`15ffb620 00007ff9`f274fb41 combase!ComInvokeWithLockAndIPID+0xd14
(Inline Function) --------`-------- combase!ComInvoke+0x1a6
(Inline Function) --------`-------- combase!ThreadDispatch+0x21e
000000c9`15ffb8f0 00007ff9`f2d0ca66 combase!ThreadWndProc+0x3c1
000000c9`15ffba20 00007ff9`f2d0c582 user32!UserCallWinProcCheckWow+0x266
000000c9`15ffbba0 00007ff9`f278d149 user32!DispatchMessageWorker+0x1b2
(Inline Function) --------`-------- combase!CCliModalLoop::MyDispatchMessage+0xb
000000c9`15ffbc20 00007ff9`f278d55a combase!CCliModalLoop::PeekRPCAndDDEMessage+0x75
000000c9`15ffbc90 00007ff9`f278bf51 combase!CCliModalLoop::FindMessage+0x42
000000c9`15ffbd00 00007ff9`f278caf1 combase!CCliModalLoop::HandleWakeForMsg+0x51
000000c9`15ffbda0 00007ff9`f278c801 combase!CCliModalLoop::BlockFn+0x2ad
000000c9`15ffbe20 00007ff9`f277d913 combase!ModalLoop+0xb5
000000c9`15ffbe90 00007ff9`f277d088 combase!ThreadSendReceive+0x2a3
(Inline Function) --------`-------- combase!CSyncClientCall::SwitchAptAndDispatchCall+0x96
000000c9`15ffc480 00007ff9`f278c5a8 combase!CSyncClientCall::SendReceive2+0x178
(Inline Function) --------`-------- combase!SyncClientCallRetryContext::SendReceiveWithRetry+0x25
(Inline Function) --------`-------- combase!CSyncClientCall::SendReceiveInRetryContext+0x25
000000c9`15ffc670 00007ff9`f277c55d combase!ClassicSTAThreadSendReceive+0xa8
000000c9`15ffc7a0 00007ff9`f2750a54 combase!CSyncClientCall::SendReceive+0x12d
000000c9`15ffc9d0 00007ff9`f27ac54e combase!CClientChannel::SendReceive+0x84
000000c9`15ffca40 00007ff9`f23ca009 combase!NdrExtpProxySendReceive+0x4e
000000c9`15ffca70 00007ff9`f27aad7b RPCRT4!NdrpClientCall3+0x8e9
000000c9`15ffce20 00007ff9`f281ce92 combase!ObjectStublessClient+0x13b
000000c9`15ffd1b0 00007ff9`d00e220b combase!ObjectStubless+0x42
000000c9`15ffd200 00007ff9`afaaa956 AccessibleHandler!mozilla::a11y::AccessibleHandler::get_accChild+0x5b
000000c9`15ffd270 00007ff9`afaaa665 xul!GetProxiedAccessibleInSubtree+0x166
000000c9`15ffd310 00007ff9`afaa7dd4 xul!mozilla::a11y::AccessibleWrap::GetRemoteIAccessibleFor+0xd5
000000c9`15ffd390 00007ff9`afaa7cda xul!mozilla::a11y::AccessibleWrap::GetIAccessibleFor+0xb4
000000c9`15ffd410 00007ff9`afaa6963 xul!mozilla::a11y::AccessibleWrap::get_accChild+0x4a
000000c9`15ffd460 00007ff9`f2367803 xul!mozilla::a11y::LazyInstantiator::get_accChild+0x53
000000c9`15ffd4d0 00007ff9`f230436c RPCRT4!Invoke+0x73
000000c9`15ffd530 00007ff9`f23453f3 RPCRT4!NdrStubCall2+0x42c
000000c9`15ffdb60 00007ff9`f27ac473 RPCRT4!NdrStubCall3+0xe3
000000c9`15ffdbc0 00007ff9`f234978b combase!CStdStubBuffer_Invoke+0x73
000000c9`15ffdc00 00007ff9`f271f203 RPCRT4!CStdStubBuffer_Invoke+0x3b
(Inline Function) --------`-------- combase!InvokeStubWithExceptionPolicyAndTracing::__l6::<lambda_76d9e92c799d246a4afbe64a2bf5673d>::operator()+0x18
000000c9`15ffdc30 00007ff9`f271eff4 combase!ObjectMethodExceptionHandlingAction<<lambda_76d9e92c799d246a4afbe64a2bf5673d> >+0x43
(Inline Function) --------`-------- combase!InvokeStubWithExceptionPolicyAndTracing+0xa8
000000c9`15ffdc90 00007ff9`f27b2df6 combase!DefaultStubInvoke+0x1c4
(Inline Function) --------`-------- combase!SyncStubCall::Invoke+0x22
000000c9`15ffdde0 00007ff9`f2752e55 combase!SyncServerCall::StubInvoke+0x26
(Inline Function) --------`-------- combase!StubInvoke+0x265
000000c9`15ffde20 00007ff9`f277ded2 combase!ServerCall::ContextInvoke+0x435
(Inline Function) --------`-------- combase!CServerChannel::ContextInvoke+0x79
(Inline Function) --------`-------- combase!DefaultInvokeInApartment+0x92
000000c9`15ffe230 00007ff9`f27647a0 combase!ReentrantSTAInvokeInApartment+0x1a2
000000c9`15ffe2b0 00007ff9`f2764064 combase!AppInvoke+0x200
000000c9`15ffe340 00007ff9`f274fb41 combase!ComInvokeWithLockAndIPID+0xd14
(Inline Function) --------`-------- combase!ComInvoke+0x1a6
(Inline Function) --------`-------- combase!ThreadDispatch+0x21e
000000c9`15ffe610 00007ff9`f2d0ca66 combase!ThreadWndProc+0x3c1
000000c9`15ffe740 00007ff9`f2d0c582 user32!UserCallWinProcCheckWow+0x266
000000c9`15ffe8c0 00007ff9`ab72c3fc user32!DispatchMessageWorker+0x1b2
000000c9`15ffe940 00007ff9`ab72be26 xul!nsAppShell::ProcessNextNativeEvent+0x43c
000000c9`15ffea00 00007ff9`ab54cbe8 xul!nsBaseAppShell::OnProcessNextEvent+0xb6
000000c9`15ffea80 00007ff9`ab54c9b9 xul!nsThread::ProcessNextEvent+0x168
000000c9`15ffefb0 00007ff9`ab72badb xul!NS_ProcessNextEvent+0x29
000000c9`15fff000 00007ff9`ab524e18 xul!mozilla::ipc::MessagePump::Run+0xfb
000000c9`15fff070 00007ff9`ab54c6b1 xul!MessageLoop::RunHandler+0x28
000000c9`15fff0c0 00007ff9`ab72b9b8 xul!MessageLoop::Run+0x51
000000c9`15fff110 00007ff9`ab72b293 xul!nsBaseAppShell::Run+0x28
000000c9`15fff150 00007ff9`ab72b242 xul!nsAppShell::Run+0x23
000000c9`15fff180 00007ff9`ab5a7955 xul!nsAppStartup::Run+0x22
000000c9`15fff1b0 00007ff9`ab503028 xul!XREMain::XRE_mainRun+0x625
000000c9`15fff3c0 00007ff9`ab502c13 xul!XREMain::XRE_main+0x2f8
000000c9`15fff470 00007ff6`b4551858 xul!XRE_main+0x43
000000c9`15fff5e0 00007ff6`b45513d6 firefox!do_main+0xc8
000000c9`15fff750 00007ff6`b4551113 firefox!NS_internal_main+0xa6
000000c9`15fff7d0 00007ff6`b4598588 firefox!wmain+0x113
000000c9`15fff830 00007ff9`f2eb81f4 firefox!__scrt_common_main_seh+0x10c
000000c9`15fff870 00007ff9`f4eea251 KERNEL32!BaseThreadInitThunk+0x14
000000c9`15fff8a0 00000000`00000000 ntdll!RtlUserThreadStart+0x21

content process

0:061> ~0k
Child-SP          RetAddr           Call Site
0000007c`96bfce80 00007ff9`f104eead ntdll!RtlSleepConditionVariableSRW+0xe4
0000007c`96bfcef0 00007ff9`ebc3f5c3 KERNELBASE!SleepConditionVariableSRW+0x2d
0000007c`96bfcf30 00007ff9`ab732749 mozglue!mozilla::detail::ConditionVariableImpl::wait+0x13
0000007c`96bfcf60 00007ff9`ab54d214 xul!mozilla::ThreadEventQueue<mozilla::PrioritizedEventQueue<mozilla::EventQueue> >::GetEvent+0x149
0000007c`96bfcff0 00007ff9`ab54c9b9 xul!nsThread::ProcessNextEvent+0x794
0000007c`96bfd520 00007ff9`aede3366 xul!NS_ProcessNextEvent+0x29
0000007c`96bfd570 00007ff9`aedd1f38 xul!mozilla::SpinEventLoopUntil<mozilla::ProcessFailureBehavior::ReportToCaller,`lambda at z:/task_1552427320/build/src/dom/localstorage/LSObject.cpp:1080:7'>+0x66
0000007c`96bfd5c0 00007ff9`aedd1c17 xul!mozilla::dom::`anonymous namespace'::RequestHelper::StartAndReturnResponse+0x1c8
0000007c`96bfd650 00007ff9`aedd1086 xul!mozilla::dom::LSObject::DoRequestSynchronously+0x57
0000007c`96bfd6a0 00007ff9`aedd13ed xul!mozilla::dom::LSObject::EnsureDatabase+0x1d6
0000007c`96bfd900 00007ff9`ae08b1e9 xul!mozilla::dom::LSObject::GetItem+0x3d
0000007c`96bfd960 00007ff9`ab5ca343 xul!mozilla::dom::Storage_Binding::getItem+0x109
0000007c`96bfdb20 00007ff9`abe76e9e xul!mozilla::dom::binding_detail::GenericMethod<mozilla::dom::binding_detail::NormalThisPolicy,mozilla::dom::binding_detail::ThrowExceptions>+0x103
0000007c`96bfdbe0 00007ff9`abe778bb xul!js::InternalCallOrConstruct+0x1de
0000007c`96bfdcc0 00007ff9`abe70a1a xul!InternalCall+0xbb
0000007c`96bfdd20 00007ff9`abe69220 xul!Interpret+0x732a
0000007c`96bfe0f0 00007ff9`abe78594 xul!js::RunScript+0x150
0000007c`96bfe170 00007ff9`abe7870e xul!js::ExecuteKernel+0xe4
0000007c`96bfe210 00007ff9`abf1a086 xul!js::Execute+0xbe
0000007c`96bfe290 00007ff9`aed5221c xul!ExecuteScript+0x106
0000007c`96bfe330 00007ff9`abc45754 xul!mozilla::dom::ExecuteCompiledScript+0x17c
0000007c`96bfe3b0 00007ff9`abc44b8a xul!mozilla::dom::ScriptLoader::EvaluateScript+0x754
0000007c`96bfe7a0 00007ff9`abc42c9e xul!mozilla::dom::ScriptLoader::ProcessRequest+0x40a
0000007c`96bfe860 00007ff9`abc40db6 xul!mozilla::dom::ScriptLoader::ProcessScriptElement+0x10ee
0000007c`96bfebd0 00007ff9`abc418d3 xul!mozilla::dom::ScriptElement::MaybeProcessScript+0x1d6
0000007c`96bfec50 00007ff9`abc2f211 xul!nsHtml5TreeOpExecutor::RunScript+0xf3
0000007c`96bfecb0 00007ff9`abc2ecae xul!nsHtml5TreeOpExecutor::RunFlushLoop+0x4f1
0000007c`96bfed80 00007ff9`aceb298f xul!nsHtml5ExecutorFlusher::Run+0x3e
0000007c`96bfedd0 00007ff9`ab54cf24 xul!mozilla::SchedulerGroup::Runnable::Run+0x2f
0000007c`96bfee10 00007ff9`ab54c9b9 xul!nsThread::ProcessNextEvent+0x4a4
0000007c`96bff340 00007ff9`ab72badb xul!NS_ProcessNextEvent+0x29
0000007c`96bff390 00007ff9`ab524e18 xul!mozilla::ipc::MessagePump::Run+0xfb
0000007c`96bff400 00007ff9`ab54c6b1 xul!MessageLoop::RunHandler+0x28
0000007c`96bff450 00007ff9`ab72b9b8 xul!MessageLoop::Run+0x51
0000007c`96bff4a0 00007ff9`ab72b293 xul!nsBaseAppShell::Run+0x28
0000007c`96bff4e0 00007ff9`afd2f8d5 xul!nsAppShell::Run+0x23
0000007c`96bff510 00007ff9`ab524e18 xul!XRE_RunAppShell+0x45
0000007c`96bff550 00007ff9`ab54c6b1 xul!MessageLoop::RunHandler+0x28
0000007c`96bff5a0 00007ff9`afd2f556 xul!MessageLoop::Run+0x51
0000007c`96bff5f0 00007ff6`b45514f5 xul!XRE_InitChildProcess+0x686
0000007c`96bff830 00007ff6`b455144b firefox!content_process_main+0x75
0000007c`96bff890 00007ff6`b4551113 firefox!NS_internal_main+0x11b
0000007c`96bff910 00007ff6`b4598588 firefox!wmain+0x113
0000007c`96bff970 00007ff9`f2eb81f4 firefox!__scrt_common_main_seh+0x10c
0000007c`96bff9b0 00007ff9`f4eea251 KERNEL32!BaseThreadInitThunk+0x14
0000007c`96bff9e0 00000000`00000000 ntdll!RtlUserThreadStart+0x21

0:061> ~42k
Child-SP          RetAddr           Call Site
0000007c`9ae3cbe8 00007ff9`f108c7ee ntdll!NtWaitForMultipleObjects+0x14
0000007c`9ae3cbf0 00007ff9`f108c6de KERNELBASE!WaitForMultipleObjectsEx+0xfe
0000007c`9ae3cef0 00007ff9`ad58fbb6 KERNELBASE!WaitForMultipleObjects+0xe
0000007c`9ae3cf30 00007ff9`ad5910d6 xul!mozilla::mscom::SpinEvent::Wait+0x76
0000007c`9ae3cfe0 00007ff9`ad58da7b xul!mozilla::mscom::MainThreadInvoker::Invoke+0xe6
0000007c`9ae3d040 00007ff9`ad58d76a xul!mozilla::mscom::Interceptor::QueryInterfaceTarget+0xeb
0000007c`9ae3d0b0 00007ff9`ad58feb5 xul!mozilla::mscom::Interceptor::GetInterceptorForIID+0x1ea
0000007c`9ae3d1d0 00007ff9`f27588c7 xul!mozilla::mscom::WeakReferenceSupport::QueryInterface+0x95
0000007c`9ae3d230 00007ff9`f275f67a combase!CStdMarshal::CreateStub+0xd7
(Inline Function) --------`-------- combase!CStdMarshal::ConnectSrvIPIDEntry+0x26
(Inline Function) --------`-------- combase!CStdMarshal::MarshalServerIPID+0x1cb
(Inline Function) --------`-------- combase!CStdMarshal::MarshalIPID+0x1d5
0000007c`9ae3d460 00007ff9`f274567c combase!CStdMarshal::MarshalObjRefImpl+0x5ca
0000007c`9ae3d5d0 00007ff9`f274542f combase!CStdMarshal::MarshalObjRef+0x8c
0000007c`9ae3d680 00007ff9`ad5918df combase!CStdMarshal::MarshalInterface+0x5cf
0000007c`9ae3daa0 00007ff9`ad58d0c3 xul!mozilla::mscom::FastMarshaler::MarshalInterface+0x5f
0000007c`9ae3db20 00007ff9`f27c0955 xul!mozilla::mscom::Interceptor::MarshalInterface+0xb3
0000007c`9ae3dbd0 00007ff9`f2367803 combase!CRemoteUnknown::RemQueryInterface2+0x1c5
0000007c`9ae3dcb0 00007ff9`f23cb4a6 RPCRT4!Invoke+0x73
0000007c`9ae3dd20 00007ff9`f23453d9 RPCRT4!Ndr64StubWorker+0xbc6
0000007c`9ae3e3e0 00007ff9`f27ac45f RPCRT4!NdrStubCall3+0xc9
0000007c`9ae3e440 00007ff9`f271f203 combase!CStdStubBuffer_Invoke+0x5f
(Inline Function) --------`-------- combase!InvokeStubWithExceptionPolicyAndTracing::__l6::<lambda_76d9e92c799d246a4afbe64a2bf5673d>::operator()+0x18
0000007c`9ae3e480 00007ff9`f271eff4 combase!ObjectMethodExceptionHandlingAction<<lambda_76d9e92c799d246a4afbe64a2bf5673d> >+0x43
(Inline Function) --------`-------- combase!InvokeStubWithExceptionPolicyAndTracing+0xa8
0000007c`9ae3e4e0 00007ff9`f27b2df6 combase!DefaultStubInvoke+0x1c4
(Inline Function) --------`-------- combase!SyncStubCall::Invoke+0x22
0000007c`9ae3e630 00007ff9`f2752e55 combase!SyncServerCall::StubInvoke+0x26
(Inline Function) --------`-------- combase!StubInvoke+0x265
0000007c`9ae3e670 00007ff9`f27aab2d combase!ServerCall::ContextInvoke+0x435
(Inline Function) --------`-------- combase!CServerChannel::ContextInvoke+0x70
0000007c`9ae3ea80 00007ff9`f27647a0 combase!DefaultInvokeInApartment+0xad
0000007c`9ae3ead0 00007ff9`f2764064 combase!AppInvoke+0x200
0000007c`9ae3eb60 00007ff9`f2769d57 combase!ComInvokeWithLockAndIPID+0xd14
0000007c`9ae3ee30 00007ff9`f2344a38 combase!ThreadInvoke+0x1f67
0000007c`9ae3f1a0 00007ff9`f23204b0 RPCRT4!DispatchToStubInCNoAvrf+0x18
0000007c`9ae3f1f0 00007ff9`f23200f0 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0x1a0
0000007c`9ae3f2c0 00007ff9`f231200f RPCRT4!RPC_INTERFACE::DispatchToStubWithObject+0x160
0000007c`9ae3f360 00007ff9`f231165a RPCRT4!LRPC_SCALL::DispatchRequest+0x16f
0000007c`9ae3f440 00007ff9`f2310c21 RPCRT4!LRPC_SCALL::HandleRequest+0x7fa
0000007c`9ae3f540 00007ff9`f2310692 RPCRT4!LRPC_ADDRESS::HandleRequest+0x341
0000007c`9ae3f5e0 00007ff9`f2307465 RPCRT4!LRPC_ADDRESS::ProcessIO+0x8a2
0000007c`9ae3f720 00007ff9`f4ecf4c0 RPCRT4!LrpcIoComplete+0xc5
0000007c`9ae3f7c0 00007ff9`f4ed0348 ntdll!TppAlpcpExecuteCallback+0x260
0000007c`9ae3f840 00007ff9`f2eb81f4 ntdll!TppWorkerThread+0x3c8
0000007c`9ae3fb30 00007ff9`ebc2644e KERNEL32!BaseThreadInitThunk+0x14
0000007c`9ae3fb60 00007ff9`f4eea251 mozglue!patched_BaseThreadInitThunk+0x8e
0000007c`9ae3fbe0 00000000`00000000 ntdll!RtlUserThreadStart+0x21

:m_kato, How often do you hit this dead lock ?
We thought we fixed this in bug 1534208 and bug 1516136.
Can you provide more details like, what screen reader you use ?
Thanks.

(In reply to Jan Varga [:janv] from comment #1)

:m_kato, How often do you hit this dead lock ?

one or two per day. Until last week, I turn off a11y code by accessibility.force_disabled=1, but from this week, I turn on a11y on my workstation for test.

We thought we fixed this in bug 1534208 and bug 1516136.

https://hg.mozilla.org/mozilla-central/rev/add98afa5f0ca1ca17aa87eaa045442a3e1fa07a will include bug 1534208's fix.

Can you provide more details like, what screen reader you use ?
Thanks.

ATOK that is Japanese IME. Some IMEs use a11y API to analyze document.

also, Microsoft Japanese IME uses a11y API.

(In reply to Makoto Kato [:m_kato] from comment #2)

We thought we fixed this in bug 1534208 and bug 1516136.

https://hg.mozilla.org/mozilla-central/rev/add98afa5f0ca1ca17aa87eaa045442a3e1fa07a will include bug 1534208's fix.

Your build does contain that fix, so there must be other edge case that is causing a hang.

:m_kato, If I gave you a build from try server, would you be able to test it on your machine ?

Flags: needinfo?(m_kato)

(In reply to Jan Varga [:janv] from comment #5)

:m_kato, If I gave you a build from try server, would you be able to test it on your machine ?

Yes, of course!

Flags: needinfo?(m_kato)

OK, I am testing it.

Flags: needinfo?(m_kato)

There are some failing tests, but it should be good enough for normal use and verifying that unfinished PBackground initialization can still cause hangs.

Assignee: nobody → jvarga
Blocks: 1517090
Component: IPC: MSCOM → DOM: Web Storage
Priority: -- → P1

(In reply to Jan Varga [:janv] from comment #7)

Makoto, here's a try push with a possible fix:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=f918d33953bde4df9a543ae4ddc4f25b075c0b85

Although I use your try server build, this dead lock issue still occurs.

Flags: needinfo?(m_kato)

Ok, thank you.
I will have to check other possibilities.

I guess, you have no idea when it happens, for example, when you issued clearing of some origins/sites, at shutdown/application quit, etc.

(In reply to Jan Varga [:janv] from comment #12)

I guess, you have no idea when it happens, for example, when you issued clearing of some origins/sites, at shutdown/application quit, etc.

If I know a easy reproduce step such as accessing specific URL, I provide this step. But this occurs suddenly when accessing web page. This seems to be race condition issue...

m_kato, does one of the background tabs by any chance run the Twitter or Mobile Twitter web application where tweets refresh periodically? I have a feeling that https://mobile.twitter.com running in a background tab, logged in, seems to trigger a deadlock eventually for me if some bigger tweet refresh happens at some point. But this can sometimes take hours to manifest itself for me. I don't even need to be on that tab at the time it happens. But without a Twitter tab open, I see this much less often, if at all.

So I was thinking, if your browser session also contains Twitter or Mobile Twitter in the background somewhere?

(In reply to Marco Zehe (:MarcoZ) from comment #14)

m_kato, does one of the background tabs by any chance run the Twitter or Mobile Twitter web application where tweets refresh periodically?

Yes, when testing comment #7's build, I click a link on twitter, then Firefox opens new tab. At that time, this dead lock occur.

This patch adds a timer for synchronous local storage requests. Once the timer
fires the request is canceled. The parent reports debugging information upon receiving cancellation.

Keywords: leave-open
Pushed by jvarga@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/32eb745d3238 Add infrastructure for hang debugging; r=asuth

Makoto, I landed a patch which should output some debugging info when the deadlock happens, but you need to set these environment variables:
set MOZ_LOG=LocalStorage:3,sync
set MOZ_LOG_FILE=log.txt
set LSNG_CRASH_ON_CANCEL=1

It should work in next Nightly.
See also https://developer.mozilla.org/en-US/docs/Mozilla/Developer_guide/Gecko_Logging

If you don't want to wait for next Nightly, you can actually use a build from comment 18:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&revision=d15d511d7fed036d69d37cecbacdea779a983a34

Flags: needinfo?(m_kato)

Log is the following only.

[Parent 19772: IPDL Background]: I/LocalStorage PrepareDatastoreOp::RecvCancel
[Parent 19772: IPDL Background]: I/LocalStorage   mNestedState: CheckClosingDatastore
[Parent 19772: IPDL Background]: I/LocalStorage LSRequestBase::RecvCancel
[Parent 19772: IPDL Background]: I/LocalStorage   mState: Nesting
Flags: needinfo?(m_kato)

That's a good start, thank you for helping with this.

Here's what we know so far:

  1. PBackground is fully initialized since RecvCancel is called in the parent
  2. mNestedState: CheckClosingDatastore indicates that the request is waiting
    for an already running request to finish. It's probably the datastore
    preloading that somehow can't finish.

So we need to add more debugging info which checks the preloading request,
especially its state.

I have a new patch for this, it adds more state reporting for the CheckClosingDatastore state.
I'm guessing that the preloading is stuck in DirectoryOpenPending, so I added state reporting for that too.
DirectoryOpenPending reports a pending directory lock info along with info for locks that block the pending lock.
I'll clean it up a bit and request a review.

Makoto, I have new try builds:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=6134db6147b31b065581e36d319a21c4465be0e7

Please note that the setting of MOZ_LOG has changed to:
set MOZ_LOG=QuotaManager:3,LocalStorage:3,sync

I really appreciate your help.

Flags: needinfo?(m_kato)
Pushed by jvarga@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/70c2025fdad9 Add more robust logging including more detailed logging for CheckClosingDatastore and DirectoryOpenPending state; r=asuth

When using MOZ_LOG=QuotaManager:3,LocalStorage:3, log is the following only in log.txt (parent process).

[Parent 12348: IPDL Background]: I/LocalStorage LSRequestBase [00000259C5369C00]
[Parent 12348: IPDL Background]: I/LocalStorage   mState: Nesting
[Parent 12348: IPDL Background]: I/LocalStorage   mNestedState: CheckClosingDatastore
[Parent 12348: IPDL Background]: I/LocalStorage   mDelayedBy: [00000259C53A3000]
[Parent 12348: IPDL Background]: I/LocalStorage LSRequestBase [00000259C53A3000]
[Parent 12348: IPDL Background]: I/LocalStorage   mState: WaitingForFinish
Flags: needinfo?(m_kato)

Ok, so according to the log, this seems to be the same issue as in bug 1533789.
A fix for that already landed on inbound and should be available in next Nightly.

Thanks again for cooperation.

Yeah, latest Nightly has the fix. Just to be sure it's fixed for real, please keep the environment variables set. Thanks.

Status: NEW → ASSIGNED

Even I use https://hg.mozilla.org/mozilla-central/rev/00c5ef76d951a834ccf87c83d04e0878f6c2c515, this dead lock occurs.

[Parent 15712: IPDL Background]: I/LocalStorage LSRequestBase [0000022F08766800]
[Parent 15712: IPDL Background]: I/LocalStorage   mState: Nesting
[Parent 15712: IPDL Background]: I/LocalStorage   mNestedState: CheckClosingDatastore
[Parent 15712: IPDL Background]: I/LocalStorage   mDelayedBy: [0000022F085BBC00]
[Parent 15712: IPDL Background]: I/LocalStorage LSRequestBase [0000022F085BBC00]
[Parent 15712: IPDL Background]: I/LocalStorage   mState: WaitingForFinish

Yeah, there must be something still. Has the frequency of deadlocks changed for you ?

Makoto, here is another try push that could help with revealing issues:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=725b8386948bb6010f72b6fa53f8e327c4bab9d1

This time it could crash elsewhere and the crash message would be "Found dangling UnsafePtr".

Thanks.

(In reply to Jan Varga [:janv] from comment #32)

Yeah, there must be something still. Has the frequency of deadlocks changed for you ?

one or two per day. But frequency becomes lower.

(In reply to Jan Varga [:janv] from comment #33)

Makoto, here is another try push that could help with revealing issues:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=725b8386948bb6010f72b6fa53f8e327c4bab9d1

This time it could crash elsewhere and the crash message would be "Found dangling UnsafePtr".

Thanks.

OK, I will test this next week since now is late Friday.

No longer blocks: 1517090
Blocks: 1540402

(In reply to Jan Varga [:janv] from comment #33)

Makoto, here is another try push that could help with revealing issues:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=725b8386948bb6010f72b6fa53f8e327c4bab9d1

This time it could crash elsewhere and the crash message would be "Found dangling UnsafePtr".

Thanks.

No crash message when dead lock occurs (with Comment 31's log) even I use this build. Also, bp-cab9907d-d127-4ee6-8434-f88d90190403 is with LSNG_CRASH_ON_CANCEL=1.

Ok, thanks.
So if UnsafePtr didn't catch anything, it probably means that a real previous request is blocking the new one. The previous request is in the WaitingForFinish state.
In the meantime, we landed a new fix in bug 1540189, that can help here in theory along with newly filed bug 1541325.
We also converted all debug assertions to diagnostic assertions which can help with finding bugs that cause deadlocks like this.

Even logging the following, Firefox Nightly doesn't crash.

[Parent 3676: IPDL Background]: I/LocalStorage LSRequestBase [000001FF5E1BDC00]
[Parent 3676: IPDL Background]: I/LocalStorage   mState: Nesting
[Parent 3676: IPDL Background]: I/LocalStorage   mNestedState: CheckClosingDatastore
[Parent 3676: IPDL Background]: I/LocalStorage   mDelayedBy: [000001FF5E1BC400]
[Parent 3676: IPDL Background]: I/LocalStorage LSRequestBase [000001FF5E1BC400]
[Parent 3676: IPDL Background]: I/LocalStorage   mState: WaitingForFinish

Yeah, it can happen that if there's a deadlock even MOZ_CRASH can't crash it I guess.

I think I've finally figured out how this can happen. I'm working on a patch.

Makoto, here's a new try push with a fix:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=943f27b2971aaf983ae8caf6d404ad322daccdab

I believe this should fix the deadlock for real.
Can you verify it ? Thanks.

Flags: needinfo?(m_kato)

(In reply to Jan Varga [:janv] from comment #40)

Makoto, here's a new try push with a fix:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=943f27b2971aaf983ae8caf6d404ad322daccdab

I believe this should fix the deadlock for real.
Can you verify it ? Thanks.

Thanks. I will try it

(In reply to Jan Varga [:janv] from comment #40)

Makoto, here's a new try push with a fix:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=943f27b2971aaf983ae8caf6d404ad322daccdab

I believe this should fix the deadlock for real.
Can you verify it ? Thanks.

I test for 3 days, then I cannot reproduce this dead lock with this try build. Thanks!

Flags: needinfo?(m_kato)
Pushed by jvarga@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/8269eee6ed74 Dead lock with a11y's mscom and mozilla::dom::LSObject; r=asuth

Thanks a lot for helping out!

Keywords: leave-open

https://hg.mozilla.org/mozilla-central/rev/8269eee6ed74

Status: ASSIGNED → RESOLVED
Closed: 6 years ago
status-firefox68: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla68
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: