HwScsiStartIo never called on resume from hibernate

NTDEV
1

What would cause scsiport to not call my HwScsiStartIo on resume from
hibernation? The first and second resumes always appear to work
correctly, but the third or fourth fail. HwScsiAdapterControl is called,
and it returns ScsiAdapterControlSuccess as it should. This is under XP.

No scsi reset is issued (but then that’s kind of expected if there are
no outstanding requests), and I can ping the system, and it doesn’t
crash or anything even after 2 days, it just sits there at the textmode
‘restore from hibernation’ screen.

Given that it’s failing after the third or fourth hibernate I’m guessing
that I’m leaking some resource, but I can’t see what. Is there anything
useful the debugger could tell me (not that it’s much fun debugging over
a hibernate/resume cycle).

All suggestions appreciated!

Thanks

James

2

>

What would cause scsiport to not call my HwScsiStartIo on resume from
hibernation? The first and second resumes always appear to work
correctly, but the third or fourth fail. HwScsiAdapterControl is
called,
and it returns ScsiAdapterControlSuccess as it should. This is under
XP.

No scsi reset is issued (but then that’s kind of expected if there are
no outstanding requests), and I can ping the system, and it doesn’t
crash or anything even after 2 days, it just sits there at the
textmode
‘restore from hibernation’ screen.

Given that it’s failing after the third or fourth hibernate I’m
guessing
that I’m leaking some resource, but I can’t see what. Is there
anything
useful the debugger could tell me (not that it’s much fun debugging
over
a hibernate/resume cycle).

All suggestions appreciated!

I’m trying to work my way through the debugger… my driver is called
XenVbd:

kd> !devobj 0x81fb4458
Device object (81fb4458) is for:
XenVbd1Port0Path0Target0Lun0 \Driver\XenVbd DriverObject 81ec4328
Current Irp 00000000 RefCount 0 Type 00000007 Flags 00001050
Dacl e10192bc DevExt 81fb4510 DevObjExt 81fb49f0 Dope 81eab8f8 DevNode
82140008
ExtensionFlags (0xc0000000) DOE_BOTTOM_OF_FDO_STACK, DOE_DESIGNATED_FDO
AttachedDevice (Upper) 81d78ab8 \Driver\Disk
DeviceQueue: 81e62270 81ce9008 81aa2500 81cf7608
81df29a0 82016e68 81dfc8e8 81d0fda8
81d185a8 81d4e668 81d731c8 81fc1f48
81d102a0 81f22b48 81fc3c50 81d089e8
81cf81b0 81d17e50 81d0c2a0 81c8b398
81d1a878 81c8b138 81cf8410 81cfc008
81e5cda8 81cc2230 81d73da8 81d4fce8
81cceda8 81d1ae50 81c7a990

So that looks like there are a bunch of IRP’s banked up there right?

kd> !devobj 0x81e785a8
Device object (81e785a8) is for:
0000003b \Driver\XenPCI DriverObject 8217dad8
Current Irp 00000000 RefCount 0 Type 00000004 Flags 00001044
Dacl e13634e4 DevExt 81e78210 DevObjExt 81e78678 DevNode 81d79ee8
ExtensionFlags (0xc0000000) DOE_BOTTOM_OF_FDO_STACK, DOE_DESIGNATED_FDO
AttachedDevice (Upper) 81ee0d28 \DRIVER\VERIFIER
Device queue is not busy.

kd> !devobj 81ee0d28
Device object (81ee0d28) is for:
\DRIVER\VERIFIER DriverObject 81e47340
Current Irp 00000000 RefCount 0 Type 00000022 Flags 00000004
DevExt 81ee0de0 DevObjExt 81ee0df0
ExtensionFlags (0xd0000000) DOE_BOTTOM_OF_FDO_STACK, DOE_DESIGNATED_FDO
Unknown flags 0x10000000
AttachedDevice (Upper) 81ee0738 \Driver\XenVbd
AttachedTo (Lower) 81e785a8 \Driver\XenPCI
Device queue is not busy.

kd> !devobj 81ee0738
Device object (81ee0738) is for:
XenVbd1 \Driver\XenVbd DriverObject 81ec4328
Current Irp 81d22408 RefCount 0 Type 00000004 Flags 00000050
Dacl e13634e4 DevExt 81ee07f0 DevObjExt 81ee0cd8
ExtensionFlags (0xe0000000) DOE_RAW_FDO, DOE_BOTTOM_OF_FDO_STACK,
DOE_DESIGNATED_FDO
AttachedDevice (Upper) 81ee0610 \DRIVER\VERIFIER
AttachedTo (Lower) 81ee0d28 \DRIVER\VERIFIER
Device queue is busy – Queue empty.

So there’s a current IRP…

kd> !irp 81d22408
Irp is active with 5 stacks 1 is current (= 0x81d22478)
No Mdl: No System Buffer: Thread 00000000: Irp stack trace. Pending
has been returned
cmd flg cl Device File Completion-Context

[f, 0] 0 e1 81fb4458 00000000 f84f48f2-81d78dc0 Success Error
Cancel pending
\Driver\XenVbd CLASSPNP!ClasspPowerUpCompletion
Args: 81d78de4 00000000 00000000 00000000
[16, 2] 0 e1 81d78ab8 00000000 f872776e-00000000 Success Error
Cancel pending
\Driver\Disk PartMgr!PmPowerCompletion
Args: 00000003 00000001 00000001 00000003
[16, 2] 0 e1 81e38938 00000000 80522322-badc780a Success Error
Cancel pending
\Driver\PartMgr nt!PopCompleteRequestIrp
Args: 00000003 00000001 00000001 00000003
[0, 0] 0 0 81e38938 00000000 00000000-00000000
\Driver\PartMgr
Args: 81fb4458 00000002 00000001 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 80558f60 80558f60 81d22408 00000000

So there’s an outstanding power request, I think, but I’m a bit lost
with what the above is telling me. What does “Success Error Cancel
pending” mean? I type “power” into the debugger help index and it
doesn’t have any hits.

XenVbd is my scsiport driver. XenPCI is the bus driver for my scsiport
(and other) devices. XenPCI is a KMDF driver and I see the D0Entry get
called as expected.

Thanks

James

3

I went through the archives and found that I’m just digging over old
ground on this, eg a thread of mine from 3 years ago
http://www.osronline.com/showThread.CFM?link=151567 which still had no
outcome other than Doron suggesting that I make sure I am not setting
DO_POWER_PAGABLE (which I wasn’t).

James

-----Original Message-----
From: xxxxx@lists.osr.com [mailto:bounce-449814-
xxxxx@lists.osr.com] On Behalf Of James Harper
Sent: Monday, 18 April 2011 19:56
To: Windows System Software Devs Interest List
Subject: RE: [ntdev] HwScsiStartIo never called on resume from
hibernate

>
> What would cause scsiport to not call my HwScsiStartIo on resume
from
> hibernation? The first and second resumes always appear to work
> correctly, but the third or fourth fail. HwScsiAdapterControl is
called,
> and it returns ScsiAdapterControlSuccess as it should. This is under
XP.
>
> No scsi reset is issued (but then that’s kind of expected if there
are
> no outstanding requests), and I can ping the system, and it doesn’t
> crash or anything even after 2 days, it just sits there at the
textmode
> ‘restore from hibernation’ screen.
>
> Given that it’s failing after the third or fourth hibernate I’m
guessing
> that I’m leaking some resource, but I can’t see what. Is there
anything
> useful the debugger could tell me (not that it’s much fun debugging
over
> a hibernate/resume cycle).
>
> All suggestions appreciated!
>

I’m trying to work my way through the debugger… my driver is called
XenVbd:

kd> !devobj 0x81fb4458
Device object (81fb4458) is for:
XenVbd1Port0Path0Target0Lun0 \Driver\XenVbd DriverObject 81ec4328
Current Irp 00000000 RefCount 0 Type 00000007 Flags 00001050
Dacl e10192bc DevExt 81fb4510 DevObjExt 81fb49f0 Dope 81eab8f8 DevNode
82140008
ExtensionFlags (0xc0000000) DOE_BOTTOM_OF_FDO_STACK,
DOE_DESIGNATED_FDO
AttachedDevice (Upper) 81d78ab8 \Driver\Disk
DeviceQueue: 81e62270 81ce9008 81aa2500 81cf7608
81df29a0 82016e68 81dfc8e8 81d0fda8
81d185a8 81d4e668 81d731c8 81fc1f48
81d102a0 81f22b48 81fc3c50 81d089e8
81cf81b0 81d17e50 81d0c2a0 81c8b398
81d1a878 81c8b138 81cf8410 81cfc008
81e5cda8 81cc2230 81d73da8 81d4fce8
81cceda8 81d1ae50 81c7a990

So that looks like there are a bunch of IRP’s banked up there right?

kd> !devobj 0x81e785a8
Device object (81e785a8) is for:
0000003b \Driver\XenPCI DriverObject 8217dad8
Current Irp 00000000 RefCount 0 Type 00000004 Flags 00001044
Dacl e13634e4 DevExt 81e78210 DevObjExt 81e78678 DevNode 81d79ee8
ExtensionFlags (0xc0000000) DOE_BOTTOM_OF_FDO_STACK,
DOE_DESIGNATED_FDO
AttachedDevice (Upper) 81ee0d28 \DRIVER\VERIFIER
Device queue is not busy.

kd> !devobj 81ee0d28
Device object (81ee0d28) is for:
\DRIVER\VERIFIER DriverObject 81e47340
Current Irp 00000000 RefCount 0 Type 00000022 Flags 00000004
DevExt 81ee0de0 DevObjExt 81ee0df0
ExtensionFlags (0xd0000000) DOE_BOTTOM_OF_FDO_STACK,
DOE_DESIGNATED_FDO
Unknown flags 0x10000000
AttachedDevice (Upper) 81ee0738 \Driver\XenVbd
AttachedTo (Lower) 81e785a8 \Driver\XenPCI
Device queue is not busy.

kd> !devobj 81ee0738
Device object (81ee0738) is for:
XenVbd1 \Driver\XenVbd DriverObject 81ec4328
Current Irp 81d22408 RefCount 0 Type 00000004 Flags 00000050
Dacl e13634e4 DevExt 81ee07f0 DevObjExt 81ee0cd8
ExtensionFlags (0xe0000000) DOE_RAW_FDO, DOE_BOTTOM_OF_FDO_STACK,
DOE_DESIGNATED_FDO
AttachedDevice (Upper) 81ee0610 \DRIVER\VERIFIER
AttachedTo (Lower) 81ee0d28 \DRIVER\VERIFIER
Device queue is busy – Queue empty.

So there’s a current IRP…

kd> !irp 81d22408
Irp is active with 5 stacks 1 is current (= 0x81d22478)
No Mdl: No System Buffer: Thread 00000000: Irp stack trace. Pending
has been returned
cmd flg cl Device File Completion-Context
>[f, 0] 0 e1 81fb4458 00000000 f84f48f2-81d78dc0 Success Error
Cancel pending
\Driver\XenVbd CLASSPNP!ClasspPowerUpCompletion
Args: 81d78de4 00000000 00000000 00000000
[16, 2] 0 e1 81d78ab8 00000000 f872776e-00000000 Success Error
Cancel pending
\Driver\Disk PartMgr!PmPowerCompletion
Args: 00000003 00000001 00000001 00000003
[16, 2] 0 e1 81e38938 00000000 80522322-badc780a Success Error
Cancel pending
\Driver\PartMgr nt!PopCompleteRequestIrp
Args: 00000003 00000001 00000001 00000003
[0, 0] 0 0 81e38938 00000000 00000000-00000000
\Driver\PartMgr
Args: 81fb4458 00000002 00000001 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 80558f60 80558f60 81d22408 00000000

So there’s an outstanding power request, I think, but I’m a bit lost
with what the above is telling me. What does “Success Error Cancel
pending” mean? I type “power” into the debugger help index and it
doesn’t have any hits.

XenVbd is my scsiport driver. XenPCI is the bus driver for my scsiport
(and other) devices. XenPCI is a KMDF driver and I see the D0Entry get
called as expected.

Thanks

James

NTDEV is sponsored by OSR

For our schedule of WDF, WDM, debugging and other seminars visit:
http://www.osr.com/seminars

To unsubscribe, visit the List Server section of OSR Online at
http://www.osronline.com/page.cfm?name=ListServer

4

Run !stacks 1 command and see if any kernel thread is waiting for paging. Also see whether power worker thread is waiting for anything. Run !exqueue to see if worker threads are deadlocked.

5

James Harper wrote:

So there’s a current IRP…

kd> !irp 81d22408
Irp is active with 5 stacks 1 is current (= 0x81d22478)
No Mdl: No System Buffer: Thread 00000000: Irp stack trace. Pending
has been returned
cmd flg cl Device File Completion-Context

> [f, 0] 0 e1 81fb4458 00000000 f84f48f2-81d78dc0 Success Error
Cancel pending
\Driver\XenVbd CLASSPNP!ClasspPowerUpCompletion
Args: 81d78de4 00000000 00000000 00000000
[16, 2] 0 e1 81d78ab8 00000000 f872776e-00000000 Success Error
Cancel pending
\Driver\Disk PartMgr!PmPowerCompletion
Args: 00000003 00000001 00000001 00000003
[16, 2] 0 e1 81e38938 00000000 80522322-badc780a Success Error
Cancel pending
\Driver\PartMgr nt!PopCompleteRequestIrp
Args: 00000003 00000001 00000001 00000003
[0, 0] 0 0 81e38938 00000000 00000000-00000000
\Driver\PartMgr
Args: 81fb4458 00000002 00000001 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 80558f60 80558f60 81d22408 00000000

So there’s an outstanding power request, I think, but I’m a bit lost
with what the above is telling me. What does “Success Error Cancel
pending” mean?

When you register a completion routine, you can tell it whether the
routine should be called on successful completion, on an error
completion, or on a cancellation. “Success Error Cancel” means the
routine (f84f48f2 in the first case) was registered for all three, as is
commonly done. “Pending” means the “pending” bit is set (i.e.,
IoMarkIrpPending).

–
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.

6

> > So there’s an outstanding power request, I think, but I’m a bit lost

> with what the above is telling me. What does “Success Error Cancel
> pending” mean?

When you register a completion routine, you can tell it whether the
routine should be called on successful completion, on an error
completion, or on a cancellation. “Success Error Cancel” means the
routine (f84f48f2 in the first case) was registered for all three, as
is
commonly done. “Pending” means the “pending” bit is set (i.e.,
IoMarkIrpPending).

Thanks Tim!

James

7

>

Run !stacks 1 command and see if any kernel thread is waiting for
paging.

kd> !stacks 1
Proc.Thread .Thread Ticks ThreadState Blocker
[8215f5f0 System]
4.000008 8215f378 00005e8 Blocked nt!MmZeroPageThread+0x61
4.000010 8215eb30 000122a Blocked Ntfs!NtfsWaitSync+0x1c
4.000014 8215e8b8 000126a Blocked Ntfs!NtfsWaitSync+0x1c
4.000018 8215e640 00014ea Blocked nt!MiWaitForInPageComplete+0x1a
4.00001c 8215e3c8 000136a Blocked Ntfs!NtfsWaitSync+0x1c
4.000020 8215d020 00014e9 Blocked Ntfs!NtfsWaitSync+0x1c
4.000024 8215dda8 00012ea Blocked nt!MiWaitForInPageComplete+0x1a
4.000028 8215db30 0000000 RUNNING nt!KeBugCheckEx+0x1b
4.00002c 8215d8b8 00010b7 Blocked nt!MiWaitForInPageComplete+0x1a
4.000030 8215d640 00014e9 Blocked nt!MiWaitForInPageComplete+0x1a
4.000034 8215d3c8 00014e9 Blocked nt!MiWaitForInPageComplete+0x1a
4.000038 8215c020 00014e9 Blocked nt!MiWaitForInPageComplete+0x1a
4.00003c 8215cda8 00000c9 Blocked
nt!ExAcquireTimeRefreshLock+0x1e
4.000040 8215cb30 00006bd Blocked nt!ExpWorkerThread+0xd6
4.000044 8215c8b8 000002a Blocked
nt!ExpWorkerThreadBalanceManager+0x5e
4.000048 82158020 012fe71 Blocked
nt!MiDereferenceSegmentThread+0x4e
4.00004c 82158da8 0000001 Blocked nt!MiGatherPagefilePages+0x3d
4.000050 82158b30 000002a Blocked nt!KeBalanceSetManager+0x75
4.000054 821588b8 00014ea Blocked
nt!MiMakeOutswappedPageResident+0x347
4.000058 82183da8 01359cd Blocked nt!FsRtlWorkerThread+0x35
4.00005c 82183b30 01359cd Blocked nt!FsRtlWorkerThread+0x35
4.000060 82142340 00014cc Blocked ACPI!ACPIWorker+0x47
4.000064 81eaa4e8 00014ea Blocked Ntfs!NtfsWaitSync+0x1c
4.000068 820e97b8 00014c0 Blocked
wdf01000!FxSystemThread::Thread+0xea
4.00006c 820aa048 00014c1 Blocked
xenpci!XenPci_BalloonThreadProc+0x14e
4.000070 820b9890 0135976 Blocked dmio!voliod_loop+0x399
4.000074 8205f7a0 00014ba Blocked
wdf01000!FxSystemThread::Thread+0xea
4.000078 820e13a0 00014c0 Blocked
wdf01000!FxSystemThread::Thread+0xea
4.00007c 820ba278 012fecb Blocked NDIS!ndisWorkerThread+0x30
4.000090 81f58210 013581f Blocked
rdpdr!RxpWorkerThreadDispatcher+0x4b
4.000094 81f2dda8 013581f Blocked
rdpdr!RxpWorkerThreadDispatcher+0x4b
4.000098 81c37130 013581f Blocked
rdpdr!RxpWorkerThreadDispatcher+0x4b
4.00009c 81f37308 00005e8 Blocked
rdpdr!RxSpinUpRequestsDispatcher+0x58
4.0000a0 81f4f110 012fecc Blocked
raspptp!MainPassiveLevelThread+0x7b
4.0000a4 81f83788 013581e Blocked
raspptp!PacketWorkingThread+0x57
4.000150 81c6b480 0000008 Blocked
USBPORT!USBPORT_WorkerThread+0x3c
4.000160 81ff3da8 01357ee Blocked
rasacd!AcdNotificationRequestThread+0xe2
4.000164 81c99b38 0131233 Blocked
rdbss!RxpWorkerThreadDispatcher+0x4b
4.00016c 81c4ab00 01352a1 Blocked
rdbss!RxpWorkerThreadDispatcher+0x4b
4.000170 81f31d00 00006b9 Blocked nt!MiWaitForInPageComplete+0x1a
4.000210 81ca2020 0130053 Blocked nt!KiFastCallEntry+0xf8
4.0005c0 81c73ac0 01353e8 Blocked
mrxdav!RxpWorkerThreadDispatcher+0x4b
4.0005c4 81a762c8 01353e8 Blocked
mrxdav!RxpWorkerThreadDispatcher+0x4b
4.0005c8 81a5c5b0 01353e8 Blocked
mrxdav!RxpWorkerThreadDispatcher+0x4b
4.0005cc 81b0ada8 00005e8 Blocked
mrxdav!RxSpinUpRequestsDispatcher+0x58
4.0005e4 81b5dda8 00014e8 Blocked
mrxdav!MRxDAVContextTimerThread+0x66
4.0006f8 81ff1bc8 01353c2 Blocked Stack paged out
4.000700 81b2b990 01353c0 Blocked Stack paged out
4.000598 81f88b30 00014e8 Blocked nt!MiWaitForInPageComplete+0x1a
4.000318 81a4f3c0 0135233 Blocked HTTP!UlpThreadPoolWorker+0xf9
4.0005b4 81a4f148 0135233 Blocked HTTP!UlpThreadPoolWorker+0xf9
4.0005b8 81b5d420 0135233 Blocked HTTP!UlpThreadPoolWorker+0xf9
4.000594 81b5d1a8 00014ea Blocked nt!MiWaitForInPageComplete+0x1a
4.00035c 81afd710 00010b7 Blocked nt!MiWaitForInPageComplete+0x1a
4.0001f4 81aaa020 0000015 Blocked mrxsmb!SmbCeScavenger+0x23
4.0000f8 81a24198 0135a80 INITIALIZEDnt!KiThreadStartup

The disk is blocked so lots will be waiting for paging.

Also see whether power worker thread is waiting for anything.

How do I tell what is the power worker thread?

Run !exqueue to see if worker threads are deadlocked.

kd> !exqueue
Dumping ExWorkerQueue: 8055B140

**** Critical WorkQueue( current = 0 maximum = 1 )
THREAD 8215eb30 Cid 0004.0010 Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215e8b8 Cid 0004.0014 Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215e640 Cid 0004.0018 Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215e3c8 Cid 0004.001c Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215d020 Cid 0004.0020 Teb: 00000000 Win32Thread: 00000000 WAIT

**** Delayed WorkQueue( current = 1 maximum = 1 )
WARNING: active threads = maximum active threads in the queue. No new
workitems schedulable in this queue until they finish or block.
THREAD 8215dda8 Cid 0004.0024 Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215db30 Cid 0004.0028 Teb: 00000000 Win32Thread: 00000000
RUNNING on processor 0
THREAD 8215d8b8 Cid 0004.002c Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215d640 Cid 0004.0030 Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215d3c8 Cid 0004.0034 Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215c020 Cid 0004.0038 Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215cda8 Cid 0004.003c Teb: 00000000 Win32Thread: 00000000 WAIT

ReadMemory for I/O work item at 81c868a0 failed
**** HyperCritical WorkQueue( current = 0 maximum = 1 )
THREAD 8215cb30 Cid 0004.0040 Teb: 00000000 Win32Thread: 00000000 WAIT

Does that tell you anything?

Thanks

James

8

This shows that paging path deadlocked.

Is your miniport a system boot device (paging device)?

What’s your device stack architecture? Are you using system workitems? you CANNOT use system workitems to serve a paging device.

For threads in Delayed list of !exqueue output, run !thread to see their callstack. See if some of your drivers is on that stack.

Is any of your drivers blocking in power up or down path?

9

>

This shows that paging path deadlocked.

Is your miniport a system boot device (paging device)?

Yes, it has the page file, boot filesystem, and hiberfile on it.

What’s your device stack architecture?

Are you using system workitems? you
CANNOT use system workitems to serve a paging device.

Yes I am. Not for the scsiport device obviously but some of the PDO
setup and teardown runs in workitems, but nothing critical (eg those
workitems blocking won’t prevent the device from coming up). These do
run successfully and I don’t think it’s blocking there, but I haven’t
actually checked. I puzzled over this issue a while back and seem to
remember being told that workitems could run when the pagefile wasn’t
(yet) available, but it’s possible I misunderstood. At the time I was
trying to track down what I thought was a deadlock but it turned out to
be a stack overflow because I was allocating a stupid amount of data on
the stack in a scsiport proc.

For threads in Delayed list of !exqueue output, run !thread to see
their
callstack. See if some of your drivers is on that stack.

Is any of your drivers blocking in power up or down path?

Nothing of mine in the !exqueue except for the workitem that called the
bugcheck (I created a bugcheck to cause a crash so I had a dump file to
debug).

Thanks for taking the time to think about this - I feel a bit lost once
I start using the debugger!

James

10

One more thing to add, I am tracking all FDO (bus driver) and PDO
(scsiport) power state transitions… they all look identical in the
success and fail situations.

In the failure case the last thing I see is:

PDOPowerStateChange PostProcess WdfDevStatePowerStartSelfManagedIoNP
PDOPowerStateChange Leave WdfDevStatePowerStartSelfManagedIoNP to
WdfDevStatePowerD0BusWakeOwner
PDOPowerStateChange Enter WdfDevStatePowerD0BusWakeOwnerNP from
WdfDevStatePowerStartSelfManaged
PDOPowerStateChange PostProcess WdfDevStatePowerD0BusWakeOwnerNP

And I believe that WdfDevStatePowerD0BusWakeOwnerNP is a “working” state
in that the power state stays there until shutdown or hibernate.

James

11

Run

!stacks 2 filter

Where filter is a string that matches your bus driver name. This will show all stacks that have your bus driver in them.

What HwScsiControlAdapter codes do you handle? Do you claim to handle SCsiSetRunningConfig and ScsiRestartAdapter?

12

> Run

!stacks 2 filter

Where filter is a string that matches your bus driver name. This will
show all
stacks that have your bus driver in them.

kd> !stacks 2 xenpci
Proc.Thread .Thread Ticks ThreadState Blocker
[8215f5f0 System]
4.00002c 8215d8b8 0000000 RUNNING nt!KeBugCheckEx+0x1b
xenpci!XenPci_SysrqHandler+0xfc

xenpci!XenBus_WatchWorkItemProc+0x14b

wdf01000!FxWorkItem::WorkItemHandler+0xad

wdf01000!FxWorkItem::WorkItemThunk+0x19
nt!IopProcessWorkItem+0x13
nt!ExpWorkerThread+0x100
nt!PspSystemThreadStartup+0x34
nt!KiThreadStartup+0x16
4.00006c 81ddb790 0000488 Blocked nt!KiSwapContext+0x2e
nt!KiSwapThread+0x46
nt!KeWaitForSingleObject+0x1c2

nt!VerifierKeWaitForSingleObject+0x56

xenpci!XenPci_BalloonThreadProc+0x14e
nt!PspSystemThreadStartup+0x34
nt!KiThreadStartup+0x16

the first thread listed is the workitem that got a message from Xen that
we wanted to trigger a bug check. The second is a driver thread that
listens to xen for information about how much memory we should be giving
or taking from xen (memory ballooning). Neither are critical for the
boot / resume process.

What HwScsiControlAdapter codes do you handle? Do you claim to handle
SCsiSetRunningConfig and ScsiRestartAdapter?

I support StopAdapter and RestartAdapter. StopAdapter does nothing.
RestartAdapter does more-or-less what Init does. RestartAdapter
correctly completes on resume from hibernation in all cases, it’s just
that on the 3rd resume, Windows never gives me a StartIo.

Thanks

James

13

Are you sure you don’t have DO_POWER_PAGABLE in any device object on your stack(s)?

14

>

Are you sure you don’t have DO_POWER_PAGABLE in any device object on
your
stack(s)?

I call WdfDeviceInitSetPowerNotPageable on the FDO bus driver and the
PDO’s it enumerates.

James

15

Run !devstack for the parent and PDO stacks and check all device objects.

16

>

Run !devstack for the parent and PDO stacks and check all device
objects.

kd> !devstack 0x82164740
!DevObj !DrvObj !DevExt ObjectName
820b9730 \DRIVER\VERIFIER 820b97e8
820ba8a0 \Driver\XenVbd 820ba958 XenVbd1
820b9848 \DRIVER\VERIFIER 820b9900

82164740 \Driver\XenPCI 82164210 0000003f

kd> !devobj 820ba8a0
Device object (820ba8a0) is for:
XenVbd1 \Driver\XenVbd DriverObject 820b9a88
Current Irp 81f94ad0 RefCount 0 Type 00000004 Flags 00000050
Dacl e13ce14c DevExt 820ba958 DevObjExt 820bae40
ExtensionFlags (0xe0000000) DOE_RAW_FDO, DOE_BOTTOM_OF_FDO_STACK,
DOE_DESIGNATED_FDO
AttachedDevice (Upper) 820b9730 \DRIVER\VERIFIER
AttachedTo (Lower) 820b9848 \DRIVER\VERIFIER
Device queue is busy – Queue empty.

d> !irp 81f94ad0
Irp is active with 5 stacks 1 is current (= 0x81f94b40)
No Mdl: No System Buffer: Thread 00000000: Irp stack trace. Pending
has been returned
cmd flg cl Device File Completion-Context

[f, 0] 0 e1 820bf880 00000000 f889fa4c-81f864fc Success Error
Cancel pending
\Driver\XenVbd IrpSys
Args: 81e4ade4 00000000 00000000 00000000
[16, 2] 0 e1 81e4aab8 00000000 f8727554-00000000 Success Error
Cancel pending
\Driver\Disk PartMgr!PmPowerCompletion
Args: 00000003 00000001 00000001 00000003
[16, 2] 0 e1 81feae08 00000000 80522f24-ba5bf80a Success Error
Cancel pending
\Driver\PartMgr nt!PopCompleteRequestIrp
Args: 00000003 00000001 00000001 00000003
[0, 0] 0 0 81feae08 00000000 00000000-00000000
\Driver\PartMgr
Args: 820bf880 00000002 00000001 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000

Args: 80559ce0 80559ce0 81f94ad0 00000000

So we’re back here again… but looking closer than last time, that’s a
IRP_MJ_POWER at Disk and PartMgr, but then an IRP_MJ_INTERNAL at XenVbd
(my scsiport driver). Given that it’s scsiport, it would be reasonable
to assume that it’s an SRB…

kd> dt _IO_STACK_LOCATION Parameters.Scsi.Srb 0x81f94b40
nt!_IO_STACK_LOCATION
+0x004 Parameters :
+0x000 Scsi :
+0x000 Srb : 0x81e4ade4 _SCSI_REQUEST_BLOCK

kd> dt _SCSI_REQUEST_BLOCK 0x81e4ade4
xenvbd!_SCSI_REQUEST_BLOCK
+0x000 Length : 0x40
+0x002 Function : 0 ‘’
+0x003 SrbStatus : 0 ‘’
+0x004 ScsiStatus : 0 ‘’
+0x005 PathId : 0 ‘’
+0x006 TargetId : 0 ‘’
+0x007 Lun : 0 ‘’
+0x008 QueueTag : 0xff ‘’
+0x009 QueueAction : 0x20 ’ ’
+0x00a CdbLength : 0x6 ‘’
+0x00b SenseInfoBufferLength : 0x12 ‘’
+0x00c SrbFlags : 0x80128
+0x010 DataTransferLength : 0
+0x014 TimeOutValue : 0xf0
+0x018 DataBuffer : (null)
+0x01c SenseInfoBuffer : 0xf89303a8
+0x020 NextSrb : (null)
+0x024 OriginalRequest : 0x820bfcb8
+0x028 SrbExtension : 0xf8930398
+0x02c InternalStatus : 0
+0x02c QueueSortKey : 0
+0x02c LinkTimeoutValue : 0
+0x030 Cdb : [16] “???”

Function 0 is SRB_FUNCTION_EXECUTE_SCSI…

kd> db 0x81e4ae14 (the CDB)
81e4ae14 1b 00 00 00 01 00 00 00-00 00 00 00 00 00 00 00
…

And that’s a SCSIOP_START_STOP_UNIT. There are a bunch of places I could
have gone wrong, but it seems that the IRP has been changed from a
IRP_MJ_POWER to a IRP_MJ_SCSI / SCSIOP_START_STOP_UNIT request as its
gone down the stack (maybe that’s the ‘wake up device’ call?). Does that
seem right based on the above? My device never sees the
SCSIOP_START_STOP_UNIT request in StartIo though.

James

17

After failure happens, and you issue !exqueue, do you always see the message “ReadMemory for I/O work item at XXXXXXX failed”?

18

If you MUST queue a work item (for out-of-band processing, for example), you could always use your OWN work item, instead of the system work queue package.

Peter
OSR

19

>

If you MUST queue a work item (for out-of-band processing, for
example), you
could always use your OWN work item, instead of the system work queue
package.

I’m pretty sure work items are fine in my case. They aren’t used
anywhere that would block the paging path. Or were you addressing the
general case of if I did need a workitem in the paging path?

James

20

>

After failure happens, and you issue !exqueue, do you always see the
message
“ReadMemory for I/O work item at XXXXXXX failed”?

It seems not…

kd> !exqueue
Dumping ExWorkerQueue: 8055B1C0

**** Critical WorkQueue( current = 0 maximum = 1 )
THREAD 8215eb30 Cid 0004.0010 Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215e8b8 Cid 0004.0014 Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215e640 Cid 0004.0018 Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215e3c8 Cid 0004.001c Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215d020 Cid 0004.0020 Teb: 00000000 Win32Thread: 00000000 WAIT

**** Delayed WorkQueue( current = 2 maximum = 1 )
WARNING: active threads = maximum active threads in the queue. No new
workitems schedulable in this queue until they finish or block.
THREAD 8215dda8 Cid 0004.0024 Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215db30 Cid 0004.0028 Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215d8b8 Cid 0004.002c Teb: 00000000 Win32Thread: 00000000
RUNNING on processor 0
THREAD 8215d640 Cid 0004.0030 Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215d3c8 Cid 0004.0034 Teb: 00000000 Win32Thread: 00000000
READY
THREAD 8215c020 Cid 0004.0038 Teb: 00000000 Win32Thread: 00000000 WAIT
THREAD 8215cda8 Cid 0004.003c Teb: 00000000 Win32Thread: 00000000 WAIT

**** HyperCritical WorkQueue( current = 0 maximum = 1 )
THREAD 8215cb30 Cid 0004.0040 Teb: 00000000 Win32Thread: 00000000 WAIT

James