Software Diagnostics Library

A complete memory dump was generated from a totally unresponsive frozen system. Looking at its virtual memory stats we see the shortage of nonpaged pool (insufficient kernel pool memory pattern):

0: kd> !vm

*** Virtual Memory Usage ***
 Physical Memory:     1047977 (   4191908 Kb)
 Page File: \??\C:\pagefile.sys
   Current:   4195328 Kb  Free Space:   4167696 Kb
   Minimum:   4195328 Kb  Maximum:      4195328 Kb
 Page File: \??\E:\pagefile.sys
   Current:   8372224 Kb  Free Space:   8348916 Kb
   Minimum:   8372224 Kb  Maximum:      8388608 Kb
 Available Pages:      855939 (   3423756 Kb)
 ResAvail Pages:       958559 (   3834236 Kb)
 Locked IO Pages:         100 (       400 Kb)
 Free System PTEs:     200627 (    802508 Kb)
 Free NP PTEs:              0 (         0 Kb)
 Free Special NP:      120925 (    483700 Kb)
 Modified Pages:           52 (       208 Kb)
 Modified PF Pages:        52 (       208 Kb)
 NonPagedPool Usage:    65199 (    260796 Kb)
 NonPagedPool Max:      65536 (    262144 Kb)
 ********** Excessive NonPaged Pool Usage *****
 PagedPool 0 Usage:      7731 (     30924 Kb)
 PagedPool 1 Usage:      6334 (     25336 Kb)
 PagedPool 2 Usage:      6316 (     25264 Kb)
 PagedPool 3 Usage:      6333 (     25332 Kb)
 PagedPool 4 Usage:      6318 (     25272 Kb)
 PagedPool Usage:       33032 (    132128 Kb)
 PagedPool Maximum:     66560 (    266240 Kb)

 ********** 7041316 pool allocations have failed **********

 Session Commit:         2860 (     11440 Kb)
 Shared Commit:          3904 (     15616 Kb)
 Special Pool:            255 (      1020 Kb)
 Shared Process:         9336 (     37344 Kb)
 PagedPool Commit:      33032 (    132128 Kb)
 Driver Commit:          2147 (      8588 Kb)
 Committed pages:      174724 (    698896 Kb)
 Commit limit:        4148057 (  16592228 Kb)

Dumping sorted pool consumers we see the most used were DRV* pool tags:

0: kd> !poolused 3
   Sorting by  NonPaged Pool Consumed

  Pool Used:
            NonPaged                    
 Tag    Allocs    Frees     Diff     Used 
 DRV2 21683882 21280457   403425 80685000 UNKNOWN pooltag ‘DRV2′, please update pooltag.txt
 DRV4 46621052 46217627   403425 54156728 UNKNOWN pooltag ‘DRV4′, please update pooltag.txt
 DRV5 37848660 37065132   783528 31341120 UNKNOWN pooltag ‘DRV5′, please update pooltag.txt
 MmCm    15754    14607     1147 24917536 Calls made to MmAllocateContiguousMemory , Binary: nt!mm
 DRV3 16189418 15785993   403425 19364400 UNKNOWN pooltag ‘DRV3′, please update pooltag.txt
[…]

We also check CPU consumption and see two spiking threads:

0: kd> !running

System Processors f (affinity mask)
  Idle Processors 9

Prcbs  Current   Next   
  1    f7727120  87c5ca48            …………….
  2    f772f120  881ccae0            …………….

We see the first thread spent much more kernel time and stack trace involved DriverA module:

0: kd> !thread 87c5ca48 1f
THREAD 87c5ca48  Cid 0ba0.0bc8  Teb: 7ffd7000 Win32Thread: 00000000 RUNNING on processor 1
Not impersonating
DeviceMap                 e10028f0
Owning Process            87c3a978       Image:         ApplicationB.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      4516745        Ticks: 2 (0:00:00:00.031)
Context Switch Count      2234544            
UserTime                  00:00:58.500
KernelTime                00:55:09.218
Win32 Start Address ApplicationB (0×402016bd)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init b8771000 Current b87708b4 Base b8771000 Limit b876e000 Call 0
Priority 13 BasePriority 8 PriorityDecrement 1
ChildEBP RetAddr 
b8770bd0 80892b6f nt!ExFreePoolWithTag+0xb7
b8770be0 80933bcd nt!ExFreePool+0xf
b8770c0c 808bb471 nt!ObOpenObjectByName+0×163
b8770cf8 b951f08e nt!NtOpenKey+0×1ad
WARNING: Stack unwind information not available. Following frames may be wrong.
b8770d50 808897cc DriverA+0×1608e
b8770d50 7c82860c nt!KiFastCallEntry+0xfc (TrapFrame @ b8770d64)
00c0f0b4 7c827369 ntdll!KiFastSystemCallRet
00c0f0b8 7d206cb1 ntdll!ZwOpenKey+0xc
00c0f118 7d1fe187 ADVAPI32!LocalBaseRegOpenKey+0xd0
00c0f14c 40202284 ADVAPI32!RegOpenKeyExA+0×11c
[…]
00c0ffb8 77e6482f ApplicationB+0×1891
00c0ffec 00000000 kernel32!BaseThreadStart+0×34

0: kd> !thread 881ccae0 1f
THREAD 881ccae0  Cid 05b8.05c4  Teb: 7ffde000 Win32Thread: 00000000 RUNNING on processor 2
Not impersonating
DeviceMap                 e10028f0
Owning Process            881cf020       Image:         ApplicationC.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      4516747        Ticks: 0
Context Switch Count      115916            
UserTime                  00:00:03.468
KernelTime                00:00:53.156
Win32 Start Address ADVAPI32!ScSvcctrlThreadA (0×7d1f5e70)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init b900d000 Current b900cc50 Base b900d000 Limit b900a000 Call 0
Priority 13 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr 
005bf9c4 7d1eef7e ADVAPI32!LocalBaseRegEnumKey+0×2
005bfc24 010091c9 ADVAPI32!RegEnumKeyExA+0×12f
WARNING: Stack unwind information not available. Following frames may be wrong.
005bfc74 0100a28c ApplicationC+0×91c9
[…]
005bffb8 77e6482f ApplicationC+0×8b13
005bffec 00000000 kernel32!BaseThreadStart+0×34

We check the pool entry it was freeing:

0: kd> .thread /r /p 87c5ca48
Implicit thread is now 87c5ca48
Implicit process is now 87c3a978
Loading User Symbols

0: kd> kv L1
ChildEBP RetAddr  Args to Child             
b8770bd0 80892b6f 8ab6b3c8 00000000 b8770c0c nt!ExFreePoolWithTag+0xb7

0: kd> !pool 8ab6b3c8
Pool page 8ab6b3c8 region is Nonpaged pool
 8ab6b000 size:   c8 previous size:    0  (Allocated)  DRV2
 8ab6b0c8 size:   70 previous size:   c8  (Allocated)  MmCa
 8ab6b138 size:   10 previous size:   70  (Free)       DRV2
 8ab6b148 size:   30 previous size:   10  (Allocated)  DRV3
 8ab6b178 size:   30 previous size:   30  (Allocated)  DRV3
 8ab6b1a8 size:   28 previous size:   30  (Allocated)  NtFs
 8ab6b1d0 size:   30 previous size:   28  (Allocated)  DRV3
 8ab6b200 size:   18 previous size:   30  (Free)       IrpC
 8ab6b218 size:   a8 previous size:   18  (Allocated)  File (Protected)
 8ab6b2c0 size:  100 previous size:   a8  (Allocated)  MmCi
*8ab6b3c0 size:   38 previous size:  100  (Allocated) *ObCi
  Pooltag ObCi : captured information for ObCreateObject, Binary : nt!ob
 8ab6b3f8 size:   48 previous size:   38  (Allocated)  DRV2
 8ab6b440 size:    8 previous size:   48  (Free)       DRV4
 8ab6b448 size:   28 previous size:    8  (Allocated)  NtFs
 8ab6b470 size:    8 previous size:   28  (Free)       Mdl
 8ab6b478 size:   60 previous size:    8  (Allocated)  DRV4
 8ab6b4d8 size:   c8 previous size:   60  (Allocated)  DRV2
 8ab6b5a0 size:   a8 previous size:   c8  (Allocated)  File (Protected)
 8ab6b648 size:   c8 previous size:   a8  (Allocated)  DRV2
 8ab6b710 size:   c8 previous size:   c8  (Allocated)  DRV2
 8ab6b7d8 size:   10 previous size:   c8  (Free)       File
 8ab6b7e8 size:   98 previous size:   10  (Allocated)  DRV4
 8ab6b880 size:   30 previous size:   98  (Allocated)  DRV3
 8ab6b8b0 size:   28 previous size:   30  (Allocated)  NtFs
 8ab6b8d8 size:   28 previous size:   28  (Allocated)  DRV5
 8ab6b900 size:   30 previous size:   28  (Allocated)  DRV3
 8ab6b930 size:   a8 previous size:   30  (Allocated)  File (Protected)
 8ab6b9d8 size:  100 previous size:   a8  (Allocated)  MmCi
 8ab6bad8 size:   10 previous size:  100  (Free)       ObCi
[…]

In the output above we see all clustering of DRV* pool tags and check their contents:

0: kd> dps 8ab6b000
8ab6b000  0a190000
[…]
8ab6b06c  b95349a0 DriverA+0×2b9a0
8ab6b070  87cb85c8
8ab6b074  002d0000
8ab6b078  8ab6b078
8ab6b07c  8ab6b078

0: kd> dps 8ab6b8d8
8ab6b8d8  0a050005
[…]
8ab6b8f8  b95349a0 DriverA+0×2b9a0
8ab6b8fc  00000074
[…]

It looks like all DRV* pool entries have symbolic references in the range of DriverA (data contents locality):

0: kd> lm m DriverA
start    end        module name
b9509000 b9537f00   DriverA       (no symbols)

So the conclusion was to refer to DriverA vendor for any updates.

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