Manual and early crash dump, stack trace collection, main thread, blocked threads and pass through functions: pattern cooperation
The system was hanging and a manual kernel dump file was generated:
0: kd> !analyze -v
[...]
NMI_HARDWARE_FAILURE (80)
This is typically due to a hardware malfunction. The hardware supplier should
be called.
Arguments:
Arg1: 004f4454
Arg2: 00000000
Arg3: 00000000
Arg4: 00000000
[...]
Initially it looked like an earlier premature crash dump taken after the reboot:
0: kd> version
[...]
System Uptime: 0 days 0:00:54.203
[…]
However the incident description stated that the system was hanging during its startup so we went further to look at a stack trace collection of all its threads and found the main thread of spooler was hanging for about 23 seconds after 4 seconds since process creation:
0: kd> !process 0 ff
[...]
PROCESS 8cf06020 SessionId: 0 Cid: 04a4 Peb: 7ffde000 ParentCid: 0244
DirBase: cff8c1a0 ObjectTable: d70086d0 HandleCount: 24.
Image: spoolsv.exe
VadRoot 8bb19130 Vads 32 Clone 0 Private 60. Modified 0. Locked 0.
DeviceMap d66028f0
Token d6e88988
ElapsedTime 00:00:27.921
UserTime 00:00:00.000
KernelTime 00:00:00.000
QuotaPoolUsage[PagedPool] 27844
QuotaPoolUsage[NonPagedPool] 1280
Working Set Sizes (now,min,max) (312, 50, 345) (1248KB, 200KB, 1380KB)
PeakWorkingSetSize 312
VirtualSize 12 Mb
PeakVirtualSize 12 Mb
PageFaultCount 322
MemoryPriority BACKGROUND
BasePriority 8
CommitCharge 80
THREAD 8cf22db0 Cid 04a4.04a8 Teb: 7ffdd000 Win32Thread: bc155948 WAIT: (Unknown) KernelMode Non-Alertable
8beeca28 SynchronizationEvent
IRP List:
8beecd08: (0006,0094) Flags: 00000884 Mdl: 00000000
Not impersonating
DeviceMap d66028f0
Owning Process 8cf06020 Image: spoolsv.exe
Attached Process N/A Image: N/A
Wait Start TickCount 1981 Ticks: 1488 (0:00:00:23.250)
Context Switch Count 9 LargeStack
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address 0×0100468c
Start Address 0×77e617f8
Stack Init b6a63b30 Current b6a630cc Base b6a64000 Limit b6a60000 Call b6a63b34
Priority 9 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr
b6a630e4 80833465 nt!KiSwapContext+0×26
b6a63110 80829a62 nt!KiSwapThread+0×2e5
b6a63158 b5dbc727 nt!KeWaitForSingleObject+0×346
b6a6318c b5dbd020 mrxdav!RxConstructSrvCall+0×187
b6a63200 b5dbd144 mrxdav!RxFindOrCreateConnections+0×58a
b6a6324c b5dbd552 mrxdav!RxConstructVirtualNetRoot+0×38
b6a632b8 b5db27fc mrxdav!RxFindOrConstructVirtualNetRoot+0×220
b6a63304 b5da7ff1 mrxdav!RxPrefixClaim+0×160
b6a6331c b5d93f72 mrxdav!RxCommonDevFCBIoCtl+0×71
b6a633ac b5da780c mrxdav!RxFsdCommonDispatch+0×320
b6a633cc b5da0fc4 mrxdav!RxFsdDispatch+0xd4
b6a63440 8081df65 mrxdav!MRxDAVFsdDispatch+0×1f0
b6a63454 bace232e nt!IofCallDriver+0×45
b6a63460 bace24f6 Mup!MupiIssueQueryRequest+0×18
b6a63488 bace2414 Mup!MupiResolvePrefix+0×11b
b6a634d4 bacdf4ed Mup!CreateRedirectedFile+0×385
b6a63530 8081df65 Mup!MupCreate+0×1cb
b6a63544 808f8f71 nt!IofCallDriver+0×45
b6a6362c 80937942 nt!IopParseDevice+0xa35
b6a636ac 80933a76 nt!ObpLookupObjectName+0×5b0
b6a63700 808ec76b nt!ObOpenObjectByName+0xea
b6a63884 8088978c nt!NtQueryAttributesFile+0×11d
b6a63884 7c8285ec nt!KiFastCallEntry+0xfc (TrapFrame @ b6a63894)
Looking at IRP we see that I/O request was redirected to the following file share:
0: kd> !irp 8beecd08
Irp is active with 1 stacks 1 is current (= 0x8beecd78)
No Mdl: No System Buffer: Thread 8cf22db0: Irp stack trace.
cmd flg cl Device File Completion-Context
>[ 0, 0] 0 0 8cfdcee8 b6a637f0 00000000-00000000
\FileSystem\Mup
Args: b6a63570 01200000 00070000 00000000
0: kd> !fileobj b6a637f0
\SERVER-A\f$\AppFiles\Component.dll
Device Object: 0x8cfdcee8 \FileSystem\Mup
Vpb is NULL
Flags: 0x0
CurrentByteOffset: 0
When looking at other processes we see 2 threads blocked in svchost.exe in the same redirector component:
0: kd> !stacks
Proc.Thread .Thread Ticks ThreadState Blocker
[...]
[8bb2a728 svchost.exe]
3d0.0003d4 8bb2a290 0000701 Blocked nt!NtReadFile+0x5d5
3d0.0003d8 8bb2aba0 00006ff Blocked nt!ObpWaitForMultipleObjects+0x202
3d0.0003dc 8bb338c0 00005eb Blocked nt!ObpWaitForMultipleObjects+0x202
3d0.0003e8 8bb2cdb0 0000892 Blocked nt!ObpWaitForMultipleObjects+0x202
3d0.0003ec 8bb2c838 0000892 Blocked nt!KiFastCallEntry+0xfc
3d0.0003f0 8bb26cd0 0000892 Blocked nt!KiFastCallEntry+0xfc
3d0.000488 8ceffb88 00006fb Blocked mrxdav!UMRxAssignWork+0xdf
3d0.00048c 8cec3db0 00005d0 Blocked mrxdav!UMRxAssignWork+0xdf
3d0.000490 8cec3b40 00006fb Blocked nt!KiFastCallEntry+0xfc
3d0.0004d4 8bb02918 00005c7 Blocked nt!KiFastCallEntry+0xfc
3d0.0004d8 8bafdb40 00005c4 Blocked nt!KiFastCallEntry+0xfc
[…]
In these two threads we see pass through functions in driverA and driverB:
0: kd> !thread 8ceffb88
THREAD 8ceffb88 Cid 03d0.0488 Teb: 7ffd8000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
8cef1f28 QueueObject
Not impersonating
DeviceMap d6e2c298
Owning Process 8bb2a728 Image: svchost.exe
Attached Process N/A Image: N/A
Wait Start TickCount 1682 Ticks: 1787 (0:00:00:27.921)
Context Switch Count 2
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address 0x5a005e80
Start Address 0x77e617ec
Stack Init b5ed8000 Current b5ed7a64 Base b5ed8000 Limit b5ed5000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr
b5ed7a7c 80833465 nt!KiSwapContext+0x26
b5ed7aa8 8082b60f nt!KiSwapThread+0x2e5
b5ed7af0 b5da714d nt!KeRemoveQueue+0x417
b5ed7b10 b5d9d7db mrxdav!UMRxAssignWork+0xdf
b5ed7b70 bae71bc5 mrxdav!MRxDAVFastIoDeviceControl+0x13d
b5ed7ba8 bae7f42d fltmgr!FltpPerformFastIoCall+0x153
b5ed7bf4 b5f57300 fltmgr!FltpFastIoDeviceControl+0xb1
b5ed7c20 b6e20f8f driverB!FS_FastIoDeviceControl+0×60
b5ed7c5c 808f5e2f driverA!FastIoDeviceControl+0xcf
b5ed7d00 808eed08 nt!IopXxxControlFile+0×255
b5ed7d34 8088978c nt!NtDeviceIoControlFile+0×2a
b5ed7d34 7c8285ec nt!KiFastCallEntry+0xfc (TrapFrame @ b5ed7d64)
- Dmitry Vostokov @ DumpAnalysis.org -