Search code examples
.net-4.0deadlockwindbgfinalizersos

is this indication of blocked finalizer


I see following call stack for finalizer thread. Is it normal to have a call to WaitForSingleObject at top in finalizer? Is there anyway I can determine if its not deadlocked or waiting for really long time?

0:009> k
Child-SP          RetAddr           Call Site
00000000`0a56e5c8 000007fe`fd5010dc ntdll!NtWaitForSingleObject+0xa
00000000`0a56e5d0 000007fe`fdfabeb5 KERNELBASE!WaitForSingleObjectEx+0x79
00000000`0a56e670 000007fe`fe04a576 rpcrt4!UTIL_GetOverlappedResultEx+0x45
00000000`0a56e6b0 000007fe`fdfaf0dd rpcrt4!WS_SyncRecv+0xf6
00000000`0a56e720 000007fe`fdfe7a29 rpcrt4!OSF_CCONNECTION::TransSendReceive+0x18d
00000000`0a56e780 000007fe`fdfa7f61 rpcrt4!OSF_CCONNECTION::SendBindPacket+0xa5c
00000000`0a56e930 000007fe`fdfa8e27 rpcrt4!OSF_CCONNECTION::ActuallyDoBinding+0xc1
00000000`0a56e9d0 000007fe`fdfa8bb6 rpcrt4!OSF_CCONNECTION::OpenConnectionAndBind+0x207
00000000`0a56ea90 000007fe`fdfa8acd rpcrt4!OSF_CCALL::BindToServer+0xc6
00000000`0a56eb40 000007fe`fdfadaeb rpcrt4!OSF_BINDING_HANDLE::InitCCallWithAssociation+0xa5
00000000`0a56eba0 000007fe`fdfad9d0 rpcrt4!OSF_BINDING_HANDLE::AllocateCCall+0x102
00000000`0a56ecd0 000007fe`fdfc74eb rpcrt4!OSF_BINDING_HANDLE::NegotiateTransferSyntax+0x30
00000000`0a56ed20 000007fe`ff462271 rpcrt4!I_RpcNegotiateTransferSyntax+0x9f
00000000`0a56edb0 000007fe`ff45d185 ole32!CRpcChannelBuffer::NegotiateSyntax+0x69 
00000000`0a56ee20 000007fe`fe05ba22 ole32!NdrExtNegotiateTransferSyntax+0xe5 
00000000`0a56ee60 000007fe`fe05cbbb rpcrt4!Ndr64pClientSetupTransferSyntax+0x453
00000000`0a56eec0 000007fe`ff4621d0 rpcrt4!NdrpClientCall3+0xcb
00000000`0a56f180 000007fe`ff31d8a2 ole32!ObjectStublessClient+0x11d 
00000000`0a56f510 000007fe`ff321bb3 ole32!ObjectStubless+0x42 
00000000`0a56f560 000007fe`ff321b22 ole32!RemoteReleaseRifRefHelper+0x57 
00000000`0a56f5b0 000007fe`ff3217eb ole32!RemoteReleaseRifRef+0xca 
00000000`0a56f620 000007fe`ff321417 ole32!CStdMarshal::DisconnectCliIPIDs+0x4c2 
00000000`0a56f720 000007fe`ff3194fa ole32!CStdMarshal::Disconnect+0x40c 
00000000`0a56f780 000007fe`ff319428 ole32!CStdIdentity::~CStdIdentity+0xa6 [d:\w7rtm\com\ole32\com\dcomrem\stdid.cxx @ 312]
00000000`0a56f7b0 000007fe`ff319b49 ole32!CStdIdentity::`scalar deleting destructor'+0x14
00000000`0a56f7e0 000007fe`f2a79f94 ole32!CStdIdentity::CInternalUnk::Release+0xdc [d:\w7rtm\com\ole32\com\dcomrem\stdid.cxx @ 767]
00000000`0a56f810 000007fe`f2ba8bea clr!SafeReleasePreemp+0x74
00000000`0a56f860 000007fe`f2ba8acc clr!RCW::ReleaseAllInterfaces+0xda
00000000`0a56f8b0 000007fe`f2ba8c14 clr!RCW::ReleaseAllInterfacesCallBack+0x54
00000000`0a56f930 000007fe`f2ba937e clr!RCW::Cleanup+0x25
00000000`0a56f980 000007fe`f2ba9214 clr!RCWCleanupList::ReleaseRCWListRaw+0x16
00000000`0a56f9b0 000007fe`f2bb005a clr!RCWCleanupList::ReleaseRCWListInCorrectCtx+0x94
00000000`0a56f9f0 000007fe`f2be326e clr!RCWCleanupList::CleanupAllWrappers+0xe5
00000000`0a56fa70 000007fe`f2be319f clr!SyncBlockCache::CleanupSyncBlocks+0xc2
00000000`0a56fae0 000007fe`f2be47c7 clr!Thread::DoExtraWorkForFinalizer+0xdc
00000000`0a56fb10 000007fe`f2a5458c clr!SVR::GCHeap::FinalizerThreadWorker+0x78
00000000`0a56fb50 000007fe`f2a5451a clr!Frame::Pop+0x50
00000000`0a56fb90 000007fe`f2a54491 clr!COMCustomAttribute::PopSecurityContextFrame+0x192
00000000`0a56fc90 000007fe`f2b31bfe clr!COMCustomAttribute::PopSecurityContextFrame+0xbd
00000000`0a56fd20 000007fe`f2b45020 clr!ManagedThreadBase_NoADTransition+0x3f
00000000`0a56fd80 000007fe`f2ab33de clr!SVR::GCHeap::FinalizerThreadStart+0xb4
00000000`0a56fdc0 00000000`772459ed clr!Thread::intermediateThreadProc+0x7d
00000000`0a56fe80 00000000`7747c541 kernel32!BaseThreadInitThunk+0xd
00000000`0a56feb0 00000000`00000000 ntdll!RtlUserThreadStart+0x1d

0:009> !CLRStack
OS Thread Id: 0x1338 (6)
        Child SP               IP Call Site
000000000b67fcd8 00000000774a12fa [DebuggerU2MCatchHandlerFrame: 000000000b67fcd8] 

Solution

  • This is a finalizer worker and it is blocked for a RPC response. In this case if the thread is not waiting for more than a few milliseconds (depending on how long the COM server takes to respond to the request) it is normal. But if we are waiting longer then you might want to investigate what happened to the response packet.

    There is no way in user mode to understand what's the tick-count of the thread you may want to examine the same thread using livekd on a running system if the problem is re-producible