How many request can be delivered to a queue configured with WdfIoQueueDispatchSequential

tuple_cat · July 6, 2023, 2:58pm

I am trying to figure out why I get this:

BAD_POOL_CALLER (c2)
The current thread is making a bad pool request.  Typically this is at a bad IRQL level or double freeing the same allocation, etc.

I have two queues. One default queue that is configured with WdfIoQueueDispatchParallel. Lets call this queue 1. This queue completes one of the IOCTL messages (message A), and forwards messages B to a second queue, which is configured with WdfIoQueueDispatchSequential. Lets call this queue 2.

Is it correct that with this setup I could get multiple A and B messages delivered to queue 1, but only one B message at a time delivered from queue 2?

When the above bug check occured I can see that the different stack traces for the different processors points to that the above is not correct.

nt!DbgBreakPointWithStatus
nt!KiBugCheckDebugBreak+0x12
nt!KeBugCheck2+0x946
nt!KeBugCheckEx+0x107
nt!ExFreeHeapPool+0x20b232
nt!ExFreePool+0x9
USBDriver!doThings+0x167 [C:\Users\WDKRemoteUser.DESKTOP-1ODDJ59\code\suite\lib\usb\windows\USBDriver\USBDriver\Async.cpp @ 90] 
USBDriver!Queue2EvtIoDeviceControl+0x10e9 [C:\Users\WDKRemoteUser.DESKTOP-1ODDJ59\code\suite\lib\usb\windows\USBDriver\USBDriver\NonAudioQueue.cpp @ 135] 
Wdf01000!FxIoQueueIoDeviceControl::Invoke+0x41 [minkernel\wdf\framework\shared\inc\private\common\FxIoQueueCallbacks.hpp @ 226] 
Wdf01000!FxIoQueue::DispatchRequestToDriver+0x162 [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 3325] 
Wdf01000!FxIoQueue::DispatchEvents+0x520 [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 3125] 
Wdf01000!FxIoQueue::QueueRequestFromForward+0x98 [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 2496] 
Wdf01000!FxIoQueue::ForwardRequestWorker+0x11b [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 1444] 
Wdf01000!FxIoQueue::ForwardRequest+0x26 [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 1781] 
Wdf01000!imp_WdfRequestForwardToIoQueue+0xce [minkernel\wdf\framework\shared\core\fxrequestapi.cpp @ 3149] 
USBDriver!WdfRequestForwardToIoQueue+0x22 [C:\Program Files (x86)\Windows Kits\10\Include\wdf\kmdf\1.15\wdfrequest.h @ 1583] 
USBDriver!Queue1EvtIoDeviceControl+0x7f [C:\Users\WDKRemoteUser.DESKTOP-1ODDJ59\code\suite\lib\usb\windows\USBDriver\USBDriver\DefaultQueue.cpp @ 82] 
Wdf01000!FxIoQueueIoDeviceControl::Invoke+0x41 [minkernel\wdf\framework\shared\inc\private\common\FxIoQueueCallbacks.hpp @ 226] 
Wdf01000!FxIoQueue::DispatchRequestToDriver+0x162 [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 3325] 
Wdf01000!FxIoQueue::DispatchEvents+0x520 [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 3125] 
Wdf01000!FxIoQueue::QueueRequest+0xae [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 2371] 
Wdf01000!FxPkgIo::DispatchStep2+0x5ac [minkernel\wdf\framework\shared\irphandlers\io\fxpkgio.cpp @ 469] 
Wdf01000!FxPkgIo::DispatchStep1+0x627 [minkernel\wdf\framework\shared\irphandlers\io\fxpkgio.cpp @ 324] 
Wdf01000!FxPkgIo::Dispatch+0x5d [minkernel\wdf\framework\shared\irphandlers\io\fxpkgio.cpp @ 119] 
Wdf01000!DispatchWorker+0x6a [minkernel\wdf\framework\shared\core\fxdevice.cpp @ 1589] 
Wdf01000!FxDevice::Dispatch+0x88 [minkernel\wdf\framework\shared\core\fxdevice.cpp @ 1603] 
Wdf01000!FxDevice::DispatchWithLock+0x156 [minkernel\wdf\framework\shared\core\fxdevice.cpp @ 1447] 
nt!IofCallDriver+0x55
nt!IopSynchronousServiceTail+0x34c
nt!IopXxxControlFile+0xc71
nt!NtDeviceIoControlFile+0x56
nt!KiSystemServiceCopyEnd+0x28
ntdll!NtDeviceIoControlFile+0x14
KERNELBASE!DeviceIoControl+0x6b
KERNEL32!DeviceIoControlImplementation+0x81
MyApp+0x4e3a4

USBDriver!doThings+0xc4 [C:\Users\WDKRemoteUser.DESKTOP-1ODDJ59\code\suite\lib\usb\windows\USBDriver\USBDriver\Async.cpp @ 83] 
USBDriver!Queue2EvtIoDeviceControl+0x10e9 [C:\Users\WDKRemoteUser.DESKTOP-1ODDJ59\code\suite\lib\usb\windows\USBDriver\USBDriver\NonAudioQueue.cpp @ 135] 
Wdf01000!FxIoQueueIoDeviceControl::Invoke+0x41 [minkernel\wdf\framework\shared\inc\private\common\FxIoQueueCallbacks.hpp @ 226] 
Wdf01000!FxIoQueue::DispatchRequestToDriver+0x162 [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 3325] 
Wdf01000!FxIoQueue::DispatchEvents+0x520 [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 3125] 
Wdf01000!FxIoQueue::QueueRequestFromForward+0x98 [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 2496] 
Wdf01000!FxIoQueue::ForwardRequestWorker+0x11b [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 1444] 
Wdf01000!FxIoQueue::ForwardRequest+0x26 [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 1781] 
Wdf01000!imp_WdfRequestForwardToIoQueue+0xce [minkernel\wdf\framework\shared\core\fxrequestapi.cpp @ 3149] 
USBDriver!WdfRequestForwardToIoQueue+0x22 [C:\Program Files (x86)\Windows Kits\10\Include\wdf\kmdf\1.15\wdfrequest.h @ 1583] 
USBDriver!Queue1EvtIoDeviceControl+0x7f [C:\Users\WDKRemoteUser.DESKTOP-1ODDJ59\code\suite\lib\usb\windows\USBDriver\USBDriver\DefaultQueue.cpp @ 82] 
Wdf01000!FxIoQueueIoDeviceControl::Invoke+0x41 [minkernel\wdf\framework\shared\inc\private\common\FxIoQueueCallbacks.hpp @ 226] 
Wdf01000!FxIoQueue::DispatchRequestToDriver+0x162 [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 3325] 
Wdf01000!FxIoQueue::DispatchEvents+0x520 [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 3125] 
Wdf01000!FxIoQueue::QueueRequest+0xae [minkernel\wdf\framework\shared\irphandlers\io\fxioqueue.cpp @ 2371] 
Wdf01000!FxPkgIo::DispatchStep2+0x5ac [minkernel\wdf\framework\shared\irphandlers\io\fxpkgio.cpp @ 469] 
Wdf01000!FxPkgIo::DispatchStep1+0x627 [minkernel\wdf\framework\shared\irphandlers\io\fxpkgio.cpp @ 324] 
Wdf01000!FxPkgIo::Dispatch+0x5d [minkernel\wdf\framework\shared\irphandlers\io\fxpkgio.cpp @ 119] 
Wdf01000!DispatchWorker+0x6a [minkernel\wdf\framework\shared\core\fxdevice.cpp @ 1589] 
Wdf01000!FxDevice::Dispatch+0x88 [minkernel\wdf\framework\shared\core\fxdevice.cpp @ 1603] 
Wdf01000!FxDevice::DispatchWithLock+0x156 [minkernel\wdf\framework\shared\core\fxdevice.cpp @ 1447] 
nt!IofCallDriver+0x55
nt!IopSynchronousServiceTail+0x34c
nt!IopXxxControlFile+0xc71
nt!NtDeviceIoControlFile+0x56
nt!KiSystemServiceCopyEnd+0x28
ntdll!NtDeviceIoControlFile+0x14
KERNELBASE!DeviceIoControl+0x121
KERNEL32!DeviceIoControlImplementation+0x81
MyApp+0x8459f

Mark_Roddy · July 6, 2023, 6:59pm

The debugger extension !wdfkd is your friend here. My guess is that you’ve already completed the forwarded request by accident. Start with:

!wdfkd.wdflogdump
The extension can also show you the state of all requests and queues in your driver.

Tim_Roberts · July 6, 2023, 7:49pm

Are those from two different dumps, or from two processors in a single dump? What is it that you are freeing at line 83 and line 90 of your Async.cpp?

tuple_cat · July 8, 2023, 9:31pm

The stacktraces are from the same dump.

The request is not completed, but I put it on a third queue… so I actually have a third manual queue, but I did not think it was interesting when I wrote the question, and this queue is for storing request so that I can complete them later (similar to inverted call model).

…and I now realize that I probably have had the wrong understanding of when the next request is delivered to a queues EvtIoDeviceControl.

I’ve been thinking that the next request isn’t delivered until one returns from EvtIoDeviceControl with a queue configured with WdfIoQueueDispatchSequential, but I guess the next request can be delivered after I’ve called WdfRequestComplete, or after I’ve put the request on another queue.

…after I’ve put the request on the third queue I do some other things, and here I guess that I cannot be sure that there is only one thread running at the same time.