Yes, that window exists. You need to put up a gate to stop sending io and processing new io upon reception of the remove. That also means canceling times, docs, disconnecting interrupts before sending it down. Then you send the remove. Then you wait. Then you do state cleanup. This is what wdf does upon remove.
Wdf is not adding anything new here in terms of rules. Wdf may be slightly more picky, but the same exists in wdm.
d
Bent from my phone
From: Scott Noonemailto:xxxxx
Sent: ?11/?25/?2013 2:41 PM
To: Windows System Software Devs Interest Listmailto:xxxxx
Subject: Re:[ntdev] [OSR-DETECTED-SPAM] RE: [OSR-DETECTED-SPAM] RE: Conflicting statements in MSDN about IoReleaseRemoveLockAndWait
OK, so let’s say you have a WDM FDO with a KMDF lower filter. The WDM FDO
sends I/Os down the stack in the background under a remove lock. During
remove processing, the FDO:
1. Send the IRP_MN_REMOVE down the stack
2. Waits on the remove lock
Now we have a window between 1-2 where I/Os could still be sent to the lower
filter after the lower filter has processed the remove. If the framework
doesn’t allow for that, then we’ll crash in the same way as we have here.
I’m thinking that’s exactly what the OP is seeing. Here’s the crashing
stack:
nt!KiBugCheckDispatch+0x69
nt!KiPageFault+0x260
Wdf01000!FxDevice::Dispatch+0x22
Wdf01000!FxDevice::DispatchWithLock+0xa6
nt!IovCallDriver+0x566
nt!KiProcessTimerDpcTable+0x6c
nt!KiProcessExpiredTimerList+0xc6
Clearly KiProcessTimerDpcTable doesn’t call IovCallDriver, so the return has
been optimized out. However, the crashing WDF device object is for
“storflt”, which is still attached below Disk:
1: kd> !devobj @rcx
Device object (fffffa8003d40370) is for:
\Driver\storflt DriverObject fffffa8002c97e70
Current Irp 00000000 RefCount 0 Type 0000002d Flags 00000010
DevExt 00000000 DevObjExt fffffa8003d404e8
ExtensionFlags (0x9400080a) DOE_DELETE_PENDING, DOE_REMOVE_PROCESSED,
DOE_DESIGNATED_FDO
Unknown flags 0x14000800
AttachedDevice (Upper) fffffa8004062060 \Driver\Disk
Device queue is not busy.
And there’s a thread waiting for the equivalent of the remove lock in the
Disk instance:
nt!KiSwapContext+0x7a
nt!KiCommitThreadWait+0x1d2
nt!KeWaitForSingleObject+0x19f
CLASSPNP!ClassRemoveDevice+0x12a
CLASSPNP! ?? ::NNGAKEGL::`string’+0x17a6
nt!IovCallDriver+0x566
…
Thus I’m assuming that it’s Disk calling down into storflt from a timer DPC
and this operation is accounted for in Disk’s remove lock. Disk waits for
its remove lock after it sends the IRP_MN_REMOVE down to the lower driver,
which would mean we’ve hit the window between 1 and 2 above.
-scott
OSR
“Doron Holan” wrote in message
news:xxxxx@ntdev…
Yes, you do the wait after send to let the underlying bus cleanup and
complete io first. Then you wait on the lock, then you clean up state
d
Bent from my phone
From: Scott Noone
Sent: ?11/?25/?2013 12:42 PM
To: Windows System Software Devs Interest List
Subject: Re:[ntdev] [OSR-DETECTED-SPAM] RE: Conflicting statements in MSDN
about IoReleaseRemoveLockAndWait
If that’s the case, wouldn’t that mean you have to wait on the remove lock
before sending the remove IRP? Otherwise the window is there between
remove and wait and I/Os arriving at the device.
-scott
OSR
“Doron Holan” wrote in message
news:xxxxx@ntdev…
Definitely a calm into a wdf driver after the remove irp has been processed.
You need to wait on the remlock after sending the remove irp
d
Bent from my phone
From: Scott Noone
Sent: ?11/?25/?2013 12:00 PM
To: Windows System Software Devs Interest List
Subject: Re:[ntdev] Conflicting statements in MSDN about
IoReleaseRemoveLockAndWait
Do you have any timer DPCs in your drivers? It looks to me like someone is
calling into a WDF driver after the device has been removed. From the stack
I can’t tell what either of the drivers are though (tail call optimization
obscures the caller, the framework owning the entry points obscures the
callee).
I set a breakpoint on this routine on my test system and at this point RCX
should contain a device object (RCX+40 is the DeviceExtension field, WDF is
trying to access some header before this field). !devobj @rcx or "dt
nt!_device_object @rcx’ might tell you the driver, which would shed some
light on things.
-scott
OSR
wrote in message news:xxxxx@ntdev…
Thank you Scott.
My driver is WDM. I can recreate the BSOD but not regularly. Every time I
can though it shows my driver’s stack to be in the call passing the remove
IRP down, hence my suspicion on the ordering.
I will put my stack as well but first is the !analyze -v output. I have
driver verifier running on the machine and it did not detect anything
special.
<<
DRIVER_IRQL_NOT_LESS_OR_EQUAL (d1)
An attempt was made to access a pageable (or completely invalid) address at
an
interrupt request level (IRQL) that is too high. This is usually
caused by drivers using improper addresses.
If kernel debugger is available get stack backtrace.
Arguments:
Arg1: ffffffffffffffd0, memory referenced
Arg2: 0000000000000002, IRQL
Arg3: 0000000000000000, value 0 = read operation, 1 = write operation
Arg4: fffff880010d0862, address which referenced memory
Debugging Details:
------------------
READ_ADDRESS: ffffffffffffffd0
CURRENT_IRQL: 2
FAULTING_IP:
Wdf01000!FxDevice::Dispatch+22
fffff880010d0862 4c8b50d0 mov r10,qword ptr [rax-30h]<br><br>DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT<br><br>BUGCHECK_STR: 0xD1<br><br>PROCESS_NAME: System<br><br>TRAP_FRAME: fffff8800203d2c0 -- (.trap 0xfffff8800203d2c0)<br>NOTE: The trap frame does not contain all registers.<br>Some register values may be zeroed or incorrect.<br>rax=0000000000000000 rbx=0000000000000000 rcx=fffffa8003d40370<br>rdx=fffff9800b642e10 rsi=0000000000000000 rdi=0000000000000000<br>rip=fffff880010d0862 rsp=fffff8800203d450 rbp=0000000000000002<br>r8=fffffa8002c97e70 r9=0000000000000001 r10=fffff9800b642e10<br>r11=fffff9800b642e02 r12=0000000000000000 r13=0000000000000000<br>r14=0000000000000000 r15=0000000000000000<br>iopl=0 nv up ei pl zr na po nc<br>Wdf01000!FxDevice::Dispatch+0x22:<br>fffff880
010d0862 4c8b50d0 mov r10,qword ptr [rax-30h]
ds:dc18:ffd0=???
Resetting default scope
LAST_CONTROL_TRANSFER: from fffff80001dc9a12 to fffff80001cd0a30
STACK_TEXT:
fffff8800203ca08 fffff800
01dc9a12 : ffffffffffffffd0 fffff880
0201ff40
0000000000000065 fffff800
01d13888 : nt!RtlpBreakWithStatusInstruction
fffff8800203ca10 fffff800
01dca7fe : 0000000000000003 00000000
00000000
fffff80001d140e0 00000000
000000d1 : nt!KiBugCheckDebugBreak+0x12
fffff8800203ca70 fffff800
01cd8d04 : fffffa80036e9e20 fffff880
00e60872
0000000000000001 fffff800
01d550c4 : nt!KeBugCheck2+0x71e
fffff8800203d140 fffff800
01cd81a9 : 000000000000000a ffffffff
ffffffd0
0000000000000002 00000000
00000000 : nt!KeBugCheckEx+0x104
fffff8800203d180 fffff800
01cd6e20 : 0000000000000000 00000000
a0000003
fffff9801f920e10 fffff980
0b642e10 : nt!KiBugCheckDispatch+0x69
fffff8800203d2c0 fffff880
010d0862 : fffffa8003d40370 00000000
00000002
fffffa800473ff40 fffff800
0217ee96 : nt!KiPageFault+0x260
fffff8800203d450 fffff880
010d0aa6 : fffff9800b642e10 00000000
00000002
fffffa8003d40370 fffff880
0203dc18 : Wdf01000!FxDevice::Dispatch+0x22
fffff8800203d490 fffff800
02182d26 : fffff9800b642e10 00000000
00000002
fffffa8003d40370 e83f03ff
ffe00007 :
Wdf01000!FxDevice::DispatchWithLock+0xa6
fffff8800203d4d0 fffff800
01ce384c : fffff8800203d5f0 00000000
00000000
0000000000000001 fffffa80
0473ff40 : nt!IovCallDriver+0x566
fffff8800203d530 fffff800
01ce36e6 : fffffa8004360748 fffffa80
04360748
0000000000000000 00000000
00000000 : nt!KiProcessTimerDpcTable+0x6c
fffff8800203d5a0 fffff800
01ce35ce : 0000001479a9100e fffff880
0203dc18
0000000000089683 fffff880
020185e8 : nt!KiProcessExpiredTimerList+0xc6
fffff8800203dbf0 fffff800
01ce33b7 : 0000140b8ff202c5 0000140b
00089683
0000140b8ff20263 00000000
00000083 : nt!KiTimerExpiration+0x1be
fffff8800203dc90 fffff800
01cd090a : fffff88002015180 fffff880
0201ff40
0000000000000001 fffff800
00000000 : nt!KiRetireDpcList+0x277
fffff8800203dd40 00000000
00000000 : fffff8800203e000 fffff880
02038000
fffff8800203dd00 00000000
00000000 : nt!KiIdleLoop+0x5a
STACK_COMMAND: kb
FOLLOWUP_IP:
Wdf01000!FxDevice::Dispatch+22
fffff880010d0862 4c8b50d0 mov r10,qword ptr [rax-30h]<br><br>SYMBOL_STACK_INDEX: 6<br><br>SYMBOL_NAME: Wdf01000!FxDevice::Dispatch+22<br><br>FOLLOWUP_NAME: MachineOwner<br><br>MODULE_NAME: Wdf01000<br><br>IMAGE_NAME: Wdf01000.sys<br><br>DEBUG_FLR_IMAGE_TIMESTAMP: 5010aa89<br><br>FAILURE_BUCKET_ID: X64_0xD1_VRF_Wdf01000!FxDevice::Dispatch+22<br><br>BUCKET_ID: X64_0xD1_VRF_Wdf01000!FxDevice::Dispatch+22<br><br>Followup: MachineOwner<br>---------<br>>><br><br>and the thread's stack related to the PnP device removal that's going<br>through my driver (DcsPMF and DcsDf) at the time of the BSOD (note: the<br>drivers send the IRP down and wait for its completion so if STATUS_PENDING<br>is returned there's a WaitForSingleObject that wakes up when the IRP<br>completion routine sets a private event).<br><br><<<br> *** Stack trace for last set context - .thread/.cxr resets it<br>Child-SP RetAddr : Args to Child<br>: Call Site<br>fffff880
059aac50 fffff80001cce612 : 00000000
00000017 fffffa80044153c0<br>00000000
00000000 0000000000000008 : nt!KiSwapContext+0x7a<br>fffff880
059aad90 fffff80001cdf98f : fffffa80
02ca6001 fffffa80040621b0<br>00000000
00000000 0000000000000000 : nt!KiCommitThreadWait+0x1d2<br>fffff880
059aae20 fffff880013e08fa : 00000000
00000000 0000000000000000<br>fffffa80
04062000 fffffa8004062100 : nt!KeWaitForSingleObject+0x19f<br>fffff880
059aaec0 fffff880013dcb08 : fffffa80
03d40370 0000000000000000<br>00000000
00000002 fffff880013d7110 : CLASSPNP!ClassRemoveDevice+0x12a<br>fffff880
059aaf00 fffff80002182d26 : fffffa80
040621b0 fffffa8002ca6038<br>fffff980
1f614c60 fffff8000217e48e : CLASSPNP! ??<br>::NNGAKEGL::
string’+0x17a6
fffff880059aaf90 fffff800
021855ea : fffff9801f614e50 fffffa80
04062060
fffffa80044372a0 fffffa80
018fc320 : nt!IovCallDriver+0x566
fffff880059aaff0 fffff800
02182d26 : fffff9801f614c60 00000000
00000002
fffffa80044372a0 fffffa80
0421a0b0 : nt!ViFilterDispatchPnp+0xea
fffff880059ab020 fffff880
017e270c : fffff9801f614c60 00000000
00000002
fffff9801f614f18 fffffa80
0421a0b0 : nt!IovCallDriver+0x566
fffff880059ab080 fffff880
017e6298 : fffffa8002d26830 fffff980
1f614c60
fffffa8002d26830 fffffa80
032a1410 :
DcsDf!DiskPerfForwardIrpSynchronous+0xac
fffff880059ab110 fffff880
017e5778 : fffffa8002d26830 fffff980
1f614c60
0000000000000000 00000000
00000000 : DcsDf!DiskPerfRemoveDevice+0x58
fffff880059ab150 fffff800
02182d26 : fffffa8002d26830 fffff980
1f614c60
fffff9801f614c60 fffff800
0217e48e : DcsDf!DiskPerfDispatchPnp+0x148
fffff880059ab1d0 fffff800
021855ea : fffff9801f614ee0 fffffa80
02d26830
fffffa80042f5af0 fffffa80
032a1410 : nt!IovCallDriver+0x566
fffff880059ab230 fffff800
02182d26 : fffff9801f614c60 00000000
00000002
fffffa80042f5af0 fffffa80
03212a70 : nt!ViFilterDispatchPnp+0xea
fffff880059ab260 fffff880
014b6926 : fffff9801f614c60 00000000
00000002
fffff9801f614fa8 fffffa80
03212a70 : nt!IovCallDriver+0x566
fffff880059ab2c0 fffff880
014b82c5 : fffffa8003405060 fffff980
1f614c60
fffff880059ab3f0 fffff880
059ab3d8 : DcsPMF!PMFForwardIrpSynchronous+0xd6
fffff880059ab340 fffff880
014b8d78 : fffffa8003405060 fffff980
1f614c60
0000000000000003 00000000
00000000 : DcsPMF!PMFRemoveDevice+0x2e5
fffff880059ab510 fffff800
02182d26 : fffffa8003405060 fffff980
1f614c60
fffff9801f614c60 fffff800
0217e48e : DcsPMF!PMFDispatchPnp+0x738
fffff880059ab5d0 fffff800
021855ea : fffff9801f614f70 fffffa80
03405060
fffffa8003fd2700 fffffa80
043d6eb0 : nt!IovCallDriver+0x566
fffff880059ab630 fffff800
02182d26 : fffff9801f614c60 00000000
00000002
fffffa8003fd2700 fffffa80
03b2a010 : nt!ViFilterDispatchPnp+0xea
fffff880059ab660 fffff880
0108530e : fffff9801f614c60 fffff980
1f614fb8
0000000000000000 fffffa80
03b2a010 : nt!IovCallDriver+0x566
fffff880059ab6c0 fffff800
02182d26 : fffff9801f614c60 00000000
00000002
fffffa80039c0330 00000000
c00000bb : partmgr!PmPnp+0xfe
fffff880059ab710 fffff800
01f46d11 : fffffa80039c0330 fffff880
059ab828
00000000c00000bb fffffa80
03b44010 : nt!IovCallDriver+0x566
fffff880059ab770 fffff800
020c5681 : fffffa8004743060 00000000
00000000
fffffa80047384a0 00000000
00000801 : nt!IopSynchronousCall+0xe1
fffff880059ab7e0 fffff800
01ddb063 : fffff8a0023b6f20 fffff8a0
023b6f20
0000000000000018 00000000
00000000 : nt!IopRemoveDevice+0x101
fffff880059ab8a0 fffff800
020c51d4 : fffffa80047384a0 00000000
00000000
0000000000000002 00000000
00000000 : nt!PnpRemoveLockedDeviceNode+0x1a3
fffff880059ab8f0 fffff800
020c52e0 : 0000000000000000 fffffa80
04743000
fffff8a0074b8900 fffff800
01edca80 : nt!PnpDeleteLockedDeviceNode+0x44
fffff880059ab920 fffff800
020c53d9 : fffffa8004601602 fffffa80
04601600
0000000000000001 00000000
00000000 : nt!PnpDeleteLockedDeviceNodes+0xa0
fffff880059ab990 fffff800
020c5551 : fffffa8004601600 00000000
00000000
fffffa8004601600 00000000
00010286 : nt!PnpDelayedRemoveWorker+0x79
fffff880059ab9e0 fffff800
01ddb289 : 0000000000000000 fffffa80
035e0a50
0000000000000001 00000000
00000000 : nt!PnpChainDereferenceComplete+0x131
fffff880059aba20 fffff800
02156570 : 0000000000000000 fffffa80
04738400
fffff8a00398cef0 00000000
00000001 : nt!PnpIsChainDereferenced+0xc9
fffff880059abaa0 fffff800
0215680c : fffff880059abc78 00000000
00010200
fffff880059abc00 00000000
00000000 : nt!PnpProcessQueryRemoveAndEject+0xff0
fffff880059abbe0 fffff800
0203f9ae : 0000000000000000 fffffa80
0466eb00
fffff8a00398cef0 fffff880
059abc00 : nt!PnpProcessTargetDeviceEvent+0x4c
fffff880059abc10 fffff800
01ce2251 : fffff80001f45b98 fffff8a0
0398cef0
fffff80001e7e2d8 fffff800
01e7e2d8 : nt! ?? ::NNGAKEGL::string'+0x552ab<br>fffff880
059abc70 fffff80001f76ede : 00000000
00000000 fffffa80044153c0<br>00000000
00000080 fffffa8001876890 : nt!ExpWorkerThread+0x111<br>fffff880
059abd00 fffff80001cc9906 : fffff880
02015180 fffffa80044153c0<br>fffffa80
028dcb50 0000000000000202 : nt!PspSystemThreadStartup+0x5a<br>fffff880
059abd40 0000000000000000 : fffff880
059ac000 fffff880059a6000<br>fffff880
059aa8a0 00000000`00000000 : nt!KxStartSystemThread+0x16
>>
—
NTDEV is sponsored by OSR
Visit the list at: http://www.osronline.com/showlists.cfm?list=ntdev
OSR is HIRING!! See http://www.osr.com/careers
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
—
NTDEV is sponsored by OSR
Visit the list at: http://www.osronline.com/showlists.cfm?list=ntdev
OSR is HIRING!! See http://www.osr.com/careers
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
—
NTDEV is sponsored by OSR
Visit the list at: http://www.osronline.com/showlists.cfm?list=ntdev
OSR is HIRING!! See http://www.osr.com/careers
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</mailto:xxxxx></mailto:xxxxx>