Crash Dump Analysis Patterns (Part 13b)
Sometimes handle leaks also result in insufficient memory especially if handles point to structures allocated by OS. Here is the typical example of the handle leak resulted in freezing several servers. The complete memory dump shows exhausted non-paged pool:
0: kd> !vm
*** Virtual Memory Usage ***
Physical Memory: 1048352 ( 4193408 Kb)
Page File: \??\C:\pagefile.sys
Current: 4190208 Kb Free Space: 3749732 Kb
Minimum: 4190208 Kb Maximum: 4190208 Kb
Available Pages: 697734 ( 2790936 Kb)
ResAvail Pages: 958085 ( 3832340 Kb)
Locked IO Pages: 95 ( 380 Kb)
Free System PTEs: 199971 ( 799884 Kb)
Free NP PTEs: 105 ( 420 Kb)
Free Special NP: 0 ( 0 Kb)
Modified Pages: 195 ( 780 Kb)
Modified PF Pages: 195 ( 780 Kb)
NonPagedPool Usage: 65244 ( 260976 Kb)
NonPagedPool Max: 65503 ( 262012 Kb)
********** Excessive NonPaged Pool Usage *****
PagedPool 0 Usage: 6576 ( 26304 Kb)
PagedPool 1 Usage: 629 ( 2516 Kb)
PagedPool 2 Usage: 624 ( 2496 Kb)
PagedPool 3 Usage: 608 ( 2432 Kb)
PagedPool 4 Usage: 625 ( 2500 Kb)
PagedPool Usage: 9062 ( 36248 Kb)
PagedPool Maximum: 66560 ( 266240 Kb)
********** 184 pool allocations have failed **********
Shared Commit: 7711 ( 30844 Kb)
Special Pool: 0 ( 0 Kb)
Shared Process: 10625 ( 42500 Kb)
PagedPool Commit: 9102 ( 36408 Kb)
Driver Commit: 1759 ( 7036 Kb)
Committed pages: 425816 ( 1703264 Kb)
Commit limit: 2052560 ( 8210240 Kb)
Looking at non-paged pool consumption reveals excessive number of thread objects:
0: kd> !poolused 3
Sorting by NonPaged Pool Consumed
Pool Used:
NonPaged
Tag Allocs Frees Diff Used
Thre 772672 463590 309082 192867168 Thread objects , Binary: nt!ps
MmCm 42 9 33 12153104 Calls made to MmAllocateContiguousMemory , Binary: nt!mm
…
…
…
The next logical step would be to list processes and find their handle usage. Indeed there is such a process:
0: kd> !process 0 0
…
…
…
PROCESS 88b75020 SessionId: 7 Cid: 172e4 Peb: 7ffdf000 ParentCid: 17238
DirBase: c7fb6bc0 ObjectTable: e17f50a0 HandleCount: 143428.
Image: iexplore.exe
…
…
…
Making the process current and listing its handles shows contiguously allocated handles to thread objects:
0: kd> .process 88b75020
Implicit process is now 88b75020
0: kd> .reload /user
0: kd> !handle
…
…
…
0d94: Object: 88a6b020 GrantedAccess: 001f03ff Entry: e35e1b28
Object: 88a6b020 Type: (8b780c68) Thread
ObjectHeader: 88a6b008
HandleCount: 1 PointerCount: 1
0d98: Object: 88a97320 GrantedAccess: 001f03ff Entry: e35e1b30
Object: 88a97320 Type: (8b780c68) Thread
ObjectHeader: 88a97308
HandleCount: 1 PointerCount: 1
0d9c: Object: 88b2b020 GrantedAccess: 001f03ff Entry: e35e1b38
Object: 88b2b020 Type: (8b780c68) Thread
ObjectHeader: 88b2b008
HandleCount: 1 PointerCount: 1
0da0: Object: 88b2a730 GrantedAccess: 001f03ff Entry: e35e1b40
Object: 88b2a730 Type: (8b780c68) Thread
ObjectHeader: 88b2a718
HandleCount: 1 PointerCount: 1
0da4: Object: 88b929a0 GrantedAccess: 001f03ff Entry: e35e1b48
Object: 88b929a0 Type: (8b780c68) Thread
ObjectHeader: 88b92988
HandleCount: 1 PointerCount: 1
0da8: Object: 88a57db0 GrantedAccess: 001f03ff Entry: e35e1b50
Object: 88a57db0 Type: (8b780c68) Thread
ObjectHeader: 88a57d98
HandleCount: 1 PointerCount: 1
0dac: Object: 88b92db0 GrantedAccess: 001f03ff Entry: e35e1b58
Object: 88b92db0 Type: (8b780c68) Thread
ObjectHeader: 88b92d98
HandleCount: 1 PointerCount: 1
0db0: Object: 88b4a730 GrantedAccess: 001f03ff Entry: e35e1b60
Object: 88b4a730 Type: (8b780c68) Thread
ObjectHeader: 88b4a718
HandleCount: 1 PointerCount: 1
0db4: Object: 88a7e730 GrantedAccess: 001f03ff Entry: e35e1b68
Object: 88a7e730 Type: (8b780c68) Thread
ObjectHeader: 88a7e718
HandleCount: 1 PointerCount: 1
0db8: Object: 88a349a0 GrantedAccess: 001f03ff Entry: e35e1b70
Object: 88a349a0 Type: (8b780c68) Thread
ObjectHeader: 88a34988
HandleCount: 1 PointerCount: 1
0dbc: Object: 88a554c0 GrantedAccess: 001f03ff Entry: e35e1b78
Object: 88a554c0 Type: (8b780c68) Thread
ObjectHeader: 88a554a8
HandleCount: 1 PointerCount: 1
…
…
…
Examination of these threads shows their stack traces and start address:
0: kd> !thread 88b4a730
THREAD 88b4a730 Cid 0004.1885c Teb: 00000000 Win32Thread: 00000000 TERMINATED
Not impersonating
DeviceMap e1000930
Owning Process 8b7807a8 Image: System
Wait Start TickCount 975361 Ticks: 980987 (0:04:15:27.921)
Context Switch Count 1
UserTime 00:00:00.0000
KernelTime 00:00:00.0000
Start Address mydriver!StatusWaitThread (0xf5c5d128)
Stack Init 0 Current f3c4cc98 Base f3c4d000 Limit f3c4a000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr Args to Child
f3c4ccac 8083129e ffdff5f0 8697ba00 a674c913 hal!KfLowerIrql+0×62
f3c4ccc8 00000000 808ae498 8697ba00 00000000 nt!KiExitDispatcher+0×130
0: kd> !thread 88a554c0
THREAD 88a554c0 Cid 0004.1888c Teb: 00000000 Win32Thread: 00000000 TERMINATED
Not impersonating
DeviceMap e1000930
Owning Process 8b7807a8 Image: System
Wait Start TickCount 975380 Ticks: 980968 (0:04:15:27.625)
Context Switch Count 1
UserTime 00:00:00.0000
KernelTime 00:00:00.0000
Start Address mydriver!StatusWaitThread (0xf5c5d128)
Stack Init 0 Current f3c4cc98 Base f3c4d000 Limit f3c4a000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr Args to Child
f3c4ccac 8083129e ffdff5f0 8697ba00 a674c913 hal!KfLowerIrql+0×62
f3c4ccc8 00000000 808ae498 8697ba00 00000000 nt!KiExitDispatcher+0×130
We can see that they have been terminated and their start address belongs to mydriver.sys. Therefore we can say that mydriver code has to be examined to find the source of the handle leak.
- Dmitry Vostokov @ DumpAnalysis.org -
October 2nd, 2007 at 1:20 pm
Enabling Application Verifier using gflags.exe before running the leaking application and then using !htrace WinDbg command can show stack traces for handle usage. For example, quick test for notepad.exe:
0:001> !htrace 0×00000100
————————————–
Handle = 0×00000100 - CLOSE
Thread ID = 0×00002d7c, Process ID = 0×0000237c
00×7c836b0c: ntdll!LdrGetDllHandleEx+0×000002b8
0×7c836cf9: ntdll!LdrGetDllHandle+0×00000018
0×77e645c2: kernel32!GetModuleHandleForUnicodeString+0×00000049
0×77e66516: kernel32!BasepGetModuleHandleExW+0×0000017f
0×77e663f4: kernel32!GetModuleHandleW+0×00000029
0×773a2eb3: USER32!_InitializeImmEntryTable+0×00000047
0×773c5369: USER32!_UserClientDllInitialize+0×00000163
0×5a61897f: verifier!AVrfpStandardDllEntryPointRoutine+0×0000014f
0×7c82257a: ntdll!LdrpCallInitRoutine+0×00000014
0×7c8358fb: ntdll!LdrpRunInitializeRoutines+0×00000367
————————————–
Handle = 0×00000100 - OPEN
Thread ID = 0×00002d7c, Process ID = 0×0000237c
00×7c836b0c: ntdll!LdrGetDllHandleEx+0×000002b8
0×7c836cf9: ntdll!LdrGetDllHandle+0×00000018
0×77e645c2: kernel32!GetModuleHandleForUnicodeString+0×00000049
0×77e66516: kernel32!BasepGetModuleHandleExW+0×0000017f
0×77e663f4: kernel32!GetModuleHandleW+0×00000029
0×773a2eb3: USER32!_InitializeImmEntryTable+0×00000047
0×773c5369: USER32!_UserClientDllInitialize+0×00000163
0×5a61897f: verifier!AVrfpStandardDllEntryPointRoutine+0×0000014f
————————————–
Parsed 0×2EC stack traces.
Dumped 0×2 stack traces.
Another example from the complete memory dump where Application Verifier was enabled for MyApp.exe:
03: kd> .process /p /r 0×8896e670
Implicit process is now 8896e670
Loading User Symbols
03: kd> dt _PEB 7ffdd000
ntdll!_PEB
+0×000 InheritedAddressSpace : 0 ”
+0×001 ReadImageFileExecOptions : 0×1 ”
+0×002 BeingDebugged : 0 ”
+0×003 BitField : 0 ”
+0×003 ImageUsesLargePages : 0y0
+0×003 SpareBits : 0y0000000 (0)
+0×004 Mutant : 0xffffffff
+0×008 ImageBaseAddress : 0×00400000
+0×00c Ldr : 0×7c889e00 _PEB_LDR_DATA
+0×010 ProcessParameters : 0×00020000 _RTL_USER_PROCESS_PARAMETERS
+0×014 SubSystemData : (null)
+0×018 ProcessHeap : 0×00140000
+0×01c FastPebLock : 0×7c889d40 _RTL_CRITICAL_SECTION
+0×020 AtlThunkSListPtr : (null)
+0×024 SparePtr2 : (null)
+0×028 EnvironmentUpdateCount : 1
+0×02c KernelCallbackTable : 0×77382970
+0×030 SystemReserved : [1] 0
+0×034 SpareUlong : 0
+0×038 FreeList : (null)
+0×03c TlsExpansionCounter : 0
+0×040 TlsBitmap : 0×7c888910
+0×044 TlsBitmapBits : [2] 0xffff
+0×04c ReadOnlySharedMemoryBase : 0×7f6f0000
+0×050 ReadOnlySharedMemoryHeap : 0×7f6f0000
+0×054 ReadOnlyStaticServerData : 0×7f6f0688 -> (null)
+0×058 AnsiCodePageData : 0×7ffb0000
+0×05c OemCodePageData : 0×7ffc1000
+0×060 UnicodeCaseTableData : 0×7ffd2000
+0×064 NumberOfProcessors : 4
>>>>> +0×068 NtGlobalFlag : 0×100
+0×070 CriticalSectionTimeout : _LARGE_INTEGER 0xffffe86d`079b8000
+0×078 HeapSegmentReserve : 0×100000
+0×07c HeapSegmentCommit : 0×2000
+0×080 HeapDeCommitTotalFreeThreshold : 0×10000
+0×084 HeapDeCommitFreeBlockThreshold : 0×1000
+0×088 NumberOfHeaps : 0xb
+0×08c MaximumNumberOfHeaps : 0×10
+0×090 ProcessHeaps : 0×7c888340 -> 0×00140000
+0×094 GdiSharedHandleTable : 0×015f0000
+0×098 ProcessStarterHelper : (null)
+0×09c GdiDCAttributeList : 0×14
+0×0a0 LoaderLock : 0×7c889d94 _RTL_CRITICAL_SECTION
+0×0a4 OSMajorVersion : 5
+0×0a8 OSMinorVersion : 2
+0×0ac OSBuildNumber : 0xece
+0×0ae OSCSDVersion : 0×100
+0×0b0 OSPlatformId : 2
+0×0b4 ImageSubsystem : 2
+0×0b8 ImageSubsystemMajorVersion : 4
+0×0bc ImageSubsystemMinorVersion : 0
+0×0c0 ImageProcessAffinityMask : 0
+0×0c4 GdiHandleBuffer : [34] 0
+0×14c PostProcessInitRoutine : (null)
+0×150 TlsExpansionBitmap : 0×7c888908
+0×154 TlsExpansionBitmapBits : [32] 1
+0×1d4 SessionId : 1
+0×1d8 AppCompatFlags : _ULARGE_INTEGER 0×0
+0×1e0 AppCompatFlagsUser : _ULARGE_INTEGER 0×0
+0×1e8 pShimData : (null)
+0×1ec AppCompatInfo : (null)
+0×1f0 CSDVersion : _UNICODE_STRING “Service Pack 1″
+0×1f8 ActivationContextData : (null)
+0×1fc ProcessAssemblyStorageMap : (null)
+0×200 SystemDefaultActivationContextData : 0×00130000 _ACTIVATION_CONTEXT_DATA
+0×204 SystemAssemblyStorageMap : (null)
+0×208 MinimumStackCommit : 0
+0×20c FlsCallback : 0×001454a8 -> (null)
+0×210 FlsListHead : _LIST_ENTRY [ 0×141f60 - 0×169018 ]
+0×218 FlsBitmap : 0×7c888388
+0×21c FlsBitmapBits : [4] 7
+0×22c FlsHighIndex : 2
03: kd> !process 0 0
**** NT ACTIVE PROCESS DUMP ****
PROCESS 8896e670 SessionId: 1 Cid: 24b4 Peb: 7ffdd000 ParentCid: 1270
DirBase: 48e9f000 ObjectTable: e11109d0 HandleCount: 8717.
Image: MyApp.exe
03: kd> !handle
processor number 3, process 8896e670
PROCESS 8896e670 SessionId: 1 Cid: 24b4 Peb: 7ffdd000 ParentCid: 1270
DirBase: 48e9f000 ObjectTable: e11109d0 HandleCount: 8717.
Image: MyApp.exe
…
…
…
0Handle table at e50ed000 with 8717 Entries in use
0004: Object: 88f39978 GrantedAccess: 00000410 Entry: e102a008
Object: 88f39978 Type: (8a392ca0) Process
ObjectHeader: 88f39960 (old version)
HandleCount: 8459 PointerCount: 8507
00008: Object: 88f39978 GrantedAccess: 00000410 Entry: e102a010
Object: 88f39978 Type: (8a392ca0) Process
ObjectHeader: 88f39960 (old version)
HandleCount: 8459 PointerCount: 8507
0000c: Object: 88f39978 GrantedAccess: 00000410 Entry: e102a018
Object: 88f39978 Type: (8a392ca0) Process
ObjectHeader: 88f39960 (old version)
HandleCount: 8459 PointerCount: 8507
…
…
…
03: kd> !htrace 0 8896e670
Process 0×8896e670
ObjectTable 0xe11109d0
0————————————–
Handle 0×8878 - OPEN
Thread ID = 0×00000ca4, Process ID = 0×000024b4
00×809b94d8: nt!ExpUpdateDebugInfo+0×16D
0×8097232e: nt!ExCreateHandle+0×4A
0×8092b6ba: nt!ObpCreateHandle+0×3DE
0×80927674: nt!ObOpenObjectByPointer+0xA8
0×8093c2a5: nt!NtOpenProcess+0×22C
0×80834d3f: nt!KiFastCallEntry+0xFC
0×66861404: MyDLL!GetProcHandle+0×20
0×66862966: MyDLL!MainWndProc+0×1CC
0×7739c3b7: USER32!InternalCallWinProc+0×28
0×7739c484: USER32!UserCallWinProcCheckWow+0×151
0×7739ca68: USER32!DispatchClientMessage+0xD9
0×7739ce7a: USER32!__fnDWORD+0×24
0×7c82ec9e: ntdll!KiUserCallbackDispatcher+0×2E
0×66863244: MyDLL!Load+0×377
0×5a614cb0: verifier!AVrfpStandardThreadFunction+0×60
October 8th, 2007 at 4:50 pm
Example of handle leak in System process:
kd> !process 0 0
**** NT ACTIVE PROCESS DUMP ****
PROCESS 8d1615d8 SessionId: none Cid: 0004 Peb: 00000000 ParentCid: 0000
DirBase: bffba020 ObjectTable: e1002e08 HandleCount: 10879.
Image: System
3: kd> !handle 0 12
Kernel Handle table at e1765000 with 10879 Entries in use
1c20: Object: e4fca908 GrantedAccess: 00000004 Entry: e4b18840
Object: e4fca908 Type: (8d18a110) Directory
ObjectHeader: e4fca8f0 (old version)
1c24: Object: e5bf14c8 GrantedAccess: 00000004 Entry: e4b18848
Object: e5bf14c8 Type: (8d18a110) Directory
ObjectHeader: e5bf14b0 (old version)
1c28: Object: e496d490 GrantedAccess: 00000004 Entry: e4b18850
Object: e496d490 Type: (8d18a110) Directory
ObjectHeader: e496d478 (old version)
1c2c: Object: ea4a1370 GrantedAccess: 00000004 Entry: e4b18858
Object: ea4a1370 Type: (8d18a110) Directory
ObjectHeader: ea4a1358 (old version)
1c30: Object: e68558d0 GrantedAccess: 00000004 Entry: e4b18860
Object: e68558d0 Type: (8d18a110) Directory
ObjectHeader: e68558b8 (old version)
1c34: Object: e49f7d88 GrantedAccess: 00000004 Entry: e4b18868
Object: e49f7d88 Type: (8d18a110) Directory
ObjectHeader: e49f7d70 (old version)
1c38: Object: e3d8c6e8 GrantedAccess: 00000004 Entry: e4b18870
Object: e3d8c6e8 Type: (8d18a110) Directory
ObjectHeader: e3d8c6d0 (old version)
1c3c: Object: eb435bb8 GrantedAccess: 00000004 Entry: e4b18878
Object: eb435bb8 Type: (8d18a110) Directory
ObjectHeader: eb435ba0 (old version)
1c40: Object: ebd53f30 GrantedAccess: 00000004 Entry: e4b18880
Object: ebd53f30 Type: (8d18a110) Directory
ObjectHeader: ebd53f18 (old version)
1c44: Object: e7314698 GrantedAccess: 00000004 Entry: e4b18888
Object: e7314698 Type: (8d18a110) Directory
ObjectHeader: e7314680 (old version)
1c48: Object: eb32c378 GrantedAccess: 00000004 Entry: e4b18890
Object: eb32c378 Type: (8d18a110) Directory
ObjectHeader: eb32c360 (old version)
1c4c: Object: ece075c0 GrantedAccess: 00000004 Entry: e4b18898
Object: ece075c0 Type: (8d18a110) Directory
ObjectHeader: ece075a8 (old version)
3: kd> !object ebd53f30
Object: ebd53f30 Type: (8d18a110) Directory
ObjectHeader: ebd53f18 (old version)
HandleCount: 1 PointerCount: 2
Directory Object: e62c4ab8 Name: WindowStations
Hash Address Type Name
—- ——- —- —-
3: kd> !object ece075c0
Object: ece075c0 Type: (8d18a110) Directory
ObjectHeader: ece075a8 (old version)
HandleCount: 1 PointerCount: 2
Directory Object: ec331ae0 Name: WindowStations
Hash Address Type Name
—- ——- —- —-
3: kd> !object eb92af60
Object: eb92af60 Type: (8d18a110) Directory
ObjectHeader: eb92af48 (old version)
HandleCount: 1 PointerCount: 2
Directory Object: e67cfbc8 Name: WindowStations
February 28th, 2008 at 6:38 pm
[…] pattern can also be seen a specialization of a more general Handle Leak […]
September 11th, 2008 at 4:22 pm
[…] Insufficient Memory (handle leak) […]
September 18th, 2008 at 9:39 am
[…] Crash Dump Analysis Patterns (Part 13b) […]
February 13th, 2009 at 3:19 pm
[…] difference of this pattern and similar Handle Leak or Zombie Processes is the fact that leaks usually happen when a process forgets to close handles […]
June 10th, 2009 at 2:55 pm
[…] kernel dump and we cannot inspect user space of that process. We can only say that it was not a handle leak because the number of handles is low (380). We also inspect paged pool stats and find a 3rd-party […]
October 15th, 2009 at 11:02 pm
[…] We can confirm the absence of handle leaks: […]
November 30th, 2009 at 4:47 pm
[…] dump analysis is all about deviations and of them is Size Deviation (a super pattern), be it a handle table size, a heap size, a number of contended locks, time spent in kernel, and so on. Every system or […]
December 30th, 2009 at 11:29 am
[…] Insufficient Memory (handle leak) […]
April 13th, 2010 at 10:20 am
[…] we introduce an icon for Insufficient Memory (handle leak) […]
August 13th, 2010 at 7:13 pm
[…] Dumping processes we notice signs of possible handle leak: […]
May 29th, 2012 at 8:23 pm
Miscellaneous Checks in driver verifier to enable handle traces in system process http://msdn.microsoft.com/en-us/library/ff549253.aspx