February 2009

Volume 24 Number 02

Stack Trace - Working With An Incomplete Or Invalid IRP

By Bob Golding | February 2009

How many times have you looked at a hang and found an IRP that looks like this:

0: kd> !irp 8667a928 Irp is active with 10 stacks 5 is current (= 0x8667aa28) Mdl = 86041108 Thread 8a613768: Irp stack trace. cmd flg cl Device File Completion-Context [ 0, 0] 0 0 00000000 00000000 00000000-00000000 Args: 00000000 00000000 00000000 00000000 [ 0, 0] 0 0 00000000 00000000 00000000-00000000 Args: 00000000 00000000 00000000 00000000 [ 0, 0] 0 0 00000000 00000000 00000000-00000000 Args: 00000000 00000000 00000000 00000000 [ 0, 0] 0 0 00000000 00000000 00000000-00000000 Args: 00000000 00000000 00000000 00000000 >[ 4,34] c e0 8a58b030 00000000 f74c95d0-8a58be00 Success Error Cancel <------ Where's the device and \Driver\Disk PartMgr!PmIoCompletion the rest of the irp? Args: 00010000 00000000 be82ee00 00000000 [ 4, 0] c e1 8a58be00 00000000 f73fc5dc-8a430e68 Success Error Cancel pending \Driver\PartMgr ftdisk!FtpRefCountCompletionRoutine

How do you find the physical device? Starting in 2003, the classpnp driver allocates a second IRP and sends it to the port driver. Where can you find them? Well, if you have the FDO for the partition, you can find all of the transfer packets:

Device object (8a58b030) is for: DR2 \Driver\Disk DriverObject 8a58c550 Current Irp 00000000 RefCount 0 Type 00000007 Flags 00002050 Vpb 8a439758 Dacl e13f624c DevExt 8a58b0e8 DevObjExt 8a58b548 Dope 8a439700 ExtensionFlags (0000000000) AttachedDevice (Upper) 8a58be00 \Driver\PartMgr AttachedTo (Lower) 8a43a028 \Driver\raidisk Device queue is not busy. 0: kd> Take the device extension and find the private data. 0: kd> dt classpnp!_FUNCTIONAL_DEVICE_EXTENSION 8a58b0e8 +0x000 Version : 3 +0x004 DeviceObject : 0x8a58b030 +0x000 CommonExtension : _COMMON_DEVICE_EXTENSION +0x100 LowerPdo : 0x8a43a028 +0x104 DeviceDescriptor : 0x8a4371e0 +0x108 AdapterDescriptor : 0x8a575f90 +0x10c DevicePowerState : 1 ( PowerDeviceD0 ) .................. +0x204 ScanForSpecialFlags : 0 +0x208 PowerRetryDpc : _KDPC +0x228 PowerRetryTimer : _KTIMER +0x250 PowerContext : _CLASS_POWER_CONTEXT +0x2b4 PrivateFdoData : 0x8a437350 +0x2b8 Reserved2 : 0

Then display the Private data:

0: kd> dt classpnp!_CLASS_PRIVATE_FDO_DATA 8a437350 +0x000 AllFdosListEntry : _LIST_ENTRY [ 0x8a193008 - 0x8a588008 ] <------ They're linked to make things easy, maybe +0x008 Perf : __unnamed +0x014 HackFlags : 0 +0x018 HotplugInfo : _STORAGE_HOTPLUG_INFO +0x020 Retry : __unnamed +0x088 TimerStarted : 0 '' +0x089 LoggedTURFailureSinceLastIO : 0 '' +0x08a LoggedSYNCFailure : 0 '' +0x08b ReleaseQueueIrpAllocated : 0x1 '' +0x08c ReleaseQueueIrp : 0x8a437268 +0x090 AllTransferPacketsList : _LIST_ENTRY [ 0x8a434f10 - 0x860e3308 ] <------ All the xfer packets for that FDO +0x098 FreeTransferPacketsList : _SLIST_HEADER +0x0a0 NumFreeTransferPackets : 0 +0x0a4 NumTotalTransferPackets : 0x41

Just dump the packet list. The original IRP (8667a928 above) is offset 14 in one of the packets on the list. Just find that IRP and dump the packet to find other info:

0: kd> dl 0x8a434f10 8a434f10 8a332308 8a4373e0 00000000 8a6188d0 8a332308 8a2e7008 8a434f10 00000000 8a155008 8a2e7008 89ec9be0 8a332308 00000000 8a267678 89ec9be0 89e31950 8a2e7008 00000000 89f18008 89e31950 89e33858 89ec9be0 00000000 89e55a48 89e33858 892bb2f8 89e31950 00000000 89eef578 892bb2f8 8a318678 89e33858 00000000 89563b28 ..................................... <----- For space, the whole list was not dumped : kd> dt classpnp!_TRANSFER_PACKET 87652c80 +0x000 AllPktsListEntry : _LIST_ENTRY [ 0x8a251f10 - 0x862a81b0 ] +0x008 SlistEntry : _SINGLE_LIST_ENTRY +0x00c Irp : 0x86025d98 +0x010 Fdo : 0x8a58b030 +0x014 OriginalIrp : 0x8667a928 <----- This is the IRP that we started with +0x018 CompleteOriginalIrpWhenLastPacketCompletes : 0x1 '' +0x01c NumRetries : 8 +0x020 RetryTimer : _KTIMER +0x048 RetryTimerDPC : _KDPC +0x068 RetryIntervalSec : 0 +0x06c SyncEventPtr : (null) +0x070 InLowMemRetry : 0 '' +0x074 LowMemRetry_remainingBufPtr : (null) +0x078 LowMemRetry_remainingBufLen : 0 +0x080 LowMemRetry_nextChunkTargetLocation : _LARGE_INTEGER 0x0 +0x088 BufPtrCopy : 0x8a3ee000 "RCRD(" +0x08c BufLenCopy : 0x10000 +0x090 TargetLocationCopy : _LARGE_INTEGER 0xbe82ee00 +0x098 SrbErrorSenseData : _SENSE_DATA +0x0ac Srb : _SCSI_REQUEST_BLOCK 0: kd> !irp 0x86025d98 Irp is active with 4 stacks 3 is current (= 0x86025e50) Mdl = 86041108 Thread 00000000: Irp stack trace. Pending has been returned cmd flg cl Device File Completion-Context [ 0, 0] 0 0 00000000 00000000 00000000-00000000 Args: 00000000 00000000 00000000 00000000 [ 0, 0] 0 0 00000000 00000000 00000000-00000000 Args: 00000000 00000000 00000000 00000000 >[ f, 0] 0 e1 8a58d030 00000000 f721c30a-8a3264d0 Success Error Cancel pending <---- This is the device we want! \Driver\CPQKGPSA RAIDISK Args: 87652d2c 00000000 00000000 00000000 [ f, 0] c e1 8a43a028 00000000 f732e540-87652c80 Success Error Cancel pending \Driver\raidisk CLASSPNP!TransferPktComplete Args: 87652d2c 63d46296 01c49a05 00000000

Bob Golding has been with Microsoft since 1997. He is a Senior Escalation Engineer on the Global Escalation Services team where he supports Microsoft's largest customers with their most critical issues.

David Butler has been with Microsoft since 2000. He is an Escalation Engineer on the Global Escalation Services team where he supports Microsoft's largest customers with their most critical issues.