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 -

13 Responses to “Crash Dump Analysis Patterns (Part 13b)”

  1. Dmitry Vostokov Says:

    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

  2. Dmitry Vostokov Says:

    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

  3. Crash Dump Analysis » Blog Archive » Crash Dump Analysis Patterns (Part 54) Says:

    […] pattern can also be seen a specialization of a more general Handle Leak […]

  4. Crash Dump Analysis » Blog Archive » First-order and second-order memory leaks Says:

    […] Insufficient Memory (handle leak) […]

  5. !analyze -v : Crash Dump Analysis Patterns (Part 13b) Says:

    […] Crash Dump Analysis Patterns (Part 13b) […]

  6. Crash Dump Analysis » Blog Archive » Crash Dump Analysis Patterns (Part 80) Says:

    […] 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 […]

  7. Crash Dump Analysis » Blog Archive » Invalid pointer, incorrect stack trace, multiple exceptions, insufficient memory and memory leak: pattern cooperation Says:

    […] 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 […]

  8. Crash Dump Analysis » Blog Archive » Looking for abnormal: case study Says:

    […] We can confirm the absence of handle leaks: […]

  9. Crash Dump Analysis » Blog Archive » Crash Dump Analysis Patterns (Part 94a) Says:

    […] 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 […]

  10. Crash Dump Analysis » Blog Archive » Insufficient Memory Patterns Says:

    […] Insufficient Memory (handle leak) […]

  11. Crash Dump Analysis » Blog Archive » Icons for Memory Dump Analysis Patterns (Part 23) Says:

    […] we introduce an icon for Insufficient Memory (handle leak) […]

  12. Crash Dump Analysis » Blog Archive » Insufficient memory, handle leak, wait chain, deadlock, inconsistent dump and overaged system: pattern cooperation Says:

    […] Dumping processes we notice signs of possible handle leak: […]

  13. Dmitry Vostokov Says:

    Miscellaneous Checks in driver verifier to enable handle traces in system process http://msdn.microsoft.com/en-us/library/ff549253.aspx

Leave a Reply