Crash Dump Analysis Patterns (Part 29e)

This is High Contention pattern variant for .NET heap where we can see gc_heap functions in unmanaged Stack Trace Collection, Spiking Threads doing garbage collection, and threads waiting for object allocation:

0:000> ~*k

[...]

4  Id: ad8.1338 Suspend: 0 Teb: 00007ff5`ff774000 Unfrozen
# Child-SP          RetAddr           Call Site
00 00000030`f9dff1c8 00007ff9`f4121118 ntdll!NtWaitForSingleObject+0xa
01 00000030`f9dff1d0 00007ff9`ee3594fb KERNELBASE!WaitForSingleObjectEx+0x94
02 00000030`f9dff270 00007ff9`ee3594a7 clr!CLREventWaitHelper2+0x38
03 00000030`f9dff2b0 00007ff9`ee359430 clr!CLREventWaitHelper+0x1f
04 00000030`f9dff310 00007ff9`ee533c96 clr!CLREventBase::WaitEx+0x63
05 00000030`f9dff3a0 00007ff9`ee85849a clr!SVR::gc_heap::user_thread_wait+0x58
06 00000030`f9dff3d0 00007ff9`ee74073f clr!SVR::gc_heap::background_gc_wait+0x4a
07 00000030`f9dff400 00007ff9`ee740cfd clr!SVR::GCHeap::GarbageCollect+0x2998df
08 00000030`f9dff440 00007ff9`ee4ccdf9 clr!SVR::WaitForFinalizerEvent+0x3272ed
09 00000030`f9dff480 00007ff9`ee35c481 clr!SVR::GCHeap::FinalizerThreadWorker+0x4a
0a 00000030`f9dff4c0 00007ff9`ee35c408 clr!ManagedThreadBase_DispatchInner+0x2d
0b 00000030`f9dff500 00007ff9`ee35c379 clr!ManagedThreadBase_DispatchMiddle+0x6c
0c 00000030`f9dff600 00007ff9`ee46c477 clr!ManagedThreadBase_DispatchOuter+0x75
0d 00000030`f9dff690 00007ff9`ee417de6 clr!SVR::GCHeap::FinalizerThreadStart+0xd7
0e 00000030`f9dff730 00007ff9`f60413d2 clr!Thread::intermediateThreadProc+0x7d
0f 00000030`f9dff7f0 00007ff9`f6ea54e4 kernel32!BaseThreadInitThunk+0x22
10 00000030`f9dff820 00000000`00000000 ntdll!RtlUserThreadStart+0x34

[...]

8  Id: ad8.1960 Suspend: 0 Teb: 00007ff5`ff58c000 Unfrozen
# Child-SP          RetAddr           Call Site
00 00000030`fb90b898 00007ff9`f4121118 ntdll!NtWaitForSingleObject+0xa
01 00000030`fb90b8a0 00007ff9`ee3594fb KERNELBASE!WaitForSingleObjectEx+0x94
02 00000030`fb90b940 00007ff9`ee3594a7 clr!CLREventWaitHelper2+0x38
03 00000030`fb90b980 00007ff9`ee359430 clr!CLREventWaitHelper+0x1f
04 00000030`fb90b9e0 00007ff9`ee533c96 clr!CLREventBase::WaitEx+0x63
05 00000030`fb90ba70 00007ff9`ee85849a clr!SVR::gc_heap::user_thread_wait+0x58
06 00000030`fb90baa0 00007ff9`ee780417 clr!SVR::gc_heap::background_gc_wait+0x4a
07 00000030`fb90bad0 00007ff9`ee4c41e8 clr!SVR::gc_heap::wait_for_bgc_high_memory+0x2b8907
08 00000030`fb90bb60 00007ff9`ee355272 clr!SVR::GCHeap::Alloc+0×257
09 00000030`fb90bbc0 00007ff9`eb524a1d clr!JIT_New+0×142

0a 00000030`fb90be70 00007ff9`e8bd8ec8 System_Xml_ni+0×154a1d
0b 00000030`fb90bed0 00007ff9`e8d6ec7c System_Runtime_Serialization_ni+0xa8ec8
0c 00000030`fb90bf20 00007ff9`e9ed637b System_Runtime_Serialization_ni+0×23ec7c
0d 00000030`fb90bf80 00007ff9`ea6df472 System_ServiceModel_ni+0xdd637b
0e 00000030`fb90bfe0 00000030`fb90bfc0 System_ServiceModel_ni+0×15df472
0f 00000030`fb90bfe8 00000000`00000000 0×00000030`fb90bfc0

[...]

14  Id: ad8.11d4 Suspend: 0 Teb: 00007ff5`ff586000 Unfrozen
# Child-SP          RetAddr           Call Site
00 00000031`4a42eb10 00007ff9`ee4a3a76 clr!SVR::gc_heap::background_mark_simple1+0xcd9
01 00000031`4a42eba0 00007ff9`ee4a458b clr!SVR::gc_heap::background_mark_simple+0×99
02 00000031`4a42ebd0 00007ff9`ee52e68c clr!SVR::gc_heap::background_promote+0×15d
03 00000031`4a42ec40 00007ff9`ee538836 clr!PinObject+0×2c
04 00000031`4a42ec80 00007ff9`ee532fc8 clr!ScanConsecutiveHandlesWithoutUserData+0×62
05 00000031`4a42ecb0 00007ff9`ee5338f2 clr!BlockScanBlocksWithoutUserData+0×44
06 00000031`4a42ece0 00007ff9`ee5339fc clr!ProcessScanQNode+0×3d
07 00000031`4a42ed10 00007ff9`ee53397d clr!ProcessScanQueue+0×3d
08 00000031`4a42ed40 00007ff9`ee533bcf clr!xxxTableScanQueuedBlocksAsync+0×5d
09 00000031`4a42ed70 00007ff9`ee5353a5 clr!xxxAsyncSegmentIterator+0×2d
0a 00000031`4a42eda0 00007ff9`ee533ab6 clr!TableScanHandles+0×79
0b 00000031`4a42ee50 00007ff9`ee535607 clr!xxxTableScanHandlesAsync+0×9b
0c 00000031`4a42eff0 00007ff9`ee53795d clr!HndScanHandlesForGC+0×137
0d 00000031`4a42f090 00007ff9`ee535769 clr!Ref_TracePinningRoots+0xfd
0e 00000031`4a42f110 00007ff9`ee4a4351 clr!CNameSpace::GcScanHandles+0×4d
0f 00000031`4a42f150 00007ff9`ee55cbe9 clr!SVR::gc_heap::background_mark_phase+0×331
10 00000031`4a42f1e0 00007ff9`ee4a32ed clr!SVR::gc_heap::gc1+0xcd
11 00000031`4a42f240 00007ff9`ee417de6 clr!SVR::gc_heap::bgc_thread_function+0×177
12 00000031`4a42f280 00007ff9`f60413d2 clr!Thread::intermediateThreadProc+0×7d
13 00000031`4a42fcc0 00007ff9`f6ea54e4 kernel32!BaseThreadInitThunk+0×22
14 00000031`4a42fcf0 00000000`00000000 ntdll!RtlUserThreadStart+0×34

15  Id: ad8.f9c Suspend: 0 Teb: 00007ff5`ff648000 Unfrozen
# Child-SP          RetAddr           Call Site
00 00000030`f4eddb58 00007ff9`f4121118 ntdll!NtWaitForSingleObject+0xa
01 00000030`f4eddb60 00007ff9`ee3594fb KERNELBASE!WaitForSingleObjectEx+0x94
02 00000030`f4eddc00 00007ff9`ee3594a7 clr!CLREventWaitHelper2+0x38
03 00000030`f4eddc40 00007ff9`ee359430 clr!CLREventWaitHelper+0x1f
04 00000030`f4eddca0 00007ff9`ee533c96 clr!CLREventBase::WaitEx+0x63
05 00000030`f4eddd30 00007ff9`ee85849a clr!SVR::gc_heap::user_thread_wait+0x58
06 00000030`f4eddd60 00007ff9`ee780417 clr!SVR::gc_heap::background_gc_wait+0x4a
07 00000030`f4eddd90 00007ff9`ee4c41e8 clr!SVR::gc_heap::wait_for_bgc_high_memory+0x2b8907
08 00000030`f4edde20 00007ff9`ee355272 clr!SVR::GCHeap::Alloc+0×257
09 00000030`f4edde80 00007ff9`e9f72cfe clr!JIT_New+0×142

0a 00000030`f4ede130 00007ff9`e6e1bf11 System_ServiceModel_ni+0xe72cfe
0b 00000030`f4ede1b0 00007ff9`e6e1be90 System_ServiceModel_Internals_ni+0×4bf11
0c 00000030`f4ede210 00007ff9`ed205156 System_ServiceModel_Internals_ni+0×4be90
0d 00000030`f4ede270 00007ff9`ee35ab53 mscorlib_ni+0×545156
0e 00000030`f4ede2d0 00007ff9`ee35aa3e clr!CallDescrWorkerInternal+0×83
0f 00000030`f4ede310 00007ff9`ee395b80 clr!CallDescrWorkerWithHandler+0×4a
10 00000030`f4ede350 00007ff9`ee9160b8 clr!DispatchCallSimple+0×60
11 00000030`f4ede3e0 00007ff9`ee35c481 clr!BindIoCompletionCallBack_Worker+0xb8
12 00000030`f4ede470 00007ff9`ee35c408 clr!ManagedThreadBase_DispatchInner+0×2d
13 00000030`f4ede4b0 00007ff9`ee35c379 clr!ManagedThreadBase_DispatchMiddle+0×6c
14 00000030`f4ede5b0 00007ff9`ee35c4bb clr!ManagedThreadBase_DispatchOuter+0×75
15 00000030`f4ede640 00007ff9`ee916219 clr!ManagedThreadBase_FullTransitionWithAD+0×2f
16 00000030`f4ede6a0 00007ff9`ee916129 clr!BindIoCompletionCallbackStubEx+0xb9
17 00000030`f4ede720 00007ff9`ee4da72d clr!BindIoCompletionCallbackStub+0×9
18 00000030`f4ede750 00007ff9`ee417de6 clr!ThreadpoolMgr::CompletionPortThreadStart+0×23d
19 00000030`f4ede7f0 00007ff9`f60413d2 clr!Thread::intermediateThreadProc+0×7d
1a 00000030`f4edf7b0 00007ff9`f6ea54e4 kernel32!BaseThreadInitThunk+0×22
1b 00000030`f4edf7e0 00000000`00000000 ntdll!RtlUserThreadStart+0×34

16  Id: ad8.d50 Suspend: 0 Teb: 00007ff5`ff64a000 Unfrozen
# Child-SP          RetAddr           Call Site
00 00000030`f4cde038 00007ff9`f4121118 ntdll!NtWaitForSingleObject+0xa
01 00000030`f4cde040 00007ff9`ee3594fb KERNELBASE!WaitForSingleObjectEx+0x94
02 00000030`f4cde0e0 00007ff9`ee3594a7 clr!CLREventWaitHelper2+0x38
03 00000030`f4cde120 00007ff9`ee359430 clr!CLREventWaitHelper+0x1f
04 00000030`f4cde180 00007ff9`ee533c96 clr!CLREventBase::WaitEx+0x63
05 00000030`f4cde210 00007ff9`ee85849a clr!SVR::gc_heap::user_thread_wait+0x58
06 00000030`f4cde240 00007ff9`ee780417 clr!SVR::gc_heap::background_gc_wait+0x4a
07 00000030`f4cde270 00007ff9`ee4c41e8 clr!SVR::gc_heap::wait_for_bgc_high_memory+0x2b8907
08 00000030`f4cde300 00007ff9`ee355272 clr!SVR::GCHeap::Alloc+0×257
09 00000030`f4cde360 00007ff9`e9f72cfe clr!JIT_New+0×142

0a 00000030`f4cde610 00007ff9`e6e1bf11 System_ServiceModel_ni+0xe72cfe
0b 00000030`f4cde690 00007ff9`e6e1be90 System_ServiceModel_Internals_ni+0×4bf11
0c 00000030`f4cde6f0 00007ff9`ed205156 System_ServiceModel_Internals_ni+0×4be90
0d 00000030`f4cde750 00007ff9`ee35ab53 mscorlib_ni+0×545156
0e 00000030`f4cde7b0 00007ff9`ee35aa3e clr!CallDescrWorkerInternal+0×83
0f 00000030`f4cde7f0 00007ff9`ee395b80 clr!CallDescrWorkerWithHandler+0×4a
10 00000030`f4cde830 00007ff9`ee9160b8 clr!DispatchCallSimple+0×60
11 00000030`f4cde8c0 00007ff9`ee35c481 clr!BindIoCompletionCallBack_Worker+0xb8
12 00000030`f4cde950 00007ff9`ee35c408 clr!ManagedThreadBase_DispatchInner+0×2d
13 00000030`f4cde990 00007ff9`ee35c379 clr!ManagedThreadBase_DispatchMiddle+0×6c
14 00000030`f4cdea90 00007ff9`ee35c4bb clr!ManagedThreadBase_DispatchOuter+0×75
15 00000030`f4cdeb20 00007ff9`ee916219 clr!ManagedThreadBase_FullTransitionWithAD+0×2f
16 00000030`f4cdeb80 00007ff9`ee916129 clr!BindIoCompletionCallbackStubEx+0xb9
17 00000030`f4cdec00 00007ff9`ee4da72d clr!BindIoCompletionCallbackStub+0×9
18 00000030`f4cdec30 00007ff9`ee417de6 clr!ThreadpoolMgr::CompletionPortThreadStart+0×23d
19 00000030`f4cdecd0 00007ff9`f60413d2 clr!Thread::intermediateThreadProc+0×7d
1a 00000030`f4cdfd10 00007ff9`f6ea54e4 kernel32!BaseThreadInitThunk+0×22
1b 00000030`f4cdfd40 00000000`00000000 ntdll!RtlUserThreadStart+0×34

17  Id: ad8.1584 Suspend: 0 Teb: 00007ff5`ff644000 Unfrozen
# Child-SP          RetAddr           Call Site
00 00000030`f4dde9e8 00007ff9`f4121118 ntdll!NtWaitForSingleObject+0xa
01 00000030`f4dde9f0 00007ff9`ee3594fb KERNELBASE!WaitForSingleObjectEx+0x94
02 00000030`f4ddea90 00007ff9`ee3594a7 clr!CLREventWaitHelper2+0x38
03 00000030`f4ddead0 00007ff9`ee359430 clr!CLREventWaitHelper+0x1f
04 00000030`f4ddeb30 00007ff9`ee533c96 clr!CLREventBase::WaitEx+0x63
05 00000030`f4ddebc0 00007ff9`ee85849a clr!SVR::gc_heap::user_thread_wait+0x58
06 00000030`f4ddebf0 00007ff9`ee780417 clr!SVR::gc_heap::background_gc_wait+0x4a
07 00000030`f4ddec20 00007ff9`ee4c41e8 clr!SVR::gc_heap::wait_for_bgc_high_memory+0x2b8907
08 00000030`f4ddecb0 00007ff9`ee35579d clr!SVR::GCHeap::Alloc+0×257
09 00000030`f4dded10 00007ff9`ee355f32 clr!AllocateArrayEx+0×1a6
0a 00000030`f4ddee40 00007ff9`ed204d4f clr!JIT_NewArr1+0×252

0b 00000030`f4ddf0f0 00007ff9`e6e13574 mscorlib_ni+0×544d4f
0c 00000030`f4ddf150 00007ff9`e6e1bf11 System_ServiceModel_Internals_ni+0×43574
0d 00000030`f4ddf1c0 00007ff9`e6e1be90 System_ServiceModel_Internals_ni+0×4bf11
0e 00000030`f4ddf220 00007ff9`ed205156 System_ServiceModel_Internals_ni+0×4be90
0f 00000030`f4ddf280 00007ff9`ee35ab53 mscorlib_ni+0×545156
10 00000030`f4ddf2e0 00007ff9`ee35aa3e clr!CallDescrWorkerInternal+0×83
11 00000030`f4ddf320 00007ff9`ee395b80 clr!CallDescrWorkerWithHandler+0×4a
12 00000030`f4ddf360 00007ff9`ee9160b8 clr!DispatchCallSimple+0×60
13 00000030`f4ddf3f0 00007ff9`ee35c481 clr!BindIoCompletionCallBack_Worker+0xb8
14 00000030`f4ddf480 00007ff9`ee35c408 clr!ManagedThreadBase_DispatchInner+0×2d
15 00000030`f4ddf4c0 00007ff9`ee35c379 clr!ManagedThreadBase_DispatchMiddle+0×6c
16 00000030`f4ddf5c0 00007ff9`ee35c4bb clr!ManagedThreadBase_DispatchOuter+0×75
17 00000030`f4ddf650 00007ff9`ee916219 clr!ManagedThreadBase_FullTransitionWithAD+0×2f
18 00000030`f4ddf6b0 00007ff9`ee916129 clr!BindIoCompletionCallbackStubEx+0xb9
19 00000030`f4ddf730 00007ff9`ee4da72d clr!BindIoCompletionCallbackStub+0×9
1a 00000030`f4ddf760 00007ff9`ee417de6 clr!ThreadpoolMgr::CompletionPortThreadStart+0×23d
1b 00000030`f4ddf800 00007ff9`f60413d2 clr!Thread::intermediateThreadProc+0×7d
1c 00000030`f4ddf840 00007ff9`f6ea54e4 kernel32!BaseThreadInitThunk+0×22
1d 00000030`f4ddf870 00000000`00000000 ntdll!RtlUserThreadStart+0×34

[...]

20  Id: ad8.fcc Suspend: 0 Teb: 00007ff5`ff64c000 Unfrozen
# Child-SP          RetAddr           Call Site
00 00000030`f4fde938 00007ff9`f4121118 ntdll!NtWaitForSingleObject+0xa
01 00000030`f4fde940 00007ff9`ee3594fb KERNELBASE!WaitForSingleObjectEx+0x94
02 00000030`f4fde9e0 00007ff9`ee3594a7 clr!CLREventWaitHelper2+0x38
03 00000030`f4fdea20 00007ff9`ee359430 clr!CLREventWaitHelper+0x1f
04 00000030`f4fdea80 00007ff9`ee533c96 clr!CLREventBase::WaitEx+0x63
05 00000030`f4fdeb10 00007ff9`ee85849a clr!SVR::gc_heap::user_thread_wait+0x58
06 00000030`f4fdeb40 00007ff9`ee780417 clr!SVR::gc_heap::background_gc_wait+0x4a
07 00000030`f4fdeb70 00007ff9`ee4c41e8 clr!SVR::gc_heap::wait_for_bgc_high_memory+0x2b8907
08 00000030`f4fdec00 00007ff9`ee3555f0 clr!SVR::GCHeap::Alloc+0×257
09 00000030`f4fdec60 00007ff9`ee41963a clr!AllocateObject+0×68

0a 00000030`f4fdecf0 00007ff9`ee41983d clr!Thread::GetExposedObject+0×4e
0b 00000030`f4fded90 00007ff9`ee355a3a clr!GetCurrentThreadHelper+0×99
0c 00000030`f4fdeef0 00007ff9`ed162b87 clr!ThreadNative::GetCurrentThread+0×22
0d 00000030`f4fdef20 00007ff9`ed162ab9 mscorlib_ni+0×4a2b87
0e 00000030`f4fdf080 00007ff9`ed1e49c2 mscorlib_ni+0×4a2ab9
0f 00000030`f4fdf0b0 00007ff9`ed1e47ae mscorlib_ni+0×5249c2
10 00000030`f4fdf140 00007ff9`ed18c084 mscorlib_ni+0×5247ae
11 00000030`f4fdf1b0 00007ff9`ee35ab53 mscorlib_ni+0×4cc084
12 00000030`f4fdf250 00007ff9`ee35aa3e clr!CallDescrWorkerInternal+0×83
13 00000030`f4fdf290 00007ff9`ee35b1d2 clr!CallDescrWorkerWithHandler+0×4a
14 00000030`f4fdf2d0 00007ff9`ee40e053 clr!MethodDescCallSite::CallTargetWorker+0×251
15 00000030`f4fdf480 00007ff9`ee35c481 clr!AppDomainTimerCallback_Worker+0×23
16 00000030`f4fdf570 00007ff9`ee35c408 clr!ManagedThreadBase_DispatchInner+0×2d
17 00000030`f4fdf5b0 00007ff9`ee35c379 clr!ManagedThreadBase_DispatchMiddle+0×6c
18 00000030`f4fdf6b0 00007ff9`ee35c4bb clr!ManagedThreadBase_DispatchOuter+0×75
19 00000030`f4fdf740 00007ff9`ee40dfe5 clr!ManagedThreadBase_FullTransitionWithAD+0×2f
1a 00000030`f4fdf7a0 00007ff9`ee40df59 clr!AppDomainTimerCallback+0×66
1b 00000030`f4fdf800 00007ff9`ee40db62 clr!ThreadpoolMgr::AsyncTimerCallbackCompletion+0×36
1c 00000030`f4fdf850 00007ff9`ee540af6 clr!UnManagedPerAppDomainTPCount::DispatchWorkItem+0×122
1d 00000030`f4fdf8f0 00007ff9`ee5409ea clr!ThreadpoolMgr::ExecuteWorkRequest+0×46
1e 00000030`f4fdf920 00007ff9`ee417de6 clr!ThreadpoolMgr::WorkerThreadStart+0xf4
1f 00000030`f4fdf9b0 00007ff9`f60413d2 clr!Thread::intermediateThreadProc+0×7d
20 00000030`f4fdfbf0 00007ff9`f6ea54e4 kernel32!BaseThreadInitThunk+0×22
21 00000030`f4fdfc20 00000000`00000000 ntdll!RtlUserThreadStart+0×34

0:000> !runaway
User Mode Time
Thread       Time
8:1960      0 days 1:09:12.218
14:11d4      0 days 0:03:31.937

2:9e8       0 days 0:03:03.250
3:e34       0 days 0:02:41.562
13:f54       0 days 0:02:38.718
4:1338      0 days 0:00:07.984
0:1014      0 days 0:00:00.046
11:1534      0 days 0:00:00.015
7:1798      0 days 0:00:00.015
20:fcc       0 days 0:00:00.000
19:f48       0 days 0:00:00.000
18:1a60      0 days 0:00:00.000
17:1584      0 days 0:00:00.000
16:d50       0 days 0:00:00.000
15:f9c       0 days 0:00:00.000
12:1988      0 days 0:00:00.000
10:14fc      0 days 0:00:00.000
9:1ae0      0 days 0:00:00.000
6:14cc      0 days 0:00:00.000
5:1a50      0 days 0:00:00.000
1:1258      0 days 0:00:00.000

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -

Leave a Reply