1. 4th parameter containing the blocked IRP address.
-- In the case of #1, if the analyze -v doesn't show anything, and the stack is useless, you'd run !irp 123addresshere123 and it would show the culprit '>'.
2. 1st parameter = 0x4, which implies that a power IRP has failed to synchronize with the PnP Manager.
-- In the case of #2, it's a bit different, so let's get into a recent debugging I did. I learned most of this from documentation provided by my good friend x BlueRobot, and other parts viewing various developer forums.
--------------------
0: kd> .bugcheck1st parameter = 0x4.
Bugcheck code 0000009F
Arguments 00000000`00000004 00000000`00000258 fffffa80`070b5b50 fffff800`00b9c3d0
Let's take a look at the call stack:
0: kd> knLNot really much info, just a few PnP routines that call into the bugcheck eventually. No driver in the stack, etc.
# Child-SP RetAddr Call Site
00 fffff800`00b9c398 fffff800`033577e6 nt!KeBugCheckEx
01 fffff800`00b9c3a0 fffff800`0350834c nt!PnpBugcheckPowerTimeout+0x76
02 fffff800`00b9c400 fffff800`032d085c nt!PopBuildDeviceNotifyListWatchdog+0x1c
03 fffff800`00b9c430 fffff800`032d06f6 nt!KiProcessTimerDpcTable+0x6c
04 fffff800`00b9c4a0 fffff800`032d05de nt!KiProcessExpiredTimerList+0xc6
05 fffff800`00b9caf0 fffff800`032d03c7 nt!KiTimerExpiration+0x1be
06 fffff800`00b9cb90 fffff800`032bd8ca nt!KiRetireDpcList+0x277
07 fffff800`00b9cc40 00000000`00000000 nt!KiIdleLoop+0x5a
Let's run !locks to see what's going on:
0: kd> !locksLet's take the address in the 'Threads' field and run !thread:
**** DUMP OF ALL RESOURCE OBJECTS ****
KD: Scanning for held locks..
Resource @ nt!IopDeviceTreeLock (0xfffff800034c9ce0) Shared 1 owning threads
Contention Count = 35
Threads: fffffa80070b5b50-01<*>
KD: Scanning for held locks.
Resource @ nt!PiEngineLock (0xfffff800034c9be0) Exclusively owned
Contention Count = 41
Threads: fffffa80070b5b50-01<*>
KD: Scanning for held locks.............
31147 total locks, 2 locks currently held
0: kd> !thread fffffa80070b5b50We have an IRP list, and a little bit of a more informative stack text. We can see a few partmgr routines (Partition Management system driver).
THREAD fffffa80070b5b50 Cid 0004.0030 Teb: 0000000000000000 Win32Thread: 0000000000000000 WAIT: (Executive) KernelMode Non-Alertable
fffff88003762370 NotificationEvent
IRP List:
fffffa800d1fc730: (0006,0430) Flags: 00060000 Mdl: fffffa800d7bd520
Not impersonating
DeviceMap fffff8a000008b30
Owning Process fffffa8006f93380 Image: System
Attached Process N/A Image: N/A
Wait Start TickCount 563451 Ticks: 216 (0:00:00:03.369)
Context Switch Count 2944 IdealProcessor: 4 NoStackSwap
UserTime 00:00:00.000
KernelTime 00:00:00.452
Win32 Start Address nt!ExpWorkerThread (0xfffff800032cf150)
Stack Init fffff88003762c70 Current fffff88003762070
Base fffff88003763000 Limit fffff8800375d000 Call 0
Priority 12 BasePriority 12 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
Child-SP RetAddr : Args to Child : Call Site
fffff880`037620b0 fffff800`032bb5f2 : 00000000`00000000 fffffa80`070b5b50 00000000`00000000 00000000`00000001 : nt!KiSwapContext+0x7a
fffff880`037621f0 fffff800`032cc99f : fffffa80`0d1fcad0 00000000`00000000 fffffa80`00000000 fffff880`017b8975 : nt!KiCommitThreadWait+0x1d2
fffff880`03762280 fffff800`035e66b8 : fffffa80`0cdec700 fffff880`00000000 fffffa80`62747300 00000000`00000700 : nt!KeWaitForSingleObject+0x19f
fffff880`03762320 fffff800`035e65d6 : fffffa80`000003e6 fffffa80`08064960 00000000`00000000 00000000`000007ff : nt!FstubReadSector+0x98
fffff880`037623a0 fffff800`035e66f5 : fffffa80`0cdec8f0 fffffa80`0de3a1a0 fffff880`03762438 fffffa80`081d6010 : nt!FstubDetectPartitionStyle+0x22
fffff880`037623d0 fffff880`00f9b512 : fffffa80`0cdec8f0 fffff880`00000001 00000000`00000000 fffffa80`08064960 : nt!IoReadPartitionTableEx+0x2d
fffff880`03762400 fffff880`00fa803e : fffffa80`081d6010 00000000`00000000 fffffa80`0cdec8f0 fffffa80`0de3a1a0 : partmgr!PmGetDriveLayoutEx+0x5d2
fffff880`03762500 fffff880`00f9ec1d : 00000000`00000000 fffffa80`0de3a1a0 fffffa80`0cdec8f0 00000000`00000000 : partmgr!PmSetSystemCriticalFlag+0x2e
fffff880`03762530 fffff880`00fa832a : 00000000`00000000 fffffa80`081d6010 fffffa80`081d6010 fffffa80`0cdec7a0 : partmgr!PmStartDevice+0x1fd
fffff880`03762600 fffff800`0368218e : fffffa80`081d6010 fffffa80`0d47eae0 fffffa80`0cdec7a0 fffff880`009b3180 : partmgr!PmPnp+0x11a
fffff880`03762650 fffff800`033bc7ad : fffffa80`0ea70050 fffffa80`0d47eae0 fffff800`033c5ed0 00000000`00000000 : nt!PnpAsynchronousCall+0xce
fffff880`03762690 fffff800`03691506 : fffff800`034c99a0 fffffa80`07c2fd10 fffffa80`0d47eae0 fffffa80`07c2feb8 : nt!PnpStartDevice+0x11d
fffff880`03762750 fffff800`036917a4 : fffffa80`07c2fd10 fffffa80`07040043 fffffa80`070421e0 00000000`00000001 : nt!PnpStartDeviceNode+0x156
fffff880`037627e0 fffff800`036b4eb6 : fffffa80`07c2fd10 fffffa80`070421e0 00000000`00000002 00000000`00000000 : nt!PipProcessStartPhase1+0x74
fffff880`03762810 fffff800`036b5448 : 00000000`00000000 fffff800`033c4e76 00000000`00000000 00000000`00000000 : nt!PipProcessDevNodeTree+0x296
fffff880`03762a80 fffff800`033c8827 : 00000001`00000003 00000000`00000000 00000000`00000001 fffffa80`00000084 : nt!PiProcessReenumeration+0x98
fffff880`03762ad0 fffff800`032cf261 : fffff800`033c8500 ffffffff`80000201 fffff800`0364bc00 fffffa80`070b5b50 : nt!PnpDeviceActionWorker+0x327
fffff880`03762b70 fffff800`035622ea : 00000000`00000000 fffffa80`070b5b50 00000000`00000080 fffffa80`06f93380 : nt!ExpWorkerThread+0x111
fffff880`03762c00 fffff800`032b68e6 : fffff880`03589180 fffffa80`070b5b50 fffff880`035940c0 00000000`00000000 : nt!PspSystemThreadStartup+0x5a
fffff880`03762c40 00000000`00000000 : fffff880`03763000 fffff880`0375d000 fffff880`03762370 00000000`00000000 : nt!KxStartSystemThread+0x16
** I've gone through a few 0x9F's in which dumping the !thread didn't provide an IRP list address. I am not sure why this would be the case, but my only guess is simply not enough information was available at the time of the crash to obtain an IRP list address.
Let's go ahead and take a look at the current IRP within the thread:
0: kd> !irp fffffa800d1fc730 7^^ Disk.sys and partmgr.sys. Disk.sys is the PnP Disk system driver.
Irp is active with 12 stacks 11 is current (= 0xfffffa800d1fcad0)
Mdl=fffffa800d7bd520: No System Buffer: Thread fffffa80070b5b50: Irp stack trace.
Flags = 00060000
ThreadListEntry.Flink = fffffa80070b5f40
ThreadListEntry.Blink = fffffa80070b5f40
IoStatus.Status = 00000000
IoStatus.Information = 00000000
RequestorMode = 00000000
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = fffff88003762360
UserEvent = fffff88003762370
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000
UserBuffer = 00000000
&Tail.Overlay.DeviceQueueEntry = fffffa800d1fc7a8
Tail.Overlay.Thread = fffffa80070b5b50
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = fffffa800d1fcad0
Tail.Overlay.OriginalFileObject = 00000000
Tail.Apc = 00000001
Tail.CompletionKey = 00000001
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
[ 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,34] 2 e0 fffffa800dd8f060 00000000 fffff88000f9e1b0-00000000 Success Error Cancel
\Driver\Disk partmgr!PmReadWriteCompletion
Args: 00000200 00000000 00000000 00000000
[ 3, 0] 2 0 fffffa800cdec7a0 00000000 00000000-00000000
\Driver\partmgr
Args: 4632491f2 00000000 00000000 00000000
Let's now go ahead and run !devstack on the hightlighted address for Disk.sys:
0: kd> !devstack fffffa800dd8f060We can see mention of AmUStor.sys here which is the ALCOR Micro SD Card Controller driver.
!DevObj !DrvObj !DevExt ObjectName
fffffa800cdec7a0 \Driver\partmgr fffffa800cdec8f0
> fffffa800dd8f060 \Driver\Disk fffffa800dd8f1b0 DR66
fffffa800ea70050 \Driver\AmUStor fffffa800ea701a0 00000267
!DevNode fffffa8007c2fd10 :
DeviceInstis "USBSTOR\Disk&Ven_Multiple&Prod_Card_Reader&Rev_1.00\058F63666433&01"
ServiceName is "disk"
-- FAILURE_BUCKET_ID: X64_0x9F_4_disk_IMAGE_AmUStor.SYS
We can see this matches our FBID.
--------------------
As the card controller drivers was OEM, there appeared to be no relevant updates, therefore it was disabled (or the card reader was removed) and it was solved.
Thanks for sharing.
ReplyDeleteReverseEngineering