Using WinDBG to troubleshoot Windows BugCheck 9F – DRIVER_POWER_STATE_FAILURE


Microsoft (R) Windows Debugger Version 6.11.0001.404 X86
Copyright (c) Microsoft Corporation. All rights reserved.Loading Dump File [C:WindowsMEMORY.DMP]
Kernel Summary Dump File: Only kernel address space is available

Symbol search path is: SRV*c:websymbols*http://msdl.microsoft.com/download/symbols
Executable search path is:
Windows Server 2008/Windows Vista Kernel Version 6002 (Service Pack 2) MP (2 procs) Free x86 compatible
Product: WinNt, suite: TerminalServer SingleUserTS
Built by: 6002.18267.x86fre.vistasp2_gdr.100608-0458
Machine Name:
Kernel base = 0x82036000 PsLoadedModuleList = 0x8214dc70
Debug session time: Wed Aug 11 18:35:44.648 2010 (GMT-4)
System Uptime: 0 days 4:19:37.181
Loading Kernel Symbols
………………………………………………………
……………………………………………………….
……………………………
Loading User Symbols

Loading unloaded module list
…………..
*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************

Use !analyze -v to get detailed debugging information.

BugCheck 9F, {3, 8491b970, 86a02030, 8556dbf8}

*** ERROR: Module load completed but symbols could not be loaded for appliand.sys
Probably caused by : appliand.sys

Followup: MachineOwner
———


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: 8491b970, Physical Device Object of the stack
Arg3: 86a02030, Functional Device Object of the stack
Arg4: 8556dbf8, The blocked IRP

Debugging Details:
——————

DRVPOWERSTATE_SUBCODE: 3

IRP_ADDRESS: 8556dbf8

DEVICE_OBJECT: 86a02030

DRIVER_OBJECT: 86cf4e08

IMAGE_NAME: appliand.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 4bffaef4

MODULE_NAME: appliand

FAULTING_MODULE: 8f585000 appliand

DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT

BUGCHECK_STR: 0x9F

PROCESS_NAME: System

CURRENT_IRQL: 2

LAST_CONTROL_TRANSFER: from 820673fb to 82103b8d

STACK_TEXT:
8212bacc 820673fb 0000009f 00000003 8491b970 nt!KeBugCheckEx+0x1e
8212bb28 82067018 8212bb94 8212bc50 82144401 nt!PopCheckIrpWatchdog+0x1ad
8212bb68 820e030b 821444e0 00000000 8952e4aa nt!PopCheckForIdleness+0x343
8212bc88 820dff41 8212bcd0 44b95302 8212bcd8 nt!KiTimerListExpire+0x367
8212bce8 820e0635 00000000 00000000 000f3c82 nt!KiTimerExpiration+0x2a0
8212bd50 820de89d 00000000 0000000e 00000000 nt!KiRetireDpcList+0xba
8212bd54 00000000 0000000e 00000000 00000000 nt!KiIdleLoop+0x49

STACK_COMMAND: kb

FOLLOWUP_NAME: MachineOwner

FAILURE_BUCKET_ID: 0x9F_IMAGE_appliand.sys

BUCKET_ID: 0x9F_IMAGE_appliand.sys

Followup: MachineOwner
———


0: kd> !devobj ffffffff86a02030 f
Device object (86a02030) is for:
NDMP24 DriverappliandMP DriverObject 86cf4e08
Current Irp 00000000 RefCount 0 Type 00000017 Flags 00002050
Dacl 8b65d048 DevExt 86a020e8 DevObjExt 86a02c70
ExtensionFlags (0x00000800)
Unknown flags 0x00000800
AttachedTo (Lower) 8491b970 DriverPnpManager
Device queue is not busy.


0: kd> !drvobj ffffffff86cf4e08 f
Driver object (86cf4e08) is for:
DriverappliandMP
Driver Extension List: (id , addr)
(4e4d4944 86d07010)
Device Object list:
8659e030 869f7360 868d3030 868d2030
86a02030 86a01030 87055030

DriverEntry: 8f58c2d3 appliand
DriverStartIo: 00000000
DriverUnload: 8275ca0e ndis!ndisMUnload
AddDevice: 8275605a ndis!ndisPnPAddDevice

Dispatch routines:
[00] IRP_MJ_CREATE 8267ce79 ndis!ndisCreateIrpHandler
[01] IRP_MJ_CREATE_NAMED_PIPE 8274a78c ndis!ndisDummyIrpHandler
[02] IRP_MJ_CLOSE 8267d309 ndis!ndisCloseIrpHandler
[03] IRP_MJ_READ 8274a78c ndis!ndisDummyIrpHandler
[04] IRP_MJ_WRITE 8274a78c ndis!ndisDummyIrpHandler
[05] IRP_MJ_QUERY_INFORMATION 8274a78c ndis!ndisDummyIrpHandler
[06] IRP_MJ_SET_INFORMATION 8274a78c ndis!ndisDummyIrpHandler
[07] IRP_MJ_QUERY_EA 8274a78c ndis!ndisDummyIrpHandler
[08] IRP_MJ_SET_EA 8274a78c ndis!ndisDummyIrpHandler
[09] IRP_MJ_FLUSH_BUFFERS 8274a78c ndis!ndisDummyIrpHandler
[0a] IRP_MJ_QUERY_VOLUME_INFORMATION 8274a78c ndis!ndisDummyIrpHandler
[0b] IRP_MJ_SET_VOLUME_INFORMATION 8274a78c ndis!ndisDummyIrpHandler
[0c] IRP_MJ_DIRECTORY_CONTROL 8274a78c ndis!ndisDummyIrpHandler
[0d] IRP_MJ_FILE_SYSTEM_CONTROL 8274a78c ndis!ndisDummyIrpHandler
[0e] IRP_MJ_DEVICE_CONTROL 8274b0a7 ndis!ndisDeviceControlIrpHandler
[0f] IRP_MJ_INTERNAL_DEVICE_CONTROL 8274a78c ndis!ndisDummyIrpHandler
[10] IRP_MJ_SHUTDOWN 8274a78c ndis!ndisDummyIrpHandler
[11] IRP_MJ_LOCK_CONTROL 8274a78c ndis!ndisDummyIrpHandler
[12] IRP_MJ_CLEANUP 8274a78c ndis!ndisDummyIrpHandler
[13] IRP_MJ_CREATE_MAILSLOT 8274a78c ndis!ndisDummyIrpHandler
[14] IRP_MJ_QUERY_SECURITY 8274a78c ndis!ndisDummyIrpHandler
[15] IRP_MJ_SET_SECURITY 8274a78c ndis!ndisDummyIrpHandler
[16] IRP_MJ_POWER 82762e1f ndis!ndisPowerDispatch
[17] IRP_MJ_SYSTEM_CONTROL 8274d172 ndis!ndisWMIDispatch
[18] IRP_MJ_DEVICE_CHANGE 8274a78c ndis!ndisDummyIrpHandler
[19] IRP_MJ_QUERY_QUOTA 8274a78c ndis!ndisDummyIrpHandler
[1a] IRP_MJ_SET_QUOTA 8274a78c ndis!ndisDummyIrpHandler


0: kd> !irp 8556dbf8 7
Irp is active with 3 stacks 2 is current (= 0x8556dc8c)
No Mdl: No System Buffer: Thread 00000000: Irp stack trace.
Flags = 00000000
ThreadListEntry.Flink = 8556dc08
ThreadListEntry.Blink = 8556dc08
IoStatus.Status = c00000bb
IoStatus.Information = 00000000
RequestorMode = 00000000
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = 00000000
UserEvent = 00000000
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 – 00000000
CancelRoutine = 00000000
UserBuffer = 00000000
&Tail.Overlay.DeviceQueueEntry = 8556dc38
Tail.Overlay.Thread = 00000000
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 85147860
Tail.Overlay.ListEntry.Blink = 82143f98
Tail.Overlay.CurrentStackLocation = 8556dc8c
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
>[ 16, 2] 0 e1 86a02030 00000000 8230ebf3-8655dba0 Success Error Cancel pending
DriverappliandMP nt!PopSystemIrpCompletion
Args: 00014400 00000000 00000004 00000002
[ 0, 0] 0 0 00000000 00000000 00000000-8655dba0

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


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

Resource @ nt!IopDeviceTreeLock (0x8216a680) Shared 1 owning threads
Threads: 8494d2d8-01<*>
KD: Scanning for held locks.

Resource @ nt!PiEngineLock (0x8216a600) Exclusively owned
Contention Count = 28
NumberOfExclusiveWaiters = 2
Threads: 8494d2d8-01<*>
Threads Waiting On Exclusive Access:
8494d828 8494e020

KD: Scanning for held

locks……………………………………………………………………………………………………….

……………………………………………………………………………………………………………

……………………………………………………………………………………………………………

……………………………………………………………………………………………………………

…………………………
16572 total locks, 2 locks currently held


0: kd> !thread 8494d2d8
THREAD 8494d2d8 Cid 0004.0044 Teb: 00000000 Win32Thread: 00000000 WAIT: (Executive) KernelMode Non-Alertable
8b96ba04 Semaphore Limit 0x24
Not impersonating
DeviceMap 8b608728
Owning Process 8490f910 Image: System
Attached Process N/A Image: N/A
Wait Start TickCount 959990 Ticks: 38540 (0:00:10:01.227)
Context Switch Count 56424 NoStackSwap
UserTime 00:00:00.000
KernelTime 00:00:08.424
Win32 Start Address nt!ExpWorkerThread (0x820dbd25)
Stack Init 8b96c000 Current 8b96b910 Base 8b96c000 Limit 8b969000 Call 0
Priority 14 BasePriority 12 PriorityDecrement 1 IoPriority 2 PagePriority 5
ChildEBP RetAddr Args to Child
8b96b928 820e2352 8494d2d8 8494d360 8213813c nt!KiSwapContext+0x26 (FPO: [Uses EBP] [0,0,4])
8b96b96c 8207df28 8494d2d8 00000000 87072450 nt!KiSwapThread+0x44f
8b96b9c4 8230e9de 8b96ba04 00000000 00000000 nt!KeWaitForSingleObject+0x492
8b96ba44 8230e674 00000002 8b96bad8 8b96baf0 nt!PopSleepDeviceList+0x12a
8b96baa4 8230e413 8b96bab8 00000002 00000000 nt!PoBroadcastSystemState+0x251
8b96bad8 8230f55f 9f1a9366 8b96bc10 8b96bc94 nt!PopSetDevicesSystemState+0x7b
8b96bbfc 82080c7a 00000002 00000000 00000000 nt!NtSetSystemPowerState+0x4b4
8b96bbfc 8207fb8d 00000002 00000000 00000000 nt!KiFastCallEntry+0x12a (FPO: [0,3] TrapFrame @ 8b96bc10)
8b96bc80 822c3f45 00000002 00000004 a0000000 nt!ZwSetSystemPowerState+0x11 (FPO: [3,0,0])
8b96bccc 822c38d8 00000000 00000002 00000004 nt!PopIssueActionRequest+0x352
8b96bd08 8206691e 9f1a95de 8213813c 8494d2d8 nt!PopPolicyWorkerAction+0x45
8b96bd44 820dbe22 0000000c 00000000 8494d2d8 nt!PopPolicyWorkerThread+0x6e
8b96bd7c 8220bc42 80000000 9f1a955a 00000000 nt!ExpWorkerThread+0xfd
8b96bdc0 82074f4e 820dbd25 00000001 00000000 nt!PspSystemThreadStartup+0x9d
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16


0: kd> !locks -v 8216a680

Resource @ nt!IopDeviceTreeLock (0x8216a680) Shared 1 owning threads
Threads: 8494d2d8-01<*>

THREAD 8494d2d8 Cid 0004.0044 Teb: 00000000 Win32Thread: 00000000 WAIT: (Executive) KernelMode Non-Alertable
8b96ba04 Semaphore Limit 0x24
Not impersonating
DeviceMap 8b608728
Owning Process 8490f910 Image: System
Attached Process N/A Image: N/A
Wait Start TickCount 959990 Ticks: 38540 (0:00:10:01.227)
Context Switch Count 56424 NoStackSwap
UserTime 00:00:00.000
KernelTime 00:00:08.424
Win32 Start Address nt!ExpWorkerThread (0x820dbd25)
Stack Init 8b96c000 Current 8b96b910 Base 8b96c000 Limit 8b969000 Call 0
Priority 14 BasePriority 12 PriorityDecrement 1 IoPriority 2 PagePriority 5
ChildEBP RetAddr
8b96b928 820e2352 nt!KiSwapContext+0x26 (FPO: [Uses EBP] [0,0,4])
8b96b96c 8207df28 nt!KiSwapThread+0x44f
8b96b9c4 8230e9de nt!KeWaitForSingleObject+0x492
8b96ba44 8230e674 nt!PopSleepDeviceList+0x12a
8b96baa4 8230e413 nt!PoBroadcastSystemState+0x251
8b96bad8 8230f55f nt!PopSetDevicesSystemState+0x7b
8b96bbfc 82080c7a nt!NtSetSystemPowerState+0x4b4
8b96bbfc 8207fb8d nt!KiFastCallEntry+0x12a (FPO: [0,3] TrapFrame @ 8b96bc10)
8b96bc80 822c3f45 nt!ZwSetSystemPowerState+0x11 (FPO: [3,0,0])
8b96bccc 822c38d8 nt!PopIssueActionRequest+0x352
8b96bd08 8206691e nt!PopPolicyWorkerAction+0x45
8b96bd44 820dbe22 nt!PopPolicyWorkerThread+0x6e
8b96bd7c 8220bc42 nt!ExpWorkerThread+0xfd
8b96bdc0 82074f4e nt!PspSystemThreadStartup+0x9d
00000000 00000000 nt!KiThreadStartup+0x16

1 total locks, 1 locks currently held


Leave a Reply