ProfilingAPI: `ICorProfilerInfo14::GetNonGCHeapBounds` deadlock on .NET 8.0-preview7

[ww898]

Hi there,
We started to use ICorProfilerInfo14::GetNonGCHeapBounds and got permanent red tests on:

• Windows ARM64 for some kinds of x64 and x86 processes
• macOS ARM64 for some kinds of x64 processes

I think the deadlock appears because we call ICorProfilerInfo14::GetNonGCHeapBounds during the initialization of the execution engine.

Stack trace:

0:000:ARM64EC> ~* k

.  0  Id: 44b8.57b8 Suspend: 1 Teb: 000000e3`ff155000 Unfrozen
 #   Arch   Child-SP          RetAddr               Call Site
00  ARM64EC 000000e3`fefde6f0 00007ffd`12e65334     ntdll!#NtWaitForSingleObject+0x14
01  ARM64EC 000000e3`fefde700 00007ffd`12f93444     KERNELBASE!WaitForSingleObjectEx+0x84
02  ARM64EC 000000e3`fefde790 00007ffc`97779e4d     KERNELBASE!$ientry_thunk$cdecl$i8$i8+0x24
03    AMD64 (Inline Function) --------`--------     coreclr!GCEvent::Impl::Wait+0xc [D:\a\_work\1\s\src\coreclr\gc\windows\gcenv.windows.cpp @ 1372] 
04    AMD64 (Inline Function) --------`--------     coreclr!GCEvent::Wait+0x13 [D:\a\_work\1\s\src\coreclr\gc\windows\gcenv.windows.cpp @ 1422] 
05    AMD64 000000e3`fefde840 00007ffc`979078ea     coreclr!WKS::gc_heap::wait_for_gc_done+0x29 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 14543] 
06    AMD64 (Inline Function) --------`--------     coreclr!WKS::WaitLonger+0x44 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 1635] 
07    AMD64 (Inline Function) --------`--------     coreclr!WKS::enter_spin_lock+0xa6e85 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 1690] 
08    AMD64 000000e3`fefde870 00007ffc`97860a17     coreclr!WKS::gc_heap::insert_ro_segment+0xa6eba [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 9868] 
09    AMD64 000000e3`fefde8c0 00007ffc`97864178     coreclr!WKS::GCHeap::RegisterFrozenSegment+0x87 [D:\a\_work\1\s\src\coreclr\gc\gcee.cpp @ 466] 
0a    AMD64 000000e3`fefde8f0 00007ffc`9778c21f     coreclr!FrozenObjectSegment::FrozenObjectSegment+0xb0 [D:\a\_work\1\s\src\coreclr\vm\frozenobjectheap.cpp @ 149] 
0b    AMD64 000000e3`fefde950 00007ffc`9778bc46     coreclr!FrozenObjectHeapManager::TryAllocateObject+0x15f [D:\a\_work\1\s\src\coreclr\vm\frozenobjectheap.cpp @ 66] 
0c    AMD64 (Inline Function) --------`--------     coreclr!AllocateString+0x4d [D:\a\_work\1\s\src\coreclr\vm\gchelpers.cpp @ 971] 
0d    AMD64 (Inline Function) --------`--------     coreclr!AllocateStringObject+0x54 [D:\a\_work\1\s\src\coreclr\vm\stringliteralmap.cpp @ 472] 
0e    AMD64 000000e3`fefde9d0 00007ffc`9778ba9d     coreclr!GlobalStringLiteralMap::AddStringLiteral+0x76 [D:\a\_work\1\s\src\coreclr\vm\stringliteralmap.cpp @ 503] 
0f    AMD64 (Inline Function) --------`--------     coreclr!GlobalStringLiteralMap::GetStringLiteral+0x5a [D:\a\_work\1\s\src\coreclr\vm\stringliteralmap.cpp @ 396] 
10    AMD64 000000e3`fefdeae0 00007ffc`977cbb22     coreclr!StringLiteralMap::GetStringLiteral+0xdd [D:\a\_work\1\s\src\coreclr\vm\stringliteralmap.cpp @ 170] 
11    AMD64 000000e3`fefdeb40 00007ffc`977cbaa8     coreclr!LoaderAllocator::GetStringObjRefPtrFromUnicodeString+0x4e [D:\a\_work\1\s\src\coreclr\vm\loaderallocator.cpp @ 1751] 
12    AMD64 000000e3`fefdeb80 00007ffc`977cba5d     coreclr!StringObject::InitEmptyStringRefPtr+0x48 [D:\a\_work\1\s\src\coreclr\vm\object.cpp @ 859] 
13    AMD64 000000e3`fefdebd0 00007ffc`977cb9f5     coreclr!StringObject::GetEmptyString+0x1d [D:\a\_work\1\s\src\coreclr\vm\object.h @ 989] 
14    AMD64 000000e3`fefdec00 00007ffc`97812877     coreclr!AppDomain::SetupSharedStatics+0x51 [D:\a\_work\1\s\src\coreclr\vm\appdomain.cpp @ 3059] 
15    AMD64 000000e3`fefdec40 00007ffc`9783c5a3     coreclr!EEStartupHelper+0x697 [D:\a\_work\1\s\src\coreclr\vm\ceemain.cpp @ 933] 
16    AMD64 000000e3`fefdee60 00007ffc`9783c54a     coreclr!EEStartup+0x27 [D:\a\_work\1\s\src\coreclr\vm\ceemain.cpp @ 1051] 
17    AMD64 000000e3`fefdeeb0 00007ffc`9783c488     coreclr!EnsureEEStarted+0x92 [D:\a\_work\1\s\src\coreclr\vm\ceemain.cpp @ 300] 
18    AMD64 000000e3`fefdef00 00007ffc`9784d040     coreclr!CorHost2::Start+0x58 [D:\a\_work\1\s\src\coreclr\vm\corhost.cpp @ 101] 
19    AMD64 000000e3`fefdef40 00007ffc`c47335b0     coreclr!coreclr_initialize+0x180 [D:\a\_work\1\s\src\coreclr\dlls\mscoree\exports.cpp @ 320] 
1a    AMD64 000000e3`fefdf010 00007ffc`c4752068     hostpolicy!coreclr_t::create+0x2b0 [D:\a\_work\1\s\src\native\corehost\hostpolicy\coreclr.cpp @ 73] 
1b    AMD64 000000e3`fefdf190 00007ffc`c4753c37     hostpolicy!`anonymous namespace'::create_coreclr+0x158 [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 82] 
1c    AMD64 000000e3`fefdf1f0 00007ffc`c5a2b5ac     hostpolicy!corehost_main+0x187 [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 427] 
1d    AMD64 000000e3`fefdf2f0 00007ffc`c5a2e166     hostfxr!execute_app+0x2ac [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 145] 
1e    AMD64 000000e3`fefdf3f0 00007ffc`c5a30316     hostfxr!`anonymous namespace'::read_config_and_execute+0xa6 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 532] 
1f    AMD64 000000e3`fefdf4e0 00007ffc`c5a2e744     hostfxr!fx_muxer_t::handle_exec_host_command+0x166 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 1007] 
20    AMD64 000000e3`fefdf590 00007ffc`c5a28533     hostfxr!fx_muxer_t::execute+0x494 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 578] 
21    AMD64 000000e3`fefdf6d0 00007ff6`51ec3399     hostfxr!hostfxr_main_startupinfo+0xb3 [D:\a\_work\1\s\src\native\corehost\fxr\hostfxr.cpp @ 61] 
22    AMD64 000000e3`fefdf7d0 00007ff6`51ec3706     DetectMemoryLeak!exe_start+0x859 [D:\a\_work\1\s\src\native\corehost\corehost.cpp @ 242] 
23    AMD64 000000e3`fefdf9a0 00007ff6`51ec4c58     DetectMemoryLeak!wmain+0xa6 [D:\a\_work\1\s\src\native\corehost\corehost.cpp @ 313] 
24    AMD64 (Inline Function) --------`--------     DetectMemoryLeak!invoke_main+0x22 [D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 90] 
25    AMD64 000000e3`fefdf9d0 00007ffd`1535f0cc     DetectMemoryLeak!__scrt_common_main_seh+0x10c [D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 288] 
26  ARM64EC 000000e3`fefdfa10 00007ffd`152f6020     KERNEL32!$iexit_thunk$cdecl$i8$i8+0x1c
27  ARM64EC 000000e3`fefdfa40 00007ffd`17188308     KERNEL32!#BaseThreadInitThunk+0x30
28  ARM64EC 000000e3`fefdfa50 00000000`00000000     ntdll!#RtlUserThreadStart+0x48

  15  Id: 44b8.5344 Suspend: 1 Teb: 000000e3`ff173000 Unfrozen
 #   Arch   Child-SP          RetAddr               Call Site
00  ARM64EC 000000e3`822fe530 00007ffd`171cd188     ntdll!#NtWaitForAlertByThreadId+0x14
01  ARM64EC 000000e3`822fe540 00007ffd`171cc5e8     ntdll!#RtlpWaitOnCriticalSection+0x390
02  ARM64EC 000000e3`822fe650 00007ffd`171ca580     ntdll!#RtlpEnterCriticalSectionContended+0x308
03  ARM64EC 000000e3`822fe6d0 00007ffd`1727e654     ntdll!#RtlEnterCriticalSection+0x70
04  ARM64EC 000000e3`822fe6f0 00007ffc`9776b55a     ntdll!$ientry_thunk$cdecl$i8$i8+0x24
05    AMD64 000000e3`822fe7a0 00007ffc`979b04e4     coreclr!CrstBase::Enter+0x5a [D:\a\_work\1\s\src\coreclr\vm\crst.cpp @ 328] 
06    AMD64 (Inline Function) --------`--------     coreclr!CrstBase::AcquireLock+0x8 [D:\a\_work\1\s\src\coreclr\vm\crst.h @ 187] 
07    AMD64 (Inline Function) --------`--------     coreclr!CrstBase::CrstHolder::{ctor}+0xd [D:\a\_work\1\s\src\coreclr\vm\crst.h @ 378] 
08    AMD64 000000e3`822fe7d0 00007ffc`83bf8a97     coreclr!ProfToEEInterfaceImpl::GetNonGCHeapBounds+0x44 [D:\a\_work\1\s\src\coreclr\vm\proftoeeinterfaceimpl.cpp @ 7676] 
09    AMD64 000000e3`822fe810 00007ffc`83bf56f6     JetBrains_Profiler_Core!jbprof::GraphGatherer::get_non_gc_heaps+0xb7 [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\profilers\memory\GraphGatherer.cpp @ 174] 
0a    AMD64 000000e3`822feb70 00007ffc`83c90510     JetBrains_Profiler_Core!jbprof::GraphGatherer::WriteGarbageCollectionStarted+0x206 [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\profilers\memory\GraphGatherer.cpp @ 256] 
0b    AMD64 000000e3`822fee20 00007ffc`83c94f46     JetBrains_Profiler_Core!`jbprof::memory_profiler::GarbageCollectionStarted'::`10'::<lambda_2>::operator()+0x5b0 [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\profilers\memory\memory_profiler.gc.cpp @ 341] 
0c    AMD64 000000e3`822ff010 00007ffc`83c8d786     JetBrains_Profiler_Core!jbprof::do_noexcept_log<`jbprof::memory_profiler::GarbageCollectionStarted'::`10'::<lambda_2>,`jbprof::memory_profiler::GarbageCollectionStarted'::`10'::<lambda_3> >+0x26 [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\utility\do_noexcept_log.hpp @ 21] 
0d    AMD64 000000e3`822ff040 00007ffc`9796f587     JetBrains_Profiler_Core!jbprof::memory_profiler::GarbageCollectionStarted+0x2d6 [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\profilers\memory\memory_profiler.gc.cpp @ 342] 
0e    AMD64 000000e3`822ff170 00007ffc`979a694b     coreclr!EEToProfInterfaceImpl::GarbageCollectionStarted+0x7f [D:\a\_work\1\s\src\coreclr\vm\eetoprofinterfaceimpl.cpp @ 5866] 
0f    AMD64 000000e3`822ff1c0 00007ffc`978c5207     coreclr!ProfControlBlock::DoProfilerCallbackHelper<int (__cdecl*)(ProfilerInfo *),long (__cdecl*)(EEToProfInterfaceImpl *,int,int * const,enum __MIDL___MIDL_itf_corprof_0000_0001_0006),int,int *,enum __MIDL___MIDL_itf_corprof_0000_0001_0006>+0x3f [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 284] 
10    AMD64 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoOneProfilerIteration+0x5e [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 199] 
11    AMD64 (Inline Function) --------`--------     coreclr!ProfControlBlock::IterateProfilers+0x5e [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 207] 
12    AMD64 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoProfilerCallback+0x6c [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 295] 
13    AMD64 (Inline Function) --------`--------     coreclr!ProfControlBlock::GarbageCollectionStarted+0x6c [D:\a\_work\1\s\src\coreclr\inc\profilepriv.inl @ 1656] 
14    AMD64 000000e3`822ff200 00007ffc`9779fc49     coreclr!GarbageCollectionStartedCallback+0x12555f [D:\a\_work\1\s\src\coreclr\vm\proftoeeinterfaceimpl.cpp @ 680] 
15    AMD64 000000e3`822ff2a0 00007ffc`9779f4d0     coreclr!GCToEEInterface::DiagGCStart+0x1d [D:\a\_work\1\s\src\coreclr\vm\gcenv.ee.cpp @ 771] 
16    AMD64 000000e3`822ff300 00007ffc`977a1cf9     coreclr!WKS::gc_heap::garbage_collect+0x16c [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 23758] 
17    AMD64 000000e3`822ff350 00007ffc`97a237b9     coreclr!WKS::GCHeap::GarbageCollectGeneration+0x141 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 50081] 
18    AMD64 000000e3`822ff3a0 00007ffc`979d476e     coreclr!WKS::GCHeap::GarbageCollect+0xc9 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 49252] 
19    AMD64 000000e3`822ff3e0 00007ffc`979ab82f     coreclr!ETW::GCLog::ForceGCForDiagnostics+0xc6 [D:\a\_work\1\s\src\coreclr\vm\eventtrace_gcheap.cpp @ 492] 
1a    AMD64 000000e3`822ff4b0 00007ffc`83c6c9a4     coreclr!ProfToEEInterfaceImpl::ForceGC+0x7f [D:\a\_work\1\s\src\coreclr\vm\proftoeeinterfaceimpl.cpp @ 4686] 
1b    AMD64 000000e3`822ff4e0 00007ffc`83c6d8eb     JetBrains_Profiler_Core!jbprof::gc_command_queue::thread_data::force_gc_thread+0x264 [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\profilers\memory\gc_command_queue.cpp @ 367] 
1c    AMD64 000000e3`822ff730 00007ffc`83c71996     JetBrains_Profiler_Core!`jbprof::gc_command_queue::raw_force_gc_thread'::`2'::<lambda_1>::operator()+0xab [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\profilers\memory\gc_command_queue.cpp @ 303] 
1d    AMD64 000000e3`822ff7c0 00007ffc`83c7195b     JetBrains_Profiler_Core!jbprof::do_noexcept_log<`jbprof::gc_command_queue::raw_force_gc_thread'::`2'::<lambda_1>,`jbprof::do_noexcept_log<`jbprof::gc_command_queue::raw_force_gc_thread'::`2'::<lambda_1> >'::`2'::<lambda_1> >+0x26 [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\utility\do_noexcept_log.hpp @ 21] 
1e    AMD64 000000e3`822ff7f0 00007ffc`83c6c4ed     JetBrains_Profiler_Core!jbprof::do_noexcept_log<`jbprof::gc_command_queue::raw_force_gc_thread'::`2'::<lambda_1> >+0x2b [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\utility\do_noexcept_log.hpp @ 34] 
1f    AMD64 000000e3`822ff830 00007ffd`1535f0cc     JetBrains_Profiler_Core!jbprof::gc_command_queue::raw_force_gc_thread+0x5d [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\profilers\memory\gc_command_queue.cpp @ 305] 
20  ARM64EC 000000e3`822ff890 00007ffd`152f6020     KERNEL32!$iexit_thunk$cdecl$i8$i8+0x1c
21  ARM64EC 000000e3`822ff8c0 00007ffd`17188308     KERNEL32!#BaseThreadInitThunk+0x30
22  ARM64EC 000000e3`822ff8d0 00000000`00000000     ntdll!#RtlUserThreadStart+0x48

Could you please fix before release?

Tagging subscribers to this area: @tommcdon
See info in area-owners.md if you want to be subscribed.

Issue Details

---

Hi there,
We stared to use ICorProfilerInfo14::GetNonGCHeapBounds and got permanent red tests on Windows ARM64 for some kinds of x64 and x86 processes (it may be a coincidence). I think, the deadlock appears because we call ICorProfilerInfo14::GetNonGCHeapBounds inside ICorProfilerCallback2::GarbageCollectionStarted.

Stack trace:

0:000:ARM64EC> ~* k

.  0  Id: 44b8.57b8 Suspend: 1 Teb: 000000e3`ff155000 Unfrozen
 #   Arch   Child-SP          RetAddr               Call Site
00  ARM64EC 000000e3`fefde6f0 00007ffd`12e65334     ntdll!#NtWaitForSingleObject+0x14
01  ARM64EC 000000e3`fefde700 00007ffd`12f93444     KERNELBASE!WaitForSingleObjectEx+0x84
02  ARM64EC 000000e3`fefde790 00007ffc`97779e4d     KERNELBASE!$ientry_thunk$cdecl$i8$i8+0x24
03    AMD64 (Inline Function) --------`--------     coreclr!GCEvent::Impl::Wait+0xc [D:\a\_work\1\s\src\coreclr\gc\windows\gcenv.windows.cpp @ 1372] 
04    AMD64 (Inline Function) --------`--------     coreclr!GCEvent::Wait+0x13 [D:\a\_work\1\s\src\coreclr\gc\windows\gcenv.windows.cpp @ 1422] 
05    AMD64 000000e3`fefde840 00007ffc`979078ea     coreclr!WKS::gc_heap::wait_for_gc_done+0x29 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 14543] 
06    AMD64 (Inline Function) --------`--------     coreclr!WKS::WaitLonger+0x44 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 1635] 
07    AMD64 (Inline Function) --------`--------     coreclr!WKS::enter_spin_lock+0xa6e85 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 1690] 
08    AMD64 000000e3`fefde870 00007ffc`97860a17     coreclr!WKS::gc_heap::insert_ro_segment+0xa6eba [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 9868] 
09    AMD64 000000e3`fefde8c0 00007ffc`97864178     coreclr!WKS::GCHeap::RegisterFrozenSegment+0x87 [D:\a\_work\1\s\src\coreclr\gc\gcee.cpp @ 466] 
0a    AMD64 000000e3`fefde8f0 00007ffc`9778c21f     coreclr!FrozenObjectSegment::FrozenObjectSegment+0xb0 [D:\a\_work\1\s\src\coreclr\vm\frozenobjectheap.cpp @ 149] 
0b    AMD64 000000e3`fefde950 00007ffc`9778bc46     coreclr!FrozenObjectHeapManager::TryAllocateObject+0x15f [D:\a\_work\1\s\src\coreclr\vm\frozenobjectheap.cpp @ 66] 
0c    AMD64 (Inline Function) --------`--------     coreclr!AllocateString+0x4d [D:\a\_work\1\s\src\coreclr\vm\gchelpers.cpp @ 971] 
0d    AMD64 (Inline Function) --------`--------     coreclr!AllocateStringObject+0x54 [D:\a\_work\1\s\src\coreclr\vm\stringliteralmap.cpp @ 472] 
0e    AMD64 000000e3`fefde9d0 00007ffc`9778ba9d     coreclr!GlobalStringLiteralMap::AddStringLiteral+0x76 [D:\a\_work\1\s\src\coreclr\vm\stringliteralmap.cpp @ 503] 
0f    AMD64 (Inline Function) --------`--------     coreclr!GlobalStringLiteralMap::GetStringLiteral+0x5a [D:\a\_work\1\s\src\coreclr\vm\stringliteralmap.cpp @ 396] 
10    AMD64 000000e3`fefdeae0 00007ffc`977cbb22     coreclr!StringLiteralMap::GetStringLiteral+0xdd [D:\a\_work\1\s\src\coreclr\vm\stringliteralmap.cpp @ 170] 
11    AMD64 000000e3`fefdeb40 00007ffc`977cbaa8     coreclr!LoaderAllocator::GetStringObjRefPtrFromUnicodeString+0x4e [D:\a\_work\1\s\src\coreclr\vm\loaderallocator.cpp @ 1751] 
12    AMD64 000000e3`fefdeb80 00007ffc`977cba5d     coreclr!StringObject::InitEmptyStringRefPtr+0x48 [D:\a\_work\1\s\src\coreclr\vm\object.cpp @ 859] 
13    AMD64 000000e3`fefdebd0 00007ffc`977cb9f5     coreclr!StringObject::GetEmptyString+0x1d [D:\a\_work\1\s\src\coreclr\vm\object.h @ 989] 
14    AMD64 000000e3`fefdec00 00007ffc`97812877     coreclr!AppDomain::SetupSharedStatics+0x51 [D:\a\_work\1\s\src\coreclr\vm\appdomain.cpp @ 3059] 
15    AMD64 000000e3`fefdec40 00007ffc`9783c5a3     coreclr!EEStartupHelper+0x697 [D:\a\_work\1\s\src\coreclr\vm\ceemain.cpp @ 933] 
16    AMD64 000000e3`fefdee60 00007ffc`9783c54a     coreclr!EEStartup+0x27 [D:\a\_work\1\s\src\coreclr\vm\ceemain.cpp @ 1051] 
17    AMD64 000000e3`fefdeeb0 00007ffc`9783c488     coreclr!EnsureEEStarted+0x92 [D:\a\_work\1\s\src\coreclr\vm\ceemain.cpp @ 300] 
18    AMD64 000000e3`fefdef00 00007ffc`9784d040     coreclr!CorHost2::Start+0x58 [D:\a\_work\1\s\src\coreclr\vm\corhost.cpp @ 101] 
19    AMD64 000000e3`fefdef40 00007ffc`c47335b0     coreclr!coreclr_initialize+0x180 [D:\a\_work\1\s\src\coreclr\dlls\mscoree\exports.cpp @ 320] 
1a    AMD64 000000e3`fefdf010 00007ffc`c4752068     hostpolicy!coreclr_t::create+0x2b0 [D:\a\_work\1\s\src\native\corehost\hostpolicy\coreclr.cpp @ 73] 
1b    AMD64 000000e3`fefdf190 00007ffc`c4753c37     hostpolicy!`anonymous namespace'::create_coreclr+0x158 [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 82] 
1c    AMD64 000000e3`fefdf1f0 00007ffc`c5a2b5ac     hostpolicy!corehost_main+0x187 [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 427] 
1d    AMD64 000000e3`fefdf2f0 00007ffc`c5a2e166     hostfxr!execute_app+0x2ac [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 145] 
1e    AMD64 000000e3`fefdf3f0 00007ffc`c5a30316     hostfxr!`anonymous namespace'::read_config_and_execute+0xa6 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 532] 
1f    AMD64 000000e3`fefdf4e0 00007ffc`c5a2e744     hostfxr!fx_muxer_t::handle_exec_host_command+0x166 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 1007] 
20    AMD64 000000e3`fefdf590 00007ffc`c5a28533     hostfxr!fx_muxer_t::execute+0x494 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 578] 
21    AMD64 000000e3`fefdf6d0 00007ff6`51ec3399     hostfxr!hostfxr_main_startupinfo+0xb3 [D:\a\_work\1\s\src\native\corehost\fxr\hostfxr.cpp @ 61] 
22    AMD64 000000e3`fefdf7d0 00007ff6`51ec3706     DetectMemoryLeak!exe_start+0x859 [D:\a\_work\1\s\src\native\corehost\corehost.cpp @ 242] 
23    AMD64 000000e3`fefdf9a0 00007ff6`51ec4c58     DetectMemoryLeak!wmain+0xa6 [D:\a\_work\1\s\src\native\corehost\corehost.cpp @ 313] 
24    AMD64 (Inline Function) --------`--------     DetectMemoryLeak!invoke_main+0x22 [D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 90] 
25    AMD64 000000e3`fefdf9d0 00007ffd`1535f0cc     DetectMemoryLeak!__scrt_common_main_seh+0x10c [D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 288] 
26  ARM64EC 000000e3`fefdfa10 00007ffd`152f6020     KERNEL32!$iexit_thunk$cdecl$i8$i8+0x1c
27  ARM64EC 000000e3`fefdfa40 00007ffd`17188308     KERNEL32!#BaseThreadInitThunk+0x30
28  ARM64EC 000000e3`fefdfa50 00000000`00000000     ntdll!#RtlUserThreadStart+0x48

  15  Id: 44b8.5344 Suspend: 1 Teb: 000000e3`ff173000 Unfrozen
 #   Arch   Child-SP          RetAddr               Call Site
00  ARM64EC 000000e3`822fe530 00007ffd`171cd188     ntdll!#NtWaitForAlertByThreadId+0x14
01  ARM64EC 000000e3`822fe540 00007ffd`171cc5e8     ntdll!#RtlpWaitOnCriticalSection+0x390
02  ARM64EC 000000e3`822fe650 00007ffd`171ca580     ntdll!#RtlpEnterCriticalSectionContended+0x308
03  ARM64EC 000000e3`822fe6d0 00007ffd`1727e654     ntdll!#RtlEnterCriticalSection+0x70
04  ARM64EC 000000e3`822fe6f0 00007ffc`9776b55a     ntdll!$ientry_thunk$cdecl$i8$i8+0x24
05    AMD64 000000e3`822fe7a0 00007ffc`979b04e4     coreclr!CrstBase::Enter+0x5a [D:\a\_work\1\s\src\coreclr\vm\crst.cpp @ 328] 
06    AMD64 (Inline Function) --------`--------     coreclr!CrstBase::AcquireLock+0x8 [D:\a\_work\1\s\src\coreclr\vm\crst.h @ 187] 
07    AMD64 (Inline Function) --------`--------     coreclr!CrstBase::CrstHolder::{ctor}+0xd [D:\a\_work\1\s\src\coreclr\vm\crst.h @ 378] 
08    AMD64 000000e3`822fe7d0 00007ffc`83bf8a97     coreclr!ProfToEEInterfaceImpl::GetNonGCHeapBounds+0x44 [D:\a\_work\1\s\src\coreclr\vm\proftoeeinterfaceimpl.cpp @ 7676] 
09    AMD64 000000e3`822fe810 00007ffc`83bf56f6     JetBrains_Profiler_Core!jbprof::GraphGatherer::get_non_gc_heaps+0xb7 [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\profilers\memory\GraphGatherer.cpp @ 174] 
0a    AMD64 000000e3`822feb70 00007ffc`83c90510     JetBrains_Profiler_Core!jbprof::GraphGatherer::WriteGarbageCollectionStarted+0x206 [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\profilers\memory\GraphGatherer.cpp @ 256] 
0b    AMD64 000000e3`822fee20 00007ffc`83c94f46     JetBrains_Profiler_Core!`jbprof::memory_profiler::GarbageCollectionStarted'::`10'::<lambda_2>::operator()+0x5b0 [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\profilers\memory\memory_profiler.gc.cpp @ 341] 
0c    AMD64 000000e3`822ff010 00007ffc`83c8d786     JetBrains_Profiler_Core!jbprof::do_noexcept_log<`jbprof::memory_profiler::GarbageCollectionStarted'::`10'::<lambda_2>,`jbprof::memory_profiler::GarbageCollectionStarted'::`10'::<lambda_3> >+0x26 [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\utility\do_noexcept_log.hpp @ 21] 
0d    AMD64 000000e3`822ff040 00007ffc`9796f587     JetBrains_Profiler_Core!jbprof::memory_profiler::GarbageCollectionStarted+0x2d6 [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\profilers\memory\memory_profiler.gc.cpp @ 342] 
0e    AMD64 000000e3`822ff170 00007ffc`979a694b     coreclr!EEToProfInterfaceImpl::GarbageCollectionStarted+0x7f [D:\a\_work\1\s\src\coreclr\vm\eetoprofinterfaceimpl.cpp @ 5866] 
0f    AMD64 000000e3`822ff1c0 00007ffc`978c5207     coreclr!ProfControlBlock::DoProfilerCallbackHelper<int (__cdecl*)(ProfilerInfo *),long (__cdecl*)(EEToProfInterfaceImpl *,int,int * const,enum __MIDL___MIDL_itf_corprof_0000_0001_0006),int,int *,enum __MIDL___MIDL_itf_corprof_0000_0001_0006>+0x3f [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 284] 
10    AMD64 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoOneProfilerIteration+0x5e [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 199] 
11    AMD64 (Inline Function) --------`--------     coreclr!ProfControlBlock::IterateProfilers+0x5e [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 207] 
12    AMD64 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoProfilerCallback+0x6c [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 295] 
13    AMD64 (Inline Function) --------`--------     coreclr!ProfControlBlock::GarbageCollectionStarted+0x6c [D:\a\_work\1\s\src\coreclr\inc\profilepriv.inl @ 1656] 
14    AMD64 000000e3`822ff200 00007ffc`9779fc49     coreclr!GarbageCollectionStartedCallback+0x12555f [D:\a\_work\1\s\src\coreclr\vm\proftoeeinterfaceimpl.cpp @ 680] 
15    AMD64 000000e3`822ff2a0 00007ffc`9779f4d0     coreclr!GCToEEInterface::DiagGCStart+0x1d [D:\a\_work\1\s\src\coreclr\vm\gcenv.ee.cpp @ 771] 
16    AMD64 000000e3`822ff300 00007ffc`977a1cf9     coreclr!WKS::gc_heap::garbage_collect+0x16c [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 23758] 
17    AMD64 000000e3`822ff350 00007ffc`97a237b9     coreclr!WKS::GCHeap::GarbageCollectGeneration+0x141 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 50081] 
18    AMD64 000000e3`822ff3a0 00007ffc`979d476e     coreclr!WKS::GCHeap::GarbageCollect+0xc9 [D:\a\_work\1\s\src\coreclr\gc\gc.cpp @ 49252] 
19    AMD64 000000e3`822ff3e0 00007ffc`979ab82f     coreclr!ETW::GCLog::ForceGCForDiagnostics+0xc6 [D:\a\_work\1\s\src\coreclr\vm\eventtrace_gcheap.cpp @ 492] 
1a    AMD64 000000e3`822ff4b0 00007ffc`83c6c9a4     coreclr!ProfToEEInterfaceImpl::ForceGC+0x7f [D:\a\_work\1\s\src\coreclr\vm\proftoeeinterfaceimpl.cpp @ 4686] 
1b    AMD64 000000e3`822ff4e0 00007ffc`83c6d8eb     JetBrains_Profiler_Core!jbprof::gc_command_queue::thread_data::force_gc_thread+0x264 [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\profilers\memory\gc_command_queue.cpp @ 367] 
1c    AMD64 000000e3`822ff730 00007ffc`83c71996     JetBrains_Profiler_Core!`jbprof::gc_command_queue::raw_force_gc_thread'::`2'::<lambda_1>::operator()+0xab [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\profilers\memory\gc_command_queue.cpp @ 303] 
1d    AMD64 000000e3`822ff7c0 00007ffc`83c7195b     JetBrains_Profiler_Core!jbprof::do_noexcept_log<`jbprof::gc_command_queue::raw_force_gc_thread'::`2'::<lambda_1>,`jbprof::do_noexcept_log<`jbprof::gc_command_queue::raw_force_gc_thread'::`2'::<lambda_1> >'::`2'::<lambda_1> >+0x26 [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\utility\do_noexcept_log.hpp @ 21] 
1e    AMD64 000000e3`822ff7f0 00007ffc`83c6c4ed     JetBrains_Profiler_Core!jbprof::do_noexcept_log<`jbprof::gc_command_queue::raw_force_gc_thread'::`2'::<lambda_1> >+0x2b [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\utility\do_noexcept_log.hpp @ 34] 
1f    AMD64 000000e3`822ff830 00007ffd`1535f0cc     JetBrains_Profiler_Core!jbprof::gc_command_queue::raw_force_gc_thread+0x5d [C:\Work\dotnet-products\Profiler\Native\Solution\core\src\profilers\memory\gc_command_queue.cpp @ 305] 
20  ARM64EC 000000e3`822ff890 00007ffd`152f6020     KERNEL32!$iexit_thunk$cdecl$i8$i8+0x1c
21  ARM64EC 000000e3`822ff8c0 00007ffd`17188308     KERNEL32!#BaseThreadInitThunk+0x30
22  ARM64EC 000000e3`822ff8d0 00000000`00000000     ntdll!#RtlUserThreadStart+0x48

Could you please fix before release?

Author:	ww898
Assignees:	-
Labels:	area-Diagnostics-coreclr
Milestone:	-

[EgorBo]

Thanks for the feedback! Checking it now

[ww898]

Hi @EgorBo,

Our profiler run the separate helper thread which is used only for ForceGC calls and immediately asked to execute ForceGC (because some data in .NET is only available after the first GC). It happens somewhere at the end of SystemDomain::NotifyProfilerStartup in ICorProfilerCallback::AppDomainCreationStarted. Then SetupSharedStatics allocates memory in FOH...

#ifdef PROFILING_SUPPORTED
        // <TODO>This is to compensate for the DefaultDomain workaround contained in
        // SystemDomain::Attach in which the first user domain is created before profiling
        // services can be initialized.  Profiling services cannot be moved to before the
        // workaround because it needs SetupThread to be called.</TODO>

        SystemDomain::NotifyProfilerStartup();
#endif // PROFILING_SUPPORTED

        g_fEEInit = false;

        SystemDomain::System()->DefaultDomain()->LoadSystemAssemblies();

        SystemDomain::System()->DefaultDomain()->SetupSharedStatics();

[EgorBo]

Thanks! I have a limited understanding of VM's internals and Profiler APIs so my interpretation of what is happening is:

One thread is registering a frozen segment (empty string literal object triggered it) in COOP mode + it owns FrozenObjectHeapManager::m_Crst lock (that has CRST_UNSAFE_COOPGC if that is important). During that registration it is waiting for GC to finish (wait_for_gc_done) while still being under that lock and coop.

Presumably, GC waits for Profiler's thread (preemptive?) to finish/reach a safepoint that is waiting for Lock to release here:

runtime/src/coreclr/vm/proftoeeinterfaceimpl.cpp

Line 7676 in 5b448cf

CrstHolder ch(&foh->m_Crst);

[EgorBo]

@jkotas @davmason does what I am saying make any sense? Should we maybe switch to preemptive to call RegisterFrozenSegment in FrozenObjectHeapManager? (or avoid CRST_UNSAFE_COOPGC)

Perhaps, CRST_UNSAFE_COOPGC is incorrect for profiler's thread to take the lock (as it switches to coop?) and CRST_UNSAFE_ANYMODE should be used instead?

PS: it seems that we don't really need to take any lock to enumerate the nongc heap since it's never shrinked, but the last object can be not fully initialized yet.

[EgorBo]

Managed to reproduce this locally based on our profiler test suite (modified runtime to create new frozen segment for each object) + created a thread that does forcegc in while(true) loop in background.

It seems that the problem that we should not take any locks in GC's callbacks, e.g. GarbageCollectionFinished
so my repro produces the same call stacks, e.g.:

1. Thread1 attempts to register a new ro segment and end up spinning & waiting for GC to complete: https://gist.github.com/EgorBo/b41c608f1cb94a7ab11e8247d3b1f613
2. Thread2 - is a GC's callback that is used by profiler to enumerate objects. Inside that callback we take the lock again and end up deadlocking https://gist.github.com/EgorBo/d445cac221db520e549b3e3b236a97ea

[jkotas]

This looks like a classic A->B, B->A deadlock.

The thread that is registering the frozen segment takes the locks in FrozenObjectHeapManager::m_crst -> gc_lock order, the GC thread running the garbage collection takes them in opposite order gc_lock -> FrozenObjectHeapManager::m_crst.

The easiest way to fix it may be to release the FrozenObjectHeapManager lock while registering the new segment with the GC. A second fine-grained lock can be used to prevent the segment from being registered more than once. Something like:

take FrozenObjectHeapManager::m_crst
{
    if (not enough space)
    {
        allocate new segment
    }

    allocate the object
}
release FrozenObjectHeapManager::m_crst

if (!pSegmentUsedForAllocation->_isRegistered)
{
    take FrozenObjectHeapManager::m_crstRegistration

    register pSegmentUsedForAllocation with the GC
    pSegmentUsedForAllocation->_isRegistered

    release FrozenObjectHeapManager::m_crstRegistration
}

if (publish)
{
    PublishFrozenObject(obj);
}

(There are number of other ways to fix it. I am not attached to this particular way of fixing it.)

It seems that the problem that we should not take any locks in GC's callbacks

You can take locks in GC callback. Such locks should never be taken around GC lock on other threads.