Archive for the ‘.NET Debugging’ Category

Crash Dump Analysis Patterns (Part 8c)

Saturday, August 11th, 2018

For completion, we introduce a managed space version of Hidden Exception in addition to user and kernel space variants.

0:000> ~*kL
[...]
13 Id: 1b70.1c2c Suspend: 0 Teb: 00446000 Unfrozen
# ChildEBP RetAddr
00 08e7ec4c 755e1cf3 ntdll!NtWaitForMultipleObjects+0xc
01 08e7ede0 6ef8bc6e KERNELBASE!WaitForMultipleObjectsEx+0x133
02 08e7ee30 6ef8b9b3 clr!WaitForMultipleObjectsEx_SO_TOLERANT+0x3c
03 08e7eebc 6ef8baa4 clr!Thread::DoAppropriateWaitWorker+0x237
04 08e7ef28 6ef8bc14 clr!Thread::DoAppropriateWait+0x64
05 08e7ef74 6eef648b clr!CLREventBase::WaitEx+0x128
06 08e7ef8c 6f0058f6 clr!CLREventBase::Wait+0x1a
07 08e7f018 6f005834 clr!AwareLock::EnterEpilogHelper+0xa8
08 08e7f060 6f005980 clr!AwareLock::EnterEpilog+0x48
09 08e7f078 6f00662c clr!AwareLock::Enter+0x4a
0a 08e7f104 08d71d79 clr!JITutil_MonEnterWorker+0x9c
WARNING: Frame IP not in any known module. Following frames may be wrong.
0b 08e7f120 6dd9608d 0x8d71d79
0c 08e7f12c 6ddc2925 mscorlib_ni+0x3c608d
0d 08e7f190 6ddc2836 mscorlib_ni+0x3f2925
0e 08e7f1a4 6ddc27f1 mscorlib_ni+0x3f2836
0f 08e7f1c0 6dd95fe8 mscorlib_ni+0x3f27f1
10 08e7f1d8 6ee6eaf6 mscorlib_ni+0x3c5fe8
11 08e7f1e4 6ee71d50 clr!CallDescrWorkerInternal+0x34
12 08e7f238 6ee77764 clr!CallDescrWorkerWithHandler+0x6b
13 08e7f2a0 6eef4d2d clr!MethodDescCallSite::CallTargetWorker+0x16a
14 08e7f414 6efae269 clr!ThreadNative::KickOffThread_Worker+0x173
15 08e7f428 6efae2d3 clr!ManagedThreadBase_DispatchInner+0x71
16 08e7f4cc 6efae3a0 clr!ManagedThreadBase_DispatchMiddle+0x7e
17 08e7f528 6ee7af05 clr!ManagedThreadBase_DispatchOuter+0x5b
18 08e7f534 6ee7aea2 clr!ManagedThreadBase_DispatchInCorrectAD+0x15
19 08e7f600 6ee7af4d clr!Thread::DoADCallBack+0x328
1a 08e7f624 6efae2d3 clr!ManagedThreadBase_DispatchInner+0x4e
1b 08e7f6c8 6efae3a0 clr!ManagedThreadBase_DispatchMiddle+0x7e
1c 08e7f724 6efae40f clr!ManagedThreadBase_DispatchOuter+0x5b
1d 08e7f748 6eef4be2 clr!ManagedThreadBase_FullTransitionWithAD+0x2f
1e 08e7f7c4 6eef62d1 clr!ThreadNative::KickOffThread+0x256
1f 08e7fbe4 76c28484 clr!Thread::intermediateThreadProc+0x55
20 08e7fbf8 77842fea kernel32!BaseThreadInitThunk+0x24
21 08e7fc40 77842fba ntdll!__RtlUserThreadStart+0x2f
22 08e7fc50 00000000 ntdll!_RtlUserThreadStart+0x1b
[...]

0:000> ~13s
eax=00000000 ebx=00000001 ecx=00000000 edx=00000000 esi=00000001 edi=00000001
eip=7784a7bc esp=08e7ec50 ebp=08e7ede0 iopl=0 nv up ei pl nz ac pe nc
cs=0023 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000216
ntdll!NtWaitForMultipleObjects+0xc:
7784a7bc c21400 ret 14h

0:013> !CLRStack
OS Thread Id: 0x1c2c (13)
Child SP IP Call Site
08e7efb4 7784a7bc [GCFrame: 08e7efb4]
08e7f094 7784a7bc [HelperMethodFrame_1OBJ: 08e7f094] System.Threading.Monitor.Enter(System.Object)
08e7f10c 08d71d79 UserQuery+ClassMain.thread_proc_1()
08e7f128 6dd9608d *** ERROR: Module load completed but symbols could not be loaded for mscorlib.ni.dll
System.Threading.ThreadHelper.ThreadStart_Context(System.Object)
08e7f134 6ddc2925 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
08e7f1a0 6ddc2836 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
08e7f1b4 6ddc27f1 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
08e7f1cc 6dd95fe8 System.Threading.ThreadHelper.ThreadStart()
08e7f308 6ee6eaf6 [GCFrame: 08e7f308]
08e7f4e8 6ee6eaf6 [DebuggerU2MCatchHandlerFrame: 08e7f4e8]
08e7f554 6ee6eaf6 [ContextTransitionFrame: 08e7f554]
08e7f6e4 6ee6eaf6 [DebuggerU2MCatchHandlerFrame: 08e7f6e4]

0:013> !teb
TEB at 00446000
ExceptionList: 08e7edd0
StackBase: 08e80000
StackLimit: 08e7a000

SubSystemTib: 00000000
FiberData: 00001e00
ArbitraryUserPointer: 00000000
Self: 00446000
EnvironmentPointer: 00000000
ClientId: 00001b70 . 00001c2c
RpcHandle: 00000000
Tls Storage: 008eb8e8
PEB Address: 0040a000
LastErrorValue: 0
LastStatusValue: c0000034
Count Owned Locks: 0
HardErrorMode: 0

0:013> !DumpStackObjects 08e7a000 08e80000
OS Thread Id: 0×1c2c (13)
ESP/REG Object Name
08E7DD18 0270f714 LINQPad.ExecutionModel.OutPipe
08E7DD20 02736ca8 LINQPad.Disposable
08E7DD2C 0270f714 LINQPad.ExecutionModel.OutPipe
08E7DD3C 02736ca8 LINQPad.Disposable
08E7DD40 02736c88 System.Action
08E7DD44 02736ca8 LINQPad.Disposable
08E7DD64 0270f714 LINQPad.ExecutionModel.OutPipe
08E7DD98 02736ca8 LINQPad.Disposable
08E7DDB8 0270f714 LINQPad.ExecutionModel.OutPipe
08E7DE78 0270f9ec System.Object
08E7DE7C 0270f990 LINQPad.ObjectGraph.Formatters.HtmlWriter
08E7DEAC 0270f990 LINQPad.ObjectGraph.Formatters.HtmlWriter
08E7DEE4 0262e16c System.String
08E7DEF8 026aa9d0 System.String
08E7DF04 0270f990 LINQPad.ObjectGraph.Formatters.HtmlWriter
08E7E054 02724ecc System.Threading.ThreadHelper
08E7E058 026fad7c System.Threading.ContextCallback
08E7E06C 026fad7c System.Threading.ContextCallback
08E7E074 02724ecc System.Threading.ThreadHelper
08E7E0A8 0272fb68 System.NullReferenceException
08E7E0AC 026fad7c System.Threading.ContextCallback
08E7E0B8 02724ecc System.Threading.ThreadHelper
08E7E340 0272fcc0 System.Runtime.CompilerServices.RuntimeHelpers+TryCode
08E7E344 0272fce0 System.Runtime.CompilerServices.RuntimeHelpers+CleanupCode
08E7E348 0272fca4 System.Environment+ResourceHelper+GetResourceStringUserData
08E7E35C 0272fce0 System.Runtime.CompilerServices.RuntimeHelpers+CleanupCode
08E7E378 0272fca4 System.Environment+ResourceHelper+GetResourceStringUserData
08E7E37C 0272fc0c System.Environment+ResourceHelper
08E7E964 0272fb68 System.NullReferenceException
08E7EB3C 02724ecc System.Threading.ThreadHelper
08E7ECCC 02724ecc System.Threading.ThreadHelper
08E7ECD0 026fad7c System.Threading.ContextCallback
08E7ECD8 0272fa88 System.String critical section 1
08E7EFE8 0272fabc System.String critical section 2
08E7F034 026fad7c System.Threading.ContextCallback
08E7F088 02724ecc System.Threading.ThreadHelper
08E7F08C 026fad7c System.Threading.ContextCallback
08E7F0B8 02724ecc System.Threading.ThreadHelper
08E7F0C0 026fad7c System.Threading.ContextCallback
08E7F0F0 0272fabc System.String critical section 2
08E7F11C 026fad7c System.Threading.ContextCallback
08E7F128 02724f00 System.Threading.ExecutionContext
08E7F134 02724e98 System.Threading.Thread
08E7F144 02724e98 System.Threading.Thread
08E7F188 02724f00 System.Threading.ExecutionContext
08E7F18C 026fad7c System.Threading.ContextCallback
08E7F19C 02724ecc System.Threading.ThreadHelper
08E7F1B0 02724ecc System.Threading.ThreadHelper
08E7F1B8 02724ecc System.Threading.ThreadHelper
08E7F1BC 02724f00 System.Threading.ExecutionContext
08E7F1C8 02724ecc System.Threading.ThreadHelper
08E7F244 02724ee0 System.Threading.ThreadStart
08E7F2C4 02724ee0 System.Threading.ThreadStart
08E7F2D8 02724ee0 System.Threading.ThreadStart

The example dump can be downloaded from here.

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

Crash Dump Analysis Patterns (Part 256)

Saturday, August 4th, 2018

Backwards disassembling used in memory analysis patterns such as Coincidental Symbolic Information may be ambiguous and can show Wild Code output. This may also be debugger disassembling algorithm dependent. For example, default 8-instruction backwards disassembly shows this code:

0:011> ub 00007ff8`cdc9b4bf
00007ff8`cdc9b4ab 855948 test dword ptr [rcx+48h],ebx
00007ff8`cdc9b4ae b988bf03a8 mov ecx,0A803BF88h
00007ff8`cdc9b4b3 f4 hlt
00007ff8`cdc9b4b4 0100 add dword ptr [rax],eax
00007ff8`cdc9b4b6 00488b add byte ptr [rax-75h],cl
00007ff8`cdc9b4b9 09e8 or eax,ebp
00007ff8`cdc9b4bb 117236 adc dword ptr [rdx+36h],esi
00007ff8`cdc9b4be 5f pop rdi

However, if we specify the number of instructions to disassemble except 7 and 8 we get a different result (which is more correct from the forward code execution view since we disassembled the saved return address from the stack region):

0:011> ub 00007ff8`cdc9b4bf L1
00007ff8`cdc9b4ba e81172365f call clr!JIT_MonEnter (00007ff9`2d0026d0)

0:011> ub 00007ff8`cdc9b4bf L2
00007ff8`cdc9b4b7 488b09 mov rcx,qword ptr [rcx]
00007ff8`cdc9b4ba e81172365f call clr!JIT_MonEnter (00007ff9`2d0026d0)

0:011> k L10
# Child-SP RetAddr Call Site
00 0000002a`fc23e308 00007ff9`53d06099 ntdll!NtWaitForMultipleObjects+0x14
01 0000002a`fc23e310 00007ff9`2d1a96be KERNELBASE!WaitForMultipleObjectsEx+0xf9
02 0000002a`fc23e610 00007ff9`2d1a951c clr!WaitForMultipleObjectsEx_SO_TOLERANT+0x62
03 0000002a`fc23e670 00007ff9`2d1a9315 clr!Thread::DoAppropriateWaitWorker+0x1e4
04 0000002a`fc23e770 00007ff9`2d0c2b7f clr!Thread::DoAppropriateWait+0x7d
05 0000002a`fc23e7f0 00007ff9`2d1aa491 clr!CLREventBase::WaitEx+0xc4
06 0000002a`fc23e880 00007ff9`2d1aa39e clr!AwareLock::EnterEpilogHelper+0xc2
07 0000002a`fc23e940 00007ff9`2d1c1a92 clr!AwareLock::EnterEpilog+0x62
08 0000002a`fc23e9a0 00007ff8`cdc9b4bf clr!JITutil_MonEnterWorker+0xe2
09 0000002a`fc23eb40 00007ff9`275231d3 0×00007ff8`cdc9b4bf
0a 0000002a`fc23eb80 00007ff9`27523064 mscorlib_ni+0×5031d3
0b 0000002a`fc23ec50 00007ff9`27523032 mscorlib_ni+0×503064
0c 0000002a`fc23ec80 00007ff9`2751c812 mscorlib_ni+0×503032
0d 0000002a`fc23ecd0 00007ff9`2d006bb3 mscorlib_ni+0×4fc812
0e 0000002a`fc23ed10 00007ff9`2d006a70 clr!CallDescrWorkerInternal+0×83
0f 0000002a`fc23ed50 00007ff9`2d00735d clr!CallDescrWorkerWithHandler+0×4e

We call this analysis pattern Disassembly Ambiguity. The example dump can be downloaded from here.

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

Crash Dump Analysis Patterns (Part 9h)

Saturday, May 13th, 2017

In one .NET process memory dump we noticed Managed Stack Trace pointing that the thread was waiting for .NET Finalizer to finish its work:

0:000> !CLRStack
OS Thread Id: 0x60b0 (0)
ESP       EIP
00a585d8 773dca2c [HelperMethodFrame: 00a585d8] System.GC.WaitForPendingFinalizers()
00a58628 10105bbb ComponentA.FreeMemory()

The unmanaged stack trace involved Windows forms and COM object modal loops:

0:000> k
ChildEBP RetAddr
00a58034 7644112f ntdll!NtWaitForMultipleObjects+0xc
00a581c0 75ecd433 KERNELBASE!WaitForMultipleObjectsEx+0xcc
00a58224 7655fab4 user32!MsgWaitForMultipleObjectsEx+0x163
00a5825c 7656097c combase!CCliModalLoop::BlockFn+0×111
00a58314 765591fa combase!ClassicSTAThreadWaitForHandles+0×9e
00a58344 6e59103d combase!CoWaitForMultipleHandles+0×84
00a58364 6e590f9e mscorwks!NT5WaitRoutine+0×51
00a583d0 6e590f02 mscorwks!MsgWaitHelper+0xa5
00a583f0 6e6665e8 mscorwks!Thread::DoAppropriateAptStateWait+0×28
00a58474 6e66667d mscorwks!Thread::DoAppropriateWaitWorker+0×13c
00a584c4 6e666801 mscorwks!Thread::DoAppropriateWait+0×40
00a58520 6e5056b8 mscorwks!CLREvent::WaitEx+0xf7
00a58534 6e59eea3 mscorwks!CLREvent::Wait+0×17
00a58584 6e59ec19 mscorwks!WKS::GCHeap::FinalizerThreadWait+0xfb
00a58620 10105bbb mscorwks!GCInterface::RunFinalizers+0×99

00a58684 6cd8683b 0×10105bbb
00a586a0 6c4f5a52 System_Windows_Forms_ni+0xa5683b
00a586e4 6cd8e8f4 System_Windows_Forms_ni+0×1c5a52
00a586f8 6c529a00 System_Windows_Forms_ni+0xa5e8f4
00a58700 6c529981 System_Windows_Forms_ni+0×1f9a00
00a58714 6c52985a System_Windows_Forms_ni+0×1f9981
00a58778 75ec8e71 System_Windows_Forms_ni+0×1f985a
00a587a4 75ec90d1 user32!_InternalCallWinProc+0×2b
00a58838 75ec932c user32!UserCallWinProcCheckWow+0×18e
00a58898 75ec9529 user32!DispatchClientMessage+0xdc
00a588d8 773e07d6 user32!__fnDWORD+0×49
00a588ec 01293a30 ntdll!KiUserCallbackDispatcher+0×36
00a58998 75ecb0f8 0×1293a30
00a589e8 75ec8e71 user32!DefWindowProcW+0×118
00a58a14 75ec90d1 user32!_InternalCallWinProc+0×2b
00a58aa8 75ecddd5 user32!UserCallWinProcCheckWow+0×18e
00a58ae4 6c52a033 user32!CallWindowProcW+0×8d
00a58b3c 6c5331a9 System_Windows_Forms_ni+0×1fa033
00a58b84 6c529b1e System_Windows_Forms_ni+0×2031a9
00a58bdc 6c53310a System_Windows_Forms_ni+0×1f9b1e
00a58be8 6c5330c0 System_Windows_Forms_ni+0×20310a
00a58bf0 6c532d80 System_Windows_Forms_ni+0×2030c0
00a58c04 6c529a00 System_Windows_Forms_ni+0×202d80
00a58c0c 6c529981 System_Windows_Forms_ni+0×1f9a00
00a58c20 6c52985a System_Windows_Forms_ni+0×1f9981
00a58c84 75ec8e71 System_Windows_Forms_ni+0×1f985a
00a58cb0 75ec90d1 user32!_InternalCallWinProc+0×2b
00a58d44 75ec932c user32!UserCallWinProcCheckWow+0×18e
00a58da4 75ec9529 user32!DispatchClientMessage+0xdc
00a58de4 773e07d6 user32!__fnDWORD+0×49
00a58df8 011efaa0 ntdll!KiUserCallbackDispatcher+0×36
00a58e48 75eca989 0×11efaa0
00a58e7c 765603c3 user32!PeekMessageW+0×135
00a58ed0 76560436 combase!CCliModalLoop::MyPeekMessage+0×31
00a58f10 76560630 combase!CCliModalLoop::PeekRPCAndDDEMessage+0×31
00a58f3c 76560506 combase!CCliModalLoop::FindMessage+0×2b
00a58fa0 765605fb combase!CCliModalLoop::HandleWakeForMsg+0×44
00a58fc4 7656097c combase!CCliModalLoop::BlockFn+0×19d
00a5907c 765591fa combase!ClassicSTAThreadWaitForHandles+0×9e
00a590ac 6e59103d combase!CoWaitForMultipleHandles+0×84
00a590cc 6e590f9e mscorwks!NT5WaitRoutine+0×51
00a59138 6e590f02 mscorwks!MsgWaitHelper+0xa5
00a59158 6e6665e8 mscorwks!Thread::DoAppropriateAptStateWait+0×28
00a591dc 6e66667d mscorwks!Thread::DoAppropriateWaitWorker+0×13c
00a5922c 6e666801 mscorwks!Thread::DoAppropriateWait+0×40
00a59288 6e5056b8 mscorwks!CLREvent::WaitEx+0xf7
00a5929c 6e59eea3 mscorwks!CLREvent::Wait+0×17
00a592ec 6e59ec19 mscorwks!WKS::GCHeap::FinalizerThreadWait+0xfb
00a59388 10105bbb mscorwks!GCInterface::RunFinalizers+0×99

00a593ec 6cd8683b 0×10105bbb
00a59408 6ca863bd System_Windows_Forms_ni+0xa5683b
00a59438 6cd90b7e System_Windows_Forms_ni+0×7563bd
00a59480 6c539eee System_Windows_Forms_ni+0xa60b7e
00a5951c 6c539bf7 System_Windows_Forms_ni+0×209eee
00a59574 6c539a41 System_Windows_Forms_ni+0×209bf7
00a595a4 6ca4fc97 System_Windows_Forms_ni+0×209a41
00a595bc 6ca84598 System_Windows_Forms_ni+0×71fc97
00a59648 6ca847af System_Windows_Forms_ni+0×754598
00a59bc8 0996d41c System_Windows_Forms_ni+0×7547af
00a59c2c 0bc02e6d 0×996d41c
00a59c5c 0996b842 0xbc02e6d
00a59fb8 0fa8fa87 0×996b842
00a5a00c 0fa8f205 0xfa8fa87
00a5a040 0fa8f10b 0xfa8f205
00a5a058 02676666 0xfa8f10b
00a5a094 0fa8f09f 0×2676666
00a5a0a8 0fa8ed0c 0xfa8f09f
00a5a1b8 6dc355dc 0xfa8ed0c
00a5a238 6ca59703 mscorlib_ni+0×2355dc
00a5a2bc 6cd8c376 System_Windows_Forms_ni+0×729703
00a5a31c 6c529a00 System_Windows_Forms_ni+0xa5c376
00a5a324 6c529981 System_Windows_Forms_ni+0×1f9a00
00a5a338 6c52985a System_Windows_Forms_ni+0×1f9981
00a5a378 6cd8c587 System_Windows_Forms_ni+0×1f985a
00a5a3c8 6c511125 System_Windows_Forms_ni+0xa5c587
00a5a3f0 6c52985a System_Windows_Forms_ni+0×1e1125
00a5a454 75ec8e71 System_Windows_Forms_ni+0×1f985a
00a5a480 75ec90d1 user32!_InternalCallWinProc+0×2b
00a5a514 75eca66f user32!UserCallWinProcCheckWow+0×18e
00a5a580 75eca6e0 user32!DispatchMessageWorker+0×208
00a5a58c 0f1c6f4e user32!DispatchMessageW+0×10
00a5a5c0 0f1c58ed ModuleA+0×13c4e
[…]

We found Finalizer Special Thread:

0:002> k
ChildEBP RetAddr
0316ecc8 76432cc7 ntdll!NtWaitForSingleObject+0xc
0316ed3c 76432c02 KERNELBASE!WaitForSingleObjectEx+0x99
0316ed50 765b9839 KERNELBASE!WaitForSingleObject+0x12
(Inline) -------- combase!MTAThreadWaitForCall+0x43
0316ed80 7665d524 combase!MTAThreadDispatchCrossApartmentCall+0x1ed
(Inline) -------- combase!CRpcChannelBuffer::SwitchAptAndDispatchCall+0x33a2
0316eed4 7653caea combase!CRpcChannelBuffer::SendReceive2+0×62d
(Inline) ——– combase!ClientCallRetryContext::SendReceiveWithRetry+0×2e
(Inline) ——– combase!CAptRpcChnl::SendReceiveInRetryContext+0×81
0316ef34 76581789 combase!DefaultSendReceive+0×9e
(Inline) ——– combase!CAptRpcChnl::SendReceive+0×38
0316ef98 7665a010 combase!CCtxComChnl::SendReceive+0×248
0316efbc 76f85769 combase!NdrExtpProxySendReceive+0×5c
0316efd4 77006c1b rpcrt4!NdrpProxySendReceive+0×29
0316f400 76659e1e rpcrt4!NdrClientCall2+0×22b
0316f420 7653c46f combase!ObjectStublessClient+0×6c
0316f430 76581c07 combase!ObjectStubless+0xf
0316f4c4 76583024 combase!CObjectContext::InternalContextCallback+0×1e4
0316f518 6e6fcd4b combase!CObjectContext::ContextCallback+0xbc
0316f564 6e6fd936 mscorwks!CtxEntry::EnterContextOle32BugAware+0×2b
0316f684 6e7329cf mscorwks!CtxEntry::EnterContext+0×325
0316f6b8 6e732a74 mscorwks!RCWCleanupList::ReleaseRCWListInCorrectCtx+0xc4
0316f708 6e5908e3 mscorwks!RCWCleanupList::CleanupAllWrappers+0xdb
0316f74c 6e5907f3 mscorwks!SyncBlockCache::CleanupSyncBlocks+0xec
0316f910 6e589b7c mscorwks!Thread::DoExtraWorkForFinalizer+0×40
0316f920 6e54547f mscorwks!WKS::GCHeap::FinalizerThreadWorker+0×9a
0316f934 6e54541b mscorwks!Thread::DoADCallBack+0×32a
0316f9c8 6e54533a mscorwks!Thread::ShouldChangeAbortToUnload+0xe3
0316fa04 6e5b2763 mscorwks!Thread::ShouldChangeAbortToUnload+0×30a
0316fa2c 6e5b2774 mscorwks!ManagedThreadBase_NoADTransition+0×32
0316fa3c 6e5cb816 mscorwks!ManagedThreadBase::FinalizerBase+0xd
0316fa74 6e660ae9 mscorwks!WKS::GCHeap::FinalizerThreadStart+0xbb
0316fb10 76307c04 mscorwks!Thread::intermediateThreadProc+0×49
0316fb24 773fad1f kernel32!BaseThreadInitThunk+0×24
0316fb6c 773facea ntdll!__RtlUserThreadStart+0×2f
0316fb7c 00000000 ntdll!_RtlUserThreadStart+0×1b

We saw that it was blocked in an RPC call. Using the technique from In Search of Lost CID article we found the destination thread:

0:002> kvL
ChildEBP RetAddr  Args to Child
0316ecc8 76432cc7 0000096c 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
0316ed3c 76432c02 0000096c ffffffff 00000000 KERNELBASE!WaitForSingleObjectEx+0x99
0316ed50 765b9839 0000096c ffffffff 00ddfb88 KERNELBASE!WaitForSingleObject+0x12
(Inline) -------- -------- -------- -------- combase!MTAThreadWaitForCall+0x43
0316ed80 7665d524 00ddf298 0629fa10 0316efec combase!MTAThreadDispatchCrossApartmentCall+0x1ed
(Inline) -------- -------- -------- -------- combase!CRpcChannelBuffer::SwitchAptAndDispatchCall+0x33a2
0316eed4 7653caea 00ddfb88 0316efec 0316efb4 combase!CRpcChannelBuffer::SendReceive2+0×62d
(Inline) ——– ——– ——– ——– combase!ClientCallRetryContext::SendReceiveWithRetry+0×2e
(Inline) ——– ——– ——– ——– combase!CAptRpcChnl::SendReceiveInRetryContext+0×81
0316ef34 76581789 00ddfb88 0316efec 0316efb4 combase!DefaultSendReceive+0×9e
(Inline) ——– ——– ——– ——– combase!CAptRpcChnl::SendReceive+0×38
0316ef98 7665a010 00ddfb88 0316efec 0316efb4 combase!CCtxComChnl::SendReceive+0×248
0316efbc 76f85769 0628365c 0316f018 76f85740 combase!NdrExtpProxySendReceive+0×5c
0316efd4 77006c1b 6d6b47ca 0628365c 0316f438 rpcrt4!NdrpProxySendReceive+0×29
0316f400 76659e1e 7652d8f8 76532ff0 0316f438 rpcrt4!NdrClientCall2+0×22b
[…]

0:002> dpp 00ddfb88
00ddfb88  7652d400 7665bff0 combase!CRpcChannelBuffer::QueryInterface
00ddfb8c  76541e2c 76664690 combase![thunk]:CRpcChannelBuffer::QueryInterface`adjustor{4}’
00ddfb90  7653a65c 766646a0 combase![thunk]:CRpcChannelBuffer::QueryInterface`adjustor{8}’
00ddfb94  adb1682c
00ddfb98  429b3908
00ddfb9c  2b59b182
00ddfba0  e6a936e1
00ddfba4  00000003
00ddfba8  0000002a
00ddfbac  06268d68 00000000
00ddfbb0  00000000
00ddfbb4  00ddf298 00ddf330
00ddfbb8  00ddfe70 00000000
00ddfbbc  062d7660 00000044
00ddfbc0  00deb5f0 7652d280 combase!CStdIdentity::`vftable’
00ddfbc4  7652b2e0 76568760 combase!CDestObject::QueryInterface
00ddfbc8  00070005
00ddfbcc  00000003
00ddfbd0  000060b0
00ddfbd4  00000000
00ddfbd8  00000000
00ddfbdc  7652d400 7665bff0 combase!CRpcChannelBuffer::QueryInterface
00ddfbe0  76541e2c 76664690 combase![thunk]:CRpcChannelBuffer::QueryInterface`adjustor{4}’
00ddfbe4  7653a65c 766646a0 combase![thunk]:CRpcChannelBuffer::QueryInterface`adjustor{8}’
00ddfbe8  adb1682c
00ddfbec  429b3908

0:002> dd 00ddf298
00ddf298  00ddf330 7666ddd0 000070b8 000060b0
00ddf2a8  056aadfb 14bb2b53 a45b843e 2611fcc9
00ddf2b8  a45b843e 2611fcc9 00001800 60b070b8
00ddf2c8  66fb7794 88242aca 04000203 00020052
00ddf2d8  00dbfb20 00000000 00000000 00000000
00ddf2e8  00000001 ffffffff 00de5e48 0628365c
00ddf2f8  00000005 00000000 00000001 00000000
00ddf308  00000000 00070005 00000000 00000000

We saw that the finalizer thread #2 was waiting for the thread #0 that was waiting for the finalizer thread #2:

0:002> ~
#  0  Id: 70b8.60b0 Suspend: 0 Teb: 7ecaf000 Unfrozen
1  Id: 70b8.26e8 Suspend: 0 Teb: 7ecac000 Unfrozen
.  2  Id: 70b8.5d2c Suspend: 0 Teb: 7eca9000 Unfrozen
3  Id: 70b8.551c Suspend: 0 Teb: 7eb76000 Unfrozen
4  Id: 70b8.7194 Suspend: 0 Teb: 7eb73000 Unfrozen
5  Id: 70b8.465c Suspend: 0 Teb: 7eb0f000 Unfrozen
6  Id: 70b8.64ac Suspend: 0 Teb: 7eb0c000 Unfrozen
7  Id: 70b8.6200 Suspend: 0 Teb: 7eb09000 Unfrozen
8  Id: 70b8.5790 Suspend: 0 Teb: 7eafa000 Unfrozen
9  Id: 70b8.6c3c Suspend: 0 Teb: 7eaf4000 Unfrozen
10  Id: 70b8.7320 Suspend: 0 Teb: 7eaeb000 Unfrozen
11  Id: 70b8.1ebc Suspend: 0 Teb: 7eb06000 Unfrozen
12  Id: 70b8.459c Suspend: 0 Teb: 7eb00000 Unfrozen
13  Id: 70b8.74e8 Suspend: 0 Teb: 7eb7f000 Unfrozen
14  Id: 70b8.6758 Suspend: 0 Teb: 7eafd000 Unfrozen
15  Id: 70b8.72e8 Suspend: 0 Teb: 7eaf1000 Unfrozen
16  Id: 70b8.5eec Suspend: 0 Teb: 7eaee000 Unfrozen
17  Id: 70b8.4a74 Suspend: 0 Teb: 7e83f000 Unfrozen
18  Id: 70b8.61b0 Suspend: 0 Teb: 7e83c000 Unfrozen
19  Id: 70b8.3cc4 Suspend: 0 Teb: 7e839000 Unfrozen
20  Id: 70b8.6554 Suspend: 0 Teb: 7e836000 Unfrozen
21  Id: 70b8.5b5c Suspend: 0 Teb: 7e833000 Unfrozen
22  Id: 70b8.6c48 Suspend: 0 Teb: 7e7ff000 Unfrozen
23  Id: 70b8.12dc Suspend: 0 Teb: 7e7fc000 Unfrozen
24  Id: 70b8.3a98 Suspend: 0 Teb: 7e7f9000 Unfrozen
25  Id: 70b8.1cb4 Suspend: 0 Teb: 7e7f6000 Unfrozen
26  Id: 70b8.5df8 Suspend: 0 Teb: 7e7f3000 Unfrozen
27  Id: 70b8.287c Suspend: 0 Teb: 7e69f000 Unfrozen
28  Id: 70b8.69b4 Suspend: 0 Teb: 7e69c000 Unfrozen
29  Id: 70b8.159c Suspend: 0 Teb: 7e699000 Unfrozen
30  Id: 70b8.1678 Suspend: 0 Teb: 7e696000 Unfrozen
31  Id: 70b8.8a0 Suspend: 0 Teb: 7e693000 Unfrozen
32  Id: 70b8.5984 Suspend: 0 Teb: 7e64f000 Unfrozen
33  Id: 70b8.256c Suspend: 0 Teb: 7e649000 Unfrozen

This is a variant of Deadlock memory analysis pattern.

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

Crash Dump Analysis Patterns (Part 29e)

Monday, May 8th, 2017

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 -

Trace Analysis Patterns (Part 124)

Saturday, April 30th, 2016

Trace Extension is an obvious log analysis pattern that is about trace messages that refer to some other trace or log that may or may not exist. Sometimes, there can be instructions to enable additional tracing that is not possible to cover by the current trace source. We have seen this in some trace statements from .NET Exception Stack Traces.

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

Crash Dump Analysis Patterns (Part 35b)

Saturday, September 12th, 2015

Sometimes we notice the anomalies in object distribution in heaps and pools. Memory consumption may be high in case of big objects. Such anomalies may point to possible memory, handle, and object leaks. But it may also be a temporary condition (Memory Fluctuation) due to the large amount of queued or postponed work that can be solved by proper software configuration. Diagnosed anomalies may also direction troubleshooting efforts if they cluster around certain component(s) or specific functionality. The distribution can be assessed by both the total memory consumption and the total number of objects of a particular class.

Here’s an example of Object Distribution Anomaly analysis pattern from .NET heap. The output of !DumpHeap -stat WinDbg SOS extension command shows the abnormal distribution of objects related to SQL data queries:

Count TotalSize
[…]
2342 281040 System.Reflection.RuntimeParameterInfo
3868 309440 System.Data.Metadata.Edm.TypeUsage
13218 317232 System.Object
3484 390208 System.Reflection.RuntimeMethodInfo
6092 508044 System.Int32[]
2756 617344 System.Data.SqlClient._SqlMetaData
2770 822870 System.Char[]
24560 1375360 System.RuntimeType
18 4195296 System.Int64[]
449691 10792584 System.Data.SqlClient.SqlGen.SqlBuilder
449961 10799064 System.Int64
449691 14390112 System.Data.Query.InternalTrees.ComparisonOp
449695 14390240 System.Data.Query.InternalTrees.ConditionalOp
6360 15509435 System.Byte[]
449690 17987600 System.Data.Query.InternalTrees.ConstantOp
449938 17997520 System.Data.Query.InternalTrees.VarRefOp
450898 21643104 System.Data.Common.CommandTrees.DbPropertyExpression
[…]

The anomalous character of the distribution is also illustrated in the following diagrams:

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

Crash Dump Analysis Patterns (Part 227)

Sunday, May 17th, 2015

Managed code Nested Exceptions give us process virtual space bound stack traces. However, exception objects may be marshaled across processes and even computers. The remote stack trace return addresses don’t have the same validity in different process contexts. Fortunately, there is _remoteStackTraceString field in exception objects that contains the original stack trace. Default analysis command sometimes uses it:

0:013> !analyze -v

[...]

EXCEPTION_OBJECT: !pe 25203b0
Exception object: 00000000025203b0
Exception type: System.Reflection.TargetInvocationException
Message: Exception has been thrown by the target of an invocation.
InnerException: System.Management.Instrumentation.WmiProviderInstallationException, Use !PrintException 0000000002522cf0 to see more.
StackTrace (generated):
SP IP Function
000000001D39E720 0000000000000001 Component!Proxy.Start()+0x20
000000001D39E720 000007FEF503D0B6 mscorlib_ni!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)+0x286
000000001D39E880 000007FEF503CE1A mscorlib_ni!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)+0xa
000000001D39E8B0 000007FEF503CDD8 mscorlib_ni!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)+0x58
000000001D39E900 000007FEF4FB0302 mscorlib_ni!System.Threading.ThreadHelper.ThreadStart()+0x52

[...]

MANAGED_STACK_COMMAND: ** Check field _remoteStackTraceString **;!do 2522cf0;!do 2521900

[...]

0:013> !DumpObj 2522cf0
[...]
000007fef51b77f0 4000054 2c System.String 0 instance 2521900 _remoteStackTraceString
[…]

0:013> !DumpObj 2521900
Name: System.String
[…]
String: at System.Management.Instrumentation.InstrumentationManager.RegisterType(Type managementType)
at Component.Provider..ctor()
at Component.Start()

Checking this field may also be necessary for exceptions of interest from managed space Execution Residue. We call this pattern Distributed Exception. The basic idea is illustrated in the following diagram using the borrowed UML notation (not limited to just two computers):

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

Crash Dump Analysis Patterns (Part 220)

Tuesday, February 17th, 2015

Sometimes, due to optimization or indeterminate stack trace reconstruction, we may not see all stack trace frames. In some case it is possible to reconstruct such Hidden Calls. For example, we have the following unmanaged Stack Trace of CLR Thread:

0:000> k
ChildEBP RetAddr
0011d6b8 66fdee7c mscorwks!JIT_IsInstanceOfClass+0xd
0011d6cc 67578500 PresentationCore_ni!`string'+0x4a2bc
0011d6e0 67578527 PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x778500)
0011d6f4 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x778527)
0011d708 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d71c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d730 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d744 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d758 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d76c 67578527 PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d780 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x778527)
0011d794 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d7a8 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d7bc 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d7d0 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d7e4 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d7f8 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d80c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d820 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d834 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d848 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d85c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d870 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d884 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d898 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d8ac 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d8c0 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d8d4 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d8e8 67578527 PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d8fc 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x778527)
0011d910 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d924 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d938 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d94c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d960 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d974 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d988 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d99c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d9b0 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d9c4 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d9d8 67578527 PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011d9ec 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x778527)
0011da00 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011da14 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011da28 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011da3c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011da50 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011da64 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011da78 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011da8c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011daa0 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dab4 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dac8 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dadc 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011daf0 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011db04 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011db18 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011db2c 67578527 PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011db40 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x778527)
0011db54 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011db68 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011db7c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011db90 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dba4 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dbb8 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dbcc 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dbe0 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dbf4 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dc08 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dc1c 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dc30 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dc44 6757850d PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
0011dc58 66fc3282 PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x77850d)
*** WARNING: Unable to verify checksum for PresentationFramework.ni.dll
0011dd28 662a75e6 PresentationCore_ni!`string'+0x2e6c2
0011de08 662190a0 PresentationFramework_ni+0x2675e6
0011dffc 66fc35e2 PresentationFramework_ni+0x1d90a0
0011e0ec 66fd9dad PresentationCore_ni!`string'+0x2ea22
0011e214 66fe0459 PresentationCore_ni!`string'+0x451ed
0011e238 66fdfd40 PresentationCore_ni!`string'+0x4b899
0011e284 66fdfc9b PresentationCore_ni!`string'+0x4b180
*** WARNING: Unable to verify checksum for WindowsBase.ni.dll
0011e2b0 723ca31a PresentationCore_ni!`string'+0x4b0db
0011e2cc 723ca20a WindowsBase_ni+0x9a31a
0011e30c 723c8384 WindowsBase_ni+0x9a20a
0011e330 723cd26d WindowsBase_ni+0x98384
0011e368 723cd1f8 WindowsBase_ni+0x9d26d
0011e380 72841b4c WindowsBase_ni+0x9d1f8
0011e390 728589ec mscorwks!CallDescrWorker+0x33
0011e410 72865acc mscorwks!CallDescrWorkerWithHandler+0xa3
0011e54c 72865aff mscorwks!MethodDesc::CallDescr+0x19c
0011e568 72865b1d mscorwks!MethodDesc::CallTargetWorker+0x1f
0011e580 728bd9c8 mscorwks!MethodDescCallSite::CallWithValueTypes+0x1a
0011e74c 728bdb1e mscorwks!ExecuteCodeWithGuaranteedCleanupHelper+0x9f
*** WARNING: Unable to verify checksum for mscorlib.ni.dll
0011e7fc 68395887 mscorwks!ReflectionInvocation::ExecuteCodeWithGuaranteedCleanup+0x10f
0011e818 683804b5 mscorlib_ni+0x235887
0011e830 723cd133 mscorlib_ni+0x2204b5
0011e86c 723c7a27 WindowsBase_ni+0x9d133
0011e948 723c7d13 WindowsBase_ni+0x97a27
0011e984 723ca4fe WindowsBase_ni+0x97d13
0011e9d0 723ca42a WindowsBase_ni+0x9a4fe
0011e9f0 723ca31a WindowsBase_ni+0x9a42a
0011ea0c 723ca20a WindowsBase_ni+0x9a31a
0011ea4c 723c8384 WindowsBase_ni+0x9a20a
0011ea70 723c74e1 WindowsBase_ni+0x98384
0011eaac 723c7430 WindowsBase_ni+0x974e1
0011eadc 723c9b6c WindowsBase_ni+0x97430
0011eb2c 757462fa WindowsBase_ni+0x99b6c
0011eb58 75746d3a user32!InternalCallWinProc+0x23
0011ebd0 757477c4 user32!UserCallWinProcCheckWow+0x109
0011ec30 7574788a user32!DispatchMessageWorker+0x3bc
0011ec40 0577304e user32!DispatchMessageW+0xf
WARNING: Frame IP not in any known module. Following frames may be wrong.
0011ec5c 723c7b24 0x577304e
0011eccc 723c71f9 WindowsBase_ni+0x97b24
0011ecd8 723c719c WindowsBase_ni+0x971f9
0011ece4 6620f07e WindowsBase_ni+0x9719c
0011ecf0 6620e37f PresentationFramework_ni+0x1cf07e
0011ed14 661f56d6 PresentationFramework_ni+0x1ce37f
0011ed24 661f5699 PresentationFramework_ni+0x1b56d6
0011ed80 72841b4c PresentationFramework_ni+0x1b5699
0011eda0 72841b4c mscorwks!CallDescrWorker+0x33
0011edb0 728589ec mscorwks!CallDescrWorker+0x33
0011ee30 72865acc mscorwks!CallDescrWorkerWithHandler+0xa3
0011ef6c 72865aff mscorwks!MethodDesc::CallDescr+0x19c
0011ef88 72865b1d mscorwks!MethodDesc::CallTargetWorker+0x1f
0011efa0 728fef01 mscorwks!MethodDescCallSite::CallWithValueTypes+0x1a
0011f104 728fee21 mscorwks!ClassLoader::RunMain+0x223
0011f36c 728ff33e mscorwks!Assembly::ExecuteMainMethod+0xa6
0011f83c 728ff528 mscorwks!SystemDomain::ExecuteMainMethod+0x45e
0011f88c 728ff458 mscorwks!ExecuteEXE+0x59
0011f8d4 70aef4f3 mscorwks!_CorExeMain+0x15c
0011f90c 70b77efd mscoreei!_CorExeMain+0x10a
0011f924 70b74de3 mscoree!ShellShim__CorExeMain+0x7d
0011f92c 754c338a mscoree!_CorExeMain_Exported+0x8
0011f938 77659f72 kernel32!BaseThreadInitThunk+0xe
0011f978 77659f45 ntdll!__RtlUserThreadStart+0x70
0011f990 00000000 ntdll!_RtlUserThreadStart+0x1b

Its Managed Stack Trace is the following:

0:000> !CLRStack
OS Thread Id: 0x1520 (0)
ESP       EIP
0011e7a0 728493a4 [HelperMethodFrame_PROTECTOBJ: 0011e7a0] System.Runtime.CompilerServices.RuntimeHelpers.ExecuteCodeWithGuaranteedCleanup(TryCode, CleanupCode, System.Object)
0011e808 68395887 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
0011e824 683804b5 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
0011e83c 723cd133 System.Windows.Threading.DispatcherOperation.Invoke()
0011e874 723c7a27 System.Windows.Threading.Dispatcher.ProcessQueue()
0011e950 723c7d13 System.Windows.Threading.Dispatcher.WndProcHook(IntPtr, Int32, IntPtr, IntPtr, Boolean ByRef)
0011e99c 723ca4fe MS.Win32.HwndWrapper.WndProc(IntPtr, Int32, IntPtr, IntPtr, Boolean ByRef)
0011e9e8 723ca42a MS.Win32.HwndSubclass.DispatcherCallbackOperation(System.Object)
0011e9f8 723ca31a System.Windows.Threading.ExceptionWrapper.InternalRealCall(System.Delegate, System.Object, Boolean)
0011ea1c 723ca20a System.Windows.Threading.ExceptionWrapper.TryCatchWhen(System.Object, System.Delegate, System.Object, Boolean, System.Delegate)
0011ea64 723c8384 System.Windows.Threading.Dispatcher.WrappedInvoke(System.Delegate, System.Object, Boolean, System.Delegate)
0011ea84 723c74e1 System.Windows.Threading.Dispatcher.InvokeImpl(System.Windows.Threading.DispatcherPriority, System.TimeSpan, System.Delegate, System.Object, Boolean)
0011eac8 723c7430 System.Windows.Threading.Dispatcher.Invoke(System.Windows.Threading.DispatcherPriority, System.Delegate, System.Object)
0011eaec 723c9b6c MS.Win32.HwndSubclass.SubclassWndProc(IntPtr, Int32, IntPtr, IntPtr)
0011ec74 00270b04 [NDirectMethodFrameStandalone: 0011ec74] MS.Win32.UnsafeNativeMethods.DispatchMessage(System.Windows.Interop.MSG ByRef)
0011ec84 723c7b24 System.Windows.Threading.Dispatcher.PushFrameImpl(System.Windows.Threading.DispatcherFrame)
0011ecd4 723c71f9 System.Windows.Threading.Dispatcher.PushFrame(System.Windows.Threading.DispatcherFrame)
0011ece0 723c719c System.Windows.Threading.Dispatcher.Run()
0011ecec 6620f07e System.Windows.Application.RunDispatcher(System.Object)
0011ecf8 6620e37f System.Windows.Application.RunInternal(System.Windows.Window)
0011ed1c 661f56d6 System.Windows.Application.Run(System.Windows.Window)
0011ed2c 661f5699 System.Windows.Application.Run()
[...]

Caller-n-Callee traces also don’t reveal anything more:

Thread   0
Current frame: mscorwks!JIT_IsInstanceOfClass+0xd
ChildEBP RetAddr  Caller,Callee
0011d6b8 66fdee7c (MethodDesc 0x66ee2954 +0x3c MS.Internal.DeferredElementTreeState.GetLogicalParent(System.Windows.DependencyObject, MS.Internal.DeferredElementTreeState)), calling mscorwks!JIT_IsInstanceOfClass
0011d6cc 67578500 (MethodDesc 0x66ee1270 +0x110 MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject)), calling (MethodDesc 0x66ee2954 +0 MS.Internal.DeferredElementTreeState.GetLogicalParent(System.Windows.DependencyObject, MS.Internal.DeferredElementTreeState))
0011d6e0 67578527 (MethodDesc 0x66ee1270 +0x137 MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject)), calling (MethodDesc 0x66ee1270 +0 MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject))
0011d6f4 6757850d (MethodDesc 0x66ee1270 +0x11d MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject)), calling (MethodDesc 0x66ee1270 +0 MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject))
0011d708 6757850d (MethodDesc 0x66ee1270 +0x11d MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject)), calling (MethodDesc 0x66ee1270 +0 MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject))
0011d71c 6757850d (MethodDesc 0x66ee1270 +0x11d MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject)), calling (MethodDesc 0x66ee1270 +0 MS.Internal.UIElementHelper.InvalidateAutomationAncestors(System.Windows.DependencyObject))
[...]

However, if we check the return address for Top Module mscorwks (66fdee7c) we will see a call possibly related to 3D processing:

0:000> k
ChildEBP RetAddr
0011d6b8 66fdee7c mscorwks!JIT_IsInstanceOfClass+0xd
0011d6cc 67578500 PresentationCore_ni!`string’+0×4a2bc
0011d6e0 67578527 PresentationCore_ni!`string’ <PERF> (PresentationCore_ni+0×778500)
0011d6f4 6757850d PresentationCore_ni!`string’ <PERF> (PresentationCore_ni+0×778527)
[…]

0:000> ub 66fdee7c
PresentationCore_ni!`string'+0x4a2a2:
66fdee62 740c            je      PresentationCore_ni!`string'+0x4a2b0 (66fdee70)
66fdee64 8bc8            mov     ecx,eax
66fdee66 8b01            mov     eax,dword ptr [ecx]
66fdee68 ff90d8030000    call    dword ptr [eax+3D8h]
66fdee6e 8bf0            mov     esi,eax
66fdee70 8bd7            mov     edx,edi
66fdee72 b998670467      mov     ecx,offset PresentationCore_ni!`string'+0xb1bd8 (67046798)
66fdee77 e82c7afaff      call   PresentationCore_ni!?System.Windows.Media.Media3D.Viewport3DVisual.PrecomputeContent@@200001+0×3c (66f868a8)

The call structure seems to be valid when we check the next return address from the stack trace (67578500):

0:000> ub 67578500
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784e7):
675784e7 e8f4a2a0ff      call    PresentationCore_ni!?System.Windows.Media.Media3D.ScaleTransform3D.UpdateResource@@2002011280M802+0x108 (66f827e0)
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784ec):
675784ec eb05            jmp     PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784f3) (675784f3)
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784ee):
675784ee b801000000      mov     eax,1
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784f3):
675784f3 85c0            test    eax,eax
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784f5):
675784f5 74b1            je      PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784a8) (675784a8)
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784f7):
675784f7 8bcb            mov     ecx,ebx
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784f9):
675784f9 33d2            xor     edx,edx
PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0x7784fb):
675784fb e84069a6ff      call    PresentationCore_ni!`string’+0×4a280 (66fdee40)

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

Crash Dump Analysis Patterns (Part 216)

Wednesday, November 19th, 2014

Sometimes what looks like a memory leak when we install the new product version is not really a leak. With the previous version we had 400 MB typical memory usage but suddenly we get twice as more. We shouldn’t panic but collect a process memory dump to calmly inspect it offline. We may see Dry Weight increase: the size of all module images. For some products the new release may mean complete redesign with a new more powerful framework or incorporation of the significant number of new 3rd-party components (Module Variety). Additional sign against the memory leak hypothesis is simultaneous memory usage increase for many product processes. Although, this may be some shared module with leaking code. For example, in the example below 50% of all committed memory was image memory:

0:000> !address -summary

--- Usage Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
[...]
Image                                  1806        0`19031000 ( 402.535 Mb)   4.29%    0.00%
Heap                                     72        0`02865000 (  40.395 Mb)   0.44%    0.00%
[…]

--- Type Summary (for busy) ------ RgnCount ----------- Total Size -------- %ofBusy %ofTotal
[...]
MEM_IMAGE                              2281        0`19AA8000 ( 413.000 Mb)   4.40%    0.00%
[…]

--- State Summary ---------------- RgnCount ----------- Total Size -------- %ofBusy %ofTotal
[...]
MEM_COMMIT                             2477        0`326e8000 ( 806.906 Mb)   8.76%    0.00%
[…]

WinDbg lmt command shows almost 50 new .NET components.

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

Crash Dump Analysis Patterns (Part 61b)

Saturday, November 15th, 2014

We recently encountered Invalid Handle pattern in the context of .NET program execution. We decided to model it and wrote a small C# program:

namespace SafeHandle
{
    class Program
    {
        static void Main(string[] args)
        {
            SafeFileHandle hFile =
                 new SafeFileHandle(new IntPtr(0xDEAD), true);
            Console.WriteLine("About to close");
            Console.ReadKey();
        }
    }
}

Of course, when we execute it nothing happens. Invalid handles are ignored by default. However, to change the behavior we enabled “Enable close exception” in glags.exe:

And if we run it we get this Managed Stack Trace:

We could have detected invalid handle if we enabled Application Verifier but then we wouldn’t have Managed Code Exception.

So we load a crash dump (saved because we enabled LocalDumps) and load SOS extension:

0:002> lmv m clr
start end module name
000007fe`ed880000 000007fe`ee1eb000 clr (pdb symbols)
Loaded symbol image file: clr.dll
Image path: C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
[...]

0:002> .load C:\Windows\Microsoft.NET\Framework64\v4.0.30319\sos

0:002> !pe
Exception object: 0000000002ab5fe8
Exception type: System.Runtime.InteropServices.SEHException
Message: External component has thrown an exception.

InnerException:
StackTrace (generated):
SP IP Function
000000001B40EDD0 0000000000000000 mscorlib_ni!Microsoft.Win32.Win32Native.CloseHandle(IntPtr)+0×1
000000001B40F2F0 0000000000000000 mscorlib_ni!System.Runtime.InteropServices.SafeHandle.InternalFinalize()+0×1
000000001B40F2F0 000007FEEC62F7A6 mscorlib_ni!System.Runtime.InteropServices.SafeHandle.Finalize()+0×26

StackTraceString:
HResult: 80004005

Our unmanaged CLR Thread Exception Stack Trace is quite simple:

0:002> k
Child-SP RetAddr Call Site
00000000`1b40d6e8 000007fe`fd651430 ntdll!NtWaitForMultipleObjects+0xa
00000000`1b40d6f0 00000000`77621723 KERNELBASE!WaitForMultipleObjectsEx+0xe8
00000000`1b40d7f0 00000000`7769b5e5 kernel32!WaitForMultipleObjectsExImplementation+0xb3
00000000`1b40d880 00000000`7769b767 kernel32!WerpReportFaultInternal+0x215
00000000`1b40d920 00000000`7769b7bf kernel32!WerpReportFault+0x77
00000000`1b40d950 00000000`7769b9dc kernel32!BasepReportFault+0x1f
00000000`1b40d980 00000000`778b3398 kernel32!UnhandledExceptionFilter+0x1fc
00000000`1b40da60 00000000`778385c8 ntdll! ?? ::FNODOBFM::`string'+0x2365
00000000`1b40da90 00000000`77849d2d ntdll!_C_specific_handler+0x8c
00000000`1b40db00 00000000`778391cf ntdll!RtlpExecuteHandlerForException+0xd
00000000`1b40db30 00000000`778397c8 ntdll!RtlDispatchException+0x45a
00000000`1b40e210 00000000`778712c7 ntdll!RtlRaiseException+0x22f
00000000`1b40ebc0 000007fe`fd651873 ntdll!KiRaiseUserExceptionDispatcher+0×3a
00000000`1b40ec90 00000000`77621991 KERNELBASE!CloseHandle+0×13

00000000`1b40ecc0 000007fe`ec720418 kernel32!CloseHandleImplementation+0×3d
00000000`1b40edd0 000007fe`ed8e9e03 mscorlib_ni+0×580418
00000000`1b40eea0 000007fe`ed8e9e7e clr!CallDescrWorkerInternal+0×83
00000000`1b40eee0 000007fe`ed8ec860 clr!CallDescrWorkerWithHandler+0×4a
00000000`1b40ef20 000007fe`ed8f1a1d clr!DispatchCallSimple+0×85
00000000`1b40efb0 000007fe`ed8f19ac clr!SafeHandle::RunReleaseMethod+0×69
00000000`1b40f050 000007fe`ed8f180a clr!SafeHandle::Release+0×122
00000000`1b40f120 000007fe`eda4863e clr!SafeHandle::Dispose+0×36
00000000`1b40f190 000007fe`ec62f7a6 clr!SafeHandle::Finalize+0xa2
00000000`1b40f2f0 000007fe`ed8e9d56 mscorlib_ni+0×48f7a6
00000000`1b40f330 000007fe`eda83c4e clr!FastCallFinalizeWorker+0×6
00000000`1b40f360 000007fe`eda83bc3 clr!MethodDesc::RequiresFullSlotNumber+0×72
00000000`1b40f3a0 000007fe`eda83b0f clr!MethodTable::CallFinalizer+0xa3
00000000`1b40f3e0 000007fe`ed9fee46 clr!SVR::CallFinalizer+0×5f
00000000`1b40f420 000007fe`ed9aac5b clr!SVR::CallFinalizer+0×102
00000000`1b40f4e0 000007fe`ed8f458c clr!WKS::GCHeap::IsPromoted+0xee
00000000`1b40f520 000007fe`ed8f451a clr!Frame::Pop+0×50
00000000`1b40f560 000007fe`ed8f4491 clr!COMCustomAttribute::PopSecurityContextFrame+0×192
00000000`1b40f660 000007fe`ed9d1bfe clr!COMCustomAttribute::PopSecurityContextFrame+0xbd
00000000`1b40f6f0 000007fe`ed9d1e59 clr!ManagedThreadBase_NoADTransition+0×3f
00000000`1b40f750 000007fe`ed9533de clr!WKS::GCHeap::FinalizerThreadStart+0×193
00000000`1b40f790 00000000`776159ed clr!Thread::intermediateThreadProc+0×7d
00000000`1b40f850 00000000`7784c541 kernel32!BaseThreadInitThunk+0xd
00000000`1b40f880 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

We see that exception processing happened during object finalization. We can infer the value of the handle (may be Small Value) via disassembly if this is possible:

0:002> kn
# Child-SP RetAddr Call Site
00 00000000`1b40d6e8 000007fe`fd651430 ntdll!NtWaitForMultipleObjects+0xa
01 00000000`1b40d6f0 00000000`77621723 KERNELBASE!WaitForMultipleObjectsEx+0xe8
02 00000000`1b40d7f0 00000000`7769b5e5 kernel32!WaitForMultipleObjectsExImplementation+0xb3
03 00000000`1b40d880 00000000`7769b767 kernel32!WerpReportFaultInternal+0x215
04 00000000`1b40d920 00000000`7769b7bf kernel32!WerpReportFault+0x77
05 00000000`1b40d950 00000000`7769b9dc kernel32!BasepReportFault+0x1f
06 00000000`1b40d980 00000000`778b3398 kernel32!UnhandledExceptionFilter+0x1fc
07 00000000`1b40da60 00000000`778385c8 ntdll! ?? ::FNODOBFM::`string'+0x2365
08 00000000`1b40da90 00000000`77849d2d ntdll!_C_specific_handler+0x8c
09 00000000`1b40db00 00000000`778391cf ntdll!RtlpExecuteHandlerForException+0xd
0a 00000000`1b40db30 00000000`778397c8 ntdll!RtlDispatchException+0x45a
0b 00000000`1b40e210 00000000`778712c7 ntdll!RtlRaiseException+0x22f
0c 00000000`1b40ebc0 000007fe`fd651873 ntdll!KiRaiseUserExceptionDispatcher+0x3a
0d 00000000`1b40ec90 00000000`77621991 KERNELBASE!CloseHandle+0×13
0e 00000000`1b40ecc0 000007fe`ec720418 kernel32!CloseHandleImplementation+0×3d
0f 00000000`1b40edd0 000007fe`ed8e9e03 mscorlib_ni+0×580418
10 00000000`1b40eea0 000007fe`ed8e9e7e clr!CallDescrWorkerInternal+0×83
11 00000000`1b40eee0 000007fe`ed8ec860 clr!CallDescrWorkerWithHandler+0×4a
12 00000000`1b40ef20 000007fe`ed8f1a1d clr!DispatchCallSimple+0×85
13 00000000`1b40efb0 000007fe`ed8f19ac clr!SafeHandle::RunReleaseMethod+0×69
14 00000000`1b40f050 000007fe`ed8f180a clr!SafeHandle::Release+0×122
15 00000000`1b40f120 000007fe`eda4863e clr!SafeHandle::Dispose+0×36
16 00000000`1b40f190 000007fe`ec62f7a6 clr!SafeHandle::Finalize+0xa2
17 00000000`1b40f2f0 000007fe`ed8e9d56 mscorlib_ni+0×48f7a6
18 00000000`1b40f330 000007fe`eda83c4e clr!FastCallFinalizeWorker+0×6
19 00000000`1b40f360 000007fe`eda83bc3 clr!MethodDesc::RequiresFullSlotNumber+0×72
1a 00000000`1b40f3a0 000007fe`eda83b0f clr!MethodTable::CallFinalizer+0xa3
1b 00000000`1b40f3e0 000007fe`ed9fee46 clr!SVR::CallFinalizer+0×5f
1c 00000000`1b40f420 000007fe`ed9aac5b clr!SVR::CallFinalizer+0×102
1d 00000000`1b40f4e0 000007fe`ed8f458c clr!WKS::GCHeap::IsPromoted+0xee
1e 00000000`1b40f520 000007fe`ed8f451a clr!Frame::Pop+0×50
1f 00000000`1b40f560 000007fe`ed8f4491 clr!COMCustomAttribute::PopSecurityContextFrame+0×192
20 00000000`1b40f660 000007fe`ed9d1bfe clr!COMCustomAttribute::PopSecurityContextFrame+0xbd
21 00000000`1b40f6f0 000007fe`ed9d1e59 clr!ManagedThreadBase_NoADTransition+0×3f
22 00000000`1b40f750 000007fe`ed9533de clr!WKS::GCHeap::FinalizerThreadStart+0×193
23 00000000`1b40f790 00000000`776159ed clr!Thread::intermediateThreadProc+0×7d
24 00000000`1b40f850 00000000`7784c541 kernel32!BaseThreadInitThunk+0xd
25 00000000`1b40f880 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

0:002> .frame /c d
0d 00000000`1b40ec90 00000000`77621991 KERNELBASE!CloseHandle+0x13
rax=00000000c0000001 rbx=000000000000dead rcx=00000000009a0000
rdx=0000000000000001 rsi=000000001b40efd0 rdi=000000001b40eff8
rip=000007fefd651873 rsp=000000001b40ec90 rbp=000000001b40edf0
r8=000000001b40ce08 r9=000000001b40cf70 r10=0000000000000000
r11=0000000000000246 r12=0000000000000001 r13=0000000040000000
r14=000000001b40ef40 r15=0000000000000000
iopl=0 nv up ei pl zr na po nc
cs=0033 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000246
KERNELBASE!CloseHandle+0×13:
000007fe`fd651873 85c0 test eax,eax

0:002> ub 00000000`77621991
kernel32!CloseHandleImplementation+0×1e:
00000000`7762196e 83f9f4 cmp ecx,0FFFFFFF4h
00000000`77621971 0f83952e0100 jae kernel32!TlsGetValue+0×3ef0 (00000000`7763480c)
00000000`77621977 488bc3 mov rax,rbx
00000000`7762197a 2503000010 and eax,10000003h
00000000`7762197f 4883f803 cmp rax,3
00000000`77621983 0f847f8dfeff je kernel32!CloseHandleImplementation+0×56 (00000000`7760a708)
00000000`77621989 488bcb mov rcx,rbx
00000000`7762198c e81f000000 call kernel32!CloseHandle (00000000`776219b0)

Here we also check the value from the managed stack trace or from Execution Residue:

0:002> !CLRStack -a
OS Thread Id: 0x1390 (2)
Child SP IP Call Site
000000001b40edf8 000000007787186a [InlinedCallFrame: 000000001b40edf8] Microsoft.Win32.Win32Native.CloseHandle(IntPtr)
000000001b40edf8 000007feec720418 [InlinedCallFrame: 000000001b40edf8] Microsoft.Win32.Win32Native.CloseHandle(IntPtr)
000000001b40edd0 000007feec720418 DomainNeutralILStubClass.IL_STUB_PInvoke(IntPtr)
PARAMETERS:
<no data>

000000001b40eff8 000007feed8e9e03 [GCFrame: 000000001b40eff8]
000000001b40f148 000007feed8e9e03 [GCFrame: 000000001b40f148]
000000001b40f1f8 000007feed8e9e03 [HelperMethodFrame_1OBJ: 000000001b40f1f8] System.Runtime.InteropServices.SafeHandle.InternalFinalize()
000000001b40f2f0 000007feec62f7a6 System.Runtime.InteropServices.SafeHandle.Finalize()
PARAMETERS:
this (0x000000001b40f330) = 0×0000000002ab2d78

000000001b40f6a8 000007feed8e9d56 [DebuggerU2MCatchHandlerFrame: 000000001b40f6a8]

0:002> !dso
OS Thread Id: 0x1390 (2)
RSP/REG Object Name
000000001B40EEA0 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40EFD0 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F038 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F050 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F090 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F120 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F190 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F1B8 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F240 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F2F8 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F330 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F360 0000000002ab5e10 System.Threading.Thread
000000001B40F390 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F3E0 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F3F0 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle
000000001B40F430 0000000002ab58a8 Microsoft.Win32.SafeHandles.SafeViewOfFileHandle
000000001B40F4E0 0000000002ab2d78 Microsoft.Win32.SafeHandles.SafeFileHandle

0:002> !do 0000000002ab2d78
Name: Microsoft.Win32.SafeHandles.SafeFileHandle
MethodTable: 000007feec88a260
EEClass: 000007feec34d340
Size: 32(0x20) bytes
File: C:\windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
MT Field Offset Type VT Attr Value Name
000007feec88a338 400060d 8 System.IntPtr 1 instance dead handle
000007feec8892b8 400060e 10 System.Int32 1 instance 3 _state
000007feec887de0 400060f 14 System.Boolean 1 instance 1 _ownsHandle
000007feec887de0 4000610 15 System.Boolean 1 instance 1 _fullyInitialized

Please note that we don’t have global application flags:

0:002> !gflag
Current NtGlobalFlag contents: 0x00000000

Here is the exception stack trace from a different crash dump when we enable Application Verifier:

0:002> !gflag
Current NtGlobalFlag contents: 0x02000100
vrf - Enable application verifier
hpa - Place heap allocations at ends of pages

0:002> k
Child-SP RetAddr Call Site
00000000`24bac4a8 00000000`77cd3072 ntdll!NtWaitForSingleObject+0xa
00000000`24bac4b0 00000000`77cd32b5 ntdll!RtlReportExceptionEx+0x1d2
00000000`24bac5a0 000007fe`fa2c26fb ntdll!RtlReportException+0xb5
00000000`24bac620 00000000`77c2a5db verifier!AVrfpVectoredExceptionHandler+0x26b
00000000`24bac6b0 00000000`77c28e62 ntdll!RtlpCallVectoredHandlers+0xa8
00000000`24bac720 00000000`77c61248 ntdll!RtlDispatchException+0x22
00000000`24bace00 000007fe`fa2bae03 ntdll!KiUserExceptionDispatch+0x2e
00000000`24bad500 000007fe`fa2c268a verifier!VerifierStopMessageEx+0x6fb
00000000`24bad850 00000000`77c2a5db verifier!AVrfpVectoredExceptionHandler+0x1fa
00000000`24bad8e0 00000000`77c28e62 ntdll!RtlpCallVectoredHandlers+0xa8
00000000`24bad950 00000000`77c297c8 ntdll!RtlDispatchException+0x22
00000000`24bae030 00000000`77c612c7 ntdll!RtlRaiseException+0x22f
00000000`24bae9e0 000007fe`fa2d2386 ntdll!KiRaiseUserExceptionDispatcher+0x3a
00000000`24baeab0 000007fe`fdbd1873 verifier!AVrfpNtClose+0xbe
00000000`24baeae0 000007fe`fa2d4031 KERNELBASE!CloseHandle+0x13
00000000`24baeb10 000007fe`fa2d40cb verifier!AVrfpCloseHandleCommon+0x95
00000000`24baeb40 00000000`77a11991 verifier!AVrfpKernelbaseCloseHandle+0x23
00000000`24baeb80 000007fe`fa2d4031 kernel32!CloseHandleImplementation+0x3d
00000000`24baec90 000007fe`fa2d409c verifier!AVrfpCloseHandleCommon+0x95
*** WARNING: Unable to verify checksum for mscorlib.ni.dll
00000000`24baecc0 000007fe`e6a40418 verifier!AVrfpKernel32CloseHandle+0x2c
00000000`24baed00 000007fe`ec0e9e03 mscorlib_ni+0x580418
00000000`24baedd0 000007fe`ec0e9e7e clr!CallDescrWorkerInternal+0x83
00000000`24baee10 000007fe`ec0ec860 clr!CallDescrWorkerWithHandler+0x4a
00000000`24baee50 000007fe`ec0f1a1d clr!DispatchCallSimple+0x85
00000000`24baeee0 000007fe`ec0f19ac clr!SafeHandle::RunReleaseMethod+0x69
00000000`24baef80 000007fe`ec0f180a clr!SafeHandle::Release+0x122
00000000`24baf050 000007fe`ec24863e clr!SafeHandle::Dispose+0x36
00000000`24baf0c0 000007fe`e694f7a6 clr!SafeHandle::Finalize+0xa2
00000000`24baf220 000007fe`ec0e9d56 mscorlib_ni+0x48f7a6
00000000`24baf260 000007fe`ec283c4e clr!FastCallFinalizeWorker+0x6
00000000`24baf290 000007fe`ec283bc3 clr!MethodDesc::RequiresFullSlotNumber+0x72
00000000`24baf2d0 000007fe`ec283b0f clr!MethodTable::CallFinalizer+0xa3
00000000`24baf310 000007fe`ec1fee46 clr!SVR::CallFinalizer+0x5f
00000000`24baf350 000007fe`ec1aac5b clr!SVR::CallFinalizer+0x102
00000000`24baf410 000007fe`ec0f458c clr!WKS::GCHeap::IsPromoted+0xee
00000000`24baf450 000007fe`ec0f451a clr!Frame::Pop+0x50
00000000`24baf490 000007fe`ec0f4491 clr!COMCustomAttribute::PopSecurityContextFrame+0x192
00000000`24baf590 000007fe`ec1d1bfe clr!COMCustomAttribute::PopSecurityContextFrame+0xbd
00000000`24baf620 000007fe`ec1d1e59 clr!ManagedThreadBase_NoADTransition+0x3f
00000000`24baf680 000007fe`ec1533de clr!WKS::GCHeap::FinalizerThreadStart+0x193
00000000`24baf6c0 000007fe`fa2d4b87 clr!Thread::intermediateThreadProc+0x7d
00000000`24baf780 00000000`77a059ed verifier!AVrfpStandardThreadFunction+0x2b
00000000`24baf7c0 00000000`77c3c541 kernel32!BaseThreadInitThunk+0xd
00000000`24baf7f0 00000000`00000000 ntdll!RtlUserThreadStart+0x1d

0:002> !pe
There is no current managed exception on this thread

0:002> !CLRStack
OS Thread Id: 0x51e4 (2)
Child SP IP Call Site
0000000024baed28 0000000077c612fa [InlinedCallFrame: 0000000024baed28] Microsoft.Win32.Win32Native.CloseHandle(IntPtr)
0000000024baed28 000007fee6a40418 [InlinedCallFrame: 0000000024baed28] Microsoft.Win32.Win32Native.CloseHandle(IntPtr)
0000000024baed00 000007fee6a40418 DomainNeutralILStubClass.IL_STUB_PInvoke(IntPtr)
0000000024baef28 000007feec0e9e03 [GCFrame: 0000000024baef28]
0000000024baf078 000007feec0e9e03 [GCFrame: 0000000024baf078]
0000000024baf128 000007feec0e9e03 [HelperMethodFrame_1OBJ: 0000000024baf128] System.Runtime.InteropServices.SafeHandle.InternalFinalize()
0000000024baf220 000007fee694f7a6 System.Runtime.InteropServices.SafeHandle.Finalize()
0000000024baf5d8 000007feec0e9d56 [DebuggerU2MCatchHandlerFrame: 0000000024baf5d8]

0:002> !dso
OS Thread Id: 0x51e4 (2)
RSP/REG Object Name
0000000024BAEDD0 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAEF00 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAEF68 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAEF80 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAEFC0 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF050 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF0C0 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF0E8 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF170 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF228 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF260 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF290 000000000c285e10 System.Threading.Thread
0000000024BAF2C0 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF310 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF320 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle
0000000024BAF360 000000000c2858a8 Microsoft.Win32.SafeHandles.SafeViewOfFileHandle
0000000024BAF410 000000000c282d78 Microsoft.Win32.SafeHandles.SafeFileHandle

0:002> !CLRStack -a
OS Thread Id: 0x51e4 (2)
Child SP               IP Call Site
0000000024baed28 0000000077c612fa [InlinedCallFrame: 0000000024baed28] Microsoft.Win32.Win32Native.CloseHandle(IntPtr)
0000000024baed28 000007fee6a40418 [InlinedCallFrame: 0000000024baed28] Microsoft.Win32.Win32Native.CloseHandle(IntPtr)
0000000024baed00 000007fee6a40418 DomainNeutralILStubClass.IL_STUB_PInvoke(IntPtr)
PARAMETERS:
<no data>

0000000024baef28 000007feec0e9e03 [GCFrame: 0000000024baef28]
0000000024baf078 000007feec0e9e03 [GCFrame: 0000000024baf078]
0000000024baf128 000007feec0e9e03 [HelperMethodFrame_1OBJ: 0000000024baf128] System.Runtime.InteropServices.SafeHandle.InternalFinalize()
0000000024baf220 000007fee694f7a6 System.Runtime.InteropServices.SafeHandle.Finalize()
PARAMETERS:
this (0x0000000024baf260) = 0×000000000c282d78

0000000024baf5d8 000007feec0e9d56 [DebuggerU2MCatchHandlerFrame: 0000000024baf5d8]

0:002> !do 0x000000000c282d78
Name: Microsoft.Win32.SafeHandles.SafeFileHandle
MethodTable: 000007fee6baa260
EEClass: 000007fee666d340
Size: 32(0x20) bytes
File: C:\windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
MT Field Offset Type VT Attr Value Name
000007fee6baa338 400060d 8 System.IntPtr 1 instance dead handle
000007fee6ba92b8 400060e 10 System.Int32 1 instance 3 _state
000007fee6ba7de0 400060f 14 System.Boolean 1 instance 1 _ownsHandle
000007fee6ba7de0 4000610 15 System.Boolean 1 instance 1 _fullyInitialized

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

Crash Dump Analysis Patterns (Part 42l)

Wednesday, April 9th, 2014

This is a variation of a general Wait Chain pattern related to CLR threads. When looking at Stack Trace Collection from a complete memory dump we may find threads using a monitor synchronization mechanism:

[... 32-bit ...]
09d2e908 6ba4d409 clr!CLREvent::WaitEx+0x106
09d2e91c 6bb90160 clr!CLREvent::Wait+0x19
09d2e9ac 6bb90256 clr!AwareLock::EnterEpilogHelper+0xa8
09d2e9ec 6bb9029b clr!AwareLock::EnterEpilog+0x42
09d2ea0c 6ba90f78 clr!AwareLock::Enter+0x5f
09d2eaa8 05952499 clr!JIT_MonEnterWorker_Portable+0xf8
[…]

or

[... 64-bit ...]
00000000`2094e230 000007fe`eedc3e3a clr!CLREvent::WaitEx+0xc1
00000000`2094e2d0 000007fe`eedc3d43 clr!AwareLock::EnterEpilogHelper+0xca
00000000`2094e3a0 000007fe`eee3e613 clr!AwareLock::EnterEpilog+0x63
00000000`2094e400 000007ff`007f4c38 clr!JIT_MonEnterWorker_Portable+0×14f
[…]

When seeing such threads we may ask for a process memory dump to perform .NET memory dump analysis using SOS or other WinDbg extensions such as in Deadlock pattern example for CLR 2 (mscorwks).

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

Trace Analysis Patterns (Part 72)

Tuesday, May 21st, 2013

Sometimes we look at a trace or log and instead of Error Messages we only see their “signs” such as a DLL load event for an error or fault reporting module or a module that is related to symbol files such diasymreader.dll. We call this pattern Hidden Error by an analogy to Hidden Exception in memory dump analysis pattern catalogue although sometimes we can see such modules in memory dump Module Collection. For example, the presence of diasymreader module may signify an unreported .NET exception and suggest a dump collection strategy.

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

WinDbg Reference Cards Version 2 (Page 1)

Thursday, November 15th, 2012

Finally, the new version of WinDbg: A Reference Poster and Learning Cards is under development. This time every page is published online for comments, suggestions and corrections which are very welcome. The format of every page follows colored memory space diagram where red cards are for native kernel space commands, blue cards are for unmanaged user space, and green cards are for managed .NET space (click on a picture to open a PDF file):

Download page 1 PDF file

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

Crash Dump Analysis Patterns (Part 183)

Wednesday, October 10th, 2012

The case of an error reporting fault chain led me to First Fault Stack Trace memory dump analysis pattern that corresponds to First Fault software diagnostics pattern proper. Here the term first fault is used for an exception that was either ignored by surrounding code or led to other exceptions or error message boxes with stack traces that masked the first one. Typical examples where it is sometimes possible to get a first exception stack trace include but not limited to:

It is also sometimes possible unless a stack region was paged out to get partial stack traces from execution residue when the sequence of return addresses was partially overwritten by subsequently executed code.

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

Crash Dump Analysis Patterns (Part 29d)

Monday, September 24th, 2012

This is a high contention pattern variant where the contention is around a monitor object. For example, we have a distributed CPU spike for some threads:

0:000> !runaway
 User Mode Time
  Thread       Time
   9:6ff4      0 days 0:07:39.019
  12:6b88      0 days 0:06:19.786
  11:6bf0      0 days 0:06:13.889
  10:6930      0 days 0:06:09.240
  16:3964      0 days 0:05:44.483
  17:6854      0 days 0:05:35.326
  13:668c      0 days 0:05:35.123
  14:5594      0 days 0:05:34.858
  15:7248      0 days 0:05:23.111
   2:c54       0 days 0:00:41.215
   4:1080      0 days 0:00:00.349
   7:10f0      0 days 0:00:00.302
   0:c3c       0 days 0:00:00.271
[...]

If we look at their stack traces we find them all blocked trying to enter a monitor, for example:

0:000> ~*k

[...]

  12  Id: d50.6b88 Suspend: 0 Teb: 000007ff`fffd8000 Unfrozen
Child-SP          RetAddr           Call Site
00000000`1a98e798 000007fe`fd0c1420 ntdll!ZwWaitForMultipleObjects+0xa
00000000`1a98e7a0 00000000`76e82cf3 KERNELBASE!WaitForMultipleObjectsEx+0xe8
00000000`1a98e8a0 000007fe`f82e0669 kernel32!WaitForMultipleObjectsExImplementation+0xb3
00000000`1a98e930 000007fe`f82dbec9 mscorwks!WaitForMultipleObjectsEx_SO_TOLERANT+0xc1
00000000`1a98e9d0 000007fe`f82a0569 mscorwks!Thread::DoAppropriateAptStateWait+0x41
00000000`1a98ea30 000007fe`f82beaec mscorwks!Thread::DoAppropriateWaitWorker+0x191
00000000`1a98eb30 000007fe`f81f1b9a mscorwks!Thread::DoAppropriateWait+0x5c
00000000`1a98eba0 000007fe`f82fd3c9 mscorwks!CLREvent::WaitEx+0xbe
00000000`1a98ec50 000007fe`f81ac6be mscorwks!AwareLock::EnterEpilog+0xc9
00000000`1a98ed20 000007fe`f81c7b2b mscorwks!AwareLock::Enter+0x72
00000000`1a98ed50 000007fe`f87946af mscorwks!AwareLock::Contention+0x1fb
00000000`1a98ee20 000007ff`00161528 mscorwks!JITutil_MonContention+0xdf
00000000`1a98efd0 000007ff`0016140e 0×7ff`00161528
00000000`1a98f040 000007ff`00167271 0×7ff`0016140e
00000000`1a98f0a0 000007fe`f74e2bbb 0×7ff`00167271
00000000`1a98f130 000007fe`f753ed76 mscorlib_ni+0×2f2bbb
00000000`1a98f180 000007fe`f8390282 mscorlib_ni+0×34ed76
00000000`1a98f1d0 000007fe`f8274363 mscorwks!CallDescrWorker+0×82
00000000`1a98f220 000007fe`f8274216 mscorwks!CallDescrWorkerWithHandler+0xd3
00000000`1a98f2c0 000007fe`f81c96a7 mscorwks!DispatchCallDebuggerWrapper+0×3e
00000000`1a98f320 000007fe`f830ae42 mscorwks!DispatchCallNoEH+0×5f
00000000`1a98f3a0 000007fe`f81bdc00 mscorwks!AddTimerCallback_Worker+0×92
00000000`1a98f430 000007fe`f82a41a5 mscorwks!ManagedThreadCallState::IsAppDomainEqual+0×4c
00000000`1a98f480 000007fe`f82df199 mscorwks!SVR::gc_heap::make_heap_segment+0×155
00000000`1a98f550 000007fe`f82ececa mscorwks!DoOpenIAssemblyStress::DoOpenIAssemblyStress+0×99
00000000`1a98f590 000007fe`f830c0db mscorwks!AddTimerCallbackEx+0xba
00000000`1a98f650 000007fe`f81ebb37 mscorwks!ThreadpoolMgr::AsyncTimerCallbackCompletion+0×53
00000000`1a98f6b0 000007fe`f81fe92a mscorwks!UnManagedPerAppDomainTPCount::DispatchWorkItem+0×157
00000000`1a98f750 000007fe`f81bb1fc mscorwks!ThreadpoolMgr::WorkerThreadStart+0×1ba
00000000`1a98f7f0 00000000`76e7652d mscorwks!Thread::intermediateThreadProc+0×78
00000000`1a98fcc0 00000000`76fac521 kernel32!BaseThreadInitThunk+0xd
00000000`1a98fcf0 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

[...]

  15  Id: d50.7248 Suspend: 0 Teb: 000007ff`ffee6000 Unfrozen
Child-SP          RetAddr           Call Site
00000000`1c16e6f0 000007fe`f87946af mscorwks!AwareLock::Contention+0×13b
00000000`1c16e7c0 000007ff`0016135e mscorwks!JITutil_MonContention+0xdf

00000000`1c16e970 000007ff`0016726b 0×7ff`0016135e
00000000`1c16e9c0 000007fe`f74e2bbb 0×7ff`0016726b
00000000`1c16ea50 000007fe`f753ed76 mscorlib_ni+0×2f2bbb
00000000`1c16eaa0 000007fe`f8390282 mscorlib_ni+0×34ed76
00000000`1c16eaf0 000007fe`f8274363 mscorwks!CallDescrWorker+0×82
00000000`1c16eb40 000007fe`f8274216 mscorwks!CallDescrWorkerWithHandler+0xd3
00000000`1c16ebe0 000007fe`f81c96a7 mscorwks!DispatchCallDebuggerWrapper+0×3e
00000000`1c16ec40 000007fe`f830ae42 mscorwks!DispatchCallNoEH+0×5f
00000000`1c16ecc0 000007fe`f81bdc00 mscorwks!AddTimerCallback_Worker+0×92
00000000`1c16ed50 000007fe`f82a41a5 mscorwks!ManagedThreadCallState::IsAppDomainEqual+0×4c
00000000`1c16eda0 000007fe`f82df199 mscorwks!SVR::gc_heap::make_heap_segment+0×155
00000000`1c16ee70 000007fe`f82ececa mscorwks!DoOpenIAssemblyStress::DoOpenIAssemblyStress+0×99
00000000`1c16eeb0 000007fe`f830c0db mscorwks!AddTimerCallbackEx+0xba
00000000`1c16ef70 000007fe`f81ebb37 mscorwks!ThreadpoolMgr::AsyncTimerCallbackCompletion+0×53
00000000`1c16efd0 000007fe`f81fe92a mscorwks!UnManagedPerAppDomainTPCount::DispatchWorkItem+0×157
00000000`1c16f070 000007fe`f81bb1fc mscorwks!ThreadpoolMgr::WorkerThreadStart+0×1ba
00000000`1c16f110 00000000`76e7652d mscorwks!Thread::intermediateThreadProc+0×78
00000000`1c16f9e0 00000000`76fac521 kernel32!BaseThreadInitThunk+0xd
00000000`1c16fa10 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

[...]

Thread #15 seems was caught at the time it was trying to enter and not waiting yet. If we check a monitor object the thread #12 tries to enter we see it has an address 01af0be8:

0:000> !u 000007ff`00161528
Normal JIT generated code
[…]
000007ff`00161505 90              nop
000007ff`00161506 48b8f089ae1100000000 mov rax,11AE89F0h
000007ff`00161510 488b00          mov     rax,qword ptr [rax]
000007ff`00161513 48894528        mov     qword ptr [rbp+28h],rax
000007ff`00161517 488b4528        mov     rax,qword ptr [rbp+28h]
000007ff`0016151b 48894518        mov     qword ptr [rbp+18h],rax
000007ff`0016151f 488b4d28        mov     rcx,qword ptr [rbp+28h]
000007ff`00161523 e8b8d422f8      call    mscorwks!JIT_MonEnter (000007fe`f838e9e0)
>>> 000007ff`00161528 90              nop
000007ff`00161529 90              nop
000007ff`0016152a 90              nop
[…]
000007ff`001615d2 4883c430        add     rsp,30h
000007ff`001615d6 5d              pop     rbp
000007ff`001615d7 f3c3            rep ret

0:000> dps 11AE89F0h l1
00000000`11ae89f0  00000000`01af0be8

This object seems to be owned by the thread #17:

0:000> !syncblk
Index         SyncBlock MonitorHeld Recursion Owning Thread Info          SyncBlock Owner
 1362 000000001ba7b6c0           15         1 000000001c0173b0  6854  17   0000000001af0be8 System.Object
[…]

This thread seems to be blocked in ALPC:

0:017> k
Child-SP          RetAddr           Call Site
00000000`1d55c9e8 000007fe`fee1a776 ntdll!NtAlpcSendWaitReceivePort+0xa
00000000`1d55c9f0 000007fe`fee14e42 rpcrt4!LRPC_CCALL::SendReceive+0x156
00000000`1d55cab0 000007fe`ff0828c0 rpcrt4!I_RpcSendReceive+0x42
00000000`1d55cae0 000007fe`ff08282f ole32!ThreadSendReceive+0x40
00000000`1d55cb30 000007fe`ff08265b ole32!CRpcChannelBuffer::SwitchAptAndDispatchCall+0xa3
00000000`1d55cbd0 000007fe`fef3daaa ole32!CRpcChannelBuffer::SendReceive2+0x11b
00000000`1d55cd90 000007fe`fef3da0c ole32!CAptRpcChnl::SendReceive+0x52
00000000`1d55ce60 000007fe`ff08205d ole32!CCtxComChnl::SendReceive+0x68
00000000`1d55cf10 000007fe`feebfd61 ole32!NdrExtpProxySendReceive+0x45
00000000`1d55cf40 000007fe`ff07f82f rpcrt4!NdrpClientCall2+0x9ea
00000000`1d55d6b0 000007fe`fef3d8a2 ole32!ObjectStublessClient+0x1ad
00000000`1d55da40 000007fe`fa511ba8 ole32!ObjectStubless+0x42
[...]
 

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

Postmortem effects of -g

Sunday, February 19th, 2012

One of attendees of accelerated memory dump analysis training pointed me to the possible effects of -g option for AeDebug custom postmortem debugger command line for CDB, NTSD or WinDbg. So I tested that with x64 TestWER tool (should be the same with x86 version) and indeed there are differences.

With -g option with have this stack trace:

AeDebug\Debugger = "C:\Program Files\Debugging Tools for Windows (x64)\windbg.exe" -p %ld -e %ld -g

0:000> kL
Child-SP          RetAddr           Call Site
00000000`0012f210 00000001`40004148 TestWER64!CTestDefaultDebuggerDlg::OnBnClickedButton1+0x7e
00000000`0012f250 00000001`40004388 TestWER64!_AfxDispatchCmdMsg+0xc4
00000000`0012f280 00000001`40003552 TestWER64!CCmdTarget::OnCmdMsg+0x180
00000000`0012f2e0 00000001`4000cc44 TestWER64!CDialog::OnCmdMsg+0x32
00000000`0012f320 00000001`4000d877 TestWER64!CWnd::OnCommand+0xcc
00000000`0012f3b0 00000001`40008c2c TestWER64!CWnd::OnWndMsg+0x5f
00000000`0012f4f0 00000001`4000c272 TestWER64!CWnd::WindowProc+0x38
00000000`0012f530 00000001`4000c32d TestWER64!AfxCallWndProc+0xfe
00000000`0012f5d0 00000000`77519bd1 TestWER64!AfxWndProc+0x59
00000000`0012f610 00000000`77516aa8 USER32!UserCallWinProcCheckWow+0x1ad
00000000`0012f6d0 00000000`77516bad USER32!SendMessageWorker+0x682
00000000`0012f760 000007fe`fccb0bbf USER32!SendMessageW+0x5c
00000000`0012f7b0 000007fe`fccb47df COMCTL32!Button_ReleaseCapture+0x157
00000000`0012f7f0 00000000`77519bd1 COMCTL32!Button_WndProc+0xcbf
00000000`0012f8b0 00000000`775198da USER32!UserCallWinProcCheckWow+0x1ad
00000000`0012f970 00000000`775167c2 USER32!DispatchMessageWorker+0x3b5
00000000`0012f9f0 00000001`400079cc USER32!IsDialogMessageW+0x153
00000000`0012fa80 00000001`40009148 TestWER64!CWnd::IsDialogMessageW+0x38
00000000`0012fab0 00000001`40003513 TestWER64!CWnd::PreTranslateInput+0x28
00000000`0012fae0 00000001`4000b696 TestWER64!CDialog::PreTranslateMessage+0xc3
00000000`0012fb10 00000001`40004c1f TestWER64!CWnd::WalkPreTranslateTree+0x3a
00000000`0012fb40 00000001`40004c7f TestWER64!AfxInternalPreTranslateMessage+0x67
00000000`0012fb70 00000001`40004e26 TestWER64!AfxPreTranslateMessage+0x23
00000000`0012fba0 00000001`40004e6b TestWER64!AfxInternalPumpMessage+0x3a
00000000`0012fbd0 00000001`4000aba6 TestWER64!AfxPumpMessage+0x1b
00000000`0012fc00 00000001`40003e4a TestWER64!CWnd::RunModalLoop+0xea
00000000`0012fc60 00000001`40024da4 TestWER64!CDialog::DoModal+0x1c6
00000000`0012fd10 00000001`40024625 TestWER64!CTestDefaultDebuggerApp::InitInstance+0xc4
00000000`0012fe70 00000001`400153c2 TestWER64!AfxWinMain+0x75
00000000`0012feb0 00000000`77ad652d TestWER64!__tmainCRTStartup+0x186
00000000`0012ff60 00000000`77c0c521 kernel32!BaseThreadInitThunk+0xd
00000000`0012ff90 00000000`00000000 ntdll!RtlUserThreadStart+0x1d

0:000> r
rax=0000000000000000 rbx=0000000000000001 rcx=000000000012fd50
rdx=00000000000003e8 rsi=000000000012fd50 rdi=000000014002daa0
rip=00000001400247ae rsp=000000000012f210 rbp=0000000000000111
r8=0000000000000000  r9=0000000140024730 r10=0000000140024730
r11=000000000012f310 r12=0000000000000000 r13=00000000000003e8
r14=0000000000000110 r15=0000000000000001
iopl=0         nv up ei pl zr na po nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00010244
TestWER64!CTestDefaultDebuggerDlg::OnBnClickedButton1+0x7e:
00000001`400247ae c704250000000000000000 mov dword ptr [0],0 ds:00000000`00000000=????????

Without -g option we also see exception processing (highlighted in red):

AeDebugger\Debugger = "C:\Program Files\Debugging Tools for Windows (x64)\windbg.exe" -p %ld -e %ld

0:000> kL
Child-SP RetAddr Call Site
00000000`0012e368 000007fe`fe301420 ntdll!ZwWaitForMultipleObjects+0xa
00000000`0012e370 00000000`77ae2cf3 KERNELBASE!WaitForMultipleObjectsEx+0xe8
00000000`0012e470 00000000`77b590f5 kernel32!WaitForMultipleObjectsExImplementation+0xb3
00000000`0012e500 00000000`77b59277 kernel32!WerpReportFaultInternal+0×215
00000000`0012e5a0 00000000`77b592cf kernel32!WerpReportFault+0×77
00000000`0012e5d0 00000000`77b594ec kernel32!BasepReportFault+0×1f
00000000`0012e600 00000000`77c743b8 kernel32!UnhandledExceptionFilter+0×1fc
00000000`0012e6e0 00000000`77bf85a8 ntdll! ?? ::FNODOBFM::`string’+0×2365
00000000`0012e710 00000000`77c09d0d ntdll!_C_specific_handler+0×8c
00000000`0012e780 00000000`77bf91af ntdll!RtlpExecuteHandlerForException+0xd
00000000`0012e7b0 00000000`77c31278 ntdll!RtlDispatchException+0×45a
00000000`0012ee90 00000001`400247ae ntdll!KiUserExceptionDispatcher+0×2e

00000000`0012f450 00000001`40004148 TestWER64!CTestDefaultDebuggerDlg::OnBnClickedButton1+0×7e
00000000`0012f490 00000001`40004388 TestWER64!_AfxDispatchCmdMsg+0xc4
00000000`0012f4c0 00000001`40003552 TestWER64!CCmdTarget::OnCmdMsg+0×180
00000000`0012f520 00000001`4000cc44 TestWER64!CDialog::OnCmdMsg+0×32
00000000`0012f560 00000001`4000d877 TestWER64!CWnd::OnCommand+0xcc
00000000`0012f5f0 00000001`40008c2c TestWER64!CWnd::OnWndMsg+0×5f
00000000`0012f730 00000001`4000c272 TestWER64!CWnd::WindowProc+0×38
00000000`0012f770 00000001`4000c32d TestWER64!AfxCallWndProc+0xfe
00000000`0012f810 00000000`77519bd1 TestWER64!AfxWndProc+0×59
00000000`0012f850 00000000`77516aa8 USER32!UserCallWinProcCheckWow+0×1ad
00000000`0012f910 00000000`77516bad USER32!SendMessageWorker+0×682
00000000`0012f9a0 00000000`7751eda7 USER32!SendMessageW+0×5c
00000000`0012f9f0 00000001`400079cc USER32!IsDialogMessageW+0×85f
00000000`0012fa80 00000001`40009148 TestWER64!CWnd::IsDialogMessageW+0×38
00000000`0012fab0 00000001`40003513 TestWER64!CWnd::PreTranslateInput+0×28
00000000`0012fae0 00000001`4000b696 TestWER64!CDialog::PreTranslateMessage+0xc3
00000000`0012fb10 00000001`40004c1f TestWER64!CWnd::WalkPreTranslateTree+0×3a
00000000`0012fb40 00000001`40004c7f TestWER64!AfxInternalPreTranslateMessage+0×67
00000000`0012fb70 00000001`40004e26 TestWER64!AfxPreTranslateMessage+0×23
00000000`0012fba0 00000001`40004e6b TestWER64!AfxInternalPumpMessage+0×3a
00000000`0012fbd0 00000001`4000aba6 TestWER64!AfxPumpMessage+0×1b
00000000`0012fc00 00000001`40003e4a TestWER64!CWnd::RunModalLoop+0xea
00000000`0012fc60 00000001`40024da4 TestWER64!CDialog::DoModal+0×1c6
00000000`0012fd10 00000001`40024625 TestWER64!CTestDefaultDebuggerApp::InitInstance+0xc4
00000000`0012fe70 00000001`400153c2 TestWER64!AfxWinMain+0×75
00000000`0012feb0 00000000`77ad652d TestWER64!__tmainCRTStartup+0×186
00000000`0012ff60 00000000`77c0c521 kernel32!BaseThreadInitThunk+0xd
00000000`0012ff90 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

I now prefer omitting -g option to get stack traces equivalent to manual crash dumps saved by userdump.exe on pre-Vista platforms and Task Manager on later platforms.

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

Crash Dump Analysis Patterns (Part 166)

Sunday, February 12th, 2012

Runtime software exceptions (such as C++ exceptions) can be translated by custom exception handlers into other exceptions by changing exception data. This is different from nested exceptions where another exception is thrown. One example of such possible translation I recently encountered when looking at a raw stack data (!teb -> dps) having signs of hidden exceptions (multiple RaiseException calls) and also CLR execution residue (valid return addresses of clr module). In addition of final invalid handle exception and one hidden access violation there were many exception codes c0000027. Google search pointed to the article about skipped C++ destructors written by S. Senthil Kumar that prompted me to introduce the pattern Translated Exception.

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

Professional Software Debugging Services

Tuesday, January 31st, 2012

Memory Dump Analysis Services starts providing debugging training and assistance in addition to (based on) memory dump and software trace analysis. It has recently registered www.debugging.pro domain and is working on extending its courses to cover live debugging and additional OS platforms this year.

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

New Book: Accelerated .NET Memory Dump Analysis

Sunday, November 13th, 2011

During the previous several months some companies and individuals expressed their interest in the training (the next one is scheduled for January) but its time was not suitable due to different geographic time zones. So I have decided to publish this training in a book format (currently in PDF) and make it available in paperback on Amazon and B&N later. Book details:

  • Title: Accelerated .NET Memory Dump Analysis: Training Course Transcript and WinDbg Practice Exercises with Notes
  • Description: The full transcript of Memory Dump Analysis Services Training with 7 step-by-step exercises, notes, source code of specially created modeling applications and selected Q&A. Covers 20 .NET memory dump analysis patterns plus additional unmanaged patterns.
  • Authors: Dmitry Vostokov, Memory Dump Analysis Services
  • Publisher: OpenTask (November 2011)
  • Language: English
  • Product Dimensions: 28.0 x 21.6
  • Paperback: 204 pages
  • ISBN-13: 978-1908043320

Table of Contents

Now available for sale in PDF format from Memory Dump Analysis Services.

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

Public Preview of Accelerated .NET Memory Dump Analysis Training

Sunday, November 6th, 2011

The slides are available from Memory Dump Analysis Services:

http://www.dumpanalysis.com/Training/Accelerated-NET-Memory-Dump-Analysis-Public.pdf

It also offers the new training sessions in January, 2012:

http://www.dumpanalysis.com/accelerated-net-memory-dump-analysis

http://www.dumpanalysis.com/accelerated-windows-memory-dump-analysis

Also the registration for Advanced training session in December is still open:

http://www.dumpanalysis.com/advanced-windows-memory-dump-analysis

There are also new coming courses for 2012 so stay tuned!

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