Archive for January 11th, 2012

Crash Dump Analysis Patterns (Part 27d)

Wednesday, January 11th, 2012

In addition to stack trace collections for threads (unmanaged, managed and predicate) we introduce an additional pattern for I/O requests. Such requests are implemented via the so called I/O request packets (IRP) that “travel” from a device driver to a device driver similar to a C++ class method to another C++ class method (where a device object address is similar to a C++ object instance address). An IRP stack is used to keep a track of the current driver which is processing an IRP that is reused between device drivers. Its is basically an array of structures describing how a particular driver function was called with appropriate parameters similar to a call frame on an execution thread stack. Long time ago I created an UML diagram depicting the flow of an IRP through the driver (device) stack (diagram #3). An I/O stack location pointer is decremented (from the bottom to the top) like a thread stack pointer (ESP or RSP). We can list active and completed I/O requests with their stack traces using !irpfind -v WinDbg command:

1: kd> !irpfind -v

Scanning large pool allocation table for Tag: Irp? (832c7000 : 833c7000)

Irp    [ Thread ] irpStack: (Mj,Mn)   DevObj  [Driver]         MDL Process
8883dc18: Irp is active with 1 stacks 1 is current (= 0x8883dc88)
No Mdl: No System Buffer: Thread 888f8950:  Irp stack trace.
cmd  flg cl Device   File     Completion-Context
>[  d, 0]   5  1 88515ae8 888f82f0 00000000-00000000    pending
\FileSystem\Npfs
Args: 00000000 00000000 00110008 00000000

891204c8: Irp is active with 1 stacks 1 is current (= 0x89120538)
No Mdl: No System Buffer: Thread 889635b0:  Irp stack trace.
cmd  flg cl Device   File     Completion-Context
>[  3, 0]   0  1 88515ae8 84752028 00000000-00000000    pending
\FileSystem\Npfs
Args: 0000022a 00000000 00000000 00000000

89120ce8: Irp is active with 1 stacks 1 is current (= 0x89120d58)
No Mdl: No System Buffer: Thread 89212030:  Irp stack trace.
cmd  flg cl Device   File     Completion-Context
>[  3, 0]   0  1 88515ae8 8921be00 00000000-00000000    pending
\FileSystem\Npfs
Args: 0000022a 00000000 00000000 00000000
Searching NonPaged pool (80000000 : ffc00000) for Tag: Irp?

[...]

892cbe48: Irp is active with 9 stacks 9 is current (= 0x892cbfd8)
No Mdl: No System Buffer: Thread 892add78:  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
[  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
>[  c, 2]   0  1 8474a020 892c8c80 00000000-00000000    pending
\FileSystem\Ntfs
Args: 00000800 00000002 00000000 00000000

892daa88: Irp is active with 4 stacks 4 is current (= 0x892dab64)
No Mdl: System buffer=831559c8: Thread 8322c8e8:  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
>[  e,2d]   5  1 884ba750 83190c40 00000000-00000000    pending
\Driver\AFD
Args: 890cbc44 890cbc44 88e55297 8943b6c8

892ea4e8: Irp is active with 4 stacks 4 is current (= 0x892ea5c4)
No Mdl: No System Buffer: Thread 00000000:  Irp stack trace.  Pending has been returned
cmd  flg cl Device   File     Completion-Context
[  0, 0]   0  2 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 c0000185
[  0, 0]   0  0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[  f, 0]   0  2 83a34bb0 00000000 84d779ed-88958050
\Driver\atapi CLASSPNP!ClasspMediaChangeDetectionCompletion
Args: 88958050 00000000 00000000 83992d10
>[  0, 0]   2  0 891ee030 00000000 00000000-00000000
\Driver\cdrom
Args: 00000000 00000000 00000000 00000000

8933fcb0: Irp is active with 1 stacks 1 is current (= 0x8933fd20)
No Mdl: No System Buffer: Thread 84753d78:  Irp stack trace.
cmd  flg cl Device   File     Completion-Context
>[  3, 0]   0  1 88515ae8 84759f40 00000000-00000000    pending
\FileSystem\Npfs
Args: 0000022a 00000000 00000000 00000000

893cf550: Irp is active with 1 stacks 1 is current (= 0x893cf5c0)
No Mdl: No System Buffer: Thread 888fd3b8:  Irp stack trace.
cmd  flg cl Device   File     Completion-Context
>[  3, 0]   0  1 88515ae8 834d30d0 00000000-00000000    pending
\FileSystem\Npfs
Args: 00000400 00000000 00000000 00000000

893da468: Irp is active with 6 stacks 7 is current (= 0x893da5b0)
Mdl=892878f0: No System Buffer: Thread 00000000:  Irp is completed.  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
[  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  0 84b3e028 00000000 9747fcd0-00000000
\Driver\usbehci USBSTOR!USBSTOR_CswCompletion
Args: 00000000 00000000 00000000 00000000
[  f, 0]   0  0 892ba8f8 00000000 84d780ce-8328e0f0
\Driver\USBSTOR CLASSPNP!TransferPktComplete
Args: 00000000 00000000 00000000 00000000

893efb00: Irp is active with 10 stacks 11 is current (= 0x893efcd8)
Mdl=83159378: No System Buffer: Thread 82b7f828:  Irp is completed.  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
[  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
[  3, 0]   0  0 885a55b8 00000000 81614138-00000000
\Driver\disk partmgr!PmReadWriteCompletion
Args: 00000000 00000000 00000000 00000000
[  3, 0]   0  0 89257c90 00000000 8042e4d4-831caab0
\Driver\partmgr volmgr!VmpReadWriteCompletionRoutine
Args: 00000000 00000000 00000000 00000000
[  3, 0]   0  0 831ca9f8 00000000 84dad0be-00000000
\Driver\volmgr ecache!EcDispatchReadWriteCompletion
Args: 00000000 00000000 00000000 00000000
[  3, 0]   0  0 8319c020 00000000 84dcc4d4-8576f8ac
\Driver\Ecache volsnap!VspSignalCompletion
Args: 00000000 00000000 00000000 00000000

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