Monday, November 28, 2011

How To Troubleshoot 0x9F DRIVER_POWER_STATE_FAILURE

The Debugging Tools for Windows are required to analyze crash dump files. If you do not have the Debugging Tools for Windows installed or dump files are not being generated on system crash, see this post for installation/configuration instructions:
http://mikemstech.blogspot.com/2011/11/windows-crash-dump-analysis.html

0x0000009F (and 0x1000009F) is a fairly common bug check that occurs when a device driver does not complete processing on an I/O Request Packet (IRP) in a timely fashion (often 10 minutes). This can occur for a variety of reasons, but the main reasons are due to kernel-mode drivers not properly handling changes in power states (commonly to standby/hibernation and back to a full system working state). 

The system has 6 main power states that are usable, S0 - S5. S0 is a fully awake processing state and S5 is the shutdown state. S1-S3 are standby states and S4 is the hibernating state. To transition between states, the system must return to state S0 (ex. Standby -> Hibernate is actually Standby - > Awake -> Hibernate). If devices and drivers do not correctly handle state transitions (or even queries about the current power state), it is possible for the system to crash with the DRIVER_POWER_STATE_FAILURE.

For most of these errors, the cause is fairly straightforward and the important information can be determined from a minidump.

Example 1: Norton Antivirus (teefer2.sys)


To demonstrate this example, begin with a !analyze -v:
 
0: kd> !analyze -v
*******************************************************************************
*                                                                             *
*                        Bugcheck Analysis                                    *
*                                                                             *
*******************************************************************************

DRIVER_POWER_STATE_FAILURE (9f)
A driver is causing an inconsistent power state.
Arguments:
Arg1: 0000000000000003, A device object has been blocking an Irp for too long a time
Arg2: fffffa80026ae060, Physical Device Object of the stack
Arg3: fffff80000b9c518, Functional Device Object of the stack
Arg4: fffffa8003166010, The blocked IRP

Debugging Details:
------------------


DRVPOWERSTATE_SUBCODE:  3

IRP_ADDRESS:  fffffa8003166010

DEVICE_OBJECT: fffffa800416a050

DRIVER_OBJECT: fffffa80040a3200

IMAGE_NAME:  teefer2.sys

DEBUG_FLR_IMAGE_TIMESTAMP:  4a0b1ec0

MODULE_NAME: teefer2

FAULTING_MODULE: fffff88003da9000 teefer2

CUSTOMER_CRASH_COUNT:  1

DEFAULT_BUCKET_ID:  VISTA_DRIVER_FAULT

BUGCHECK_STR:  0x9F

PROCESS_NAME:  System

CURRENT_IRQL:  2

STACK_TEXT:  
fffff800`00b9c4c8 fffff800`02d3ee23 : 00000000`0000009f 00000000`00000003 fffffa80`026ae060 fffff800`00b9c518 : nt!KeBugCheckEx
fffff800`00b9c4d0 fffff800`02cdbfa6 : fffff800`00b9c678 fffff800`00b9c678 00000000`00000001 00000000`00000000 : nt! ?? ::FNODOBFM::`string'+0x29330
fffff800`00b9c570 fffff800`02cdb326 : fffffa80`03a8b828 fffffa80`03a8b828 00000000`00000000 00000000`00000000 : nt!KiProcessTimerDpcTable+0x66
fffff800`00b9c5e0 fffff800`02cdbe7e : 0000001e`80a56c86 fffff800`00b9cc58 00000000`000ccb2f fffff800`02e4b868 : nt!KiProcessExpiredTimerList+0xc6
fffff800`00b9cc30 fffff800`02cdb697 : 00000008`f6f3d8c7 00000008`000ccb2f 00000008`f6f3d82c 00000000`0000002f : nt!KiTimerExpiration+0x1be
fffff800`00b9ccd0 fffff800`02cd86fa : fffff800`02e48e80 fffff800`02e56c40 00000000`00000000 fffff880`041aadb0 : nt!KiRetireDpcList+0x277
fffff800`00b9cd80 00000000`00000000 : fffff800`00b9d000 fffff800`00b97000 fffff800`00b9cd40 00000000`00000000 : nt!KiIdleLoop+0x5a


STACK_COMMAND:  kb

FOLLOWUP_NAME:  MachineOwner

FAILURE_BUCKET_ID:  X64_0x9F_3_IMAGE_teefer2.sys

BUCKET_ID:  X64_0x9F_3_IMAGE_teefer2.sys

Followup: MachineOwner
---------
 
In this case, parameter 4 of the bugcheck is the IRP that is being blocked. We can look a little closer using the !irp extension command:
0: kd> !irp fffffa8003166010
Irp is active with 3 stacks 2 is current (= 0xfffffa8003166128)
 No Mdl: No System Buffer: Thread 00000000:  Irp stack trace.  
     cmd  flg cl Device   File     Completion-Context
 [  0, 0]   0  0 00000000 00000000 00000000-00000000    

   Args: 00000000 00000000 00000000 00000000
>[ 16, 3]   0 e1 fffffa800416a050 00000000 fffff80002f19f70-fffffa800267c2b0 Success Error Cancel pending
        \Driver\Teefer2 nt!PopSystemIrpCompletion
   Args: 00015400 00000000 00000005 00000003
 [  0, 0]   0  0 00000000 00000000 00000000-fffffa800267c2b0

 
The IRP shows that the completion call for the Teefer2 driver is pending. In this case, the Norton antivirus (or Endpoint Security or ...) software should be updated to the latest version. If there are no updates and the Symantec is unhelpful, then it may be easier to replace the antivirus program with another one. No antivirus program is perfect, this issue has occurred with Avira, TrendMicro, AVG, McAfee, and many others...

Example 2: FTDI Chip Issue


To demonstrate this example, begin with a !analyze -v:
0: kd> !analyze -v
*******************************************************************************
*                                                                             *
*                        Bugcheck Analysis                                    *
*                                                                             *
*******************************************************************************

DRIVER_POWER_STATE_FAILURE (9f)
A driver is causing an inconsistent power state.
Arguments:
Arg1: 00000003, A device object has been blocking an Irp for too long a time
Arg2: 88ce8d60, Physical Device Object of the stack
Arg3: 82b2dae0, Functional Device Object of the stack
Arg4: 88724df8, The blocked IRP

Debugging Details:
------------------

*** WARNING: Unable to verify timestamp for ftdibus.sys
*** ERROR: Module load completed but symbols could not be loaded for ftdibus.sys

DRVPOWERSTATE_SUBCODE:  3

IMAGE_NAME:  ftdibus.sys

DEBUG_FLR_IMAGE_TIMESTAMP:  4ae0760c

MODULE_NAME: ftdibus

FAULTING_MODULE: 9275e000 ftdibus

CUSTOMER_CRASH_COUNT:  1

DEFAULT_BUCKET_ID:  VISTA_DRIVER_FAULT

BUGCHECK_STR:  0x9F

PROCESS_NAME:  System

CURRENT_IRQL:  2

STACK_TEXT:  
82b2da94 82a43054 0000009f 00000003 88ce8d60 nt!KeBugCheckEx+0x1e
82b2db00 82a428e8 82b2dba0 00000000 82b3a280 nt!PopCheckIrpWatchdog+0x1f5
82b2db38 82a7104d 82b48a20 00000000 61ef7a8f nt!PopCheckForIdleness+0x73
82b2db7c 82a70ff1 82b30d20 82b2dca8 00000001 nt!KiProcessTimerDpcTable+0x50
82b2dc68 82a70eae 82b30d20 82b2dca8 00000000 nt!KiProcessExpiredTimerList+0x101
82b2dcdc 82a6f20e 00063037 87b0bd48 82b3a280 nt!KiTimerExpiration+0x25c
82b2dd20 82a6f038 00000000 0000000e 00000000 nt!KiRetireDpcList+0xcb
82b2dd24 00000000 0000000e 00000000 00000000 nt!KiIdleLoop+0x38


STACK_COMMAND:  kb

FOLLOWUP_NAME:  MachineOwner

FAILURE_BUCKET_ID:  0x9F_3_ftser2k_IMAGE_ftdibus.sys

BUCKET_ID:  0x9F_3_ftser2k_IMAGE_ftdibus.sys

Followup: MachineOwner
---------

 
In this case, parameter 4 of the bugcheck is the IRP that is being blocked. We can look a little closer using the !irp extension command:
0: kd> !irp 88724df8
Irp is active with 4 stacks 2 is current (= 0x88724e8c)
 No Mdl: No System Buffer: Thread 00000000:  Irp stack trace.  
     cmd  flg cl Device   File     Completion-Context
 [  0, 0]   0  0 00000000 00000000 00000000-00000000    

   Args: 00000000 00000000 00000000 00000000
>[ 16, 2]   0  0 88cf4038 00000000 00000000-00000000    
       Unable to load image \SystemRoot\system32\drivers\ftser2k.sys, Win32 error 0n2
*** WARNING: Unable to verify timestamp for ftser2k.sys
*** ERROR: Module load completed but symbols could not be loaded for ftser2k.sys
 \Driver\FTSER2K
   Args: 00012200 00000001 00000003 00000002
 [ 16, 2]   0 e1 88cec3e8 00000000 82a90871-896502d8 Success Error Cancel pending
        \Driver\Serenum nt!IopUnloadSafeCompletion
   Args: 00012200 00000001 00000003 00000002
 [  0, 0]   0  0 00000000 00000000 00000000-87bbcf18    

   Args: 00000000 00000000 00000000 00000000

 
In this case, 2 pending IRPs are shown, the one with the > is the current IRP. In this case the problem was actually due to the ftser2k.sys driver (not the ftdibus.sys driver that was shown in the main !analyze -v output. This demonstrates an important point... Always check the IRP to determine the driver that is responsible for the hang.

This fix for this error is typically updating the drivers that are associated with the FTDI Chip (and in general for the drivers that cause the IRP to hang). If the driver update does not seem to help, other suggestions are to change the port and/or replace the device encountering the issue.

Have an idea for something that you'd like to see explored? Leave a comment or send an e-mail to razorbackx_at_gmail<dot>com

See Also,

Windows Crash Dump Analysis


No comments:

Post a Comment