This weekend noticed that it is in stock and this means that I soon get it in the post:
Advanced .NET Debugging (Addison-Wesley Microsoft Technology Series)
I plan to start reading it as soon as it arrives and put notes on my Software Generalist blog.
- Dmitry Vostokov @ DumpAnalysis.org -
Sometimes we have a managed code exception that was enveloping a handled unmanaged code exception, Mixed (Nested) Exception:
0:000> !analyze -v
[...]
EXCEPTION_RECORD: ffffffff -- (.exr 0xffffffffffffffff)
ExceptionAddress: 00000000
ExceptionCode: 80000003 (Break instruction exception)
ExceptionFlags: 00000000
NumberParameters: 0
ERROR_CODE: (NTSTATUS) 0x80000003 - {EXCEPTION} Breakpoint A breakpoint has been reached.
FAULTING_THREAD: 00000cfc
[...]
EXCEPTION_OBJECT: !pe 1f9af1ac
Exception object: 1f9af1ac
Exception type: System.AccessViolationException
Message: Attempted to read or write protected memory. This is often an indication that other memory is corrupt.
InnerException: <none>
StackTrace (generated):
SP IP Function
0012EF3C 28DD9AF9 DllA!Component.getFirstField()+0×11
[…]
0012EFC8 7B194170 System_Windows_Forms_ni!System.Windows.Forms. Control.OnClick(System.EventArgs)+0×70
0012EFE0 7B6F74B4 System_Windows_Forms_ni!System.Windows.Forms. Control.WmMouseUp(System.Windows.Forms.Message ByRef, System.Windows.Forms.MouseButtons, Int32)+0×170
0012F06C 7BA29B66 System_Windows_Forms_ni!System.Windows.Forms. Control.WndProc(System.Windows.Forms.Message ByRef)+0×861516
0012F0C4 7B1D1D6A System_Windows_Forms_ni!System.Windows.Forms. ScrollableControl.WndProc(System.Windows.Forms.Message ByRef)+0×2a
0012F0D0 7B1C8640 System_Windows_Forms_ni!System.Windows.Forms. Control+ControlNativeWindow.OnMessage(System.Windows.Forms.Message ByRef)+0×10
0012F0D8 7B1C85C1 System_Windows_Forms_ni!System.Windows.Forms. Control+ControlNativeWindow.WndProc(System.Windows.Forms.Message ByRef)+0×31
0012F0EC 7B1C849A System_Windows_Forms_ni!System.Windows.Forms. NativeWindow.Callback(IntPtr, Int32, IntPtr, IntPtr)+0×5a
[...]
We see that it was the access violation exception and check the thread with TID cfc:
0:000> kL
ChildEBP RetAddr
0012db54 77d70dde ntdll!KiFastSystemCallRet
0012db58 7b1d8e48 user32!NtUserWaitMessage+0xc
0012dbec 7b1d8937 System_Windows_Forms_ni+0x208e48
0012dc44 7b1d8781 System_Windows_Forms_ni+0x208937
0012dc74 7b6edd1f System_Windows_Forms_ni+0x208781
0012dc8c 7b72246b System_Windows_Forms_ni+0x71dd1f
0012dd18 7b722683 System_Windows_Forms_ni+0x75246b
0012dd58 7b6f77f6 System_Windows_Forms_ni+0x752683
0012dd64 7b6fa27c System_Windows_Forms_ni+0x7277f6
0012f148 77d6f8d2 System_Windows_Forms_ni+0x72a27c
0012f174 77d6f794 user32!InternalCallWinProc+0x23
0012f1ec 77d70008 user32!UserCallWinProcCheckWow+0x14b
0012f250 77d70060 user32!DispatchMessageWorker+0x322
0012f260 0a1412fa user32!DispatchMessageW+0xf
WARNING: Frame IP not in any known module. Following frames may be wrong.
0012f27c 578439f7 0xa1412fa
0012f2ec 578430c9 WindowsBase_ni+0x939f7
0012f2f8 5784306c WindowsBase_ni+0x930c9
0012f304 55bed46e WindowsBase_ni+0x9306c
0012f310 55bec76f PresentationFramework_ni+0x1cd46e
0012f334 55bd3aa6 PresentationFramework_ni+0x1cc76f
If there was an exception it must be hidden so we inspect the thread raw stack:
0:000> !teb
TEB at 7ffdf000
ExceptionList: 0012e470
StackBase: 00130000
StackLimit: 0011e000
SubSystemTib: 00000000
FiberData: 00001e00
ArbitraryUserPointer: 00000000
Self: 7ffdf000
EnvironmentPointer: 00000000
ClientId: 00000b6c . 00000cfc
RpcHandle: 00000000
Tls Storage: 7ffdf02c
PEB Address: 7ffd4000
LastErrorValue: 0
LastStatusValue: c0000139
Count Owned Locks: 0
HardErrorMode: 0
0:000> dps 0011e000 00130000
0011e000 00000000
0011e004 00000000
0011e008 00000000
[...]
0012e72c 00130000
0012e730 0011e000
0012e734 00ee350d
0012e738 0012ea3c
0012e73c 77f299f7 ntdll!KiUserExceptionDispatcher+0xf
0012e740 0012e750
0012e744 0012e76c
0012e748 0012e750
0012e74c 0012e76c
0012e750 c0000005
0012e754 00000000
0012e758 00000000
0012e75c 77f17d89 ntdll!RtlLeaveCriticalSection+0×9
0012e760 00000002
0012e764 00000001
0012e768 00000028
0012e76c 0001003f
0012e770 00000000
0012e774 00000000
0012e778 00000000
0012e77c 00000000
[…]
0:000> .cxr 0012e76c
eax=00000020 ebx=09ca1fa0 ecx=781c1b78 edx=00000001 esi=00000020 edi=09ca1ff8
eip=77f17d89 esp=0012ea38 ebp=0012ea3c iopl=0 nv up ei pl nz na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00010202
ntdll!RtlLeaveCriticalSection+0x9:
77f17d89 834608ff add dword ptr [esi+8],0FFFFFFFFh ds:0023:00000028=????????
0:000> kL
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr
0012ea3c 7813e5b5 ntdll!RtlLeaveCriticalSection+0x9
0012ea44 2071c9ba msvcr80!_unlock_file+0x35
WARNING: Stack unwind information not available. Following frames may be wrong.
0012ea68 2071c31e DllB!getType+0×286a
0012ee34 206bbfbc DllB!getType+0×3eb
0012ee68 206c8abb DllC+0xbfbc
0012ee98 79e71ca7 DllC!getFirstField+0×3b
0012f148 77d6f8d2 mscorwks!NDirectGenericStubReturnFromCall
0012f1ec 77d70008 user32!InternalCallWinProc+0×23
0012f240 77db51b9 user32!DispatchMessageWorker+0×322
0012f4a4 79e95feb user32!_W32ExceptionHandler+0×18
0012f4fc 79e968b0 mscorwks!MetaSig::HasRetBuffArg+0×5
0012f50c 79e9643e mscorwks!MetaSig::MetaSig+0×3a
0012f610 79e96534 mscorwks!MethodDesc::CallDescr+0xaf
0012f62c 79e96552 mscorwks!MethodDesc::CallTargetWorker+0×1f
0012f644 79eefa45 mscorwks!MethodDescCallSite::CallWithValueTypes+0×1a
0012f7a8 79eef965 mscorwks!ClassLoader::RunMain+0×223
Therefore we identified DllB and DllC components as suspicious. If we check exception chain we see that .NET runtime registered custom exception handlers:
0:000> !exchain
0012e470: mscorwks!COMPlusNestedExceptionHandler+0 (79edd6d7)
0012f13c: mscorwks!FastNExportExceptHandler+0 (7a00a2e7)
0012f1dc: user32!_except_handler4+0 (77db51ba)
0012f240: user32!_except_handler4+0 (77db51ba)
0012f46c: mscorwks!COMPlusFrameHandler+0 (79edc3bc)
0012f4c0: mscorwks!_except_handler4+0 (79f908a2)
0012f798: mscorwks!_except_handler4+0 (79f908a2)
0012fa04: mscorwks!GetManagedNameForTypeInfo+a680 (7a328d90)
0012fed4: mscorwks!GetManagedNameForTypeInfo+82c8 (7a325a3a)
0012ff20: mscorwks!_except_handler4+0 (79f908a2)
0012ff6c: mscorwks!GetManagedNameForTypeInfo+a6e (7a319ee4)
0012ffc4: ntdll!_except_handler4+0 (77ed9834)
Invalid exception stack at ffffffff
We check that GetManagedNameForTypeInfo+a6e (7a319ee4) is an exception handler indeed:
0:000> .asm no_code_bytes
Assembly options: no_code_bytes
0:000> uf 7a319ee4
msvcr80!__CxxFrameHandler:
78158aeb push ebp
78158aec mov ebp,esp
78158aee sub esp,8
78158af1 push ebx
78158af2 push esi
78158af3 push edi
78158af4 cld
78158af5 mov dword ptr [ebp-4],eax
78158af8 xor eax,eax
78158afa push eax
78158afb push eax
78158afc push eax
78158afd push dword ptr [ebp-4]
78158b00 push dword ptr [ebp+14h]
78158b03 push dword ptr [ebp+10h]
78158b06 push dword ptr [ebp+0Ch]
78158b09 push dword ptr [ebp+8]
78158b0c call msvcr80!__InternalCxxFrameHandler (7815897e)
78158b11 add esp,20h
78158b14 mov dword ptr [ebp-8],eax
78158b17 pop edi
78158b18 pop esi
78158b19 pop ebx
78158b1a mov eax,dword ptr [ebp-8]
78158b1d mov esp,ebp
78158b1f pop ebp
78158b20 ret
mscorwks!__CxxFrameHandler3:
79f5f258 jmp dword ptr [mscorwks!_imp____CxxFrameHandler3 (79e711c4)]
mscorwks!GetManagedNameForTypeInfo+0xa6e:
7a319ee4 mov edx,dword ptr [esp+8]
7a319ee8 lea eax,[edx+0Ch]
7a319eeb mov ecx,dword ptr [edx-30h]
7a319eee xor ecx,eax
7a319ef0 call mscorwks!__security_check_cookie (79e72037)
7a319ef5 mov eax,offset mscorwks!_CT??_R0H+0xc14 (7a319f00)
7a319efa jmp mscorwks!__CxxFrameHandler3 (79f5f258)
- Dmitry Vostokov @ DumpAnalysis.org -
While doing Google search today found the site for the forthcoming Mario Hewardt’s new book Advanced .NET Debugging:
www.advanceddotnetdebugging.com
with 74-page sample chapter. Looking forward to reading this book.
- Dmitry Vostokov @ DumpAnalysis.org -
Pre-ordered today on Amazon this forthcoming book:
Advanced .NET Debugging (Addison-Wesley Microsoft Technology Series)
I was able to find TOC on InformIt. Looking forward to reading it. .NET crash dump (mixed managed and unmanaged code) and software trace analysis is a sizable part of my day-to-day activities.
When ordering I recalled that I’m was also working on a .NET debugging and memory dump analysis book:
Unmanaged Code: Escaping the Matrix of .NET
but I had to postpone it due to other commitments. It is now planned for the next year after I accumulate more material and real-world case studies.
Taking the opportunity, I also created a category .NET Debugging where I put some old blog posts and patterns related to managed code.
- Dmitry Vostokov @ DumpAnalysis.org -
Often analysis of software traces starts with searching for short textual patterns, like a failure or an exception code or simply the word “exception”. And indeed, some software components are able to record their own exceptions or exceptions that were propagated to them including full stack traces. This is all common in .NET and Java environments. Here is a synthetic and beautified example based on real software traces:
N PID TID Message
[...]
265799 8984 4216 ComponentA.Store.GetData threw exception: ‘System.Reflection.TargetInvocationException: DCOM connection to server failed with error: ‘Exception from HRESULT: 0×842D0001′ —> System.Runtime.InteropServices.COMException (0×842D0001): Exception from HRESULT: 0×842D0001
at ComponentA.GetData(Byte[] pKey)
at System.RuntimeMethodHandle._InvokeMethodFast(Object target, Object[] arguments, SignatureStruct& sig, MethodAttributes methodAttributes, RuntimeTypeHandle typeOwner)
at System.RuntimeMethodHandle.InvokeMethodFast(Object target, Object[] arguments, Signature sig, MethodAttributes methodAttributes, RuntimeTypeHandle typeOwner)
at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture, Boolean skipVisibilityChecks)
at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
at ComponentB.Connections.ComInterfaceProxy.Invoke(IMessage message)’
265800 8984 4216 === Begin Exception Dump ===
265801 8984 4216 ComponentB.Exceptions.ConnectionException: DCOM connection to server failed with error: ‘Exception from HRESULT: 0×842D0001′ —> System.Runtime.InteropServices.COMException (0×842D0001): Exception from HRESULT: 0×842D0001
265802 8984 4216 at ComponentA.Store.GetData(Byte[] pKey)
[…]
265808 8984 4216 Exception rethrown at [0]:
265809 8984 4216 at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
265810 8984 4216 at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
265811 8984 4216 at ComponentA.Store.GetData(Byte[] pKey)
265812 8984 4216 at ComponentA.App.EnumBusinessObjects()
[…]
265816 8984 4216 ===> InnerException:
265817 8984 4216 ** COM Exception Error Code: 0×842d0001
265818 8984 4216 System.Runtime.InteropServices.COMException (0×842D0001): Exception from HRESULT: 0×842D0001
265819 8984 4216 at ComponentA.Store.GetData(Byte[] pKey)
265820 8984 4216 === End Exception Dump ===
[…]
In the embedded stack trace we see that App object was trying to enumerate business objects and asked Store object to get some data and the latter object was probably trying to communicate to the real data store via DCOM. The communication attempt failed with HRESULT.
- Dmitry Vostokov @ TraceAnalysis.org -
Sometimes the assembly code looks almost wild (not like generated by your favourite compiler). For example (that also shows .NET runtime native unhandled exception processing):
0:000> kL 100
ChildEBP RetAddr
0014dbb4 77189254 ntdll!KiFastSystemCallRet
0014dbb8 75fec244 ntdll!ZwWaitForSingleObject+0xc
0014dc28 75fec1b2 kernel32!WaitForSingleObjectEx+0xbe
0014dc3c 72605389 kernel32!WaitForSingleObject+0x12
0014dc6c 726058e7 mscorwks!ClrWaitForSingleObject+0x24
0014e128 72608084 mscorwks!RunWatson+0x1df
0014e86c 7260874a mscorwks!DoFaultReportWorker+0xb59
0014e8a8 72657452 mscorwks!DoFaultReport+0xc3
0014e8cc 7265c0c7 mscorwks!WatsonLastChance+0x3f
0014e924 7265c173 mscorwks!CLRAddVectoredHandlers+0x209
0014e92c 7603f4be mscorwks!InternalUnhandledExceptionFilter+0x22
0014e9e8 771a85b7 kernel32!UnhandledExceptionFilter+0×127
0014e9f0 77139a14 ntdll!__RtlUserThreadStart+0×6f
0014ea04 771340f4 ntdll!_EH4_CallFilterFunc+0×12
0014ea2c 77189b99 ntdll!_except_handler4+0×8e
0014ea50 77189b6b ntdll!ExecuteHandler2+0×26
0014eb00 771899f7 ntdll!ExecuteHandler+0×24
0014eb00 03ca0141 ntdll!KiUserExceptionDispatcher+0xf
WARNING: Frame IP not in any known module. Following frames may be wrong.
0014ee28 634c2f42 0×3ca0141
0014ee34 67715e44 System_ni+0×132f42
0014ee70 72431b4c System_ServiceProcess_ni+0×25e44
0014ee80 724421f9 mscorwks!CallDescrWorker+0×33
0014ef00 72456571 mscorwks!CallDescrWorkerWithHandler+0xa3
0014f03c 724565a4 mscorwks!MethodDesc::CallDescr+0×19c
0014f058 724565c2 mscorwks!MethodDesc::CallTargetWorker+0×1f
0014f070 724afac5 mscorwks!MethodDescCallSite::CallWithValueTypes+0×1a
0014f1d4 724af9e5 mscorwks!ClassLoader::RunMain+0×223
0014f43c 724aff35 mscorwks!Assembly::ExecuteMainMethod+0xa6
0014f90c 724b011f mscorwks!SystemDomain::ExecuteMainMethod+0×456
0014f95c 724b004f mscorwks!ExecuteEXE+0×59
0014f9a4 72f57c24 mscorwks!_CorExeMain+0×15c
0014f9b4 75fe4911 mscoree!_CorExeMain+0×2c
0014f9c0 7716e4b6 kernel32!BaseThreadInitThunk+0xe
0014fa00 7716e489 ntdll!__RtlUserThreadStart+0×23
0014fa18 00000000 ntdll!_RtlUserThreadStart+0×1b
We set exception context:
0:000> kv 100
ChildEBP RetAddr Args to Child
[...]
0014e9e8 771a85b7 0014ea18 77139a14 00000000 kernel32!UnhandledExceptionFilter+0×127 (FPO: [SEH])
[…]
0:000> .exptr 0014ea18
----- Exception record at 0014eb18:
ExceptionAddress: 03ca0141
ExceptionCode: c0000005 (Access violation)
ExceptionFlags: 00000000
NumberParameters: 2
Parameter[0]: 00000000
Parameter[1]: 00000000
Attempt to read from address 00000000
----- Context record at 0014eb34:
eax=00000001 ebx=08394ff8 ecx=00000000 edx=00000001 esi=056a2a94 edi=00000000
eip=03ca0141 esp=0014ee00 ebp=0014ee28 iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00010246
03ca0141 3909 cmp dword ptr [ecx],ecx ds:0023:00000000=????????
Then we disassemble the code at crash point and it looks strange including calls through DS data segment:
0:000> .asm no_code_bytes
Assembly options: no_code_bytes
0:000> u 03ca0141
03ca0141 cmp dword ptr [ecx],ecx
03ca0143 call dword ptr ds:[36067C0h]
03ca0149 mov ecx,dword ptr [esi+5Ch]
03ca014c cmp dword ptr [ecx],ecx
03ca014e call dword ptr ds:[3606D10h]
03ca0154 mov dword ptr [ebp-1Ch],0
03ca015b mov dword ptr [ebp-18h],0FCh
03ca0162 push 3CA0180h
However further disassembly finally reaches RET instruction:
0:000> u
03ca0167 jmp 03ca0169
03ca0169 movzx edx,byte ptr [ebp-24h]
03ca016d mov ecx,dword ptr [ebp-28h]
03ca0170 call System_ServiceProcess_ni+0x25140 (67715140)
03ca0175 pop eax
03ca0176 jmp eax
03ca0178 lea esp,[ebp-0Ch]
03ca017b pop ebx
0:000> u
03ca017c pop esi
03ca017d pop edi
03ca017e pop ebp
03ca017f ret
03ca0180 mov dword ptr [ebp-18h],0
03ca0187 jmp 03ca0178
03ca0189 add byte ptr [eax],al
03ca018b add byte ptr [eax],al
and backward disassembling shows the matching function prolog code:
0:000> ub 03ca0141
03ca0127 movzx eax,byte ptr [ebp-24h]
03ca012b test eax,eax
03ca012d je 03ca0154
03ca012f cmp dword ptr [esi+60h],0
03ca0133 je 03ca013e
03ca0135 mov ecx,dword ptr [esi+60h]
03ca0138 call dword ptr ds:[3C20010h]
03ca013e mov ecx,dword ptr [esi+58h]
0:000> ub 03ca0127
03ca0114 push esi
03ca0115 push ebx
03ca0116 sub esp,1Ch
03ca0119 xor eax,eax
03ca011b mov dword ptr [ebp-18h],eax
03ca011e mov dword ptr [ebp-28h],ecx
03ca0121 mov dword ptr [ebp-24h],edx
03ca0124 mov esi,dword ptr [ebp-28h]
0:000> ub 03ca0114
03ca0102 retf
03ca0103 add eax,dword ptr [eax+36h]
03ca0106 retf
03ca0107 add ebx,dword ptr [esi+esi-35h]
03ca010b add esi,esp
03ca010d cmp eax,8B550360h
03ca0112 in al,dx
03ca0113 push edi
From stack trace I suspected this code as JIT-compiled .NET code of the the main assemebly method. And indeed I found the similar call signatures like mine
03ca0141 cmp dword ptr [ecx],ecx
03ca0143 call dword ptr ds:[36067C0h]
in the following MSDN article:
Drill Into .NET Framework Internals to See How the CLR Creates Runtime Objects
Hence the name of this pattern: JIT Code.
- Dmitry Vostokov @ DumpAnalysis.org -
Nested exception analysis is much simpler in managed code than in unmanaged. Exception object references the inner exception if any and so on:
WinDbg does a good job traversing all nested exceptions when executing !analyze -v command. In the following example of a Windows forms application crash ObjectDisposedException (shown in red) was re-thrown as Exception object with “Critical error” message (shown in magenta) which was re-thrown several times as Exception object with “Critical program error” message (shown in blue) that finally resulted in the process termination request in the top level exception handler:
MANAGED_STACK:
(TransitionMU)
001374B0 0B313757 System!System.Diagnostics.Process.Kill()+0x37
001374E4 0B3129C7 Component!Foo.HandleUnhandledException(System.Exception)+0x137
001374F4 07C0A7D3 Component!Foo+FooBarProcessMenuCommand(System.String)+0x33
(TransitionUM)
(TransitionMU)
[...]
EXCEPTION_OBJECT: !pe 3398614
Exception object: 03398614
Exception type: System.Exception
Message: Critical program error
InnerException: System.Exception, use !PrintException 03398560 to see more StackTrace (generated):
SP IP Function
001371A8 07C0CDD8 Foo.BarUserInteraction.Process(System.String)
00137258 07C0CCA6 Foo.BarUserInteraction.ProcessUserInteraction(Sub, BarStepType)
00137268 07C0A9BA Foo.BarMenu.Process(CMD)
00137544 07C0A8D8 Foo.BarMenu.ProcessCMD(CMD)
0013756C 07C0A7BE Foo+FooBar.ProcessBarMenuCommand(System.String)
StackTraceString: <none>
HResult: 80131500
EXCEPTION_OBJECT: !pe 3398560
Exception object: 03398560
Exception type: System.Exception
Message: Critical program error
InnerException: System.Exception, use !PrintException 033984ac to see more StackTrace (generated):
SP IP Function
00137154 07C0D4CA Foo.BarThreads+ProcessOpenQuery.Execute()
00137218 07C0D3B3 Foo.BarMenu.ProcessQuery()
00137220 07C0CCF3 Foo.BarUserInteraction.Process(System.String)
StackTraceString: <none>
HResult: 80131500
EXCEPTION_OBJECT: !pe 33984ac
Exception object: 033984ac
Exception type: System.Exception
Message: Critical program error
InnerException: System.Exception, use !PrintException 033983ec to see more StackTrace (generated):
SP IP Function
0013704C 0A6149DD Foo.Bar.OpenQueryThreaded(Foo.BarParameter)
00137154 0A6140D0 Foo.BarThreads+ProcessParameter.Execute()
[…]
StackTraceString: <none>
HResult: 80131500
EXCEPTION_OBJECT: !pe 33983ec
Exception object: 033983ec
Exception type: System.Exception
Message: Critical program error
InnerException: System.Exception, use !PrintException 033982fc to see more StackTrace (generated):
SP IP Function
00137008 0ACA59F1 Foo.BarApplication.Refresh(Boolean, Boolean)
001370C4 0A6144E0 Foo.Bar.OpenQueryThreaded(Foo.BarParameter)
StackTraceString: <none>
HResult: 80131500
EXCEPTION_OBJECT: !pe 33982fc
Exception object: 033982fc
Exception type: System.Exception
Message: Critical program error
InnerException: System.Exception, use !PrintException 03398260 to see more StackTrace (generated):
SP IP Function
00136F3C 0AE24983 Foo.BarDisplay.ShowVariableScreen(Foo.variables.BarVariables)
00136FDC 0AE204F6 Foo.variables.BarVariables.ShowVariableScreen()
00137070 0ACAFE1D Foo.BarApplication.ShowVariableScreen(Boolean)
00137080 0ACA5977 Foo.BarApplication.Refresh(Boolean, Boolean)
StackTraceString: <none>
HResult: 80131500
EXCEPTION_OBJECT: !pe 3398260
Exception object: 03398260
Exception type: System.Exception
Message: Critical error
InnerException: System.ObjectDisposedException, use !PrintException 03397db8 to see more StackTrace (generated):
SP IP Function
00136FB4 0AE24905 Foo.BarDisplay.ShowVariableScreen(Foo.variables.BarVariables)
StackTraceString: <none>
HResult: 80131500
EXCEPTION_OBJECT: !pe 3397db8
Exception object: 03397db8
Exception type: System.ObjectDisposedException
Message: Cannot access a disposed object.
InnerException: <none>
StackTrace (generated):
SP IP Function
00136258 06D36158 System.Windows.Forms.Control.CreateHandle()
001362B8 06D38F96 System.Windows.Forms.Control.get_Handle()
001362C4 0B0C8C68 System.Windows.Forms.Control.PointToScreen(System.Drawing.Point)
001362F0 0B0CECB4 System.Windows.Forms.Button.OnMouseUp(System.Windows.Forms.MouseEventArgs)
00136314 0B0C8BB7 System.Windows.Forms.Control.WmMouseUp(System.Windows.Forms.Message ByRef, System.Windows.Forms.MouseButtons, Int32)
00136384 06D385A0 System.Windows.Forms.Control.WndProc(System.Windows.Forms.Message ByRef)
001363E8 0A69C73E System.Windows.Forms.ButtonBase.WndProc(System.Windows.Forms.Message ByRef)
00136424 0A69C54D System.Windows.Forms.Button.WndProc(System.Windows.Forms.Message ByRef)
0013642C 06D37FAD System.Windows.Forms.Control+ControlNativeWindow.OnMessage(System.Windows.Forms.Message ByRef)
00136430 06D37F87 System.Windows.Forms.Control+ControlNativeWindow.WndProc(System.Windows.Forms.Message ByRef)
00136440 06D37D9F System.Windows.Forms.NativeWindow.Callback(IntPtr, Int32, IntPtr, IntPtr)
StackTraceString: <none>
HResult: 80131622
[…]
EXCEPTION_MESSAGE: Cannot access a disposed object.
STACK_TEXT:
00137448 7c827c1b ntdll!KiFastSystemCallRet
0013744c 77e4201b ntdll!NtTerminateProcess+0xc
0013745c 05d78202 kernel32!TerminateProcess+0x20
[...]
- Dmitry Vostokov @ DumpAnalysis.org -
While working on WDN book I noticed that it is possible to analyze managed code in complete memory dumps. We just need to switch to the process in question and load SOS DLL (if memory dumps are from 64-bit Windows we need to run 64-bit WinDbg because it needs to load 64-bit SOS from Microsoft.NET \ Framework64 \ vX.X.XXXXX folder).
Here is some command output from a complete memory dump generated from SystemDump when running TestDefaultDebugger.NET application where we try to find and disassemble IL code for this function:
namespace WindowsApplication1
{
public partial class Form1 : Form
{
[...]
private void button1_Click(object sender, EventArgs e)
{
System.Collections.Stack stack = new System.Collections.Stack();stack.Pop();
}
}
}
Loading Dump File [C:\W2K3\MEMORY_NET.DMP]
Kernel Complete Dump File: Full address space is available
Symbol search path is: srv*c:\mss*http://msdl.microsoft.com/download/symbols
Executable search path is:
Windows Server 2003 Kernel Version 3790 (Service Pack 2) UP Free x64
Product: Server, suite: Enterprise TerminalServer
Built by: 3790.srv03_sp2_gdr.070321-2337
Kernel base = 0xfffff800`01000000 PsLoadedModuleList = 0xfffff800`01198b00
kd> !process 0 0
**** NT ACTIVE PROCESS DUMP ****
[...]
PROCESS fffffadfe7287610
SessionId: 0 Cid: 0ad8 Peb: 7fffffdf000 ParentCid: 0acc
DirBase: 12cd9000 ObjectTable: fffffa800163c260 HandleCount: 114.
Image: TestDefaultDebugger.NET.exe
PROCESS fffffadfe67905a0
SessionId: 0 Cid: 085c Peb: 7fffffd4000 ParentCid: 0acc
DirBase: 232e2000 ObjectTable: fffffa8000917e10 HandleCount: 55.
Image: SystemDump.exe
kd> .process /r /p fffffadfe7287610
Implicit process is now fffffadf`e7287610
Loading User Symbols
kd> .loadby sos mscorwks
kd> !threads
ThreadCount: 2
UnstartedThread: 0
BackgroundThread: 1
PendingThread: 0
DeadThread: 0
Hosted Runtime: no
PreEmptive Lock
ID OSID ThreadOBJ State GC GC Alloc Context Domain Count APT Exception
1 a94 0000000000161150 6020 Enabled 0000000000000000:0000000000000000 000000000014ccb0 0 STA
2 604 00000000001688b0 b220 Enabled 0000000000000000:0000000000000000 000000000014ccb0 0 MTA (Finalizer)
kd> !process fffffadfe7287610 4
PROCESS fffffadfe7287610
SessionId: 0 Cid: 0ad8 Peb: 7fffffdf000 ParentCid: 0acc
DirBase: 12cd9000 ObjectTable: fffffa800163c260 HandleCount: 114.
Image: TestDefaultDebugger.NET.exe
THREAD fffffadfe668cbf0 Cid 0ad8.0a94 Teb: 000007fffffdd000 Win32Thread: fffff97ff4df2830 WAIT
THREAD fffffadfe727e6d0 Cid 0ad8.0f54 Teb: 000007fffffdb000 Win32Thread: 0000000000000000 WAIT
THREAD fffffadfe72d5bf0 Cid 0ad8.0604 Teb: 000007fffffd9000 Win32Thread: 0000000000000000 WAIT
THREAD fffffadfe679cbf0 Cid 0ad8.06b0 Teb: 000007fffffd7000 Win32Thread: 0000000000000000 WAIT
THREAD fffffadfe67d23d0 Cid 0ad8.0b74 Teb: 000007fffffd5000 Win32Thread: fffff97ff4b99010 WAIT
kd> !EEHeap -gc
Number of GC Heaps: 1
generation 0 starts at 0x0000000002a41030
generation 1 starts at 0x0000000002a41018
generation 2 starts at 0x0000000002a41000
ephemeral segment allocation context: (0x0000000002a8d528, 0x0000000002a8dfe8)
segment begin allocated size
00000000001a1260 0000064274e28f60 0000064274e5f610 0x00000000000366b0(222896)
00000000001a1070 000006427692ffe8 000006427695af20 0x000000000002af38(175928)
0000000000164f60 00000642787c7380 0000064278809150 0x0000000000041dd0(269776)
0000000002a40000 0000000002a41000 0000000002a8dfe8 0x000000000004cfe8(315368)
Large object heap starts at 0x0000000012a41000
segment begin allocated size
0000000012a40000 0000000012a41000 0000000012a4e738 0x000000000000d738(55096)
Total Size 0xfdad8(1039064)
------------------------------
GC Heap Size 0xfdad8(1039064)
kd> !gchandles
Bad MethodTable for Obj at 0000000002a7a7b8
Bad MethodTable for Obj at 0000000002a7a750
Bad MethodTable for Obj at 0000000002a445b0
GC Handle Statistics:
Strong Handles: 25
Pinned Handles: 7
Async Pinned Handles: 0
Ref Count Handles: 1
Weak Long Handles: 30
Weak Short Handles: 63
Other Handles: 0
Statistics:
MT Count TotalSize Class Name
[...]
0000064280016580 1 464 WindowsApplication1.Form1
[…]
kd> !dumpmt -md 0000064280016580
EEClass: 0000064280143578
Module: 0000064280012e00
Name: WindowsApplication1.Form1
mdToken: 02000002 (C:\TestDefaultDebugger.NET.exe)
BaseSize: 0×1d0
ComponentSize: 0×0
Number of IFaces in IFaceMap: 15
Slots in VTable: 375
————————————–
MethodDesc Table
Entry MethodDesc JIT Name
[…]
0000064280150208 00000642800164d0 JIT WindowsApplication1.Form1.InitializeComponent()
0000064280150210 00000642800164e0 JIT WindowsApplication1.Form1..ctor()
0000064280150218 00000642800164f0 NONE WindowsApplication1.Form1.button1_Click(System.Object, System.EventArgs)
kd> !dumpil 00000642800164f0
ilAddr = 00000000004021bc
IL_0000: newobj System.Collections.Stack::.ctor
IL_0005: stloc.0
IL_0006: ldloc.0
IL_0007: callvirt System.Collections.Stack::Pop
IL_000c: pop
IL_000d: ret
- Dmitry Vostokov @ DumpAnalysis.org -
David V provided an idea and a user dump for the next pattern which I call Missing Component. Sometimes the code raises an exception when certain DLL is missing. We need to guess that component name if we don’t have symbols and source code. This can be done by inspecting raw stack data in the close proximity of the exception ESP/RSP.
Consider the crash dump of Zune.exe with the following incomplete unmanaged stack trace:
EXCEPTION_RECORD: ffffffff -- (.exr 0xffffffffffffffff)
ExceptionAddress: 76f442eb (kernel32!RaiseException+0x00000058)
ExceptionCode: c06d007f
ExceptionFlags: 00000000
NumberParameters: 1
Parameter[0]: 0024f21c
0:000> kL
ChildEBP RetAddr
0024f1f8 6eb1081e kernel32!RaiseException+0x58
WARNING: Stack unwind information not available. Following frames may be wrong.
0024f260 6eac62fb ZuneNativeLib!ZuneLibraryExports::InteropNotifyUnAdvise+0x6aa9
0024f2ac 6ea9e269 ZuneNativeLib!ZuneLibraryExports::Phase2Initialization+0x24c9
0024f32c 79e74d79 ZuneNativeLib!ZuneLibraryExports::QueryDatabase+0x99da
0024f3d4 664bd6af mscorwks!MethodTable::IsValueType+0x35
0024f3e8 319cec9e ZuneShell_ni+0x2d6af
0024f3f4 31a15d19 UIX_ni+0x1ec9e
0024f3f8 00000000 UIX_ni+0x65d19
We can try to interpret the crash as Managed Code Exception but let’s first to check the exception code. Google search shows that the error code c06d007f means “DelayLoad Export Missing” and this definitely has to do with some missing DLL. It is not possible to tell which one was missing from the stack trace output. Additional digging is required.
Let’s look at the raw stack. First, we can try to see whether there are any calls to LoadLibrary on thread raw stack data:
0:000> !teb
TEB at 7ffdf000
ExceptionList: 0024f8c4
StackBase: 00250000
StackLimit: 00249000
SubSystemTib: 00000000
FiberData: 00001e00
ArbitraryUserPointer: 00000000
Self: 7ffdf000
EnvironmentPointer: 00000000
ClientId: 000012f4 . 00001080
RpcHandle: 00000000
Tls Storage: 004e8a18
PEB Address: 7ffde000
LastErrorValue: 126
LastStatusValue: c0000135
Count Owned Locks: 0
HardErrorMode: 0
0:000> dds 00249000 00250000
00249000 00000000
00249004 00000000
00249008 00000000
0024900c 00000000
00249010 00000000
00249014 00000000
00249018 00000000
[...]
0024f1a0 00000000
0024f1a4 00000000
0024f1a8 c06d007f
0024f1ac 00000000
0024f1b0 00000000
0024f1b4 76f442eb kernel32!RaiseException+0x58
0024f1b8 00000001
0024f1bc 0024f21c
0024f1c0 00000000
0024f1c4 00000000
0024f1c8 00000000
0024f1cc 00000000
0024f1d0 76f00000 kernel32!_imp___aullrem (kernel32+0x0)
0024f1d4 f7bd2a5d
0024f1d8 0024f1e8
0024f1dc 76fb8e8f kernel32!LookupHandler+0x10
0024f1e0 6ecb9b40 ZuneNativeLib!ShutdownSingletonMgr+0x15b024
0024f1e4 0024f21c
0024f1e8 0024f200
0024f1ec 6ec74e2a ZuneNativeLib!ShutdownSingletonMgr+0x11630e
0024f1f0 6ecb9b40 ZuneNativeLib!ShutdownSingletonMgr+0x15b024
0024f1f4 6ecb9ff0 ZuneNativeLib!ShutdownSingletonMgr+0x15b4d4
0024f1f8 0024f260
0024f1fc 6eb1081e ZuneNativeLib!ZuneLibraryExports::InteropNotifyUnAdvise+0x6aa9
0024f200 c06d007f
0024f204 00000000
0024f208 00000001
[...]
There are no such calls in our crash dump. Then we can try to interpret raw stack data as a byte stream to see “.dll” strings:
0:000> db 00249000 00250000
00249000 00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00 ................
00249010 00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00 ................
00249020 00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00 ................
00249030 00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00 ................
[...]
There are no such strings except “user32.dll”.
Now we can try to interpret every double word as a pointer to a Unicode string:
0:000> dpu 00249000 00250000
[...]
There are no strings with “.dll” inside. Finally, if we try to interpret every double word as a pointer to an ASCII string we get a few references to “ZuneService.dll”:
0:000> dpa 00249000 00250000
[...]
0024f1c8 00000000
0024f1cc 00000000
0024f1d0 76f00000 "MZ."
0024f1d4 f7bd2a5d
0024f1d8 0024f1e8 ""
0024f1dc 76fb8e8f "..t-.E."
0024f1e0 6ecb9b40 “ZuneService.dll”
0024f1e4 0024f21c “$”
0024f1e8 0024f200 “.”
0024f1ec 6ec74e2a “..^.._]..”
0024f1f0 6ecb9b40 “ZuneService.dll”
0024f1f4 6ecb9ff0 “CreateServiceInstance”
0024f1f8 0024f260 “..$”
0024f1fc 6eb1081e “.]…….e.”
0024f200 c06d007f
0024f204 00000000
0024f208 00000001
0024f20c 0024f268 “..$”
0024f210 00000000
0024f214 0024f2c8 “…n ..n<.$”
0024f218 6ecbe220 “”
0024f21c 00000024
0024f220 6ecb9960 “.”
0024f224 6ecbe05c “.c.n.2.n”
0024f228 6ecb9b40 “ZuneService.dll”
0024f22c 00000001
0024f230 6ecb9ff0 “CreateServiceInstance”
0024f234 ffffffff
0024f238 00000000
If we search for 0024f1e0 pointer in dps WinDbg command output we would see that it is in a close proximity to RaiseException call and it seems that all our pointers to “ZuneService.dll” string fall into ZuneNativeLib address range:
0024f1b4 76f442eb kernel32!RaiseException+0x58
0024f1b8 00000001
0024f1bc 0024f21c
0024f1c0 00000000
0024f1c4 00000000
0024f1c8 00000000
0024f1cc 00000000
0024f1d0 76f00000 kernel32!_imp___aullrem (kernel32+0x0)
0024f1d4 f7bd2a5d
0024f1d8 0024f1e8
0024f1dc 76fb8e8f kernel32!LookupHandler+0x10
0024f1e0 6ecb9b40 ZuneNativeLib!ShutdownSingletonMgr+0×15b024
0024f1e4 0024f21c
0024f1e8 0024f200
0024f1ec 6ec74e2a ZuneNativeLib!ShutdownSingletonMgr+0×11630e
0024f1f0 6ecb9b40 ZuneNativeLib!ShutdownSingletonMgr+0×15b024
0024f1f4 6ecb9ff0 ZuneNativeLib!ShutdownSingletonMgr+0×15b4d4
0024f1f8 0024f260
0024f1fc 6eb1081e ZuneNativeLib!ZuneLibraryExports::InteropNotifyUnAdvise+0×6aa9
0024f200 c06d007f
0024f204 00000000
0024f208 00000001
0024f20c 0024f268
0024f210 00000000
0024f214 0024f2c8
0024f218 6ecbe220 ZuneNativeLib!ShutdownSingletonMgr+0×15f704
0024f21c 00000024
0024f220 6ecb9960 ZuneNativeLib!ShutdownSingletonMgr+0×15ae44
0024f224 6ecbe05c ZuneNativeLib!ShutdownSingletonMgr+0×15f540
0024f228 6ecb9b40 ZuneNativeLib!ShutdownSingletonMgr+0×15b024
0024f22c 00000001
0024f230 6ecb9ff0 ZuneNativeLib!ShutdownSingletonMgr+0×15b4d4
0024f234 ffffffff
0024f238 00000000
When examining the system it was found that ZuneService.dll was missing there indeed.
- Dmitry Vostokov @ DumpAnalysis.org -
This is a forthcoming book about .NET debugging seen in a wider context than .NET runtime environment (CLR). There is the whole new generation of .NET software developers, designers and architects thinking in terms of managed code and associated concepts. However CLR runs in unmanaged environment which finally interfaces with native code. Therefore understanding unmanaged and native code is vital for successful debugging of real customer problems. Preliminary information is:
(*) subject to change
- Dmitry Vostokov @ DumpAnalysis.org -
In Advanced Windows Debugging book I encountered some thread stacks related to debugger events like Exit a Process, Load or Unload a Module and realized that I’ve seen process crash dumps with such stacks traces. These thread stacks are not normally encountered in healthy process dumps and, statistically speaking, when a process terminates or unloads a library the chances to save a memory dump manually using process dumpers like userdump.exe or Task Manager in Vista are very low unless an interactive debugger was attached or breakpoints were set in advance. Therefore the presence of such threads in a captured crash dump usually indicates some problem or at least focuses attention to the procedure used to save a dump. Such pattern merits its own name: Special Stack Trace.
For example, one process dump had the following stack trace showing process termination initiated from .NET runtime:
STACK_TEXT:
0012fc2c 7c827c1b ntdll!KiFastSystemCallRet
0012fc30 77e668c3 ntdll!NtTerminateProcess+0xc
0012fd24 77e66905 KERNEL32!_ExitProcess+0x63
0012fd38 01256d9b KERNEL32!ExitProcess+0x14
0012ff60 01256dc7 mscorwks!SafeExitProcess+0x11a
0012ff6c 011c5fa4 mscorwks!DisableRuntime+0xd0
0012ffb0 79181b5f mscorwks!_CorExeMain+0x8c
0012ffc0 77e6f23b mscoree!_CorExeMain+0x2c
0012fff0 00000000 KERNEL32!BaseProcessStart+0x23
The original problem was an error message box and the application disappeared when a user dismissed the message. How the dump was saved? Someone advised to attach NTSD to that process, hit ‘g’ and then save the memory dump when the process breaks into the debugger again. So the problem was already gone by that time and the better way would have been to create the manual user dump of that process when it was displaying the error message.
- Dmitry Vostokov @ DumpAnalysis.org -
Sometimes there are situations when we need to test exception handling to see whether it works and how to get dumps or logs from it. For example, a customer reports infrequent process crashes but no dumps are saved. Then we can try some application that crashes immediately to see whether it results in error messages and/or saved crash dumps. This was the motivation behind TestDefaultDebugger package. Unfortunately it contains only native applications and today I needed to test .NET CLR exception handling and see what messages it shows in my environment. So I wrote a simple program in C# that creates an empty Stack object and then calls its Pop method which triggers “Stack empty” exception sufficient for my purposes.
The updated package now includes TestDefaultDebugger.NET.exe and can be downloaded from Citrix support web site (requires free registration):
Download TestDefaultDebugger package
- Dmitry Vostokov @ DumpAnalysis.org -
Sometimes the process size constantly grows but there is no difference in the process heap size. In such cases we need to check whether the process uses Microsoft .NET runtime (CLR). If one of the loaded modules is mscorwks.dll or mscorsvr.dll then it is most likely. Then we should check CLR heap statistics.
In .NET world dynamically allocated objects are garbage collected (GC) and therefore simple allocate-and-forget memory leaks are not possible. To simulate that I created the following C# program:
using System;
namespace CLRHeapLeak
{
class Leak
{
private byte[] m_data;
public Leak()
{
m_data = new byte[1024];
}
}
class Program
{
static void Main(string[] args)
{
Leak leak = new Leak();
while (true)
{
leak = new Leak();
System.Threading.Thread.Sleep(100);
}
}
}
}
If we run it the process size will never grow. GC thread will collect and free unreferenced Leak classes. This can be seen from inspecting memory dumps taken with userdump.exe after the start, 2, 6 and 12 minutes. The GC heap never grows higher than 1Mb and the number of CLRHeapLeak.Leak and System.Byte[] objects always fluctuates between 100 and 500. For example, on 12th minute we have the following statistics:
0:000> .loadby sos mscorwks
0:000> !eeheap -gc
Number of GC Heaps: 1
generation 0 starts at 0x0147160c
generation 1 starts at 0x0147100c
generation 2 starts at 0x01471000
ephemeral segment allocation context: (0x014dc53c, 0x014dd618)
segment begin allocated size
004aedb8 790d7ae4 790f7064 0x0001f580(128384)
01470000 01471000 014dd618 0x0006c618(443928)
Large object heap starts at 0x02471000
segment begin allocated size
02470000 02471000 02473250 0x00002250(8784)
Total Size 0x8dde8(581096)
------------------------------
GC Heap Size 0×8dde8(581096)
0:000> !dumpheap -stat
total 2901 objects
Statistics:
Count TotalSize Class Name
1 12 System.Security.Permissions.SecurityPermission
1 24 System.OperatingSystem
1 24 System.Version
1 24 System.Reflection.Assembly
1 28 System.SharedStatics
1 36 System.Int64[]
1 40 System.AppDomainSetup
3 60 System.RuntimeType
5 60 System.Object
2 72 System.Security.PermissionSet
1 72 System.ExecutionEngineException
1 72 System.StackOverflowException
1 72 System.OutOfMemoryException
1 100 System.AppDomain
7 100 Free
2 144 System.Threading.ThreadAbortException
4 328 System.Char[]
418 5016 CLRHeapLeak.Leak
5 8816 System.Object[]
2026 128632 System.String
418 433048 System.Byte[]
Total 2901 objects
However, if we make Leak objects always referenced by introducing the following changes into the program:
using System;
namespace CLRHeapLeak
{
class Leak
{
private byte[] m_data;
private Leak m_prevLeak;
public Leak()
{
m_data = new byte[1024];
}
public Leak(Leak prevLeak)
{
m_prevLeak = prevLeak;
m_data = new byte[1024];
}
}
class Program
{
static void Main(string[] args)
{
Leak leak = new Leak();
while (true)
{
leak = new Leak(leak);
System.Threading.Thread.Sleep(100);
}
}
}
}
then if we run the program we would see in Task Manager that it grows over time. Taking consecutive memory dumps after the start, 10 and 16 minutes, shows that Win32 heap segments have always the same size:
0:000> !heap 0 0
Index Address Name Debugging options enabled
1: 00530000
Segment at 00530000 to 00630000 (0003d000 bytes committed)
2: 00010000
Segment at 00010000 to 00020000 (00003000 bytes committed)
3: 00520000
Segment at 00520000 to 00530000 (00003000 bytes committed)
4: 00b10000
Segment at 00b10000 to 00b50000 (00001000 bytes committed)
5: 001a0000
Segment at 001a0000 to 001b0000 (00003000 bytes committed)
6: 00170000
Segment at 00170000 to 00180000 (00008000 bytes committed)
7: 013b0000
Segment at 013b0000 to 013c0000 (00003000 bytes committed)
but GC heap and the number of Leak and System.Byte[] objects in it were growing significantly:
Process Uptime: 0 days 0:00:04.000
0:000> !eeheap -gc
Number of GC Heaps: 1
generation 0 starts at 0x013c1018
generation 1 starts at 0x013c100c
generation 2 starts at 0x013c1000
ephemeral segment allocation context: (0x013cd804, 0x013cdff4)
segment begin allocated size
0055ee08 790d7ae4 790f7064 0x0001f580(128384)
013c0000 013c1000 013cdff4 0x0000cff4(53236)
Large object heap starts at 0x023c1000
segment begin allocated size
023c0000 023c1000 023c3250 0x00002250(8784)
Total Size 0x2e7c4(190404)
------------------------------
GC Heap Size 0×2e7c4(190404)
0:000> !dumpheap -stat
total 2176 objects
Statistics:
Count TotalSize Class Name
...
...
...
46 736 CLRHeapLeak.Leak
5 8816 System.Object[]
46 47656 System.Byte[]
2035 129604 System.String
Total 2176 objects
Process Uptime: 0 days 0:09:56.000
0:000> !eeheap -gc
Number of GC Heaps: 1
generation 0 starts at 0x018cddbc
generation 1 starts at 0x01541ec4
generation 2 starts at 0x013c1000
ephemeral segment allocation context: (0x0192d668, 0x0192ddc8)
segment begin allocated size
0055ee08 790d7ae4 790f7064 0x0001f580(128384)
013c0000 013c1000 0192ddc8 0x0056cdc8(5688776)
Large object heap starts at 0x023c1000
segment begin allocated size
023c0000 023c1000 023c3240 0x00002240(8768)
Total Size 0x58e588(5825928)
------------------------------
GC Heap Size 0×58e588(5825928)
0:000> !dumpheap -stat
total 12887 objects
Statistics:
Count TotalSize Class Name
...
...
...
5 8816 System.Object[]
5403 86448 CLRHeapLeak.Leak
2026 128632 System.String
5403 5597508 System.Byte[]
Total 12887 objects
Process Uptime: 0 days 0:16:33.000
0:000> !eeheap -gc
Number of GC Heaps: 1
generation 0 starts at 0x01c59cb4
generation 1 starts at 0x0194fd20
generation 2 starts at 0x013c1000
ephemeral segment allocation context: (0x01cd3050, 0x01cd3cc0)
segment begin allocated size
0055ee08 790d7ae4 790f7064 0x0001f580(128384)
013c0000 013c1000 01cd3cc0 0x00912cc0(9514176)
Large object heap starts at 0x023c1000
segment begin allocated size
023c0000 023c1000 023c3240 0x00002240(8768)
Total Size 0x934480(9651328)
------------------------------
GC Heap Size 0×934480(9651328)
0:000> !dumpheap -stat
total 20164 objects
Statistics:
Count TotalSize Class Name
5 8816 System.Object[]
2026 128632 System.String
9038 144608 CLRHeapLeak.Leak
9038 9363368 System.Byte[]
Total 20164 objects
This is not the traditional memory leak because we have the reference chain. However, uncontrolled memory growth can be considered as a memory leak too, caused by poor application design, bad input validation or error handling, etc.
There are situations when customers think there is a memory leak but it is not. One of them is unusually big size of a process when running it on a multi-processor server. If dllhost.exe hosting typical .NET assembly DLL occupies less than 100Mb on a local workstation starts consuming more than 300Mb on a 4 processor server than it can be the case that the server version of CLR uses per processor GC heaps:
0:000> .loadby sos mscorsvr
0:000> !EEHeap -gc
generation 0 starts at 0×05c80154
generation 1 starts at 0×05c7720c
generation 2 starts at 0×102d0030
generation 0 starts at 0×179a0444
generation 1 starts at 0×1799b7a4
generation 2 starts at 0×142d0030
generation 0 starts at 0×0999ac88
generation 1 starts at 0×09990cc4
generation 2 starts at 0×182d0030
generation 0 starts at 0×242eccb0
generation 1 starts at 0×242d0030
generation 2 starts at 0×1c2d0030
…
…
…
GC Heap Size 0×109702ec(278332140)
or if this is CLR 1.x the old extension will tell you the same too:
0:000> !.\clr10\sos.eeheap -gc
Loaded Son of Strike data table version 5 from "C:\WINDOWS\Microsoft.NET\Framework\v1.1.4322\mscorsvr.dll"
Number of GC Heaps: 4
------------------------------
Heap 0 (0x000f9af0)
generation 0 starts at 0x05c80154
generation 1 starts at 0x05c7720c
generation 2 starts at 0x102d0030
...
...
...
Heap Size 0x515ed60(85,323,104)
------------------------------
Heap 1 (0x000fa070)
generation 0 starts at 0x179a0444
generation 1 starts at 0x1799b7a4
generation 2 starts at 0x142d0030
...
...
...
Heap Size 0x37c7bf0(58,489,840)
------------------------------
Heap 2 (0x000fab80)
generation 0 starts at 0x0999ac88
generation 1 starts at 0x09990cc4
generation 2 starts at 0x182d0030
...
...
...
Heap Size 0x485de34(75,882,036)
------------------------------
Heap 3 (0x000fb448)
generation 0 starts at 0x242eccb0
generation 1 starts at 0x242d0030
generation 2 starts at 0x1c2d0030
...
...
...
Heap Size 0x41ea570(69,117,296)
------------------------------
Reserved segments:
------------------------------
GC Heap Size 0x1136ecf4(288,812,276)
The more processors you have the more heaps are contributing to the overall VM size. Although the process occupies almost 400Mb if it doesn’t grow constantly over time beyond that value then it is normal.
- Dmitry Vostokov @ DumpAnalysis.org -
.NET programs also crash either from defects in .NET runtime (Common Language Runtime, CLR) or from non-handled runtime exceptions in managed code executed by .NET virtual machine. The latter exceptions are re-thrown from .NET runtime to be handled by operating system and intercepted by native debuggers. Therefore our next crash dump analysis pattern is called Managed Code Exception.
When you get a dump from .NET application it is the dump from a native process. !analyze -v output can usually tell you that exception is actually CLR exception and give you other hints to look at managed code stack (CLR stack):
FAULTING_IP:
kernel32!RaiseException+53
77e4bee7 5e pop esi
EXCEPTION_RECORD: ffffffff -- (.exr 0xffffffffffffffff)
ExceptionAddress: 77e4bee7 (kernel32!RaiseException+0x00000053)
ExceptionCode: e0434f4d (CLR exception)
ExceptionFlags: 00000001
NumberParameters: 1
Parameter[0]: 80131604
DEFAULT_BUCKET_ID: CLR_EXCEPTION
PROCESS_NAME: mmc.exe
ERROR_CODE: (NTSTATUS) 0xe0434f4d - <Unable to get error code text>
MANAGED_STACK: !dumpstack -EE
No export dumpstack found
STACK_TEXT:
05faf3d8 79f97065 e0434f4d 00000001 00000001 kernel32!RaiseException+0x53
WARNING: Stack unwind information not available. Following frames may be wrong.
05faf438 7a0945a4 023f31e0 00000000 00000000 mscorwks!DllCanUnloadNowInternal+0×37a9
05faf4fc 00f2f00a 02066be4 02085ee8 023d0df0 mscorwks!CorLaunchApplication+0×12005
05faf500 02066be4 02085ee8 023d0df0 023d0e2c 0xf2f00a
05faf504 02085ee8 023d0df0 023d0e2c 05e00dfa 0×2066be4
05faf508 023d0df0 023d0e2c 05e00dfa 023d0e10 0×2085ee8
05faf50c 023d0e2c 05e00dfa 023d0e10 05351d30 0×23d0df0
05faf510 05e00dfa 023d0e10 05351d30 023d0e10 0×23d0e2c
FOLLOWUP_IP:
mscorwks!DllCanUnloadNowInternal+37a9
79f97065 c745fcfeffffff mov dword ptr [ebp-4],0FFFFFFFEh
SYMBOL_NAME: mscorwks!DllCanUnloadNowInternal+37a9
MODULE_NAME: mscorwks
IMAGE_NAME: mscorwks.dll
PRIMARY_PROBLEM_CLASS: CLR_EXCEPTION
BUGCHECK_STR: APPLICATION_FAULT_CLR_EXCEPTION
Sometimes you can see mscorwks.dll on raw stack or see it loaded and find it on other thread stacks than the current one.
When you get such hints you might want to get managed code stack as well. First you need to load the appropriate WinDbg SOS extension (Son of Strike) corresponding to .NET runtime version. This can be done by the following command:
0:015> .loadby sos mscorwks
You can check which SOS extension version was loaded this by using .chain command:
0:015> .chain
Extension DLL search Path:
...
...
...
Extension DLL chain:
C:\WINDOWS\Microsoft.NET\Framework\v2.0.50727\sos: image 2.0.50727.42, API 1.0.0, built Fri Sep 23 08:27:26 2005
[path: C:\WINDOWS\Microsoft.NET\Framework\v2.0.50727\sos.dll]
dbghelp: image 6.6.0007.5, API 6.0.6, built Sat Jul 08 21:11:32 2006
[path: C:\Program Files\Debugging Tools for Windows\dbghelp.dll]
ext: image 6.6.0007.5, API 1.0.0, built Sat Jul 08 21:10:52 2006
[path: C:\Program Files\Debugging Tools for Windows\winext\ext.dll]
exts: image 6.6.0007.5, API 1.0.0, built Sat Jul 08 21:10:48 2006
[path: C:\Program Files\Debugging Tools for Windows\WINXP\exts.dll]
uext: image 6.6.0007.5, API 1.0.0, built Sat Jul 08 21:11:02 2006
[path: C:\Program Files\Debugging Tools for Windows\winext\uext.dll]
ntsdexts: image 6.0.5457.0, API 1.0.0, built Sat Jul 08 21:29:38 2006
[path: C:\Program Files\Debugging Tools for Windows\WINXP\ntsdexts.dll]
Then you can use !dumpstack to dump the current stack or !EEStack command to dump all thread stacks. The native stack trace would be mixed with managed stack trace:
0:015> !dumpstack
OS Thread Id: 0x16e8 (15)
Current frame: kernel32!RaiseException+0x53
ChildEBP RetAddr Caller,Callee
05faf390 77e4bee7 kernel32!RaiseException+0x53, calling ntdll!RtlRaiseException
05faf3a8 79e814da mscorwks!Binder::RawGetClass+0x23, calling mscorwks!Module::LookupTypeDef
05faf3bc 79e87ff4 mscorwks!Binder::IsClass+0x21, calling mscorwks!Binder::RawGetClass
05faf3c8 79f958b8 mscorwks!Binder::IsException+0x13, calling mscorwks!Binder::IsClass
05faf3d8 79f97065 mscorwks!RaiseTheExceptionInternalOnly+0x226, calling kernel32!RaiseException
05faf438 7a0945a4 mscorwks!JIT_Throw+0xd0, calling mscorwks!RaiseTheExceptionInternalOnly
05faf4ac 7a0944ea mscorwks!JIT_Throw+0x1e, calling mscorwks!LazyMachStateCaptureState
05faf4c8 793d424e (MethodDesc 0x7924ad68 +0x2e System.Threading.WaitHandle.WaitOne(Int64, Boolean)), calling mscorwks!WaitHandleNative::CorWaitOneNative
05faf4fc 00f2f00a (MethodDesc 0x4f97500 +0x9a Ironring.Management.MMC.SnapinBase+MmcWindow.Invoke(System.Delegate, System.Object[])), calling mscorwks!JIT_Throw
05faf510 05e00dfa (MethodDesc 0×4f98fd8 +0xca MyNamespace.MyClass.MyMethod(Boolean)), calling 05fc7124
05faf55c 00f62fbc (MethodDesc 0×4f95f90 +0×16f4 MyNamespace.MyClass.MyMethod.Initialise(System.Object))
05faf740 793d912f (MethodDesc 0×7925fc70 +0×2f System.Threading._ThreadPoolWaitCallback.WaitCallback_Context(System.Object))
05faf748 793683dd (MethodDesc 0×7913f3d0 +0×81 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object))
05faf75c 793d9218 (MethodDesc 0×7925fc80 +0×6c System.Threading._ThreadPoolWaitCallback.PerformWaitCallback(System.Object)), calling (MethodDesc 0×7913f3d0 +0 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object))
05faf774 79e88f63 mscorwks!CallDescrWorker+0×33
05faf784 79e88ee4 mscorwks!CallDescrWorkerWithHandler+0xa3, calling mscorwks!CallDescrWorker
05faf804 79f20212 mscorwks!DispatchCallBody+0×1e, calling mscorwks!CallDescrWorkerWithHandler
05faf824 79f201bc mscorwks!DispatchCallDebuggerWrapper+0×3d, calling mscorwks!DispatchCallBody
05faf888 79f2024b mscorwks!DispatchCallNoEH+0×51, calling mscorwks!DispatchCallDebuggerWrapper
05faf8bc 7a07bdf0 mscorwks!Holder
05faf90c 77e61d1e kernel32!WaitForSingleObjectEx+0xac, calling ntdll!ZwWaitForSingleObject
05faf91c 79ecb4a4 mscorwks!Thread::UserResumeThread+0xfb
05faf92c 79ecb442 mscorwks!Thread::DoADCallBack+0×355, calling mscorwks!Thread::UserResumeThread+0xae
05faf950 79e74afe mscorwks!Thread::EnterRuntimeNoThrow+0×9b, calling mscorwks!_EH_epilog3
05faf988 79e77fe8 mscorwks!PEImage::LoadImage+0×1e1, calling mscorwks!_SEH_epilog4
05faf9c0 79ecb364 mscorwks!Thread::DoADCallBack+0×541, calling mscorwks!Thread::DoADCallBack+0×2a5
05faf9fc 7a0e1b7e mscorwks!Thread::DoADCallBack+0×575, calling mscorwks!Thread::DoADCallBack+0×4d4
05fafa24 7a0e1bab mscorwks!ManagedThreadBase::ThreadPool+0×13, calling mscorwks!Thread::DoADCallBack+0×550
05fafa38 7a07cae8 mscorwks!QueueUserWorkItemCallback+0×9d, calling mscorwks!ManagedThreadBase::ThreadPool
05fafa54 7a07ca48 mscorwks!QueueUserWorkItemCallback, calling mscorwks!UnwindAndContinueRethrowHelperAfterCatch
05fafa90 7a110f08 mscorwks!ThreadpoolMgr::ExecuteWorkRequest+0×40
05fafaa8 7a112328 mscorwks!ThreadpoolMgr::WorkerThreadStart+0×1f2, calling mscorwks!ThreadpoolMgr::ExecuteWorkRequest
05fafad0 79e7839d mscorwks!EEHeapFreeInProcessHeap+0×21, calling mscorwks!EEHeapFree
05fafae0 79e782dc mscorwks!operator delete[]+0×30, calling mscorwks!EEHeapFreeInProcessHeap
05fafb14 79ecb00b mscorwks!Thread::intermediateThreadProc+0×49
05fafb48 77e65512 kernel32!FlsSetValue+0xc7, calling kernel32!_SEH_epilog
05fafb6c 75da14d0 sxs!_calloc_crt+0×19, calling sxs!calloc
05fafb80 77e65512 kernel32!FlsSetValue+0xc7, calling kernel32!_SEH_epilog
05fafb88 75da1401 sxs!_CRT_INIT+0×17e, calling sxs!_initptd
05fafb8c 75da1408 sxs!_CRT_INIT+0×185, calling kernel32!GetCurrentThreadId
05fafb9c 30403805 MMCFormsShim!DllMain+0×15, calling MMCFormsShim!PrxDllMain
05fafbb0 30418b69 MMCFormsShim!__DllMainCRTStartup+0×7a, calling MMCFormsShim!DllMain
05fafbdc 75de0e4c sxs!_SxsDllMain+0×87, calling sxs!DllStartup_CrtInit
05fafbf0 30418bf9 MMCFormsShim!__DllMainCRTStartup+0×10a, calling MMCFormsShim!__SEH_epilog4
05fafbf4 30418c22 MMCFormsShim!_DllMainCRTStartup+0×1d, calling MMCFormsShim!__DllMainCRTStartup
05fafbfc 7c81a352 ntdll!LdrpCallInitRoutine+0×14
05fafc24 7c82ee8b ntdll!LdrpInitializeThread+0×1a5, calling ntdll!RtlLeaveCriticalSection
05fafc2c 7c82edec ntdll!LdrpInitializeThread+0×18f, calling ntdll!_SEH_epilog
05fafc7c 7c82ed71 ntdll!LdrpInitializeThread+0xd8, calling ntdll!RtlActivateActivationContextUnsafeFast
05fafc80 7c82ed35 ntdll!LdrpInitializeThread+0×12c, calling ntdll!RtlDeactivateActivationContextUnsafeFast
05fafcb4 7c82edec ntdll!LdrpInitializeThread+0×18f, calling ntdll!_SEH_epilog
05fafcb8 7c827c3b ntdll!NtTestAlert+0xc
05fafcbc 7c82ecb1 ntdll!_LdrpInitialize+0×1de, calling ntdll!_SEH_epilog
05fafd10 7c82ecb1 ntdll!_LdrpInitialize+0×1de, calling ntdll!_SEH_epilog
05fafd14 7c826d9b ntdll!NtContinue+0xc
05fafd18 7c8284da ntdll!KiUserApcDispatcher+0×3a, calling ntdll!NtContinue
05faffa4 79ecaff9 mscorwks!Thread::intermediateThreadProc+0×37, calling mscorwks!_alloca_probe_16
05faffb8 77e64829 kernel32!BaseThreadStart+0×34
.NET language symbolic names are usually reconstructed from .NET assembly metadata.
You can examine a CLR exception and get managed stack trace by using !PrintException and !CLRStack commands, for example:
0:014> !PrintException
Exception object: 02320314
Exception type: System.Reflection.TargetInvocationException
Message: Exception has been thrown by the target of an invocation.
InnerException: System.Runtime.InteropServices.COMException, use !PrintException 023201a8 to see more
StackTrace (generated):
SP IP Function
075AF4FC 016BFD9A Ironring.Management.MMC.SnapinBase+MmcWindow.Invoke(System.Delegate, System.Object[])
...
...
...
075AF740 793D87AF System.Threading._ThreadPoolWaitCallback.WaitCallback_Context(System.Object)
075AF748 793608FD System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
075AF760 793D8898 System.Threading._ThreadPoolWaitCallback.PerformWaitCallback(System.Object)
StackTraceString: <none>
HResult: 80131604
0:014> !PrintException 023201a8
Exception object: 023201a8
Exception type: System.Runtime.InteropServices.COMException
Message: Error HRESULT E_FAIL has been returned from a call to a COM component.
InnerException: <none>
StackTrace (generated):
SP IP Function
00000000 00000001 Ironring.Management.MMC.IMMCFormsShim.HostUserControl3(System.Object, System.Object, System.String, System.String, Int32, Int32)
0007F724 073875B9 Ironring.Management.MMC.FormNode.SetShimControl(System.Object)
0007F738 053D9DDE Ironring.Management.MMC.FormNode.set_ControlType(System.Type)
...
...
...
StackTraceString: <none>
HResult: 80004005
0:014> !CLRStack
OS Thread Id: 0x11ec (14)
ESP EIP
075af4fc 016bfd9a Ironring.Management.MMC.SnapinBase+MmcWindow.Invoke(System.Delegate, System.Object[])
...
...
...
075af740 793d87af System.Threading._ThreadPoolWaitCallback.WaitCallback_Context(System.Object)
075af748 793608fd System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
075af760 793d8898 System.Threading._ThreadPoolWaitCallback.PerformWaitCallback(System.Object)
075af8f0 79e7be1b [GCFrame: 075af8f0]
!help command gives the list of other available SOS extension commands:
0:014> !help
Object Inspection
DumpObj (do)
DumpArray (da)
DumpStackObjects (dso)
DumpHeap
DumpVC
GCRoot
ObjSize
FinalizeQueue
PrintException (pe)
TraverseHeap
Examining code and stacks
Threads
CLRStack
IP2MD
U
DumpStack
EEStack
GCInfo
EHInfo
COMState
BPMD
Examining CLR data structures
DumpDomain
EEHeap
Name2EE
SyncBlk
DumpMT
DumpClass
DumpMD
Token2EE
EEVersion
DumpModule
ThreadPool
DumpAssembly
DumpMethodSig
DumpRuntimeTypes
DumpSig
RCWCleanupList
DumpIL
Diagnostic Utilities
VerifyHeap
DumpLog
FindAppDomain
SaveModule
GCHandles
GCHandleLeaks
VMMap
VMStat
ProcInfo
StopOnException (soe)
MinidumpMode
Other
FAQ
If you are new to .NET and interested in .NET debugging I would recommend 3 books:
Essential .NET, Volume I: The Common Language Runtime
Debugging Microsoft .NET 2.0 Applications
Advanced .NET Debugging
Expert .NET 2.0 IL Assembler
- Dmitry Vostokov @ DumpAnalysis.org -
Sometimes the root cause of a problem is not obvious from a memory dump. Here is the first version of crash dump analysis checklist to help experienced engineers not to miss any important information. The check list doesn’t prescribe any specific steps, just lists all possible points to double check when looking at a memory dump. Of course, it is not complete at the moment and any suggestions are welcome.
General:
Application or service:
System hang:
BSOD:
.NET application or service:
- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -
