WdfRequestReuse within a completion callback

Hello,

I am developing a USB driver which needs to be working for operating
systems from WinXP to Win8.1.

The driver is working perfectly on all the operating systems except the
WinXP x86 operating system.

As soon as the Windows application tries to communicate with the device the
OS gives a BSOD.

It looks like it is failing when I call ‘WdfRequestReuse’ which I call
within the ‘Bulk Read Completion Callback’. I think this is allowed. I am
really surprised because this driver works well on all the other OSes.

The !analyze -v output looks like below,

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

ATTEMPTED_SWITCH_FROM_DPC (b8)
A wait operation, attach process, or yield was attempted from a DPC routine.
This is an illegal operation and the stack track will lead to the offending
code and original DPC routine.
Arguments:
Arg1: 00000000, Original thread which is the cause of the failure
Arg2: 00000000, New thread
Arg3: 00000000, Stack address of the original thread
Arg4: 00000000

Debugging Details:

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0xB8

PROCESS_NAME: csrss.exe

LAST_CONTROL_TRANSFER: from 804f780d to 80526da8

STACK_TEXT:
8054874c 804f780d 00000003 80548aa8 00000000
nt!RtlpBreakWithStatusInstruction
80548798 804f83fa 00000003 80551920 89ce1da8 nt!KiBugCheckDebugBreak+0x19
80548b78 804f8900 000000b8 00000000 00000000 nt!KeBugCheck2+0x574
80548b98 80540c07 000000b8 ffffffff 00000202 nt!KeBugCheck+0x14
80548ba8 805409e2 80548bf4 80551920 ffdff120 nt!SwapContext+0x157
80548bbc 8050017a 805519d8 80551920 804f93fb nt!KiSwapContext+0x2e
80548bc8 804f93fb 00000000 89a47e48 89a82f88 nt!KiSwapThread+0x46
80548bf4 ba2fe81b 00000000 00000000 ffdff120 nt!KeDelayExecutionThread+0x1c9
WARNING: Stack unwind information not available. Following frames may be
wrong.
80548c34 b1de0317 765b8288 762d8400 898fdcec ustp2+0x81b
80548c60 b1dc4c36 898d04a3 89d27bf8 00000000
wdf01000!FxRequestBase::CompleteSubmitted+0xf6
80548c7c b1dc4cde 01a47d70 89b909d0 80548ca8
wdf01000!FxIoTarget::RequestCompletionRoutine+0x12d
80548c8c 804ef403 898af9a8 898d03e8 89a47d70
wdf01000!FxIoTarget::_RequestCompletionRoutine+0x35
80548ca8 804f0362 898af9a8 898d03e8 89b909d0 nt!IopUnloadSafeCompletion+0x1d
80548cd8 ba4dfee5 898d03e8 89c6d008 89d9b028 nt!IopfCompleteRequest+0xa2
80548d40 ba4e0b57 898fdd34 00000000 89d9b7d8
USBPORT!USBPORT_CompleteTransfer+0x373
80548d70 ba4e1754 026e6f44 89d9b0e0 89d9b0e0
USBPORT!USBPORT_DoneTransfer+0x137
80548da8 ba4e2f6a 89d9b028 805418a8 89d9b230
USBPORT!USBPORT_FlushDoneTransferList+0x16c
80548dd4 ba4f0fb0 89d9b028 805418a8 89d9b028 USBPORT!USBPORT_DpcWorker+0x224
80548e10 ba4f1128 89d9b028 00000001 80551b80
USBPORT!USBPORT_IsrDpcWorker+0x37e
80548e2c 80540d5d 89d9b64c 6b755044 00000000 USBPORT!USBPORT_IsrDpc+0x166
80548e50 80540cd6 00000000 0000000e 00000000 nt!KiRetireDpcList+0x46
80548e54 00000000 0000000e 00000000 00000000 nt!KiIdleLoop+0x26

STACK_COMMAND: kb

FOLLOWUP_IP:
ustp2+81b
ba2fe81b 8b5d08 mov ebx,dword ptr [ebp+8]

SYMBOL_STACK_INDEX: 8

SYMBOL_NAME: ustp2+81b

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: ustp2

IMAGE_NAME: ustp2.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 540ff1fa

FAILURE_BUCKET_ID: 0xB8_ustp2+81b

BUCKET_ID: 0xB8_ustp2+81b

Followup: MachineOwner

Previously the symbols were correct. Now don’t know what happened the
symbols appeared to be not found. Can someone give me a help regarding this?

-Pradeepa

Fixed symbols. May be it is due to the ‘KeDelayExecutionThread’?

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

ATTEMPTED_SWITCH_FROM_DPC (b8)
A wait operation, attach process, or yield was attempted from a DPC routine.
This is an illegal operation and the stack track will lead to the offending
code and original DPC routine.
Arguments:
Arg1: 00000000, Original thread which is the cause of the failure
Arg2: 00000000, New thread
Arg3: 00000000, Stack address of the original thread
Arg4: 00000000

Debugging Details:

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0xB8

PROCESS_NAME: csrss.exe

LAST_CONTROL_TRANSFER: from 804f780d to 80526da8

STACK_TEXT:
80548730 804f780d 00000003 80548a8c 00000000
nt!RtlpBreakWithStatusInstruction
8054877c 804f83fa 00000003 80551920 89cec958 nt!KiBugCheckDebugBreak+0x19
80548b5c 804f8900 000000b8 00000000 00000000 nt!KeBugCheck2+0x574
80548b7c 80540c07 000000b8 ffffffff 00000202 nt!KeBugCheck+0x14
80548b8c 805409e2 80548bd8 80551920 ffdff120 nt!SwapContext+0x157
80548ba0 8050017a 805519d8 80551920 804f93fb nt!KiSwapContext+0x2e
80548bac 804f93fb 898eb3ac 898da7b8 00000000 nt!KiSwapThread+0x46
80548bd8 baca2b89 00000000 00000000 ffdff120 nt!KeDelayExecutionThread+0x1c9
80548c34 b1107317 76725840 7636b178 898eb3ac
ustp2!RDMUsb_BulkReadComplete+0x149
[f:\rdm\ec7000\svn_pradeepa\wdf_usbdriver_rdm_without_cr_logic_in_completion_callback\src\device.c
@ 1453]
80548c60 b10ebc36 89ba2a2b 89c94e80 00000000
wdf01000!FxRequestBase::CompleteSubmitted+0xf6
80548c7c b10ebcde 018da7b8 89abb1a8 80548ca8
wdf01000!FxIoTarget::RequestCompletionRoutine+0x12d
80548c8c 804ef403 89bb82d8 89ba2970 898da7b8
wdf01000!FxIoTarget::_RequestCompletionRoutine+0x35
80548ca8 804f0362 89bb82d8 89ba2970 89abb1a8 nt!IopUnloadSafeCompletion+0x1d
80548cd8 ba4c8ee5 89ba2970 89c9f5e8 89a79028 nt!IopfCompleteRequest+0xa2
80548d40 ba4c9b57 898eb3f4 00000000 89a797d8
USBPORT!USBPORT_CompleteTransfer+0x373
80548d70 ba4ca754 026e6f44 89a790e0 89a790e0
USBPORT!USBPORT_DoneTransfer+0x137
80548da8 ba4cbf6a 89a79028 805418a8 89a79230
USBPORT!USBPORT_FlushDoneTransferList+0x16c
80548dd4 ba4d9fb0 89a79028 805418a8 89a79028 USBPORT!USBPORT_DpcWorker+0x224
80548e10 ba4da128 89a79028 00000001 80551b80
USBPORT!USBPORT_IsrDpcWorker+0x37e
80548e2c 80540d5d 89a7964c 6b755044 00000000 USBPORT!USBPORT_IsrDpc+0x166
80548e50 80540cd6 00000000 0000000e 00000000 nt!KiRetireDpcList+0x46
80548e54 00000000 0000000e 00000000 00000000 nt!KiIdleLoop+0x26

STACK_COMMAND: kb

FOLLOWUP_IP:
ustp2!RDMUsb_BulkReadComplete+149
[f:\rdm\ec7000\svn_pradeepa\wdf_usbdriver_rdm_without_cr_logic_in_completion_callback\src\device.c
@ 1453]
baca2b89 eb07 jmp ustp2!RDMUsb_BulkReadComplete+0x152
(baca2b92)

FAULTING_SOURCE_CODE:
1449: {
1450: KeDelayExecutionThread(KernelMode,FALSE,&delay);
1451: }
1452: }

1453: else
1454: {
1455: iRequestPending = 0;
1456: }
1457: }
1458:

SYMBOL_STACK_INDEX: 8

SYMBOL_NAME: ustp2!RDMUsb_BulkReadComplete+149

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: ustp2

IMAGE_NAME: ustp2.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 54102451

FAILURE_BUCKET_ID: 0xB8_ustp2!RDMUsb_BulkReadComplete+149

BUCKET_ID: 0xB8_ustp2!RDMUsb_BulkReadComplete+149

Followup: MachineOwner

-Pradeepa

On Wed, Sep 10, 2014 at 3:11 PM, Pradeepa Senanayake <
xxxxx@gmail.com> wrote:

Hello,

I am developing a USB driver which needs to be working for operating
systems from WinXP to Win8.1.

The driver is working perfectly on all the operating systems except the
WinXP x86 operating system.

As soon as the Windows application tries to communicate with the device
the OS gives a BSOD.

It looks like it is failing when I call ‘WdfRequestReuse’ which I call
within the ‘Bulk Read Completion Callback’. I think this is allowed. I am
really surprised because this driver works well on all the other OSes.

The !analyze -v output looks like below,

kd> !analyze -v

*******************************************************************************
*
*
* Bugcheck Analysis
*
*
*

*******************************************************************************

ATTEMPTED_SWITCH_FROM_DPC (b8)
A wait operation, attach process, or yield was attempted from a DPC
routine.
This is an illegal operation and the stack track will lead to the offending
code and original DPC routine.
Arguments:
Arg1: 00000000, Original thread which is the cause of the failure
Arg2: 00000000, New thread
Arg3: 00000000, Stack address of the original thread
Arg4: 00000000

Debugging Details:

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0xB8

PROCESS_NAME: csrss.exe

LAST_CONTROL_TRANSFER: from 804f780d to 80526da8

STACK_TEXT:
8054874c 804f780d 00000003 80548aa8 00000000
nt!RtlpBreakWithStatusInstruction
80548798 804f83fa 00000003 80551920 89ce1da8 nt!KiBugCheckDebugBreak+0x19
80548b78 804f8900 000000b8 00000000 00000000 nt!KeBugCheck2+0x574
80548b98 80540c07 000000b8 ffffffff 00000202 nt!KeBugCheck+0x14
80548ba8 805409e2 80548bf4 80551920 ffdff120 nt!SwapContext+0x157
80548bbc 8050017a 805519d8 80551920 804f93fb nt!KiSwapContext+0x2e
80548bc8 804f93fb 00000000 89a47e48 89a82f88 nt!KiSwapThread+0x46
80548bf4 ba2fe81b 00000000 00000000 ffdff120
nt!KeDelayExecutionThread+0x1c9
WARNING: Stack unwind information not available. Following frames may be
wrong.
80548c34 b1de0317 765b8288 762d8400 898fdcec ustp2+0x81b
80548c60 b1dc4c36 898d04a3 89d27bf8 00000000
wdf01000!FxRequestBase::CompleteSubmitted+0xf6
80548c7c b1dc4cde 01a47d70 89b909d0 80548ca8
wdf01000!FxIoTarget::RequestCompletionRoutine+0x12d
80548c8c 804ef403 898af9a8 898d03e8 89a47d70
wdf01000!FxIoTarget::_RequestCompletionRoutine+0x35
80548ca8 804f0362 898af9a8 898d03e8 89b909d0
nt!IopUnloadSafeCompletion+0x1d
80548cd8 ba4dfee5 898d03e8 89c6d008 89d9b028 nt!IopfCompleteRequest+0xa2
80548d40 ba4e0b57 898fdd34 00000000 89d9b7d8
USBPORT!USBPORT_CompleteTransfer+0x373
80548d70 ba4e1754 026e6f44 89d9b0e0 89d9b0e0
USBPORT!USBPORT_DoneTransfer+0x137
80548da8 ba4e2f6a 89d9b028 805418a8 89d9b230
USBPORT!USBPORT_FlushDoneTransferList+0x16c
80548dd4 ba4f0fb0 89d9b028 805418a8 89d9b028
USBPORT!USBPORT_DpcWorker+0x224
80548e10 ba4f1128 89d9b028 00000001 80551b80
USBPORT!USBPORT_IsrDpcWorker+0x37e
80548e2c 80540d5d 89d9b64c 6b755044 00000000 USBPORT!USBPORT_IsrDpc+0x166
80548e50 80540cd6 00000000 0000000e 00000000 nt!KiRetireDpcList+0x46
80548e54 00000000 0000000e 00000000 00000000 nt!KiIdleLoop+0x26

STACK_COMMAND: kb

FOLLOWUP_IP:
ustp2+81b
ba2fe81b 8b5d08 mov ebx,dword ptr [ebp+8]

SYMBOL_STACK_INDEX: 8

SYMBOL_NAME: ustp2+81b

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: ustp2

IMAGE_NAME: ustp2.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 540ff1fa

FAILURE_BUCKET_ID: 0xB8_ustp2+81b

BUCKET_ID: 0xB8_ustp2+81b

Followup: MachineOwner

Previously the symbols were correct. Now don’t know what happened the
symbols appeared to be not found. Can someone give me a help regarding this?

-Pradeepa

You think?

You really can figure this out yourself. Here’s how:

The IRQL constraints for KeDelayExecutionThread, from the MSDN page say it can only be called at IRQL <= APC_LEVEL. See that doc page here:
http://msdn.microsoft.com/en-us/library/windows/hardware/ff551986(v=vs.85).aspx

I/O Completion Callbacks can run at IRQL DISPATCH_LEVEL. See the MSDN page at:
http://msdn.microsoft.com/en-us/library/windows/hardware/ff540745(v=vs.85).aspx

Sooooo… the conclusion: You can NOT call KeDelayExecutionThread from within an I/O Completion Callback, because the I/O Completion Callback could be running at IRQL DISPATCH_LEVEL.

And you’ve proven that right here.

Peter
OSR
@OSRDrivers

Yeah I commented that line and it worked. Thanx. I’m a fool.

-Pradeepa

On Wed, Sep 10, 2014 at 5:45 PM, wrote:

>


>
> You think?
>
> You really can figure this out yourself. Here’s how:
>
> The IRQL constraints for KeDelayExecutionThread, from the MSDN page say it
> can only be called at IRQL <= APC_LEVEL. See that doc page here:
>
> http://msdn.microsoft.com/en-us/library/windows/hardware/ff551986(v=vs.85).aspx
>
> I/O Completion Callbacks can run at IRQL DISPATCH_LEVEL. See the MSDN page
> at:
>
> http://msdn.microsoft.com/en-us/library/windows/hardware/ff540745(v=vs.85).aspx
>
> Sooooo… the conclusion: You can NOT call KeDelayExecutionThread from
> within an I/O Completion Callback, because the I/O Completion Callback
> could be running at IRQL DISPATCH_LEVEL.
>
> And you’ve proven that right here.
>
> Peter
> OSR
> @OSRDrivers
>
>
> —
> 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
>