0x9F DRIVER_POWER_STATE_FAILURE

First off I’d like to say I’m sorry I’ve not been posting in a while but I’ll try to post a bit more.

BugCheck 9F, {4, 258, fffffa8007005660, fffff800053e83d0}

 There are two types of 0x9F bugchecks, indicated by the first parameter, the first one is indicated with a 3 which means an IRP has been held onto for too long so the system bugchecked as it holds everything else up.
The second one is what we’re going to look at which indicates a thread is holding onto a power IRP for too long which causes it to timeout and bugcheck.

So in more detail this bugcheck indicates a power IRP failed to synchronise with the PnP manager, basically a power IRP is an I/O Request Packet that sends power transitions down a device stack.
All power IRPs must reach the PDO (Physical Device Object) at the bottom of the stack to ensure power transitions are done correctly.
When one doesn’t reach the bottom for any reason the system bugchecks, in this case a thread was blocking the IRP so it couldn’t be completed within the allocated time interval.

So lets look at the locks on the system which are blocking the IRP.
To understand what this means we need to know what a lock is (ERESOURCE structure), locks are synchronisation mechanisms that allow drivers to access resources efficiently.
There are two main types of locks, exclusive and shared where the exclusive lock is the owner and shared can be implemented across multiple threads.
They contain a read/write mechanism where only one thread can write but multiple threads can read simultaneously.
Acquiring a thread exclusivly requires no threads can be currently sharing it, for thread to acquire a lock it must be put into a wait state until it is available.

This was only a brief explanation, for more information check out this article:

http://msdn.microsoft.com/en-us/library/ff548046.aspx

Back to the topic, looking at the locks.

0: kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****
KD: Scanning for held locks..

Resource @ nt!IopDeviceTreeLock (0xfffff80003492ce0)    Shared 1 owning threads
    Contention Count = 1
     Threads: fffffa8007005660-01
KD: Scanning for held locks.

Resource @ nt!PiEngineLock (0xfffff80003492be0)    Exclusively owned
    Contention Count = 21
    NumberOfExclusiveWaiters = 1
     Threads: fffffa8007005660-01
     Threads Waiting On Exclusive Access:
              fffffa800f308b50      

KD: Scanning for held locks…………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………………
18855 total locks, 2 locks currently held

Let’s look at the exclusive thread owning the lock.

0: kd> !thread fffffa8007005660
THREAD fffffa8007005660  Cid 0004.0048  Teb: 0000000000000000 Win32Thread: 0000000000000000 WAIT: (Executive) KernelMode Non-Alertable
    fffffa800d035ee8  NotificationEvent
IRP List:
    fffffa8008f5cc10: (0006,03e8) Flags: 00000000  Mdl: 00000000
Not impersonating
DeviceMap                 fffff8a000008c10
Owning Process            fffffa8006f8d890       Image:         System
Attached Process          N/A            Image:         N/A
Wait Start TickCount      396427         Ticks: 38463 (0:00:10:00.026)
Context Switch Count      44059          IdealProcessor: 2  NoStackSwap
UserTime                  00:00:00.000
KernelTime                00:00:00.343
Win32 Start Address nt!ExpWorkerThread (0xfffff80003298150)
Stack Init fffff88003bd2c70 Current fffff88003bd2280
Base fffff88003bd3000 Limit fffff88003bcd000 Call 0
Priority 15 BasePriority 12 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           : Args to Child                                                           : Call Site
fffff880`03bd22c0 fffff800`032845f2 : fffffa80`07005660 fffffa80`07005660 00000000`00000000 00000000`00000000 : nt!KiSwapContext+0x7a
fffff880`03bd2400 fffff800`0329599f : fffffa80`0d0df208 fffff880`0ae9e10b fffffa80`00000000 00000000`00000000 : nt!KiCommitThreadWait+0x1d2
fffff880`03bd2490 fffff880`0ae915dd : fffffa80`0d035000 00000000`00000000 fffffa80`0dd8ca00 00000000`00000000 : nt!KeWaitForSingleObject+0x19f
fffff880`03bd2530 fffff880`0ae92627 : fffffa80`0d035000 00000000`00000000 fffffa80`0c0891a0 fffff880`03bd2670 : ZTEusbnet+0x35dd
fffff880`03bd2580 fffff880`0215d809 : fffffa80`0c0891a0 fffff880`020f0ecd fffff880`03bd2670 fffffa80`091c5550 : ZTEusbnet+0x4627
fffff880`03bd25b0 fffff880`0215d7d0 : fffffa80`091c54a0 fffffa80`0c0891a0 fffff880`03bd2670 fffffa80`08fc2ac0 : ndis!NdisFDevicePnPEventNotify+0x89
fffff880`03bd25e0 fffff880`0215d7d0 : fffffa80`08fc2a10 fffffa80`0c0891a0 fffffa80`091f9010 fffffa80`091f90c0 : ndis!NdisFDevicePnPEventNotify+0x50
fffff880`03bd2610 fffff880`0219070c : fffffa80`0c0891a0 00000000`00000000 00000000`00000000 fffffa80`0c0891a0 : ndis!NdisFDevicePnPEventNotify+0x50
fffff880`03bd2640 fffff880`021a1da2 : 00000000`00000000 fffffa80`08f5cc10 00000000`00000000 fffffa80`0c0891a0 : ndis! ?? ::LNCPHCLB::`string’+0xddf
fffff880`03bd26f0 fffff800`034fb121 : fffffa80`091c7060 fffffa80`0c089050 fffff880`03bd2848 fffffa80`070bfa00 : ndis!ndisPnPDispatch+0x843
fffff880`03bd2790 fffff800`0367b3a1 : fffffa80`070bfa00 00000000`00000000 fffffa80`0dc19990 fffff880`03bd2828 : nt!IopSynchronousCall+0xe1
fffff880`03bd2800 fffff800`03675d78 : fffffa80`09196e00 fffffa80`070bfa00 00000000`0000030a 00000000`00000308 : nt!IopRemoveDevice+0x101
fffff880`03bd28c0 fffff800`0367aee7 : fffffa80`0dc19990 00000000`00000000 00000000`00000003 00000000`00000136 : nt!PnpSurpriseRemoveLockedDeviceNode+0x128
fffff880`03bd2900 fffff800`0367b000 : 00000000`00000000 fffff8a0`11d1c000 fffff8a0`049330d0 fffff880`03bd2a58 : nt!PnpDeleteLockedDeviceNode+0x37
fffff880`03bd2930 fffff800`0370b97f : 00000000`00000002 00000000`00000000 fffffa80`09122010 00000000`00000000 : nt!PnpDeleteLockedDeviceNodes+0xa0
fffff880`03bd29a0 fffff800`0370c53c : fffff880`03bd2b78 fffffa80`114ab700 fffffa80`07005600 fffffa80`00000000 : nt!PnpProcessQueryRemoveAndEject+0x6cf
fffff880`03bd2ae0 fffff800`035f573e : 00000000`00000000 fffffa80`114ab7d0 fffff8a0`123a25b0 00000000`00000000 : nt!PnpProcessTargetDeviceEvent+0x4c
fffff880`03bd2b10 fffff800`03298261 : fffff800`034f9f88 fffff8a0`11d1c010 fffff800`034342d8 fffff800`034342d8 : nt! ?? ::NNGAKEGL::`string’+0x54d9b
fffff880`03bd2b70 fffff800`0352b2ea : 00000000`00000000 fffffa80`07005660 00000000`00000080 fffffa80`06f8d890 : nt!ExpWorkerThread+0x111
fffff880`03bd2c00 fffff800`0327f8e6 : fffff880`03965180 fffffa80`07005660 fffff880`0396ffc0 00000000`00000000 : nt!PspSystemThreadStartup+0x5a
fffff880`03bd2c40 00000000`00000000 : fffff880`03bd3000 fffff880`03bcd000 fffff880`03bd2410 00000000`00000000 : nt!KxStartSystemThread+0x16

A brief explanation is looking at the callstack we can see ndis functions calling the ZTEusbnet network driver about a PnP event, this looks like it’s due to the power IRP being sent down the stack but it’s being blocked by the network driver so it cannot get to the bottom f the stack, which I believe in this case is the pci.sys but I’m not too sure given it’s a USB network card and not a pci card.

So let’s look at the IRP.

0: kd> !irp fffffa8008f5cc10 7
Irp is active with 10 stacks 10 is current (= 0xfffffa8008f5cf68)
 No Mdl: No System Buffer: Thread fffffa8007005660:  Irp stack trace. 
Flags = 00000000
ThreadListEntry.Flink = fffffa8007005a50
ThreadListEntry.Blink = fffffa8007005a50
IoStatus.Status = c00000bb
IoStatus.Information = 00000000
RequestorMode = 00000000
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = fffff88003bd27c0
UserEvent = fffff88003bd27d0
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 – 00000000
CancelRoutine = 00000000  
UserBuffer = 00000000
&Tail.Overlay.DeviceQueueEntry = fffffa8008f5cc88
Tail.Overlay.Thread = fffffa8007005660
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = fffffa8008f5cf68
Tail.Overlay.OriginalFileObject = 00000000
Tail.Apc = 00000000
Tail.CompletionKey = 00000000
     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
>[ 1b,17]   0  0 fffffa800c089050 00000000 00000000-00000000   
           \Driver\ZTEusbnet

            Args: 00000000 00000000 00000000 00000000
IO verifier information:
No information available – the verifier is probably disabled

So here we can see the IRP reached ZTEusbnet but stopped there, so I think this driver is to blame.
One last thing, let’s look at the device object.

0: kd> !devobj fffffa800c089050
Device object (fffffa800c089050) is for:
 NDMP14 \Driver\ZTEusbnet DriverObject fffffa800deeae70
Current Irp 00000000 RefCount 0 Type 00000017 Flags 00002050
Dacl fffff9a10009b881 DevExt fffffa800c0891a0 DevObjExt fffffa800c08a8c0
ExtensionFlags (0x00000800)  DOE_DEFAULT_SD_PRESENT
Characteristics (0x00000100)  FILE_DEVICE_SECURE_OPEN
AttachedTo (Lower) fffffa80070bfa00 \Driver\usbccgp
Device queue is not busy.

So we can see the network driver is the upper layer and the usbccgp is the lower layer which is a USB bus driver.
The way around this I believe would be to update the driver as I’ve had no reply from the OP since.

I checked the timestamp for the network driver and it’s very outdated which is probably why it was causing such issues.

0: kd> lm vm ZTEusbnet
start             end                 module name
fffff880`0ae8e000 fffff880`0aebc000   ZTEusbnet   (no symbols)          
    Loaded symbol image file: ZTEusbnet.sys
    Image path: \SystemRoot\system32\DRIVERS\ZTEusbnet.sys
    Image name: ZTEusbnet.sys
    Timestamp:        Mon Oct 13 06:50:10 2008 (48F2E192)
    CheckSum:         000329ED
    ImageSize:        0002E000
    Translations:     0000.04b0 0000.04e4 0409.04b0 0409.04e4

Hope you enjoyed reading.

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s