Crash Dump Analysis Patterns (Part 13c)
Although handle leaks may result in insufficient pool memory, many drivers allocate their own private memory and specify a 4-letter ASCII tag, for example, non-paged pool from my x64 Vista workstation:
lkd> !poolused 3
Sorting by NonPaged Pool Consumed
Pool Used:
NonPaged
Tag Allocs Frees Diff Used
EtwB 304 134 170 6550080 Etw Buffer , Binary: nt!etw
File 32630649 32618671 11978 3752928 File objects
Pool 16 11 5 3363472 Pool tables, etc.
Ntfr 204791 187152 17639 2258704 ERESOURCE , Binary: ntfs.sys
FMsl 199039 187685 11354 2179968 STREAM_LIST_CTRL structure , Binary: fltmgr.sys
MmCa 250092 240351 9741 2134368 Mm control areas for mapped files , Binary: nt!mm
ViMm 135503 134021 1482 1783824 Video memory manager , Binary: dxgkrnl.sys
Cont 53 12 41 1567664 Contiguous physical memory allocations for device drivers
Thre 72558 71527 1031 1234064 Thread objects , Binary: nt!ps
VoSm 872 851 21 1220544 Bitmap allocations , Binary: volsnap.sys
NtFs 8122505 8110933 11572 1190960 StrucSup.c , Binary: ntfs.sys
AmlH 1 0 1 1048576 ACPI AMLI Pooltags
SaSc 20281 14820 5461 1048512 UNKNOWN pooltag ‘SaSc’, please update pooltag.txt
RaRS 1000 0 1000 960000 UNKNOWN pooltag ‘RaRS’, please update pooltag.txt
…
…
…
If the pool tag is unknown the following Microsoft article KB298102 explains how to locate the corresponding driver. We can also use memory search in WinDbg to locate kernel space addresses and see what modules they correspond to.
WinDbg shows the number of failed pool allocations and also shows a message when pool usage is nearly its maximum. Below I put some examples with possible troubleshooting hints.
Session pool
3: kd> !vm
*** Virtual Memory Usage ***
Physical Memory: 1572637 ( 6290548 Kb)
Page File: \??\C:\pagefile.sys
Current: 3145728 Kb Free Space: 3001132 Kb
Minimum: 3145728 Kb Maximum: 3145728 Kb
Available Pages: 1317401 ( 5269604 Kb)
ResAvail Pages: 1478498 ( 5913992 Kb)
Locked IO Pages: 114 ( 456 Kb)
Free System PTEs: 194059 ( 776236 Kb)
Free NP PTEs: 32766 ( 131064 Kb)
Free Special NP: 0 ( 0 Kb)
Modified Pages: 443 ( 1772 Kb)
Modified PF Pages: 442 ( 1768 Kb)
NonPagedPool Usage: 13183 ( 52732 Kb)
NonPagedPool Max: 65215 ( 260860 Kb)
PagedPool 0 Usage: 11328 ( 45312 Kb)
PagedPool 1 Usage: 1473 ( 5892 Kb)
PagedPool 2 Usage: 1486 ( 5944 Kb)
PagedPool 3 Usage: 1458 ( 5832 Kb)
PagedPool 4 Usage: 1505 ( 6020 Kb)
PagedPool Usage: 17250 ( 69000 Kb)
PagedPool Maximum: 65536 ( 262144 Kb)
********** 3441 pool allocations have failed **********
Shared Commit: 8137 ( 32548 Kb)
Special Pool: 0 ( 0 Kb)
Shared Process: 8954 ( 35816 Kb)
PagedPool Commit: 17312 ( 69248 Kb)
Driver Commit: 2095 ( 8380 Kb)
Committed pages: 212476 ( 849904 Kb)
Commit limit: 2312654 ( 9250616 Kb)
Paged and non-paged pool usage is far from maximum therefore we check session pool:
3: kd> !vm 4
Terminal Server Memory Usage By Session:
Session Paged Pool Maximum is 32768K
Session View Space Maximum is 20480K
Session ID 0 @ f79a1000:
Paged Pool Usage: 9824K
Commit Usage: 10148K
Session ID 2 @ f7989000:
Paged Pool Usage: 1212K
Commit Usage: 2180K
Session ID 9 @ f79b5000:
Paged Pool Usage: 32552K
*** 7837 Pool Allocation Failures ***
Commit Usage: 33652K
Here Microsoft article KB840342 might help.
Paged pool
We might have a direct warning:
1: kd> !vm
*** Virtual Memory Usage ***
Physical Memory: 511881 ( 2047524 Kb)
Page File: \??\S:\pagefile.sys
Current: 2098176Kb Free Space: 1837740Kb
Minimum: 2098176Kb Maximum: 2098176Kb
Page File: \??\R:\pagefile.sys
Current: 1048576Kb Free Space: 792360Kb
Minimum: 1048576Kb Maximum: 1048576Kb
Available Pages: 201353 ( 805412 Kb)
ResAvail Pages: 426839 ( 1707356 Kb)
Modified Pages: 45405 ( 181620 Kb)
NonPagedPool Usage: 10042 ( 40168 Kb)
NonPagedPool Max: 68537 ( 274148 Kb)
PagedPool 0 Usage: 26820 ( 107280 Kb)
PagedPool 1 Usage: 1491 ( 5964 Kb)
PagedPool 2 Usage: 1521 ( 6084 Kb)
PagedPool 3 Usage: 1502 ( 6008 Kb)
PagedPool 4 Usage: 1516 ( 6064 Kb)
********** Excessive Paged Pool Usage *****
PagedPool Usage: 32850 ( 131400 Kb)
PagedPool Maximum: 40960 ( 163840 Kb)
Shared Commit: 14479 ( 57916 Kb)
Special Pool: 0 ( 0 Kb)
Free System PTEs: 135832 ( 543328 Kb)
Shared Process: 15186 ( 60744 Kb)
PagedPool Commit: 32850 ( 131400 Kb)
Driver Commit: 1322 ( 5288 Kb)
Committed pages: 426786 ( 1707144 Kb)
Commit limit: 1259456 ( 5037824 Kb)
or if there is no warning we can check the size manually and if paged pool usage is close to its maximum but for non-paged pool it is not then most likely failed allocations were from paged pool:
0: kd> !vm
*** Virtual Memory Usage ***
Physical Memory: 4193696 ( 16774784 Kb)
Page File: \??\C:\pagefile.sys
Current: 4193280 Kb Free Space: 3313120 Kb
Minimum: 4193280 Kb Maximum: 4193280 Kb
Available Pages: 3210617 ( 12842468 Kb)
ResAvail Pages: 4031978 ( 16127912 Kb)
Locked IO Pages: 120 ( 480 Kb)
Free System PTEs: 99633 ( 398532 Kb)
Free NP PTEs: 26875 ( 107500 Kb)
Free Special NP: 0 ( 0 Kb)
Modified Pages: 611 ( 2444 Kb)
Modified PF Pages: 590 ( 2360 Kb)
NonPagedPool 0 Used: 8271 ( 33084 Kb)
NonPagedPool 1 Used: 13828 ( 55312 Kb)
NonPagedPool Usage: 37846 ( 151384 Kb)
NonPagedPool Max: 65215 ( 260860 Kb)
PagedPool 0 Usage: 82308 ( 329232 Kb)
PagedPool 1 Usage: 12700 ( 50800 Kb)
PagedPool 2 Usage: 25702 ( 102808 Kb)
PagedPool Usage: 120710 ( 482840 Kb)
PagedPool Maximum: 134144 ( 536576 Kb)
********** 818 pool allocations have failed **********
Shared Commit: 80168 ( 320672 Kb)
Special Pool: 0 ( 0 Kb)
Shared Process: 55654 ( 222616 Kb)
PagedPool Commit: 120772 ( 483088 Kb)
Driver Commit: 1890 ( 7560 Kb)
Committed pages: 1344388 ( 5377552 Kb)
Commit limit: 5177766 ( 20711064 Kb)
!poolused 4 WinDbg command will sort paged pool consumption by pool tag:
0: kd> !poolused 4
Sorting by Paged Pool Consumed
Pool Used:
NonPaged Paged
Tag Allocs Used Allocs Used
MmSt 0 0 85622 140642616 Mm section object prototype ptes , Binary: nt!mm
Ntff 5 1040 63715 51991440 FCB_DATA , Binary: ntfs.sys
Here Microsoft article KB312362 might help.
Non-paged pool
0: kd> !vm
*** Virtual Memory Usage ***
Physical Memory: 851775 ( 3407100 Kb)
Page File: \??\C:\pagefile.sys
Current: 4190208 Kb Free Space: 4175708 Kb
Minimum: 4190208 Kb Maximum: 4190208 Kb
Available Pages: 147274 ( 589096 Kb)
ResAvail Pages: 769287 ( 3077148 Kb)
Locked IO Pages: 118 ( 472 Kb)
Free System PTEs: 184910 ( 739640 Kb)
Free NP PTEs: 110 ( 440 Kb)
Free Special NP: 0 ( 0 Kb)
Modified Pages: 168 ( 672 Kb)
Modified PF Pages: 168 ( 672 Kb)
NonPagedPool Usage: 64445 ( 257780 Kb)
NonPagedPool Max: 64640 ( 258560 Kb)
********** Excessive NonPaged Pool Usage *****
PagedPool 0 Usage: 21912 ( 87648 Kb)
PagedPool 1 Usage: 691 ( 2764 Kb)
PagedPool 2 Usage: 706 ( 2824 Kb)
PagedPool 3 Usage: 704 ( 2816 Kb)
PagedPool 4 Usage: 708 ( 2832 Kb)
PagedPool Usage: 24721 ( 98884 Kb)
PagedPool Maximum: 134144 ( 536576 Kb)
********** 429 pool allocations have failed **********
Shared Commit: 5274 ( 21096 Kb)
Special Pool: 0 ( 0 Kb)
Shared Process: 3958 ( 15832 Kb)
PagedPool Commit: 24785 ( 99140 Kb)
Driver Commit: 19289 ( 77156 Kb)
Committed pages: 646282 ( 2585128 Kb)
Commit limit: 1860990 ( 7443960 Kb)
!poolused 3 WinDbg command will sort non-paged pool consumption by pool tag:
0: kd> !poolused 3
Sorting by NonPaged Pool Consumed
Pool Used:
NonPaged
Tag Allocs Frees Diff
Ddk 9074558 3859522 5215036 Default for driver allocated memory (user’s of ntddk.h)
MmCm 43787 42677 1110 Calls made to MmAllocateContiguousMemory , Binary: nt!mm
LSwi 1 0 1 initial work context
TCPt 3281838 3281808 30 TCP/IP network protocol , Binary: TCP
Regarding Ddk tag I published a case study earlier:
The following Microsoft article KB293857 explains how we can use xpool command from old kdex2×86.dll extension which even works for Windows 2003 dumps:
0: kd> !w2kfre\kdex2x86.xpool -map
unable to get NT!MmSizeOfNonPagedMustSucceed location
unable to get NT!MmSubsectionTopPage location
unable to get NT!MmKseg2Frame location
unable to get NT!MmNonPagedMustSucceed location
Status Map of Pool Area Pages
==============================
'O': one page in use ('P': paged out)
'<': start page of contiguous pages in use ('{': paged out)
'>': last page of contiguous pages in use ('}': paged out)
'=': intermediate page of contiguous pages in use ('-': paged out)
'.': one page not used
Non-Paged Pool Area Summary
----------------------------
Maximum Number of Pages = 64640 pages
Number of Pages In Use = 36721 pages (56.8%)
+00000 +08000 +10000 +18000 +20000 +28000 +30000 +38000
82780000: ..OO.OO.OO..O.OO .O..OO.OO.OO..O. OO.O..OO.O..OO.. ..OO.O..OO.OO.OO
827c0000: .O..OO....OO..O. OO.OO.OO....OO.. O....O..OO....OO .O..OO.O..OO..O.
82800000: ..O............. ................ ................ ................
82840000: ................ ................ ................ ................
82880000: ......O.....O... ..O.O.....O..... O.....O.....O... ..O.....O.......
828c0000: ..O.........O... ......OOO.....O. ....O.....O..... O.....O.........
82900000: .O.........OO... O....O........O. ......OO........ OO.O..O.........
82940000: ...............O ..O.OO........OO ................ ...O.....O......
82980000: O.........O..O.. ....O.........O. ........O.....O. ..O.........O...
829c0000: ........O....... ..O...........O. .O..O...O..O.... ..O.........O...
82a00000: ......O..O...... O.........O..... ....O.........O. ................
82a40000: ............O... O..O.O......OO.. ......O.....O... ..O.....O...O.OO
...
...
...
893c0000: ................ ................ ................ ................
89400000: ..........=..=.. ....=.....=..... =..=......=..=.. ....=..=......=.
89440000: ..=............. ............=... =..=.....=..=... =...=.=.....==..
89480000: ....==......=.=. .........=...... ====.=.=........ ................
894c0000: ................ ................ ..........=.=... ...==...........
89500000: ..=............. ..=............. ..=............. ..=.............
89540000: ..=............. ..=............. ..=............. ..=...=.....=..=
89580000: ......=..=...... =..=......=.==== ==..==.=....=... .=....=....=.==.
895c0000: =.....==........ ..=............. =..=......=...=. ................
89600000: ........=...=..= .....=......=..= ==....=......... .........=....=.
89640000: ..=...===...=... ==......=..=..=. ..=..=......=... ......=.=.....=.
...
...
...
Here is another example:
0: kd> !vm
*** Virtual Memory Usage ***
Physical Memory: 786299 ( 3145196 Kb)
Page File: \??\C:\pagefile.sys
Current: 4193280Kb Free Space: 3407908Kb
Minimum: 4193280Kb Maximum: 4193280Kb
Available Pages: 200189 ( 800756 Kb)
ResAvail Pages: 657130 ( 2628520 Kb)
Modified Pages: 762 ( 3048 Kb)
NonPagedPool Usage: 22948 ( 91792 Kb)
NonPagedPool Max: 70145 ( 280580 Kb)
PagedPool 0 Usage: 19666 ( 78664 Kb)
PagedPool 1 Usage: 3358 ( 13432 Kb)
PagedPool 2 Usage: 3306 ( 13224 Kb)
PagedPool 3 Usage: 3312 ( 13248 Kb)
PagedPool 4 Usage: 3309 ( 13236 Kb)
********** Excessive Paged Pool Usage *****
PagedPool Usage: 32951 ( 131804 Kb)
PagedPool Maximum: 40960 ( 163840 Kb)
Shared Commit: 9664 ( 38656 Kb)
Special Pool: 0 ( 0 Kb)
Free System PTEs: 103335 ( 413340 Kb)
Shared Process: 45024 ( 180096 Kb)
PagedPool Commit: 32951 ( 131804 Kb)
Driver Commit: 1398 ( 5592 Kb)
Committed pages: 864175 ( 3456700 Kb)
Commit limit: 1793827 ( 7175308 Kb)
0: kd> !poolused 4
Sorting by Paged Pool Consumed
Pool Used:
NonPaged Paged
Tag Allocs Used Allocs Used
CM 85 5440 11045 47915424
MyAV 0 0 186 14391520
MmSt 0 0 11795 13235744
Obtb 709 90752 2712 11108352
Ntff 5 1120 9886 8541504
…
…
…
MyAV tag seems to be the prefix for MyAVDrv module and this is hardly a coincidence. Looking at the list of drivers we see that MyAVDrv.sys was loaded and unloaded several times. Could it be that it didn’t free its non-paged pool allocations?
0: kd> lmv m MyAVDrv.sys
start end module name
Unloaded modules:
a5069000 a5084000 MyAVDrv.sys
Timestamp: unavailable (00000000)
Checksum: 00000000
a5069000 a5084000 MyAVDrv.sys
Timestamp: unavailable (00000000)
Checksum: 00000000
a5069000 a5084000 MyAVDrv.sys
Timestamp: unavailable (00000000)
Checksum: 00000000
b93e1000 b93fc000 MyAVDrv.sys
Timestamp: unavailable (00000000)
Checksum: 00000000
b9ae5000 b9b00000 MyAVDrv.sys
Timestamp: unavailable (00000000)
Checksum: 00000000
be775000 be790000 MyAVDrv.sys
Timestamp: unavailable (00000000)
Checksum: 00000000
Also we see that CM tag has the most allocations and !locks command shows hundreds of threads waiting for registry, an example of High Contention pattern:
0: kd> !locks
Resource @ nt!CmpRegistryLock (0x80478b00) Shared 10 owning threads
Contention Count = 9149810
NumberOfSharedWaiters = 718
NumberOfExclusiveWaiters = 21
Therefore we see at least two problems in this memory dump: excessive paged pool usage and high thread contention around registry resource slowing down if not halting the system.
- Dmitry Vostokov @ DumpAnalysis.org -
March 26th, 2008 at 3:55 pm
Here is another example:
http://blogs.msdn.com/ntdebugging/archive/2008/03/26/nonpagedpool-depletion.aspx
April 9th, 2008 at 2:32 pm
[…] Memory pattern there is so called session pool leak briefly touched in the previous kernel pool leaks post. I decided to factor it out separately because it also involves GDI handles and structures […]
September 11th, 2008 at 4:13 pm
[…] Insufficient Memory (kernel pool) […]
September 18th, 2008 at 9:37 am
[…] Crash Dump Analysis Patterns (Part 13c) […]
December 24th, 2008 at 5:00 pm
[…] 2009 (0×7D9) - The Year of DebuggingIn one complete memory dump taken from the system refusing user connections but not hung completely we can see the signs of past pool allocation failures (see Insufficient Memory): […]
February 16th, 2009 at 1:20 pm
[…] dump was generated for analysis. Usual !vm 4 command shows pool allocation errors and particularly insufficient session pool memory for user session […]
June 10th, 2009 at 2:59 pm
[…] suspect that users cannot connect because of the lack of kernel pool resources and see the shortage of paged pool along with session pool shortage for one […]
April 14th, 2010 at 1:39 pm
[…] Today we introduce an icon for Insufficient Memory (kernel pool) pattern: […]
June 17th, 2010 at 2:11 pm
[…] system_thread_exception_not_handled system_thread_exception_not_handled (7e) windbg command pool allocations have failed receivelotsacalls trap frame vista dr watson bios disassembly ninjutsu uncovered citrix tools at […]
September 18th, 2010 at 11:30 pm
[…] Debugging Experts Magazine Online 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): […]
May 30th, 2011 at 11:19 am
To see session pool usage you need to switch to a session process first:
1: kd> !sprocess 3
[...]
PROCESS 88b0dd88 SessionId: 3 Cid: 1b90 Peb: 7ffde000 ParentCid: 1b84
DirBase: 4072d000 ObjectTable: d8651450 HandleCount: 414.
Image: ApplicationA.exe
[...]
1: kd> .process /r /p 88b0dd88
Implicit process is now 88b0dd88
Loading User Symbols
1: kd> !poolused 8
Sorting by Session Tag
[...]
November 16th, 2011 at 5:18 pm
False positive excessive nonpaged pool memory usage messages: http://support.microsoft.com/kb/2509968
November 30th, 2012 at 2:18 pm
!poolused 5 produces the same level of detail for paged pool as !poolused 3 for nonpaged pool