none
The system BSOD when test runtime Power Focused Stress with Driver Verifier's Concurrency Stress RRS feed

  • Question

  • Hi friend,

    Thanks for any advise in advance. FAULTING_MODULE is vwifibus.sys. The following is windgb analysis:

    0: kd> !analyze -v
    *******************************************************************************
    *                                                                             *
    *                        Bugcheck Analysis                                    *
    *                                                                             *
    *******************************************************************************

    DRIVER_POWER_STATE_FAILURE (9f)
    A driver has failed to complete a power IRP within a specific time (usually 10 minutes).
    Arguments:
    Arg1: 00000004, The power transition timed out waiting to synchronize with the Pnp
     subsystem.
    Arg2: 0000012c, Timeout in seconds.
    Arg3: c43fa380, The thread currently holding on to the Pnp lock.
    Arg4: 80866e04, nt!TRIAGE_9F_PNP on Win7

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

    Implicit thread is now c43fa380

    DRVPOWERSTATE_SUBCODE:  4

    IMAGE_NAME:  vwifibus.sys

    DEBUG_FLR_IMAGE_TIMESTAMP:  5010ace9

    MODULE_NAME: vwifibus

    FAULTING_MODULE: 80f96000 vwifibus

    DEFAULT_BUCKET_ID:  WIN8_DRIVER_FAULT

    BUGCHECK_STR:  0x9F

    PROCESS_NAME:  System

    CURRENT_IRQL:  2

    STACK_TEXT: 
    80866de4 81332562 0000009f 00000004 0000012c nt!KeBugCheckEx
    80866e10 8147f3c2 80866ed0 813fd788 9a2a5ad8 nt!PnpBugcheckPowerTimeout+0x5b
    80866e18 813fd788 9a2a5ad8 9a2a5af8 74854380 nt!PopBuildDeviceNotifyListWatchdog+0x16
    80866ed0 813fd3d2 93c6d1c0 80866f18 827f1d30 nt!KiExecuteAllDpcs+0x1f2
    80866ff4 81388a3c 827f1c3c 00000000 00000000 nt!KiRetireDpcList+0xed
    80866ff8 827f1c3c 00000000 00000000 00000000 nt!KiDispatchInterrupt+0x2c
    WARNING: Frame IP not in any known module. Following frames may be wrong.
    81388a3c 00000000 00000023 010e850f bb830000 0x827f1c3c


    STACK_COMMAND:  kb

    FOLLOWUP_NAME:  MachineOwner

    FAILURE_BUCKET_ID:  0x9F_VRF_4_vwifimp_IMAGE_vwifibus.sys

    BUCKET_ID:  0x9F_VRF_4_vwifimp_IMAGE_vwifibus.sys

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

    Friday, November 23, 2012 6:48 AM

Answers

  • As the !analyze alludes to, a bugcheck 0x9F occurs when the system is blocked, usually from shutting down.  The !pnptriage output above shows that thread c43fa380 - which is processing the surprise removal for your ndis miniport - is currently blocked waiting for the thread 89e12d40 to release the Mutant object. 

    If you do a !thread 89e12d40, it may show that it is also blocked waiting for an object, perhaps in this (c43fa380) thread, or perhaps in another thread which in turn is waiting for this one, etc...  Also, for what it's worth, a67e3780 is likely waiting for the "Pnp lock" (mentioned in the !analyze output above), which it indicates c43fa380 is holding.

    At this point it's a matter of discovering why c43fa380 is blocked, which should like in 89e12d40.  If 89e12d40 is blocked, then discovering why that one is blocked, etc. This is the classic deadlock situation:  thread A has resource X and wants resource Y, while thread B has resource Y and wants resource X, and neither can move in the meantime.

    Monday, November 26, 2012 7:21 PM

All replies

  • Can you share the output of !pnptriage? Thanks.

    This posting is provided AS IS with no warranties, and confers no rights.

    Friday, November 23, 2012 10:38 AM
  • Thanks. The following is the !pnptriage information.

    0: kd> !pnptriage

    ********************************************************************************
    Dumping PnP DeviceAction Queue @ 0x8144a870
    ********************************************************************************

    PnP DeviceActionWorker active!

    Dumping PnP DeviceEvent Queue @ 0x83fa6e90
    List = 0xbcce0cd0, 0xbcce0cd0

    Dumping DeviceEventEntry @ 0xbcce0cd0
      ListEntry = 0x83fa6ed4, 0x83fa6ed4, Argument = 0x00000000
      CallerEvent = 0xbc3e7a84, Callback = 0x00000000, Context = 0x00000000
      VetoType = 0x00000000, VetoName = 0x00000000

      Dumping PlugPlayEventBlock @ 0xBCCE0D00
        EventGuid = GUID_DEVICE_NOOP
        Category = TargetDeviceChangeEvent
        Result = 0xbc3e7a94, Flags = 0x00000000, TotalSize = 68
        DeviceObject = 0x00000000
          DeviceId:


      Total events in the list: 1

    ********************************************************************************
    Dumping PnP DeviceCompletion Queue @ 0x8144ce00
    ********************************************************************************

    0 Pnp operation(s) dispatched (IRP pending) currently.

    Dumping pending asynchronous request list...

    Dumping completed asynchronous request list...

    ********************************************************************************
    Dumping devnodes with problems...
    ********************************************************************************

    Dumping IopRootDeviceNode (= 0x83f66ac0)
    DevNode 0x89f45620 for PDO 0x89f446f8
      InstancePath is "ACPI\INTCF0C\1"
      State = DeviceNodeInitialized (0x302)
      Previous State = DeviceNodeUninitialized (0x301)
      Problem = CM_PROB_FAILED_INSTALL

    ********************************************************************************
    Dumping PnP locks...
    ********************************************************************************


    Resource @ nt!PiEngineLock (0x8144cf00)    Exclusively owned
        Contention Count = 372
        NumberOfExclusiveWaiters = 1
         Threads: c43fa380-01<*>
         Threads Waiting On Exclusive Access:
                  93c7d100      

    1 total locks, 1 locks currently held

    Resource @ nt!IopDeviceTreeLock (0x8144ce80)    Shared 1 owning threads
        Contention Count = 5
         Threads: c43fa380-01<*>
    1 total locks, 1 locks currently held

    Resource @ nt!PnpRegistryDeviceResource (0x8144cfc0)    Available
        Contention Count = 5049
    1 total locks

    ********************************************************************************
    If one or more of above are NOT available, do !thread on the owner thread to find the thread hung in PnP
    ********************************************************************************


    ********************************************************************************
    Dumping currently active PnP thread (if any)...
    ********************************************************************************

    Dumping device action thread...

    THREAD a67e3780  Cid 0004.161c  Teb: 00000000 Win32Thread: 00000000 WAIT: (Executive) KernelMode Non-Alertable
        bc3e7a84  NotificationEvent
    Not impersonating
    DeviceMap                 81e09ef0
    Owning Process            83f5a680       Image:         System
    Attached Process          N/A            Image:         N/A
    Wait Start TickCount      1829911        Ticks: 19201 (0:00:05:00.015)
    Context Switch Count      219819         IdealProcessor: 0  NoStackSwap
    UserTime                  00:00:00.000
    KernelTime                00:01:21.390
    Win32 Start Address nt!ExpWorkerThread (0x81272fb0)
    Stack Init bc3e7de0 Current bc3e7934 Base bc3e8000 Limit bc3e5000 Call 0
    Priority 15 BasePriority 12 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
    ChildEBP RetAddr  Args to Child             
    bc3e794c 813fc4a3 00000f00 bc3e7a84 a67e3780 nt!KiSwapContext+0x19 (FPO: [Uses EBP] [1,0,4])
    bc3e79c0 813fbb7d a67e3780 a67e3860 00000000 nt!KiCommitThreadWait+0x280 (FPO: [5,23,4])
    bc3e7a5c 815bf9e1 bc3e7a84 00000000 00000000 nt!KeWaitForSingleObject+0x269 (FPO: [Non-Fpo])
    bc3e7a98 81503680 af5a2690 8ce12ca0 00000001 nt!PnpSynchronizeDeviceEventQueue+0x64 (FPO: [Non-Fpo])
    bc3e7c8c 8152790c 8ce12ca0 af5a2690 bc3e7cbc nt!PipProcessDevNodeTree+0x51c (FPO: [Non-Fpo])
    bc3e7cc8 812b5bf2 81431578 a67e3780 81431480 nt!PiProcessReenumeration+0x75 (FPO: [Non-Fpo])
    bc3e7d1c 812730bd 00000000 a67e3780 00000000 nt!PnpDeviceActionWorker+0x116 (FPO: [1,15,4])
    bc3e7d74 812dc8e5 00010000 3dee1da4 00000000 nt!ExpWorkerThread+0x111 (FPO: [1,15,4])
    bc3e7db0 81389259 81272fb0 00010000 00000000 nt!PspSystemThreadStartup+0x4a (FPO: [Non-Fpo])
    00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x19

    Dumping device event thread...

    THREAD c43fa380  Cid 0004.1148  Teb: 00000000 Win32Thread: 00000000 WAIT: (Executive) KernelMode Non-Alertable
        8b9ceec8  Mutant - owning thread 89e12d40
    IRP List:
        b4850ed8: (0006,0124) Flags: 40000000  Mdl: 00000000
    Not impersonating
    DeviceMap                 81e09ef0
    Owning Process            83f5a680       Image:         System
    Attached Process          N/A            Image:         N/A
    Wait Start TickCount      1829911        Ticks: 19201 (0:00:05:00.015)
    Context Switch Count      53258          IdealProcessor: 0  NoStackSwap
    UserTime                  00:00:00.000
    KernelTime                00:00:20.812
    Win32 Start Address nt!ExpWorkerThread (0x81272fb0)
    Stack Init 8bf61de0 Current 8bf61674 Base 8bf62000 Limit 8bf5f000 Call 0
    Priority 15 BasePriority 12 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
    ChildEBP RetAddr  Args to Child             
    8bf6168c 813fc4a3 00001200 8b9ceec8 c43fa380 nt!KiSwapContext+0x19 (FPO: [Uses EBP] [1,0,4])
    8bf61704 813fbb7d c43fa380 c43fa460 00000000 nt!KiCommitThreadWait+0x280 (FPO: [5,23,4])
    8bf617a0 816fd6fb 8b9ceec8 00000000 00000000 nt!KeWaitForSingleObject+0x269 (FPO: [Non-Fpo])
    8bf617d4 84f01347 8b9ceec8 00000000 00000000 nt!VerifierKeWaitForSingleObject+0x120 (FPO: [Non-Fpo])
    8bf61874 84f070a1 00ac0de8 8b9cee10 a66f50e8 ndis!ndisUnbindProtocol+0x6e (FPO: [Non-Fpo])
    8bf618d4 84f085a4 a66f50e8 00000001 a66f50e8 ndis!ndisCloseMiniportBindings+0x1cc (FPO: [1,15,4])
    8bf61a00 84eed928 a66f5030 b4850ed8 a66f5128 ndis!ndisPnPRemoveDevice+0x1ce (FPO: [2,69,4])
    8bf61a20 84eed78e a66f5030 b4850ed8 b4850ed8 ndis!ndisPnPRemoveDeviceEx+0x67 (FPO: [Non-Fpo])
    8bf61a3c 84efb739 a66f5030 a66f50e8 b4850ed8 ndis!ndisPnPIrpSurpriseRemoval+0xc9 (FPO: [Non-Fpo])
    8bf61a70 816edf8b a66f5030 b4850ed8 b4850ed8 ndis! ?? ::NNGAKEGL::`string'+0x6892
    8bf61a90 81280d25 817056c3 b4850fd0 b4850ff4 nt!IovCallDriver+0x2e3 (FPO: [Non-Fpo])
    8bf61aa4 817056c3 8bf61acc 817058c3 a66f5030 nt!IofCallDriver+0x62 (FPO: [Non-Fpo])
    8bf61aac 817058c3 a66f5030 b4850ed8 a6668278 nt!ViFilterIoCallDriver+0x10 (FPO: [Non-Fpo])
    8bf61acc 816edf8b a6668278 a66f5030 a6668278 nt!ViFilterDispatchPnp+0x6f (FPO: [Non-Fpo])
    8bf61aec 81280d25 8154d330 b4850ffc 8bf61b90 nt!IovCallDriver+0x2e3 (FPO: [Non-Fpo])
    8bf61b00 8154d330 a6668008 a6733540 00000017 nt!IofCallDriver+0x62 (FPO: [Non-Fpo])
    8bf61b30 8152220a a6733540 8bf61b6c c00000bb nt!IopSynchronousCall+0x9c (FPO: [4,7,4])
    8bf61b90 81523728 a6733540 00000017 a6668008 nt!IopRemoveDevice+0xc3 (FPO: [2,15,4])
    8bf61bc4 81524b0c 0000030e a6668008 00000000 nt!PnpSurpriseRemoveLockedDeviceNode+0x99 (FPO: [Non-Fpo])
    8bf61be0 8152475c 00000003 00000000 00000000 nt!PnpDeleteLockedDeviceNode+0x3b (FPO: [Non-Fpo])
    8bf61c14 815242d3 a6733540 bcc2b820 00000003 nt!PnpDeleteLockedDeviceNodes+0x66 (FPO: [7,3,4])
    8bf61ccc 8150b6f8 8bf61d0c c2069e00 00000000 nt!PnpProcessQueryRemoveAndEject+0x22c (FPO: [Non-Fpo])
    8bf61cec 8150bd40 aa1cd458 81431578 c43fa380 nt!PnpProcessTargetDeviceEvent+0x75 (FPO: [Non-Fpo])
    8bf61d1c 812730bd c320b670 c43fa380 00000000 nt!PnpDeviceEventWorker+0x241 (FPO: [1,5,4])
    8bf61d74 812dc8e5 00010000 0a267da4 00000000 nt!ExpWorkerThread+0x111 (FPO: [1,15,4])
    8bf61db0 81389259 81272fb0 00010000 00000000 nt!PspSystemThreadStartup+0x4a (FPO: [Non-Fpo])
    00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x19

     

    Monday, November 26, 2012 2:34 AM
  • As the !analyze alludes to, a bugcheck 0x9F occurs when the system is blocked, usually from shutting down.  The !pnptriage output above shows that thread c43fa380 - which is processing the surprise removal for your ndis miniport - is currently blocked waiting for the thread 89e12d40 to release the Mutant object. 

    If you do a !thread 89e12d40, it may show that it is also blocked waiting for an object, perhaps in this (c43fa380) thread, or perhaps in another thread which in turn is waiting for this one, etc...  Also, for what it's worth, a67e3780 is likely waiting for the "Pnp lock" (mentioned in the !analyze output above), which it indicates c43fa380 is holding.

    At this point it's a matter of discovering why c43fa380 is blocked, which should like in 89e12d40.  If 89e12d40 is blocked, then discovering why that one is blocked, etc. This is the classic deadlock situation:  thread A has resource X and wants resource Y, while thread B has resource Y and wants resource X, and neither can move in the meantime.

    Monday, November 26, 2012 7:21 PM
  • Thanks for your detail analysis. However how to fix this problem, which module causes it?
    Thursday, November 29, 2012 9:20 AM
  • Did you look to see what 89e12d40 is doing - !thread 89e12d40? As Michael mentioned above, this thread owns the mutant object and is blocking c43fa380 from making progress.

    This posting is provided AS IS with no warranties, and confers no rights.

    Thursday, November 29, 2012 9:48 AM