Deadlock in process shutdown during RCW cleanup

[miguep]

We have just recently started to run into this deadlock in coreclr_t::shutdown.

this is what the main thread looks like:

ntdll.dll!_KiFastSystemCallRet@0() Unknown
ntdll.dll!_ZwWaitForSingleObject@12() Unknown
KernelBase.dll!WaitForSingleObjectEx(hHandle, dwMilliseconds, bAlertable) C
hostpolicy.dll!coreclr_t::shutdown�() C++
hostpolicy.dll!run_as_app�() C++
hostpolicy.dll!_corehost_main�() C++
hostfxr.dll!fx_muxer_t::read_config_and_execute�() C++
hostfxr.dll!fx_muxer_t::handle_exec_host_command�() C++
hostfxr.dll!fx_muxer_t::execute�() C++
hostfxr.dll!_hostfxr_main_startupinfo�() C++
QualityVaultFrontEnd.exe!exe_start�() C++
QualityVaultFrontEnd.exe!_wmain�() C++
[Inline Frame] QualityVaultFrontEnd.exe!invoke_main() C++
QualityVaultFrontEnd.exe!__scrt_common_main_seh() C++
kernel32.dll!BaseThreadInitThunk(RunProcessInit, StartAddress, Argument) C
ntdll.dll!__RtlUserThreadStart(StartAddress, Argument) C
ntdll.dll!_RtlUserThreadStart(StartAddress, Argument) C

This only seems to happen when running the master (3.0.100-preview5-011487) bits, the latest release ( 3.0.100-preview4-011228) bits do not repro this issue.

[jkotas]

cc @vitek-karas @sdmaclea @jeffschwMSFT

Looks like preview4 -> preview5 regression

[vitek-karas]

@elinor-fung
Any chance of getting a dump or something similar, so that we can drill into this a bit more?

[jkotas]

@miguep If dump is not possible, stacktraces from other threads would help too. The main thread is waiting for a lock that is held by some other thread.

[sdmaclea]

Seems surprising to me that coreclr is not in the trace

KernelBase.dll!WaitForSingleObjectEx(hHandle, dwMilliseconds, bAlertable) C
hostpolicy.dll!coreclr_t::shutdown�() C++

[sdmaclea]

Did preview5 get all the preview4 fixes that went in after we branched?

[jeffschwMSFT]

Right now Preview5 is master... Any changes that went into Preview4 need to be manually also merged into master.

[jkotas]

Seems surprising to me that coreclr is not in the trace

Yes, the stacktrace is missing frames. It can be waiting on this lock
https://github.com/dotnet/core-setup/blob/859ee7d256a043b0a9bfe3e9cc6c8483eb23efd5/src/corehost/cli/hostpolicy/coreclr.cpp#L175

[sdmaclea]

That lock makes no sense. Unless multiple threads are calling shutdown...

[vitek-karas]

@AaronRobinsonMSFT
This change has modified the lock in question:
dotnet/core-setup@d0e3248

We don't know for sure it's that lock, but it's likely. I remember that there were some "things" going on with the use of "atomic" specifically around the release branch (the fix was done in the release branch directly). @AaronRobinsonMSFT any ideas?

[AaronRobinsonMSFT]

@vitek-karas There was an issue that was addressed around a destructor also calling shutdown and that resulted in a lock. In this case, there should only be one place that is calling shutdown so I have no idea how this could be a deadlock there. We should make sure the customer has changes post dotnet/core-setup@d182472

[elinor-fung]

@miguep provided a repro machine. It does not look to be from that lock. I just started looking into it: we're getting into coreclr_shutdown_2 and blocking waiting for the finalizer thread, which appears to be cleaning up RCWs.

[AaronRobinsonMSFT]

Also all atomic issues have been resolved now that we statically link against atomic.a.

[AaronRobinsonMSFT]

@elinor-fung has a dump of the issue. This seems to be some issue with RCW cleanup. I will have to look into it.

[AaronRobinsonMSFT]

Okay, this is definitely in the coreclr binary and not in any core-setup code. Can someone transfer this over to coreclr repo?

main thread

> 	coreclr.dll!CLREventWaitHelper(void * handle, unsigned long dwMilliseconds, int alertable) Line 402	C++
 	coreclr.dll!CLREventBase::WaitEx(unsigned long dwMilliseconds, WaitMode mode, PendingSync * syncState) Line 471	C++
 	coreclr.dll!CLREventBase::Wait(unsigned long dwMilliseconds, int alertable, PendingSync * syncState) Line 418	C++
 	coreclr.dll!FinalizerThread::RaiseShutdownEvents() Line 72	C++
 	coreclr.dll!EEShutDownHelper(int fIsDllUnloading) Line 1533	C++
 	coreclr.dll!EEShutDown(int fIsDllUnloading) Line 1939	C++
 	coreclr.dll!CorHost2::UnloadAppDomain2(unsigned long dwDomainId, int fWaitUntilDone, int * pLatchedExitCode) Line 1048	C++
	coreclr.dll!coreclr_shutdown_2(void * hostHandle, unsigned int domainId, int * latchedExitCode) Line 323	C++
 	hostpolicy.dll!coreclr_t::shutdown(int *)	C++
 	hostpolicy.dll!run_as_app(class std::shared_ptr<class coreclr_t> const &,struct hostpolicy_context_t const &,int,wchar_t const * *)	C++
 	hostpolicy.dll!_corehost_main�()	C++
 	hostfxr.dll!fx_muxer_t::read_config_and_execute(class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> > const &,struct host_startup_info_t const &,class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> > const &,class std::unordered_map<class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> >,class std::vector<class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> >,class std::allocator<class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> > > >,struct std::hash<class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> > >,struct std::equal_to<class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> > >,class std::allocator<struct std::pair<class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> > const ,class	C++
 	hostfxr.dll!fx_muxer_t::handle_exec_host_command(class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> > const &,struct host_startup_info_t const &,class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> > const &,class std::unordered_map<class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> >,class std::vector<class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> >,class std::allocator<class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> > > >,struct std::hash<class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> > >,struct std::equal_to<class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> > >,class std::allocator<struct std::pair<class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> > const ,clas	C++
 	hostfxr.dll!fx_muxer_t::execute(class std::basic_string<wchar_t,struct std::char_traits<wchar_t>,class std::allocator<wchar_t> >,int,wchar_t const * * const,struct host_startup_info_t const &,wchar_t * const,int,int *)	C++
 	hostfxr.dll!_hostfxr_main_startupinfo�()	C++

Clean up

> 	coreclr.dll!CtxEntry::EnterContext(HRESULT(__stdcall*)(void *) pCallbackFunc, void * pData) Line 1511	C++
 	coreclr.dll!RCW::EnterContext(HRESULT(__stdcall*)(void *) pCallbackFunc, void * pData) Line 4204	C++
 	coreclr.dll!RCWCleanupList::ReleaseRCWListInCorrectCtx(void * pData) Line 1862	C++
 	coreclr.dll!RCWCleanupList::CleanupAllWrappers() Line 1690	C++
 	coreclr.dll!SyncBlockCache::CleanupSyncBlocks() Line 626	C++
	coreclr.dll!Thread::DoExtraWorkForFinalizer() Line 7315	C++
 	coreclr.dll!FinalizerThread::FinalizerThreadWorker(void * args) Line 494	C++
 	[Inline Frame] coreclr.dll!ManagedThreadBase_DispatchInner(ManagedThreadCallState *) Line 7394	C++
 	coreclr.dll!ManagedThreadBase_DispatchMiddle(ManagedThreadCallState * pCallState) Line 7438	C++
 	coreclr.dll!ManagedThreadBase_DispatchOuter(ManagedThreadCallState * pCallState) Line 7624	C++
 	coreclr.dll!ManagedThreadBase_NoADTransition(void(__stdcall*)(void *)) Line 7675	C++
 	coreclr.dll!FinalizerThread::FinalizerThreadStart(void * args) Line 590	C++
 	coreclr.dll!Thread::intermediateThreadProc(void * arg) Line 2099	C++

[AaronRobinsonMSFT]

Nevermind. 🙄