search

dotnet / runtime

.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps.
https://docs.microsoft.com/dotnet/core/
MIT License
14.96k stars 4.65k forks source link

[Help] [RISC-V] GC crash on System.Diagnostics.Tests.DiagnosticSourceTest.AllSubscriberStress #105808

Open t-mustafin opened 1 month ago

t-mustafin commented 1 month ago

Common information

Test System.Diagnostics.Tests.DiagnosticSourceTest.AllSubscriberStress catches intermittent crash on VisionFive2 board with disabled TieredCompilation. Run command and log:

/home/tmustafin/main_31jul_checkedO0_46ac2f8/corefx_tc/coreroot/dotnet exec --runtimeconfig System.Diagnostics.DiagnosticSource.Tests.runtimeconfig.json xunit.console.dll System.Diagnostics.DiagnosticSource.Tests.dll -xml tmp/testResults.xml -nologo -notrait category=nonnetcoreapptests -notrait category=nonlinuxtests -notrait category=failing -trait category=OuterLoop -parallel none -verbose -method "System.Diagnostics.Tests.DiagnosticSourceTest.AllSubscriberStress"
  Discovering: System.Diagnostics.DiagnosticSource.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.Diagnostics.DiagnosticSource.Tests (found 1 of 281 test case)
  Starting:    System.Diagnostics.DiagnosticSource.Tests (parallel test collections = off, stop on fail = off)
    System.Diagnostics.Tests.DiagnosticSourceTest.AllSubscriberStress(numThreads: 100, numListenersPerThread: 100) [STARTING]
   System.Diagnostics.DiagnosticSource.Tests: [Long Running Test] 'System.Diagnostics.Tests.DiagnosticSourceTest.AllSubscriberStress', Elapsed: 00:02:09

Assert failure(PID 26084 [0x000065e4], Thread: 26162 [0x6632]): (GetComponentSize() <= 2) || IsArray()
    File: /home/runtime/src/coreclr/vm/methodtable.cpp:6286
    Image: /home/tmustafin/main_31jul_checkedO0_46ac2f8/corefx_tc/dotnet_host/dotnet

Test behavior is intermittent: different asserts may fire or SIGSEGV may happen or even the test can pass. The most common path on crash inside Object::Validate, called from GC invocation. Backtrace for the assert crash above is:

(gdb) bt

#0  DBG_DebugBreak () at /home/runtime/src/coreclr/pal/src/arch/riscv64/debugbreak.S:6
#1  0x0000003ff76b131a in DebugBreak () at /home/runtime/src/coreclr/pal/src/debug/debug.cpp:407
#2  0x0000003ff74c3dca in DbgAssertDialog (szFile=0x3ff77c9a44 "/home/runtime/src/coreclr/vm/methodtable.cpp", iLine=6286, szExpr=0x3ff77caa52 "(GetComponentSize() <= 2) || IsArray()") at /home/runtime/src/coreclr/utilcode/debug.cpp:431
#3  0x0000003ff6fb7632 in MethodTable::SanityCheck (this=0xaad547df8) at /home/runtime/src/coreclr/vm/methodtable.cpp:6286
#4  0x0000003ff6fbd5d2 in MethodTable::Validate (this=0xaad547df8) at /home/runtime/src/coreclr/vm/methodtable.cpp:8456
#5  0x0000003ff6fc59e8 in Object::ValidateInner (this=0xaad77f078, bDeep=1, bVerifyNextHeader=1, bVerifySyncBlock=1) at /home/runtime/src/coreclr/vm/object.cpp:553
#6  0x0000003ff6fc4d02 in Object::Validate (this=0xaad77f078, bDeep=1, bVerifyNextHeader=1, bVerifySyncBlock=1) at /home/runtime/src/coreclr/vm/object.cpp:529
#7  0x0000003ff729df72 in GcInfoDecoder::ReportRegisterToGC (this=0x3e8c7dc120, regNum=22, gcFlags=0, pRD=0x3e8c7dd490, flags=0, pCallBack=0x3ff7131da0 <GcEnumObject(void*, OBJECTREF*, unsigned int)>, hCallBack=0x3e8c7dddf0) at /home/runtime/src/coreclr/vm/gcinfodecoder.cpp:2129
#8  0x0000003ff729cfe2 in GcInfoDecoder::ReportSlotToGC (this=0x3e8c7dc120, slotDecoder=..., slotIndex=13, pRD=0x3e8c7dd490, reportScratchSlots=false, inputFlags=0, pCallBack=0x3ff7131da0 <GcEnumObject(void*, OBJECTREF*, unsigned int)>, hCallBack=0x3e8c7dddf0) at /home/runtime/src/coreclr/inc/gcinfodecoder.h:715
#9  0x0000003ff729c4f2 in GcInfoDecoder::EnumerateLiveSlots (this=0x3e8c7dc120, pRD=0x3e8c7dd490, reportScratchSlots=false, inputFlags=0, pCallBack=0x3ff7131da0 <GcEnumObject(void*, OBJECTREF*, unsigned int)>, hCallBack=0x3e8c7dddf0) at /home/runtime/src/coreclr/vm/gcinfodecoder.cpp:1065
#10 0x0000003ff6edf5b6 in EECodeManager::EnumGcRefs (this=0x2aaab2d710, pRD=0x3e8c7dd490, pCodeInfo=0x3e8c7dd2f0, flags=0, pCallBack=0x3ff7131da0 <GcEnumObject(void*, OBJECTREF*, unsigned int)>, hCallBack=0x3e8c7dddf0, relOffsetOverride=4294967295) at /home/runtime/src/coreclr/vm/eetwain.cpp:1542
#11 0x0000003ff7132d7a in GcStackCrawlCallBack (pCF=0x3e8c7dd0c0, pData=0x3e8c7dddf0) at /home/runtime/src/coreclr/vm/gcenv.ee.common.cpp:329
#12 0x0000003ff701511c in Thread::MakeStackwalkerCallback (this=0x2aaae77940, pCF=0x3e8c7dd0c0, pCallback=0x3ff7131f84 <GcStackCrawlCallBack(CrawlFrame*, void*)>, pData=0x3e8c7dddf0, uFramesProcessed=9) at /home/runtime/src/coreclr/vm/stackwalk.cpp:831
#13 0x0000003ff701535c in Thread::StackWalkFramesEx (this=0x2aaae77940, pRD=0x3e8c7dd490, pCallback=0x3ff7131f84 <GcStackCrawlCallBack(CrawlFrame*, void*)>, pData=0x3e8c7dddf0, flags=34048, pStartFrame=0x0) at /home/runtime/src/coreclr/vm/stackwalk.cpp:911
#14 0x0000003ff701613a in Thread::StackWalkFrames (this=0x2aaae77940, pCallback=0x3ff7131f84 <GcStackCrawlCallBack(CrawlFrame*, void*)>, pData=0x3e8c7dddf0, flags=34048, pStartFrame=0x0) at /home/runtime/src/coreclr/vm/stackwalk.cpp:991
#15 0x0000003ff712b75c in ScanStackRoots (pThread=0x2aaae77940, fn=0x3ff73bacb8 <WKS::GCHeap::Promote(Object**, ScanContext*, unsigned int)>, sc=0x3e8c7de348) at /home/runtime/src/coreclr/vm/gcenv.ee.cpp:204
#16 0x0000003ff712b3a6 in GCToEEInterface::GcScanRoots (fn=0x3ff73bacb8 <WKS::GCHeap::Promote(Object**, ScanContext*, unsigned int)>, condemned=0, max_gen=2, sc=0x3e8c7de348) at /home/runtime/src/coreclr/vm/gcenv.ee.cpp:305
#17 0x0000003ff72d2ee4 in GCScan::GcScanRoots (fn=0x3ff73bacb8 <WKS::GCHeap::Promote(Object**, ScanContext*, unsigned int)>, condemned=0, max_gen=2, sc=0x3e8c7de348) at /home/runtime/src/coreclr/gc/gcscan.cpp:152
#18 0x0000003ff739c19e in WKS::gc_heap::mark_phase (condemned_gen_number=0) at /home/runtime/src/coreclr/gc/gc.cpp:29550
#19 0x0000003ff7397c6e in WKS::gc_heap::gc1 () at /home/runtime/src/coreclr/gc/gc.cpp:22276
#20 0x0000003ff73ad2d8 in WKS::gc_heap::garbage_collect (n=0) at /home/runtime/src/coreclr/gc/gc.cpp:24355
#21 0x0000003ff738e146 in WKS::GCHeap::GarbageCollectGeneration (this=0x2aaaaeaba0, gen=0, reason=reason_alloc_soh) at /home/runtime/src/coreclr/gc/gc.cpp:50593
#22 0x0000003ff738ff68 in WKS::gc_heap::trigger_gc_for_alloc (gen_number=0, gr=reason_alloc_soh, msl=0x3ff7adc478 <WKS::gc_heap::more_space_lock_soh>, loh_p=false, take_state=WKS::mt_try_budget) at /home/runtime/src/coreclr/gc/gc.cpp:18818
#23 0x0000003ff739128a in WKS::gc_heap::try_allocate_more_space (acontext=0x3e8c7e09d0, size=24, flags=2, gen_number=0) at /home/runtime/src/coreclr/gc/gc.cpp:18956
#24 0x0000003ff739149e in WKS::gc_heap::allocate_more_space (acontext=0x3e8c7e09d0, size=24, flags=2, alloc_generation_number=0) at /home/runtime/src/coreclr/gc/gc.cpp:19456
#25 0x0000003ff73e073a in WKS::gc_heap::allocate (jsize=24, acontext=0x3e8c7e09d0, flags=2) at /home/runtime/src/coreclr/gc/gc.cpp:19487
#26 WKS::GCHeap::Alloc (this=0x2aaaaeaba0, context=0x3e8c7e09d0, size=24, flags=2) at /home/runtime/src/coreclr/gc/gc.cpp:49515
#27 0x0000003ff71349fc in Alloc (size=24, flags=GC_ALLOC_CONTAINS_REF) at /home/runtime/src/coreclr/vm/gchelpers.cpp:227
#28 0x0000003ff713675a in AllocateObject (pMT=0x3f7a865f28, flags=GC_ALLOC_CONTAINS_REF) at /home/runtime/src/coreclr/vm/gchelpers.cpp:1051
#29 0x0000003ff6e270d8 in AllocateObject (pMT=0x3f7a865f28) at /home/runtime/src/coreclr/vm/gchelpers.h:68
#30 0x0000003ff715d16a in JIT_New (typeHnd_=0x3f7a865f28) at /home/runtime/src/coreclr/vm/jithelpers.cpp:1264
#31 0x0000003ff715ccce in JIT_NewS_MP_FastPortable (typeHnd_=0x3f7a865f28) at /home/runtime/src/coreclr/vm/jithelpers.cpp:1229
#32 0x0000003f7a4d69a0 in ?? ()

(gdb) frame 32

#32 0x0000003f7a4d69a0 in ?? ()
(gdb) btm

# 0 0x3f7a4d69a0   void [xunit.assert] Xunit.Assert::DoesNotContain(!!0,class [System.Runtime]System.Collections.Generic.IEnumerable`1<!!0>)[Optimized]
# 1 0x3f7a4d3608   void [xunit.assert] Xunit.Assert::All(class [System.Runtime]System.Collections.Generic.IEnumerable`1<!!0>,class [System.Runtime]System.Action`2<!!0,int32>)[Optimized]
# 2 0x3f7a4cb488   instance void [System.Diagnostics.DiagnosticSource.Tests] System.Diagnostics.Tests.DiagnosticSourceTest+<>c__DisplayClass10_1::<AllSubscriberStress>b__1()[Optimized]
# 3 0x3f7a139210   void [System.Private.CoreLib] System.Threading.ExecutionContext::RunInternal(class System.Threading.ExecutionContext,class System.Threading.ContextCallback,object)[Optimized]
# 4 0x3f7a138cd4   instance void [System.Private.CoreLib] System.Threading.Tasks.Task::ExecuteWithThreadLocal(class System.Threading.Tasks.Task&,class System.Threading.Thread)[Optimized]

Testcase creates 100 threads and each thread allocates 100-104 DiagnosticListener objects. Frame 13 above with this of type Thread gives information about thread with problematic stack which breaks stack-walking algorithm:

Hidden gdblog ``` (gdb) frame 13 #13 0x0000003ff701535c in Thread::StackWalkFramesEx (this=0x2aaae77940, pRD=0x3e8c7dd490, pCallback=0x3ff7131f84 , pData=0x3e8c7dddf0, flags=34048, pStartFrame=0x0) at /home/runtime/src/coreclr/vm/stackwalk.cpp:911 911 /home/runtime/src/coreclr/vm/stackwalk.cpp: No such file or directory. (gdb) p this->m_OSThreadId $20 = 26173 (gdb) info threads Id Target Id Frame 1 Thread 0x3ff7c3bee0 (LWP 26084) "dotnet" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaaadb684) at ./nptl/futex-internal.c:57 2 Thread 0x3f77d82160 (LWP 26085) ".NET SynchManag" 0x0000003ff7cee29c in __GI___poll (fds=0x3f77d81370, nfds=1, timeout=) at ../sysdeps/unix/sysv/linux/poll.c:41 3 Thread 0x3f77581160 (LWP 26086) ".NET EventPipe" 0x0000003ff7cee29c in __GI___poll (fds=0x3f68000da0, nfds=1, timeout=) at ../sysdeps/unix/sysv/linux/poll.c:41 4 Thread 0x3f76d5f160 (LWP 26087) ".NET DebugPipe" 0x0000003ff7ceb480 in __libc_open64 (file=0x2aaaad9434 "/tmp/clr-debug-pipe-26084-1588666088-in", oflag=) at ../sysdeps/unix/sysv/linux/open64.c:41 5 Thread 0x3f7655e160 (LWP 26088) ".NET Debugger" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab40680) at ./nptl/futex-internal.c:57 6 Thread 0x3f75c48160 (LWP 26089) ".NET Finalizer" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x3f75c46b78, op=, expected=, futex_word=0x2aaab53c94) at ./nptl/futex-internal.c:57 7 Thread 0x3f1321f160 (LWP 26095) ".NET SigHandler" __GI___libc_read (nbytes=1, buf=0x3f1321e85f, fd=143) at ../sysdeps/unix/sysv/linux/read.c:26 10 Thread 0x3f12a12160 (LWP 26104) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aab0e3f70) at ./nptl/futex-internal.c:57 11 Thread 0x3f1220d160 (LWP 26105) ".NET TP Worker" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x3f1220b3d8, op=, expected=, futex_word=0x3f0401cb74) at ./nptl/futex-internal.c:57 12 Thread 0x3f7421c160 (LWP 26106) ".NET TP Gate" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x3f04024a70) at ./nptl/futex-internal.c:57 13 Thread 0x3f119d9160 (LWP 26107) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 14 Thread 0x3f111d8160 (LWP 26108) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 15 Thread 0x3f109d7160 (LWP 26109) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 16 Thread 0x3ef3fff160 (LWP 26110) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 17 Thread 0x3ef37fe160 (LWP 26111) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 18 Thread 0x3ef2ffd160 (LWP 26112) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 19 Thread 0x3ef27fc160 (LWP 26113) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 20 Thread 0x3ef1ffb160 (LWP 26114) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 21 Thread 0x3ef17fa160 (LWP 26115) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 22 Thread 0x3ef0ff9160 (LWP 26116) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 23 Thread 0x3ed3fff160 (LWP 26117) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 24 Thread 0x3ed37fe160 (LWP 26118) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 25 Thread 0x3ed2ffd160 (LWP 26119) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 26 Thread 0x3ed27fc160 (LWP 26120) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 27 Thread 0x3ed1ffb160 (LWP 26121) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 28 Thread 0x3ed17fa160 (LWP 26122) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 29 Thread 0x3ed0ff9160 (LWP 26123) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 30 Thread 0x3eb3fff160 (LWP 26124) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 31 Thread 0x3eb37fe160 (LWP 26125) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 32 Thread 0x3eb2ffd160 (LWP 26126) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 33 Thread 0x3eb27fc160 (LWP 26127) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 34 Thread 0x3eb1ffb160 (LWP 26128) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 35 Thread 0x3eb17fa160 (LWP 26129) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 36 Thread 0x3eb0ff9160 (LWP 26130) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 37 Thread 0x3e9bfff160 (LWP 26131) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 38 Thread 0x3e9b7fe160 (LWP 26132) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 39 Thread 0x3e9affd160 (LWP 26133) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 40 Thread 0x3e9a7fc160 (LWP 26134) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 41 Thread 0x3e99ffb160 (LWP 26135) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 42 Thread 0x3e997fa160 (LWP 26136) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 43 Thread 0x3e98ff9160 (LWP 26137) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 44 Thread 0x3e987f8160 (LWP 26138) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 45 Thread 0x3e97ff7160 (LWP 26139) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 46 Thread 0x3e977f6160 (LWP 26140) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 47 Thread 0x3e96ff5160 (LWP 26141) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 48 Thread 0x3e967f4160 (LWP 26142) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 49 Thread 0x3e95ff3160 (LWP 26143) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 50 Thread 0x3e957f2160 (LWP 26144) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 51 Thread 0x3e94ff1160 (LWP 26145) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 52 Thread 0x3e947f0160 (LWP 26146) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 53 Thread 0x3e93fef160 (LWP 26147) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 54 Thread 0x3e937ee160 (LWP 26148) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 55 Thread 0x3e92fed160 (LWP 26149) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 56 Thread 0x3e927ec160 (LWP 26150) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 57 Thread 0x3e91feb160 (LWP 26151) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 58 Thread 0x3e917ea160 (LWP 26152) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f47c) at ./nptl/futex-internal.c:57 59 Thread 0x3e90fe9160 (LWP 26153) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 60 Thread 0x3e907e8160 (LWP 26154) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 61 Thread 0x3e8ffe7160 (LWP 26155) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 62 Thread 0x3e8f7e6160 (LWP 26156) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 63 Thread 0x3e8efe5160 (LWP 26157) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 64 Thread 0x3e8e7e4160 (LWP 26158) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 65 Thread 0x3e8dfe3160 (LWP 26159) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 66 Thread 0x3e8d7e2160 (LWP 26160) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 67 Thread 0x3e8cfe1160 (LWP 26161) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 * 68 Thread 0x3e8c7e0160 (LWP 26162) ".NET Long Runni" DBG_DebugBreak () at /home/runtime/src/coreclr/pal/src/arch/riscv64/debugbreak.S:6 69 Thread 0x3e8bfdf160 (LWP 26163) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 70 Thread 0x3e8b7de160 (LWP 26164) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 71 Thread 0x3e8afdd160 (LWP 26165) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 72 Thread 0x3e8a7dc160 (LWP 26166) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 73 Thread 0x3e89fdb160 (LWP 26167) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 74 Thread 0x3e897da160 (LWP 26168) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 75 Thread 0x3e88fd9160 (LWP 26169) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 76 Thread 0x3e887d8160 (LWP 26170) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 77 Thread 0x3e87fd7160 (LWP 26171) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 78 Thread 0x3e877d6160 (LWP 26172) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 79 Thread 0x3e86fd5160 (LWP 26173) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 80 Thread 0x3e867d4160 (LWP 26174) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 81 Thread 0x3e85fd3160 (LWP 26175) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 82 Thread 0x3e857d2160 (LWP 26176) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 83 Thread 0x3e84fd1160 (LWP 26177) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 84 Thread 0x3e847d0160 (LWP 26178) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 85 Thread 0x3e83fcf160 (LWP 26179) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 86 Thread 0x3e837ce160 (LWP 26180) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 87 Thread 0x3e82fcd160 (LWP 26181) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 88 Thread 0x3e827cc160 (LWP 26182) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 89 Thread 0x3e81fcb160 (LWP 26183) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 90 Thread 0x3e817ca160 (LWP 26184) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 91 Thread 0x3e80fc9160 (LWP 26185) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 92 Thread 0x3e807c8160 (LWP 26186) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 93 Thread 0x3e7ffc7160 (LWP 26187) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 94 Thread 0x3e7f7c6160 (LWP 26188) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 95 Thread 0x3e7efc5160 (LWP 26189) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 96 Thread 0x3e7e7c4160 (LWP 26190) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 97 Thread 0x3e7dfc3160 (LWP 26191) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 98 Thread 0x3e7d7c2160 (LWP 26192) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 99 Thread 0x3e7cfc1160 (LWP 26193) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 100 Thread 0x3e7c7c0160 (LWP 26194) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 101 Thread 0x3e7bfbf160 (LWP 26195) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 102 Thread 0x3e7b7be160 (LWP 26196) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 103 Thread 0x3e7afbd160 (LWP 26197) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 104 Thread 0x3e7a7bc160 (LWP 26198) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 105 Thread 0x3e79fbb160 (LWP 26199) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 106 Thread 0x3e797ba160 (LWP 26200) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 107 Thread 0x3e78fb9160 (LWP 26201) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 108 Thread 0x3e787b8160 (LWP 26202) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 109 Thread 0x3e77fb7160 (LWP 26203) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 110 Thread 0x3e777b6160 (LWP 26204) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 111 Thread 0x3e76fb5160 (LWP 26205) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 112 Thread 0x3e767b4160 (LWP 26206) ".NET Long Runni" __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 (gdb) thread 79 [Switching to thread 79 (Thread 0x3e86fd5160 (LWP 26173))] #0 __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 57 ./nptl/futex-internal.c: No such file or directory. (gdb) bt #0 __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab4f40c) at ./nptl/futex-internal.c:57 #1 __futex_abstimed_wait_common (futex_word=futex_word@entry=0x2aaab4f40c, expected=, clockid=, abstime=abstime@entry=0x0, private=, cancel=cancel@entry=true) at ./nptl/futex-internal.c:87 #2 0x0000003ff7ca4f72 in __GI___futex_abstimed_wait_cancelable64 (futex_word=futex_word@entry=0x2aaab4f40c, expected=expected@entry=0, clockid=clockid@entry=0, abstime=abstime@entry=0x0, private=private@entry=0) at ./nptl/futex-internal.c:139 #3 0x0000003ff7ca6ce4 in __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x2aaab4f410, cond=0x2aaab4f3e0) at ./nptl/pthread_cond_wait.c:503 #4 ___pthread_cond_wait (cond=0x2aaab4f3e0, mutex=0x2aaab4f410) at ./nptl/pthread_cond_wait.c:618 #5 0x0000003ff76aad28 in GCEvent::Impl::Wait (this=0x2aaab4f3e0, milliseconds=4294967295, alertable=false) at /home/runtime/src/coreclr/gc/unix/events.cpp:149 #6 0x0000003ff76aac76 in GCEvent::Wait (this=0x2aaaadfe60, timeout=4294967295, alertable=false) at /home/runtime/src/coreclr/gc/unix/events.cpp:255 #7 0x0000003ff73ebc3e in WKS::GCHeap::WaitUntilGCComplete (this=0x2aaaaeaba0, bConsiderGCStart=false) at /home/runtime/src/coreclr/gc/gcee.cpp:265 #8 0x0000003ff72565b6 in Thread::RareDisablePreemptiveGC (this=0x2aaae77940) at /home/runtime/src/coreclr/vm/threadsuspend.cpp:2230 #9 0x0000003ff6e39dc0 in Thread::DisablePreemptiveGC (this=0x2aaae77940) at /home/runtime/src/coreclr/vm/threads.h:1291 #10 0x0000003ff6e3bc52 in GCHolderBase::PopInternal<0> (this=0x3e86fd0860) at /home/runtime/src/coreclr/vm/threads.h:4595 #11 0x0000003ff6e26f04 in GCPreemp::~GCPreemp (this=0x3e86fd0860) at /home/runtime/src/coreclr/vm/threads.h:4943 #12 0x0000003ff6f70f90 in invokeCompileMethod (jitMgr=0x2aaab2d730, comp=0x3e86fd0da0, info=0x3e86fd0bc8, jitFlags=..., nativeEntry=0x3e86fd0b78, nativeSizeOfCode=0x3e86fd0b74) at /home/runtime/src/coreclr/vm/jitinterface.cpp:12546 #13 0x0000003ff6f72216 in UnsafeJitFunction (config=0x3e86fd2088, ILHeader=0x3e86fd1af8, pJitFlags=0x3e86fd19c0, pSizeOfCode=0x3e86fd1b54) at /home/runtime/src/coreclr/vm/jitinterface.cpp:12980 #14 0x0000003ff6fe83b8 in MethodDesc::JitCompileCodeLocked (this=0x3f7a8d8968, pConfig=0x3e86fd2088, pilHeader=0x3e86fd1af8, pEntry=0x3ecc0533f0, pSizeOfCode=0x3e86fd1b54) at /home/runtime/src/coreclr/vm/prestub.cpp:937 #15 0x0000003ff6fe7d48 in MethodDesc::JitCompileCodeLockedEventWrapper (this=0x3f7a8d8968, pConfig=0x3e86fd2088, pEntry=0x3ecc0533f0) at /home/runtime/src/coreclr/vm/prestub.cpp:818 #16 0x0000003ff6fe6cd0 in MethodDesc::JitCompileCode (this=0x3f7a8d8968, pConfig=0x3e86fd2088) at /home/runtime/src/coreclr/vm/prestub.cpp:705 #17 0x0000003ff6fe5fce in MethodDesc::PrepareILBasedCode (this=0x3f7a8d8968, pConfig=0x3e86fd2088) at /home/runtime/src/coreclr/vm/prestub.cpp:431 #18 0x0000003ff6fe5aa0 in MethodDesc::PrepareCode (this=0x3f7a8d8968, pConfig=0x3e86fd2088) at /home/runtime/src/coreclr/vm/prestub.cpp:319 #19 0x0000003ff6eb53f4 in CodeVersionManager::PublishVersionableCodeIfNecessary (this=0x2aaaaf6df4, pMethodDesc=0x3f7a8d8968, callerGCMode=CallerGCMode::Coop, doBackpatchRef=0x3e86fd2257, doFullBackpatchRef=0x3e86fd2256) at /home/runtime/src/coreclr/vm/codeversion.cpp:1747 #20 0x0000003ff6feeece in MethodDesc::DoPrestub (this=0x3f7a8d8968, pDispatchingMT=0x0, callerGCMode=CallerGCMode::Coop) at /home/runtime/src/coreclr/vm/prestub.cpp:2869 #21 0x0000003ff6fee1fa in PreStubWorker (pTransitionBlock=0x3e86fd2578, pMD=0x3f7a8d8968) at /home/runtime/src/coreclr/vm/prestub.cpp:2698 #22 0x0000003ff73eebda in ThePreStub () at /home/runtime/src/coreclr/vm/riscv64/asmhelpers.S:378 #23 0x0000003f7a4dd008 in ?? () (gdb) frame 23 #23 0x0000003f7a4dd008 in ?? () (gdb) btm # 0 0x3f7a4dd008 instance void [System.Private.CoreLib] System.Diagnostics.DebugProvider::Fail(string,string)[Optimized] # 1 0x3f7a4dce6c void [System.Private.CoreLib] System.Diagnostics.Debug::Fail(string,string)[Optimized] # 2 0x3f7a18ad94 void [System.Private.CoreLib] System.Runtime.EH::DispatchEx(valuetype System.Runtime.StackFrameIterator&,valuetype System.Runtime.EH/ExInfo&)[Optimized] # 3 0x3f7a18a834 void [System.Private.CoreLib] System.Runtime.EH::RhThrowEx(object,valuetype System.Runtime.EH/ExInfo&)[Optimized] ```

For launch and debugging purposes I used the following environment variables:

# Allow to put breakpoint to managed code by address
export DOTNET_EnableWriteXorExecute=0

# Jitted methods info
export DOTNET_PerfMapEnabled=1
export DOTNET_JitStdOutFile=/home/tmustafin/remote_dir/current/JitStdOutFile.txt
export DOTNET_JitDisasmSummary=1

# Tiered compilation
export DOTNET_TieredCompilation=0

# Jit log for method. Hash printed in JitStdOutFile.txt
export DOTNET_JitHashDump=0xc1516150       # Sometimes I see address of jitted Xunit.Assert::All as this for Object::Validate() invocation. Check Xunit.Assert::All part further

export DOTNET_JitReportFastTailCallDecisions=1

# Common clr log
export DOTNET_LogEnable=1
export DOTNET_LogFile=/home/tmustafin/remote_dir/current/clr.log
export DOTNET_LogLevel=10
export DOTNET_LogToFile=1
export DOTNET_LogFileAppend=0 # Rewrite previous log
export DOTNET_LogFacility=0x00080041 # LF_GCROOTS | LF_GC and | LF_SYNC. Check facility mask in src/coreclr/int/loglf.h.

JitStdOutFile.txt, clr.log and perf-26084.map collected with logs above in attachment: JitStdOut_clrlog_perfmap.tar.gz

Address of jitted code Xunit.Assert::All as Object*

Sometimes Object* in Object::Validate() frame points to jitted code as in this log:

Hidden gdblog ``` Thread 478 ".NET Long Runni" received signal SIGSEGV, Segmentation fault. [Switching to Thread 0x3e8b7de160 (LWP 19368)] 0x0000003ff6e1dcc0 in MethodTable::GetFlag (this=0xfec4250300000010, flag=MethodTable::enum_flag_HasComponentSize) at /home/runtime/src/coreclr/vm/methodtable.h:3731 3731 /home/runtime/src/coreclr/vm/methodtable.h: No such file or directory. (gdb) bt #0 0x0000003ff6e1dcc0 in MethodTable::GetFlag (this=0xfec4250300000010, flag=MethodTable::enum_flag_HasComponentSize) at /home/runtime/src/coreclr/vm/methodtable.h:3731 #1 0x0000003ff6e1dc8c in MethodTable::HasComponentSize (this=0xfec4250300000010) at /home/runtime/src/coreclr/vm/methodtable.h:1767 #2 0x0000003ff6e2ae92 in MethodTable::GetComponentSize (this=0xfec4250300000010) at /home/runtime/src/coreclr/vm/methodtable.h:1789 #3 0x0000003ff6f98326 in MethodTable::SanityCheck (this=0xfec4250300000010) at /home/runtime/src/coreclr/vm/methodtable.cpp:6208 #4 0x0000003ff6f9e2fc in MethodTable::Validate (this=0xfec4250300000010) at /home/runtime/src/coreclr/vm/methodtable.cpp:8378 #5 0x0000003ff6fa62ae in Object::ValidateInner (this=0x3f7a4d2c78, bDeep=1, bVerifyNextHeader=1, bVerifySyncBlock=1) at /home/runtime/src/coreclr/vm/object.cpp:553 #6 0x0000003ff6fa560a in Object::Validate (this=0x3f7a4d2c78, bDeep=1, bVerifyNextHeader=1, bVerifySyncBlock=1) at /home/runtime/src/coreclr/vm/object.cpp:529 #7 0x0000003ff7280304 in GcInfoDecoder::ReportRegisterToGC (this=0x3e8b7d9f08, regNum=9, gcFlags=0, pRD=0x3e8b7db380, flags=0, pCallBack=0x3ff7112d18 , hCallBack=0x3e8b7dbce0) at /home/runtime/src/coreclr/vm/gcinfodecoder.cpp:2100 #8 0x0000003ff727f31e in GcInfoDecoder::ReportSlotToGC (this=0x3e8b7d9f08, slotDecoder=..., slotIndex=1, pRD=0x3e8b7db380, reportScratchSlots=false, inputFlags=0, pCallBack=0x3ff7112d18 , hCallBack=0x3e8b7dbce0) at /home/runtime/src/coreclr/inc/gcinfodecoder.h:715 #9 0x0000003ff727e82e in GcInfoDecoder::EnumerateLiveSlots (this=0x3e8b7d9f08, pRD=0x3e8b7db380, reportScratchSlots=false, inputFlags=0, pCallBack=0x3ff7112d18 , hCallBack=0x3e8b7dbce0) at /home/runtime/src/coreclr/vm/gcinfodecoder.cpp:1036 #10 0x0000003ff6ec1102 in EECodeManager::EnumGcRefs (this=0x2aaab2cac0, pRD=0x3e8b7db380, pCodeInfo=0x3e8b7db1e0, flags=0, pCallBack=0x3ff7112d18 , hCallBack=0x3e8b7dbce0, relOffsetOverride=4294967295) at /home/runtime/src/coreclr/vm/eetwain.cpp:1492 #11 0x0000003ff711410c in GcStackCrawlCallBack (pCF=0x3e8b7dafb0, pData=0x3e8b7dbce0) at /home/runtime/src/coreclr/vm/gcenv.ee.common.cpp:329 #12 0x0000003ff6ff5c4c in Thread::MakeStackwalkerCallback (this=0x2aaadacd60, pCF=0x3e8b7dafb0, pCallback=0x3ff7112efc , pData=0x3e8b7dbce0, uFramesProcessed=2) at /home/runtime/src/coreclr/vm/stackwalk.cpp:831 #13 0x0000003ff6ff5e8c in Thread::StackWalkFramesEx (this=0x2aaadacd60, pRD=0x3e8b7db380, pCallback=0x3ff7112efc , pData=0x3e8b7dbce0, flags=34048, pStartFrame=0x0) at /home/runtime/src/coreclr/vm/stackwalk.cpp:911 #14 0x0000003ff6ff6c6a in Thread::StackWalkFrames (this=0x2aaadacd60, pCallback=0x3ff7112efc , pData=0x3e8b7dbce0, flags=34048, pStartFrame=0x0) at /home/runtime/src/coreclr/vm/stackwalk.cpp:991 #15 0x0000003ff710c6d4 in ScanStackRoots (pThread=0x2aaadacd60, fn=0x3ff73af7c4 , sc=0x3e8b7dc318) at /home/runtime/src/coreclr/vm/gcenv.ee.cpp:204 #16 0x0000003ff710c328 in GCToEEInterface::GcScanRoots (fn=0x3ff73af7c4 , condemned=0, max_gen=2, sc=0x3e8b7dc318) at /home/runtime/src/coreclr/vm/gcenv.ee.cpp:305 #17 0x0000003ff72b5df4 in GCScan::GcScanRoots (fn=0x3ff73af7c4 , condemned=0, max_gen=2, sc=0x3e8b7dc318) at /home/runtime/src/coreclr/gc/gcscan.cpp:152 #18 0x0000003ff738dbf2 in WKS::gc_heap::mark_phase (condemned_gen_number=0) at /home/runtime/src/coreclr/gc/gc.cpp:29546 #19 0x0000003ff7388cc2 in WKS::gc_heap::gc1 () at /home/runtime/src/coreclr/gc/gc.cpp:22276 #20 0x0000003ff73a13da in WKS::gc_heap::garbage_collect (n=0) at /home/runtime/src/coreclr/gc/gc.cpp:24355 #21 0x0000003ff737e7d6 in WKS::GCHeap::GarbageCollectGeneration (this=0x2aaaae9bf0, gen=0, reason=reason_alloc_soh) at /home/runtime/src/coreclr/gc/gc.cpp:50585 #22 0x0000003ff738071e in WKS::gc_heap::trigger_gc_for_alloc (gen_number=0, gr=reason_alloc_soh, msl=0x3ff7adc5f8 , loh_p=false, take_state=WKS::mt_try_budget) at /home/runtime/src/coreclr/gc/gc.cpp:18818 #23 0x0000003ff7381aba in WKS::gc_heap::try_allocate_more_space (acontext=0x3e8b7de9d0, size=24, flags=2, gen_number=0) at /home/runtime/src/coreclr/gc/gc.cpp:18956 #24 0x0000003ff7381cee in WKS::gc_heap::allocate_more_space (acontext=0x3e8b7de9d0, size=24, flags=2, alloc_generation_number=0) at /home/runtime/src/coreclr/gc/gc.cpp:19456 #25 0x0000003ff73d876e in WKS::gc_heap::allocate (jsize=24, acontext=0x3e8b7de9d0, flags=2) at /home/runtime/src/coreclr/gc/gc.cpp:19487 #26 WKS::GCHeap::Alloc (this=0x2aaaae9bf0, context=0x3e8b7de9d0, size=24, flags=2) at /home/runtime/src/coreclr/gc/gc.cpp:49507 #27 0x0000003ff7115df8 in Alloc (size=24, flags=GC_ALLOC_CONTAINS_REF) at /home/runtime/src/coreclr/vm/gchelpers.cpp:227 #28 0x0000003ff7117b56 in AllocateObject (pMT=0x3f7a82cbe8, flags=GC_ALLOC_CONTAINS_REF) at /home/runtime/src/coreclr/vm/gchelpers.cpp:1051 #29 0x0000003ff6e086d0 in AllocateObject (pMT=0x3f7a82cbe8) at /home/runtime/src/coreclr/vm/gchelpers.h:68 #30 0x0000003ff713e576 in JIT_New (typeHnd_=0x3f7a82cbe8) at /home/runtime/src/coreclr/vm/jithelpers.cpp:1264 #31 0x0000003ff713e0da in JIT_NewS_MP_FastPortable (typeHnd_=0x3f7a82cbe8) at /home/runtime/src/coreclr/vm/jithelpers.cpp:1229 #32 0x0000003f7a4d36a0 in ?? () (gdb) frame 5 #5 0x0000003ff6fa62ae in Object::ValidateInner (this=0x3f7a4d2c78, bDeep=1, bVerifyNextHeader=1, bVerifySyncBlock=1) at /home/runtime/src/coreclr/vm/object.cpp:553 553 /home/runtime/src/coreclr/vm/object.cpp: No such file or directory. (gdb) mname this Managed function 0x3f7a4d29d8 ,+ 0x564 void [xunit.assert] Xunit.Assert::All(class [System.Runtime]System.Collections.Generic.IEnumerable`1,class [System.Runtime]System.Action`2)[Optimized] (gdb) x/gx this 0x3f7a4d2c78: 0xfec4250300000013 (gdb) (gdb) thread 505 [Switching to thread 505 (Thread 0x3e7d7c2160 (LWP 19410))] #0 __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab46768) at ./nptl/futex-internal.c:57 57 ./nptl/futex-internal.c: No such file or directory. (gdb) bt #0 __futex_abstimed_wait_common64 (private=, cancel=true, abstime=0x0, op=, expected=, futex_word=0x2aaab46768) at ./nptl/futex-internal.c:57 #1 __futex_abstimed_wait_common (futex_word=futex_word@entry=0x2aaab46768, expected=, clockid=, abstime=abstime@entry=0x0, private=, cancel=cancel@entry=true) at ./nptl/futex-internal.c:87 #2 0x0000003ff7ca4f72 in __GI___futex_abstimed_wait_cancelable64 (futex_word=futex_word@entry=0x2aaab46768, expected=expected@entry=0, clockid=clockid@entry=0, abstime=abstime@entry=0x0, private=private@entry=0) at ./nptl/futex-internal.c:139 #3 0x0000003ff7ca6ce4 in __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x2aaab46770, cond=0x2aaab46740) at ./nptl/pthread_cond_wait.c:503 #4 ___pthread_cond_wait (cond=0x2aaab46740, mutex=0x2aaab46770) at ./nptl/pthread_cond_wait.c:618 #5 0x0000003ff76a4f18 in GCEvent::Impl::Wait (this=0x2aaab46740, milliseconds=4294967295, alertable=false) at /home/runtime/src/coreclr/gc/unix/events.cpp:149 #6 0x0000003ff76a4e66 in GCEvent::Wait (this=0x2aaaadee60, timeout=4294967295, alertable=false) at /home/runtime/src/coreclr/gc/unix/events.cpp:255 #7 0x0000003ff73e3e7c in WKS::GCHeap::WaitUntilGCComplete (this=0x2aaaae9bf0, bConsiderGCStart=false) at /home/runtime/src/coreclr/gc/gcee.cpp:265 #8 0x0000003ff7238448 in Thread::RareDisablePreemptiveGC (this=0x2aaadacd60) at /home/runtime/src/coreclr/vm/threadsuspend.cpp:2195 #9 0x0000003ff6e1b346 in Thread::DisablePreemptiveGC (this=0x2aaadacd60) at /home/runtime/src/coreclr/vm/threads.h:1308 #10 0x0000003ff7239052 in Thread::PulseGCMode (this=0x2aaadacd60) at /home/runtime/src/coreclr/vm/threadsuspend.cpp:2390 #11 0x0000003ff7020d6a in CommonTripThread () at /home/runtime/src/coreclr/vm/threads.cpp:6954 #12 0x0000003ff723c3ce in OnHijackWorker (pArgs=0x3e7d7c0f00) at /home/runtime/src/coreclr/vm/threadsuspend.cpp:4861 #13 0x0000003ff73e71c4 in OnHijackTripThread () at /home/runtime/src/coreclr/vm/riscv64/asmhelpers.S:671 #14 0x0000003f7a4d2c78 in ?? () (gdb) frame 14 #14 0x0000003f7a4d2c78 in ?? () (gdb) btm # 0 0x3f7a4d2c78 void [xunit.assert] Xunit.Assert::All(class [System.Runtime]System.Collections.Generic.IEnumerable`1,class [System.Runtime]System.Action`2)[Optimized] # 1 0x3f7a4ca870 instance void [System.Diagnostics.DiagnosticSource.Tests] System.Diagnostics.Tests.DiagnosticSourceTest+<>c__DisplayClass10_1::b__1()[Optimized] # 2 0x3f7a1598f8 void [System.Private.CoreLib] System.Threading.ExecutionContext::RunInternal(class System.Threading.ExecutionContext,class System.Threading.ContextCallback,object)[Optimized] # 3 0x3f7a15938c instance void [System.Private.CoreLib] System.Threading.Tasks.Task::ExecuteWithThreadLocal(class System.Threading.Tasks.Task&,class System.Threading.Thread)[Optimized] ```

Hijack::UpdateRegDisplay() A0 register for riscv64 as for arm64

Sometimes OnHijackTripThread occures on backtrace and Hijack::UpdateRegDisplay() makes a print in clr.log. There is a difference in Hijack::UpdateRegDisplay() between arm64 and riscv64. Arm64 code updates X0 value: https://github.com/dotnet/runtime/blob/f4866b0bfa52fbdc9ea92ae25e5398fdb7b1bf7c/src/coreclr/vm/arm64/stubs.cpp#L782-L790 riscv64 does not update A0 value: https://github.com/dotnet/runtime/blob/f4866b0bfa52fbdc9ea92ae25e5398fdb7b1bf7c/src/coreclr/vm/riscv64/stubs.cpp#L736-L742

However intermittent crash in GC -> Object::Validate() occurs despite applying the patch:

diff --git a/src/coreclr/vm/riscv64/stubs.cpp b/src/coreclr/vm/riscv64/stubs.cpp
index efa3d2c1e03..9e7a97d4dcf 100644
--- a/src/coreclr/vm/riscv64/stubs.cpp
+++ b/src/coreclr/vm/riscv64/stubs.cpp
@@ -738,6 +738,8 @@ void HijackFrame::UpdateRegDisplay(const PREGDISPLAY pRD, bool updateFloats)
     s = s + s%16;
     pRD->pCurrentContext->Sp = PTR_TO_TADDR(m_Args) + s ;

+    pRD->pCurrentContext->A0 = m_Args->A0;
+
     pRD->pCurrentContext->S1 = m_Args->S1;
     pRD->pCurrentContext->S2 = m_Args->S2;
     pRD->pCurrentContext->S3 = m_Args->S3;

HeapVerify

Several (~5) launches of test with export DOTNET_HeapVerify=1 environment variable did not show another assert or backtrace for this test.

@Maoni0 @jkotas @jakobbotsch I would grateful for any tips, advices or directions how to debug this intermittent crash.

cc @dotnet/samsung

jkotas commented 1 month ago

You need to find where the bad GC reference came from.

We typically debug these types of crashes using stresslog. https://github.com/dotnet/runtime/issues/45557#issuecomment-738547930 is an example of the stresslog setting to use. Stresslog has information about what happened during the past GCs - where the thread stopped for the GC, objects that got enumerated during stackwalk, etc. This crash is likely caused by an object reference missed during stackwalk. You should be able to find the object reference that was missed from the stresslog.

dotnet-policy-service[bot] commented 1 month ago

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

t-mustafin commented 1 month ago

#45557 (comment) is an example of the stresslog setting to use.

Thanks a lot for this example! I would check StressLog output and GC info via JitDisasm for methods in my testcase.

t-mustafin commented 1 month ago

I had collected StressLog on riscv64, it was a binary output. This binary log analyzed via x64 StressLogAnalyzer to obtain text output. Text has "BAD Method" and "BAD MethodTable" instead of real names. The same I got on x64 simple program.

Simple program ```cs using System; using System.Diagnostics; namespace Hello { class Program { static void CreateString() { var mfo = new String("ASDASD"); } static void Main() { // Create a string without reference CreateString(); //Force garbage collection. GC.Collect(); Process process = Process.GetCurrentProcess(); System.Console.WriteLine("GC collected. Press enter to exit. Cur ID = {0}", process.Id); System.Console.ReadLine(); } } } ```

Environment variables:

declare -x DOTNET_LogFacility="0x00080001"
declare -x DOTNET_LogLevel="6"
declare -x DOTNET_StressLog="1"
declare -x DOTNET_StressLogSize="2000000"
declare -x DOTNET_TotalStressLogSize="40000000"
declare -x DOTNET_StressLogFilename="/home/runtime/StressLog.gccollect_once.bin"

Run command:

./corerun ./gccollect_once.dll

Analyze:

./StressLogAnalyzer ../../StressLog.gccollect_once.bin -o:../../StressLog.gccollect_once.txt -a

BAD names in StressLog:

StressLog.txt ``` a1f8 18444492276.678485870 : `STARTUP` ******* DllMain THREAD_DETACH called Thread dying ******* a1ff 18444492276.678016663 : `GC` DestroyHandle: *0x7f527e8b13b0->0x7f11b680e680 a1ff 18444492276.677978516 : `GC` DestroyHandle: *0x7f527e8b13b8->0x7f11b680e970 a202 18444492276.643951416 : `ALWAYS` SetupThread managed Thread 0x556f77e499f0 Thread Id = 3 a1f8 18444492276.643730164 : `GC` CreateHandle: 0x7f527e8b13c0, type=2 a1f8 18444492276.643730164 : `GC` CreateHandle: 0x7f527e8b11e8, type=0 a1f8 18444492274.432495117 : `GC` CreateHandle: 0x7f527e8b17f0, type=1 a1f8 18444492274.396728516 : `GC`GCALLOC`GCROOTS` ========== ENDGC 1 (gen = 2, collect_classes = 1) ==========={ a1f8 18444492274.396720886 : `GC` Segment mem 0x7f11b6000028 alloc = 0x7f11b6000028 used 0x7f11b6000028 committed 0x7f11b6011000 a1f8 18444492274.396720886 : `GC` Segment mem 0x7f11b6800028 alloc = 0x7f11b680f010 used 0x7f11b6810940 committed 0x7f11b6811000 a1f8 18444492274.396720886 : `GC` Segment mem 0x7f11b8c00028 alloc = 0x7f11b8c00028 used 0x7f11b8c00028 committed 0x7f11b8c01000 a1f8 18444492274.396720886 : `GC` Segment mem 0x7f527cb74008 alloc = 0x7f527cb76bf8 used 0x7f527cb74020 committed 0x7f527cb84000 a1f8 18444492274.396720886 : `GC` GC Heap (nil) a1f8 18444492274.396663666 : `GC` Segment mem 0x7f11b6800028 alloc = 0x7f11b680f010 used 0x7f11b6810940 committed 0x7f11b6811000 a1f8 18444492274.396663666 : `GC` Segment mem 0x7f11b6400028 alloc = 0x7f11b6400028 used 0x7f11b6400028 committed 0x7f11b6401000 a1f8 18444492274.396663666 : `GC` Segment mem 0x7f11b6000028 alloc = 0x7f11b6000028 used 0x7f11b6000028 committed 0x7f11b6011000 a1f8 18444492274.396663666 : `GC` Segment mem 0x7f527cb74008 alloc = 0x7f527cb76bf8 used 0x7f527cb74020 committed 0x7f527cb84000 a1f8 18444492274.396663666 : `GC` GC Heap (nil) a1f8 18444492274.396598816 : `GC`GCROOTS` IGCHeap::Promote: Promote GC Root *0x7f527e8b13e8 = 0x7f11b4000028 MT = 0x7f520311cc58 (BAD MethodTable) a1f8 18444492274.396598816 : `GC`GCROOTS` IGCHeap::Promote: Promote GC Root *0x7f527e8b13e0 = 0x7f11b6800028 MT = 0x7f520326e1d8 (BAD MethodTable) a1f8 18444492274.396598816 : `GC`GCROOTS` IGCHeap::Promote: Promote GC Root *0x7f527e8b13d8 = 0x7f11b6800088 MT = 0x7f52032b0ae8 (BAD MethodTable) a1f8 18444492274.396595001 : `GC`GCROOTS` IGCHeap::Promote: Promote GC Root *0x7f527e8b13d0 = 0x7f11b6800100 MT = 0x7f52032b0d78 (BAD MethodTable) a1f8 18444492274.396595001 : `GC`GCROOTS` IGCHeap::Promote: Promote GC Root *0x7f527e8b13c8 = 0x7f11b6800178 MT = 0x7f52032b1008 (BAD MethodTable) a1f8 18444492274.396595001 : `GC`GCROOTS` IGCHeap::Promote: Promote GC Root *0x7f527e8b13b8 = 0x7f11b680e970 MT = 0x7f52035a5ea8 (BAD MethodTable) a1f8 18444492274.396595001 : `GC`GCROOTS` IGCHeap::Promote: Promote GC Root *0x7f527e8b13b0 = 0x7f11b680e680 MT = 0x7f52035a5ea8 (BAD MethodTable) a1f8 18444492274.396595001 : `GC`GCROOTS` IGCHeap::Promote: Promote GC Root *0x7f527e8b15f8 = 0x7f11b68001f0 MT = 0x7f5201ae4ce0 (BAD MethodTable) a1f8 18444492274.396591187 : `GC`GCROOTS` GcScanHandles (Promotion Phase = 1) a1f8 18444492274.396587372 : `GC`GCROOTS` Ending scan of Thread 0x556f77e499f0 ID = 0x3 { a1f8 18444492274.396587372 : `GCROOTS` Scanning ExplicitFrame 0x7f527cb62c68 AssocMethod = (nil) frameVTable = 0x7f5281932d30 (Unknown VTable) a1f8 18444492274.396587372 : `EH`GCROOTS` CrawlFrame (0x7ffdd6649b60): Frameless: No Address: 0x7f527cb62c68 a1f8 18444492274.396587372 : `GC`GCROOTS` } Starting scan of Thread 0x556f77e499f0 ID = 3 a1f8 18444492274.396587372 : `GC`GCROOTS` Ending scan of Thread 0x556f77e3e330 ID = 0x2 { a1f8 18444492274.396587372 : `GCROOTS` Scanning ExplicitFrame 0x7f527d777c38 AssocMethod = (nil) frameVTable = 0x7f5281932d30 (Unknown VTable) a1f8 18444492274.396583557 : `EH`GCROOTS` CrawlFrame (0x7ffdd6649b60): Frameless: No Address: 0x7f527d777c38 a1f8 18444492274.396583557 : `GC`GCROOTS` } Starting scan of Thread 0x556f77e3e330 ID = 2 a1f8 18444492274.396583557 : `GC`GCROOTS` Ending scan of Thread 0x556f77e35f40 ID = 0x1 { a1f8 18444492274.396583557 : `GC`GCROOTS` IGCHeap::Promote: Promote GC Root *0x7ffdd664dea0 = 0x7f11b680e058 MT = 0x7f52035602f0 (BAD MethodTable) a1f8 18444492274.396572113 : `GCROOTS` Scanning Frameless method 0x7f5203560c98 (BAD Method) ControlPC = 0x7f5203322d95 a1f8 18444492274.396572113 : `EH`GCROOTS` CrawlFrame (0x7ffdd6649b60): Frameless: Yes CallerSP: 0x7ffdd664d240 a1f8 18444492274.396564484 : `GCROOTS` Scanning Frameless method 0x7f52036bb6b0 (BAD Method) ControlPC = 0x7f5201c552e6 a1f8 18444492274.396564484 : `EH`GCROOTS` CrawlFrame (0x7ffdd6649b60): Frameless: Yes CallerSP: 0x7ffdd664d200 a1f8 18444492274.396564484 : `GCROOTS` Scanning ExplicitFrame 0x7ffdd664d178 AssocMethod = (nil) frameVTable = 0x7f5281947340 (Unknown VTable) a1f8 18444492274.396564484 : `EH`GCROOTS` CrawlFrame (0x7ffdd6649b60): Frameless: No Address: 0x7ffdd664d178 a1f8 18444492274.396556854 : `GCROOTS` Scanning ExplicitFrame 0x7ffdd664d178 AssocMethod = (nil) frameVTable = 0x7f5281947340 (Unknown VTable) a1f8 18444492274.396556854 : `EH`GCROOTS` CrawlFrame (0x7ffdd6649b60): Frameless: No Address: 0x7ffdd664d178 a1f8 18444492274.396549225 : `GC`GCROOTS` } Starting scan of Thread 0x556f77e35f40 ID = 1 a1f8 18444492274.396545410 : `GCROOTS` GCScan: Promotion Phase = 1 a1f8 18444492274.396545410 : `GC` Segment mem 0x7f11b6800028 alloc = 0x7f11b680f038 used 0x7f11b6810940 committed 0x7f11b6811000 a1f8 18444492274.396545410 : `GC` Segment mem 0x7f11b6400028 alloc = 0x7f11b6400028 used 0x7f11b6400028 committed 0x7f11b6401000 a1f8 18444492274.396545410 : `GC` Segment mem 0x7f11b6000028 alloc = 0x7f11b6000028 used 0x7f11b6000028 committed 0x7f11b6001000 a1f8 18444492274.396541595 : `GC` Segment mem 0x7f527cb74008 alloc = 0x7f527cb76bf8 used 0x7f527cb74020 committed 0x7f527cb84000 a1f8 18444492274.396541595 : `GC` GC Heap (nil) a1f8 18444492274.396541595 : `GC`GCALLOC`GCROOTS` } =========== BEGINGC 1, (requested generation = 2, collect_classes = 1) ========== a1f8 18444492274.396537781 : `GC` GC is triggered a1f8 18444492274.396537781 : `GC`GCALLOC`GCROOTS` condemned generation num: 2 a1f8 18444492274.382709503 : `GC` CreateHandle: 0x7f527e8b11c8, type=0 a1f8 18444492274.382652283 : `GC` CreateHandle: 0x7f527e8b13b0, type=2 a1f8 18444492274.368587494 : `GC` CreateHandle: 0x7f527e8b17f8, type=1 a1f8 18444492274.337905884 : `GC` CreateHandle: 0x7f527e8b11d0, type=0 a1f8 18444492274.337604523 : `GC` CreateHandle: 0x7f527e8b13b8, type=2 a1f8 18444492274.335346222 : `GC` CreateHandle: 0x7f527e8b11d8, type=0 a1f8 18444492274.329505920 : `GC` CreateHandle: 0x7f527e8b11e0, type=0 a1f8 18444492274.114616394 : `GC` CreateHandle: 0x7f527e8b13c0, type=2 a1f8 18444492274.114612579 : `GC` CreateHandle: 0x7f527e8b11e8, type=0 a1f8 18444492274.105621338 : `GC` CreateHandle: 0x7f527e8b15f8, type=3 a1f8 18444492274.105613708 : `GC` CreateHandle: 0x7f527e8b13c8, type=2 a1f8 18444492274.105602264 : `GC` CreateHandle: 0x7f527e8b13d0, type=2 a1f8 18444492274.105598450 : `GC` CreateHandle: 0x7f527e8b13d8, type=2 a1f8 18444492274.068523407 : `GC` CreateHandle: 0x7f527e8b13e0, type=2 a1f8 18444492274.068435669 : `GC` CreateHandle: 0x7f527e8b13e8, type=2 a1ff 18444492273.909862518 : `ALWAYS` SetupThread managed Thread 0x556f77e3e330 Thread Id = 2 a1f8 18444492273.909675598 : `GC` CreateHandle: 0x7f527e8b13f0, type=2 a1f8 18444492273.909675598 : `GC` CreateHandle: 0x7f527e8b11f0, type=0 a1f8 18444492273.909408569 : `GC l=1` TraceGC is not turned on a1f8 18444492273.909149170 : `ALWAYS` SetupThread managed Thread 0x556f77e35f40 Thread Id = 1 a1f8 18444492273.909145355 : `GC` CreateHandle: 0x7f527e8b13f8, type=2 a1f8 18444492273.909137726 : `GC` CreateHandle: 0x7f527e8b11f8, type=0 ```

@jkotas Did I do something wrong?

jkotas commented 1 month ago

I always use DumpLog command from SOS debugger extension to save stresslog into a text file (https://github.com/dotnet/diagnostics/blob/main/documentation/sos.md).

StressLogAnalyzer was implemented by the GC for use with the GC. It is missing the non-GC features like pretty printing of MethodTables and MethodDescs. @jkoritzinsky may be fixing that in https://github.com/dotnet/runtime/pull/104999 .

jkoritzinsky commented 1 month ago

I'm currently not fixing the pretty-printing in #104999. It's something we can look into in the future.

I know something the GC team is also interested in (that I think we can do in the future) supporting running StressLogAnalyzer on a dump with an embedded stresslog instead of a memory-mapped log, which would make the pretty-printing work more reliably.