Call Stacks for Pool Allocations
Hello, it's the Debug Ninja back again for another NtDebugging Blog article. For as long as I can remember user mode debuggers have had an easy way to get call stacks for heap allocations. On more recent versions of Windows this has been as simple as using gflags +ust and umdh or !heap -k. Kernel debuggers have not always had an easy way to determine who allocated a pool block. Sure, we have pool tags to help us out, but often a programmer will use the same tag in many places and devalue this as a troubleshooting technique.
Fortunately, starting in Windows Vista and Server 2008, kernel debuggers can get call stacks from pool allocations. We can even get call stacks from pool frees. This little known technique is not quite as useful as gflags +ust is for heap, but when it is needed it is very useful.
First, you need to turn on special pool using driver verifier. Verifier will obtain and track the call stack for the allocation and the free, so this technique will not work with traditional special pool as documented in KB188831 because those settings do not use driver verifier. Because special pool requires additional memory overhead to run, this technique is not valuable for large memory leaks. However, this technique is a good way to determine what code allocated or freed your pool block in other conditions. For example, this works well if you find that pool has been freed when you expected it to be allocated. This also works for smaller memory leaks, especially those for which you can easily reproduce the leak. Analyzing the allocations and stacks for a leak must be done by hand, as there is no umdh-like tool for kernel mode.
Step 1 - Turning on verifier
In this example I am using Sysinternals’ notmyfault tool to generate the pool allocations. Because I know the driver in question I set verifier to only monitor that driver. Note that a reboot is required to make this setting take effect.
Verifier /flags 1 /driver myfault.sys
Step 2 - Finding the pool allocation to analyze
For this example I am going to find the call stack of a leaked pool allocation. First find the tag that is using the most pool by using !poolused.
kd> !poolused 4
Sorting by Paged Pool Consumed
Pool Used:
NonPaged Paged
Tag Allocs Used Allocs Used
Leak 0 0 23 23552000 UNKNOWN pooltag 'Leak', please update pooltag.txt
CM31 0 0 20520 18514560 Internal Configuration manager allocations , Binary: nt!cm
CIcr 0 0 2977 8511504 Code Integrity allocations for image integrity checking , Binary: ci.dll
Next find the pool allocations for that tag with !poolfind. There is some guessing to be done with all pool leak debugging techniques; you can’t be sure that the allocation you’re looking at has really been leaked and is not just in a state where it has not yet been freed. You need to make an educated guess because there is no umdh-type functionality to analyze allocates and frees. If you have the benefit of a live debug you can go the debugger and check back later to see if the memory has been freed or not.
kd> !poolfind Leak
Scanning large pool allocation table for Tag: Leak (fffffa8002e00000 : fffffa8002f80000)
*fffff8a006a00000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a0058fa000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a006200000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a0068fa000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a0060fa000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a005a00000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a006c00000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a006400000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a0062fa000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a005afa000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a005c00000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a006e00000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a006600000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a0064fa000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a005cfa000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a006afa000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a005e00000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a006800000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a0066fa000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a005efa000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a006cfa000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a006000000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
*fffff8a005800000 :large page allocation, Tag is Leak, size is 0xfa000 bytes
Step 3 – Dump the call stack for the allocation
This step is the easy one. Once you have the address of the allocation use !verifier 0x80 Address. If you were interested in all of the call stacks in the log you can run !verifier 0x80 without the Address parameter.
kd> !verifier 0x80 fffff8a005800000
Log of recent kernel pool Allocate and Free operations:
There are up to 0x10000 entries in the log.
Parsing 0x0000000000010000 log entries, searching for address 0xfffff8a005800000.
======================================================================
Pool block fffff8a005800000, Size 00000000000fa000, Thread fffffa8002be4060
fffff80001923cc6 nt!VeAllocatePoolWithTagPriority+0x2b6
fffff80001923d3d nt!VerifierExAllocatePoolEx+0x1d
fffff880042881f6 myfault+0x11f6
fffff8800428842f myfault+0x142f
fffff8000192e750 nt!IovCallDriver+0xa0
fffff800017a3a97 nt!IopXxxControlFile+0x607
fffff800017a42f6 nt!NtDeviceIoControlFile+0x56
fffff80001487ed3 nt!KiSystemServiceCopyEnd+0x13
======================================================================
Pool block fffff8a005800000, Size 0000000000001000, Thread fffffa8002187060
fffff8000192393a nt!VfFreePoolNotification+0x4a
fffff800015b6a6f nt!ExDeferredFreePool+0x107b
fffff800017273eb nt!HvFreeDirtyData+0x7f
fffff800017269bb nt!HvOptimizedSyncHive+0x53
fffff80001726303 nt!CmFlushKey+0xaf
fffff80001726b22 nt!NtFlushKey+0x142
fffff80001487ed3 nt!KiSystemServiceCopyEnd+0x13
Parsed entry 0000000000010000/0000000000010000...
Finished parsing all pool tracking information.
Keep in mind that the log may contain allocate and free information that predates the current use of the pool block, and that the log is of a fixed size so eventually old data will fall off the end. The most recent use of the pool will be at the top of the output. Usually this is the stack at the top of the output is what you are interested in, I have highlighted the relevant call stack in red. In this instance we can see that the pool was most recently allocated by myfault.sys.
Sometimes it is useful to have historical information about previous uses of the pool block such as when dealing with pool that was improperly freed. In that scenario the most recent call stack may be from an allocate call when the pool block was reused by the memory manager and so you may need to go down several levels to find out where the pool was improperly freed.
For more information on using !verifier you can refer to the debugger help in MSDN, https://msdn.microsoft.com/en-us/library/ff565591.aspx.