Starting with Windows Vista, Driver Verifier has been updated to include circular trace buffers for interesting events. My favorite up until this point has been the pool allocate and free log, which records the call stack, calling thread, and address of pool allocations and frees. If the system then crashes due to a double free or access to a freed pool block, the debugger’s !verifier 0×80 command can be used to dump the alloc/free log. Even better, the command takes an optional address value that will show only the allocations and frees of the pool block containing that address.
You can see the results in this example from the WinDBG docs:
0: kd> !verifier 80 a2b1cf20 Parsing 00004000 array entries, searching for address a2b1cf20. ======================================= Pool block a2b1ce98, Size 00000168, Thread a2b1ce98 808f1be6 ndis!ndisFreeToNPagedPool+0x39 808f11c1 ndis!ndisPplFree+0x47 808f100f ndis!NdisFreeNetBufferList+0x3b 8088db41 NETIO!NetioFreeNetBufferAndNetBufferList+0xe 8c588d68 tcpip!UdpEndSendMessages+0xdf 8c588cb5 tcpip!UdpSendMessagesDatagramsComplete+0x22 8088d622 NETIO!NetioDereferenceNetBufferListChain+0xcf 8c5954ea tcpip!FlSendNetBufferListChainComplete+0x1c 809b2370 ndis!ndisMSendCompleteNetBufferListsInternal+0x67 808f1781 ndis!NdisFSendNetBufferListsComplete+0x1a 8c04c68e pacer!PcFilterSendNetBufferListsComplete+0xb2 809b230c ndis!NdisMSendNetBufferListsComplete+0x70 8ac4a8ba test1!HandleCompletedTxPacket+0xea ======================================= Pool block a2b1ce98, Size 00000164, Thread a2b1ce98 822af87f nt!VerifierExAllocatePoolWithTagPriority+0x5d 808f1c88 ndis!ndisAllocateFromNPagedPool+0x1d 808f11f3 ndis!ndisPplAllocate+0x60 808f1257 ndis!NdisAllocateNetBufferList+0x26 80890933 NETIO!NetioAllocateAndReferenceNetBufferListNetBufferMdlAndData+0x14 8c5889c2 tcpip!UdpSendMessages+0x503 8c05c565 afd!AfdTLSendMessages+0x27 8c07a087 afd!AfdTLFastDgramSend+0x7d 8c079f82 afd!AfdFastDatagramSend+0x5ae 8c06f3ea afd!AfdFastIoDeviceControl+0x3c1 8217474f nt!IopXxxControlFile+0x268 821797a1 nt!NtDeviceIoControlFile+0x2a 8204d16a nt!KiFastCallEntry+0x127
In the output, the most recent event is at the top. Thus, here you can see that the buffer was allocated with ndisAllocateFromNPagedPool and freed with ndisAllocateFromNPagedPool.
In addition to the pool allocation log, !verifier 0×100 shows the IRP log, which logs all IoCallDriver, IoCompleteRequest, and IoCancelIrp calls.
Based on the docs you’d think that’s all there is, but there’s an undocumented log that can be accessed with !verifier 0×200 and that is the critical region log.
This is not to be confused with the user mode concept of critical regions. In a driver, one can call KeEnterCriticalRegion and KeExitCriticalRegion in order to disable and re-enable APC delivery. Without getting too much in to why a driver needs to disable APC delivery, what’s important to note is that every call to KeEnterCriticalRegion must be matched with a call to KeExitCriticalRegion. If a driver gets this wrong, then the system will crash with an APC_INDEX_MISMATCH bugcheck when it notices that the enter/exit count is off.
The way this works is that entering a critical region decrements a field of the KTHREAD structure and exiting a critical region increments the field of the structure. At various points in the O/S, the field of the KTHREAD is checked to make sure that it is zero. If it isn’t, then the system crashes with the previously mentioned APC_INDEX_MISMATCH bugcheck code. One such place that this is checked is in the system service dispatcher before returning back to the caller, which is why you’ll see these bugchecks come from KiSystemServiceExit.
What makes these crashes particularly difficult to track down is that the crash is a secondary failure, by the time the system notices that the count field is incorrect the code that caused the bad state is gone. Enter the critical region log, which will trace every call to KeEnterCriticalRegion and KeLeaveCriticalRegion for the Verified drivers. Now, when the system crashes you can just type !verifier 0×200 in the debugger and find the mismatched call.
Note that this only works with Driver Verifier enabled, just another reason to make sure that you’re always testing with Verifier!