Bugcheck on WdfRequestComplete

Hi all,

I’m writing an upper filter driver on the USB stack using kmdf and I recently came across a problem I suppose related to the USB target object (and methods).

On a specific device I need to send every now and then a custom device request. Upon startup of the device, when the driver loads and right after everything is set up, I send down a device request and everything is ok.
I also have a timer that when expires, send the same device request.

My first attempt was to send he request synchronously. That caused a bug check. Without any further experiment I quickly switched to asynchronous with a completion routine that right now only completes he request propagating the status. Apparently the device request is sent but then I get a bug check on the wdfrequestcomplete with a IRQL_LESS_OR_EQUAL. Besides completing the request I really don’t do anything at this point. The bug check actually happens in the kmdf code but of course I believe I’m doing something wrong upfront.

Is there any specific issue that I should be considering with using USB targets and timers?

Thank you in advance,
Marco

Send the output of !analyze -v and !wdfkd.wdflogdump . You cannot call WdfRequestComplete on a driver created request BTW

d

-----Original Message-----
From: xxxxx@lists.osr.com [mailto:xxxxx@lists.osr.com] On Behalf Of xxxxx@laurenzano.it
Sent: Wednesday, September 15, 2010 2:19 PM
To: Windows System Software Devs Interest List
Subject: [ntdev] Bugcheck on WdfRequestComplete

Hi all,

I’m writing an upper filter driver on the USB stack using kmdf and I recently came across a problem I suppose related to the USB target object (and methods).

On a specific device I need to send every now and then a custom device request. Upon startup of the device, when the driver loads and right after everything is set up, I send down a device request and everything is ok.
I also have a timer that when expires, send the same device request.

My first attempt was to send he request synchronously. That caused a bug check. Without any further experiment I quickly switched to asynchronous with a completion routine that right now only completes he request propagating the status. Apparently the device request is sent but then I get a bug check on the wdfrequestcomplete with a IRQL_LESS_OR_EQUAL. Besides completing the request I really don’t do anything at this point. The bug check actually happens in the kmdf code but of course I believe I’m doing something wrong upfront.

Is there any specific issue that I should be considering with using USB targets and timers?

Thank you in advance,
Marco


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

Hi,

it turned out that removing the WdfRequestComplete from that completion routine fixed that problem.

With that out of the way, I got another problem, probably bigger, that makes me question the entire scheme that I’m trying to use.

As I mentioned, my driver is installed as a filter driver in the USB stack, and installs an handler on the IoInternalDeviceControl with the purpose of filtering the reports coming from a specific device.
The filtering of course is done in the completion routine.

Now, I would like to be able to “drop” some reports that match some criteria and in order to do that I did what I’m did in the past in a hid filter driver: in the completion routine I send back the request down instead of completing it with something like this:

WdfRequestFormatRequestUsingCurrentType(Request);
WdfRequestSetCompletionRoutine(Request, InternalIoDeviceControlCompletionRoutine, (void *) deviceExt);
WdfRequestSend(Request, Target, WDF_NO_SEND_OPTIONS);

I wrote this and I got a bugcheck IRQL_LESS_OR_EQUAL. The stack trace was pretty long but it seemed triggered by the WdfRequestSend.
Without thinking too much, I tried to move this code into a work item. So the completion routine would just move the request into a manual queue and enqueue a work item. The work item would have pretty much the same code written above.
This didn’t work out either, with exactly the same time of bugcheck.

I ran !analyze on it and I attached the results at the end of the post. I wonder if what I’m trying to do makes some sense or not. Writing a filter on the USB stack is somewhat a new thing to me and it seems that techniques that I used in other circumstances don’t really apply here.

Does anybody have any idea about this?

Thank you in advance,
Marco.

IRQL_NOT_LESS_OR_EQUAL (a)
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 a kernel debugger is available get the stack backtrace.
Arguments:
Arg1: 9a96176c, memory referenced
Arg2: 00000002, IRQL
Arg3: 00000000, bitfield :
bit 0 : value 0 = read operation, 1 = write operation
bit 3 : value 0 = not an execute operation, 1 = execute operation (only on chips which support this level of status)
Arg4: 805068e1, address which referenced memory

Debugging Details:

READ_ADDRESS: 9a96176c

CURRENT_IRQL: 2

FAULTING_IP:
nt!MmMapLockedPagesSpecifyCache+211
805068e1 8b530c mov edx,dword ptr [ebx+0Ch]

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0xA

PROCESS_NAME: System

TRAP_FRAME: f8aed9ac – (.trap 0xfffffffff8aed9ac)
ErrCode = 00000000
eax=80ead568 ebx=9a961760 ecx=82254564 edx=80553c20 esi=00000000 edi=00000163
eip=805068e1 esp=f8aeda20 ebp=f8aeda4c iopl=0 nv up ei ng nz na pe nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00210286
nt!MmMapLockedPagesSpecifyCache+0x211:
805068e1 8b530c mov edx,dword ptr [ebx+0Ch] ds:0023:9a96176c=???
Resetting default scope

LAST_CONTROL_TRANSFER: from 804f7bad to 80527c0c

STACK_TEXT:
f8aed560 804f7bad 00000003 f8aed8bc 00000000 nt!RtlpBreakWithStatusInstruction
f8aed5ac 804f879a 00000003 9a96176c 805068e1 nt!KiBugCheckDebugBreak+0x19
f8aed98c 805406cb 0000000a 9a96176c 00000002 nt!KeBugCheck2+0x574
f8aed98c 805068e1 0000000a 9a96176c 00000002 nt!KiTrap0E+0x233
f8aeda4c 80506aae 82254548 1f000000 c07c68a8 nt!MmMapLockedPagesSpecifyCache+0x211
f8aeda6c f82f3e23 82254548 00000000 00000001 nt!MmMapLockedPages+0x18
f8aedae0 806d53c8 82330028 00000000 00000000 USBPORT!USBPORT_MapTransfer+0xcf
f8aedb0c 804edf6c 821731c8 8233005c 00000001 hal!HalAllocateAdapterChannel+0x126
f8aedb24 f82f46df 821731c8 82330028 00000001 nt!IoAllocateAdapterChannel+0x2a
f8aedb68 f82f54d9 82330028 8212bbe8 80542718 USBPORT!USBPORT_FlushMapTransferList+0x1b1
f8aedbc4 f82f63c6 00cc4df8 ffffffff 80542718 USBPORT!USBPORT_FlushPendingList+0x5b1
f8aedbf4 f82fd350 822251e8 f8aedc2c f82fcf14 USBPORT!USBPORT_QueueTransferUrb+0x248
f8aedc00 f82fcf14 82330028 8212bbe8 81faf4a8 USBPORT!USBPORT_AsyncTransfer+0x30
f8aedc2c f8302088 81f85030 82330028 00000090 USBPORT!USBPORT_ProcessURB+0x3f4
f8aedc4c f82eb3d2 81f85030 8212bbe8 8212bbe8 USBPORT!USBPORT_PdoInternalDeviceControlIrp+0x7e
f8aedc70 804ee129 8212bca0 81f85188 81faf4a8 USBPORT!USBPORT_Dispatch+0x148
f8aedc80 f885a59c f8aedca8 f885e82d 8212bbe8 nt!IopfCallDriver+0x31
f8aedc88 f885e82d 8212bbe8 81f85030 8212bbe8 usbhub!USBH_PassIrp+0x18
f8aedca8 f885f0ae 81d9b0e8 8212bbe8 7e33e808 usbhub!USBH_PdoUrbFilter+0xbd
f8aedcc4 f885c5e4 81faf4a8 8212bbe8 f8aedcfc usbhub!USBH_PdoDispatch+0x202
f8aedcd4 804ee129 821bbb70 8212bbe8 00000000 usbhub!USBH_HubDispatch+0x48
f8aedce4 b17a9164 806d2720 81f45870 00000000 nt!IopfCallDriver+0x31
f8aedcfc f8a42a1d 00000005 821ba4f8 81cc17f0 wdf01000!imp_WdfRequestSend+0x2de
f8aedd14 f8a47bf8 7de45b00 7e33e808 00000000 mytdrv!WdfRequestSend+0x1d [c:\winddk\7600.16385.0\inc\wdf\kmdf\1.9\wdfrequest.h @ 661]
f8aedd38 b17bd042 7e0ba788 81f49180 81f45870 mytdrv!EvtForwardWorkItem+0x68 [c:\my code\mytdrvmain.c @ 395]
f8aedd54 b17bd0aa 81d12020 f8aedd74 8056bd37 wdf01000!FxWorkItem::WorkItemHandler+0xad
f8aedd60 8056bd37 81d12020 81f45870 8055b17c wdf01000!FxWorkItem::WorkItemThunk+0x19
f8aedd74 80534c32 81f49180 00000000 823c6b30 nt!IopProcessWorkItem+0x13
f8aeddac 805c61e0 81f49180 00000000 00000000 nt!ExpWorkerThread+0x100
f8aedddc 80541e12 80534b32 00000001 00000000 nt!PspSystemThreadStartup+0x34
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16

STACK_COMMAND: kb

FOLLOWUP_IP:
mytdrv!WdfRequestSend+1d [c:\winddk\7600.16385.0\inc\wdf\kmdf\1.9\wdfrequest.h @ 661]
f8a42a1d 5d pop ebp

FAULTING_SOURCE_CODE:
657: PWDF_REQUEST_SEND_OPTIONS Options
658: )
659: {
660: return ((PFN_WDFREQUESTSEND) WdfFunctions[WdfRequestSendTableIndex])(WdfDriverGlobals, Request, Target, Options);

661: }
662:
663: //
664: // WDF Function: WdfRequestGetStatus
665: //
666: typedef

SYMBOL_STACK_INDEX: 17

SYMBOL_NAME: mytdrv!WdfRequestSend+1d

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: mytdrv

IMAGE_NAME: mytdrv.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 4c9407d7

FAILURE_BUCKET_ID: 0xA_mytdrv!WdfRequestSend+1d

BUCKET_ID: 0xA_mytdrv!WdfRequestSend+1d

Followup: MachineOwner