Hi Doron. I've added a bit more info and realized it's probably relevant that this is happening around the request cancellation processing, though I'm not doing anything special other than not attempting to resubmit the request if any part of it appears to be cancelled. Maybe that's not enough?
>> Are you passing true IsocUrb::Submit to in all cases?
yes, that's the only place the WDFREQUEST is touched.
*>> Are you always reusing the WDFREQUEST that is being completed or possibly pulling the WDFREQUEST off a list in some (corner?) cases? *
We're Only re-using using the current, completed request.
*>> Are you always send these requests to the same WDFIOTARGET (or WDFUSBPIPE) ?
yes, each set of WDFREQUESTS is associated with, and ONLY ever sent to, the same WDFUSBPIPE.
I had a question about this info (another dump of the same crash): Does the "Requests sent:10" mean total, forever, for this pipe? Just currently submitted?? I'm not clear on what exactly it means.
0: kd> !wdfrequest 00007a707ec35de8
Treating handle as a KMDF handle!
!irp 0xffff858f8b9aeb80
State: Allocated by driver, IRP allocated by WDF
!wdfiotarget 0x00007a7086291228
Completion Routine: FocusriteUsb!UsbAudioStream::EvtRequestCompletion (fffff800639ea1a0)
Completion Context: 0xffff858f7cd50820
0: kd> !wdfiotarget 0x00007a7086291228
Treating handle as a KMDF handle!
WDFIOTARGET 00007a7086291228
=========================
WDFDEVICE: 0x00007a70831f8da8
Target Device: !devobj 0xffff858f7ce07d20
Target PDO: !devobj 0xffff858f7ce09d40
Type: Instack target
State: WdfIoTargetStarted
Requests pending: 0
Requests sent: 10
WDFREQUEST 00007a707ec34f68 !irp 0xffff858f8b516b80
WDFREQUEST 00007a707ec35a48 !irp 0xffff858f89740b80
WDFREQUEST 00007a707ec36e38 !irp 0xffff858f8a2c8b80
WDFREQUEST 00007a707ec36a98 !irp 0xffff858f8b290b80
WDFREQUEST 00007a707ec342b8 !irp 0xffff858f8ae62b80
WDFREQUEST 00007a707ec368c8 !irp 0xffff858f8acbab80
WDFREQUEST 00007a707ec34d98 !irp 0xffff858f8b3dcb80
WDFREQUEST 00007a707ec34bc8 !irp 0xffff858f8b976b80
WDFREQUEST 00007a707ec34828 !irp 0xffff858f8b87eb80
WDFREQUEST 00007a707ec35de8 !irp 0xffff858f8b9aeb80
Requests sent with ignore-target-state: 0
!wdfrequest 00007a707ec35de8
Treating handle as a KMDF handle!
!irp 0xffff858f8b9aeb80
0: kd> !irp 0xffff858f8b9aeb80
Irp is active with 12 stacks 9 is current (= 0xffff858f8b9aee90)
No Mdl: No System Buffer: Thread 00000000: Irp stack trace. Pending has been returned
cmd flg cl Device File Completion-Context
[N/A(0), N/A(0)]
0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[N/A(0), N/A(0)]
0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[N/A(0), N/A(0)]
0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[N/A(0), N/A(0)]
0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[N/A(0), N/A(0)]
0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[N/A(0), N/A(0)]
0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[N/A(0), N/A(0)]
0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[N/A(0), N/A(0)]
0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
>[IRP_MJ_INTERNAL_DEVICE_CONTROL(f), N/A(0)]
0 1 ffff858f79e83c80 ffff858f817cc980 00000000-00000000 pending
\Driver\USBXHCI
Args: ffff858f817cc980 00000000 0x220003 00000000
[IRP_MJ_INTERNAL_DEVICE_CONTROL(f), N/A(0)]
0 e0 ffff858f79eefb90 ffff858f817cc980 00000000-00000000
\Driver\USBXHCI
Args: ffff858f817cc980 00000000 0x220003 00000000
[IRP_MJ_INTERNAL_DEVICE_CONTROL(f), N/A(0)]
0 e1 ffff858f79eefb90 ffff858f817cc980 00000000-00000000 pending
\Driver\USBXHCI
Args: ffff858f817cc980 00000000 0x220003 00000000
[IRP_MJ_INTERNAL_DEVICE_CONTROL(f), N/A(0)]
0 0 ffff858f7ce09d40 ffff858f817cc980 00000000-00000000
\Driver\USBHUB3
Args: ffff858f817cc980 00000000 0x220003 00000000
Irp Extension present at 0xffff858f8b9aefb0:
Inflight Trace recorder:
0: kd> !wdflogdump fumbumblee.sys
Trace searchpath is:
Trace format prefix is: %7!u!: %!FUNC! -
Trying to extract TMF information from - c:\myserversymbols\Wdf01000.pdb\BA0D580847BC0ABC20700F3C90FF0EFE1\Wdf01000.pdb
Gather log: Please wait, this may take a moment (reading 4024 bytes).
% read so far ... 10, 20, 30, 40, 50, 60, 70, 80, 90, 100
There are 94 log entries
--- start of log ---
2250: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707BC0E208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2251: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707BC0E208
2252: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707BC0E208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2253: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086291228
2254: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086291228 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
Unknown( 14): GUID=21fc475e-f23b-3eaa-217b-e8ced99c11a1 (No Format Information found).
2256: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707BC0E208
2257: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707BC0E208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2258: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707BC0E208
2259: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707BC0E208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2260: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086291228
2261: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086291228 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
Unknown( 14): GUID=21fc475e-f23b-3eaa-217b-e8ced99c11a1 (No Format Information found).
2263: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707BC0E208
2264: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707BC0E208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
Unknown( 14): GUID=21fc475e-f23b-3eaa-217b-e8ced99c11a1 (No Format Information found).
2266: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707BC0E208
2267: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707BC0E208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2268: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086291228
2269: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086291228 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2270: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707BC0E208
2271: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707BC0E208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2272: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707BC0E208
2273: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707BC0E208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2274: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086291228
2275: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086291228 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
Unknown( 14): GUID=21fc475e-f23b-3eaa-217b-e8ced99c11a1 (No Format Information found).
2277: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707BC0E208
2278: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707BC0E208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2279: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707BC0E208
2280: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707BC0E208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2281: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086291228
2282: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086291228 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
Unknown( 14): GUID=21fc475e-f23b-3eaa-217b-e8ced99c11a1 (No Format Information found).
2284: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707BC0E208
2285: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707BC0E208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2286: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707BC0E208
2287: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707BC0E208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2288: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086291228
2289: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086291228 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2290: FxIoTarget::WaitForDisposeEvent - WDFIOTARGET 00007A707BC0E208, Waiting on Dispose event FFFFF90F5FDCB5A0
2291: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A708629CB38 state, sending WDFREQUEST FFFFF90F5FDCB820, state WdfIoTargetStarted
Unknown( 14): GUID=21fc475e-f23b-3eaa-217b-e8ced99c11a1 (No Format Information found).
2293: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707B50C208
2294: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707B50C208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2295: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707B50C208
2296: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707B50C208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2297: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086291228
2298: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086291228 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2299: FxIoTarget::WaitForDisposeEvent - WDFIOTARGET 00007A707B50C208, Waiting on Dispose event FFFFF90F5FDCB5A0
2300: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A708629CB38 state, sending WDFREQUEST FFFFF90F5FDCB820, state WdfIoTargetStarted
Unknown( 14): GUID=21fc475e-f23b-3eaa-217b-e8ced99c11a1 (No Format Information found).
2302: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707F2B6208
2303: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707F2B6208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2304: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707F2B6208
2305: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707F2B6208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2306: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086291228
2307: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086291228 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
Unknown( 14): GUID=21fc475e-f23b-3eaa-217b-e8ced99c11a1 (No Format Information found).
2309: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707F2B6208
2310: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707F2B6208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2311: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707F2B6208
2312: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707F2B6208 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2313: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086291228
2314: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086291228 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2315: FxIoTarget::WaitForDisposeEvent - WDFIOTARGET 00007A707F2B6208, Waiting on Dispose event FFFFF90F5FDCB5A0
2316: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A708629CB38 state, sending WDFREQUEST FFFFF90F5FDCB820, state WdfIoTargetStarted
Unknown( 14): GUID=21fc475e-f23b-3eaa-217b-e8ced99c11a1 (No Format Information found).
2318: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707E2A27E8
2319: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707E2A27E8 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2320: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A707E2A27E8
2321: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A707E2A27E8 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2322: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086291228
2323: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086291228 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2324: FxIoTarget::WaitForDisposeEvent - WDFIOTARGET 00007A707E2A27E8, Waiting on Dispose event FFFFF90F5FDCB5A0
2325: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A708629CB38 state, sending WDFREQUEST FFFFF90F5FDCB820, state WdfIoTargetStarted
Unknown( 14): GUID=21fc475e-f23b-3eaa-217b-e8ced99c11a1 (No Format Information found).
2327: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086287488
2328: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086287488 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2329: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086287488
2330: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086287488 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2331: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086291228
2332: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086291228 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
Unknown( 14): GUID=21fc475e-f23b-3eaa-217b-e8ced99c11a1 (No Format Information found).
2334: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086287488
2335: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086287488 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
Unknown( 14): GUID=21fc475e-f23b-3eaa-217b-e8ced99c11a1 (No Format Information found).
2337: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086287488
2338: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086287488 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2339: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086291228
2340: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086291228 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2341: FxIoTarget::CancelSentIo - Cancelling pending I/O on WDFIOTARGET 00007A7086287488
2342: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00007A7086287488 state, sending WDFREQUEST FFFFF90F5FDCB7E0, state WdfIoTargetStarted
2343: FxIoTarget::SubmitLocked - WDFREQUEST 00007A707EC35DE8 already sent to a target
---- end of log ----