Bugcheck in WDF completion routine

Hi All,

I was calling the completion routine of WDF in my ISR. I know this is not the appropriate way of doing this, but this is what I had. After several I/Os, kernel bugchecks with code 0x0A (see below). Not able to find much information on the KeAcquireQueuedSpinLockRaiseToSynch, to understand the situation better. Now I am changing the code to call the completion routine in DPC.

I have some questions in this regard.

  1. If calling a completion routine in DIRQL is a problem, why the kernel didn’t bugcheck for the first I/O? I am getting this bugcheck after several I/O completions.

  2. Is this problem different from calling completion routine in ISR?

  3. If my understanding is correct, is it appropriate to call completion routine from DPC or shuold I call it in PASSIVE_LEVEL?

  4. Is there any document on I/O completion routine path? Or can you explain this scenario?

********************************
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: 000083b4, memory referenced
Arg2: 00000002, IRQL
Arg3: 00000001, 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: 81c1d073, address which referenced memory

Debugging Details:

WRITE_ADDRESS: 000083b4

CURRENT_IRQL: 2

FAULTING_IP:
hal!KeAcquireQueuedSpinLockRaiseToSynch+33
81c1d073 8902 mov dword ptr [edx],eax

DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT

BUGCHECK_STR: 0xA

PROCESS_NAME: Dynamo.exe

TRAP_FRAME: 9388f1bc – (.trap 0xffffffff9388f1bc)
ErrCode = 00000002
eax=83b48548 ebx=00000001 ecx=81d84d42 edx=000083b4 esi=00000000 edi=81d48580
eip=81c1d073 esp=9388f230 ebp=9388f27c iopl=0 nv up ei ng nz na po nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010282
hal!KeAcquireQueuedSpinLockRaiseToSynch+0x33:
81c1d073 8902 mov dword ptr [edx],eax ds:0023:000083b4=???
Resetting default scope

LAST_CONTROL_TRANSFER: from 81d192d7 to 81d04514

STACK_TEXT:
9388ed7c 81d192d7 00000003 f4fa7a1e 00000000 nt!RtlpBreakWithStatusInstruction
9388edcc 81d19dbd 00000003 000083b4 81c1d073 nt!KiBugCheckDebugBreak+0x1c
9388f19c 81ca6d84 0000000a 000083b4 00000002 nt!KeBugCheck2+0x66d
9388f19c 81c1d073 0000000a 000083b4 00000002 nt!KiTrap0E+0x2ac
9388f230 81cc058c 862bc930 86763b38 00000000 hal!KeAcquireQueuedSpinLockRaiseToSynch+0x33
9388f27c 81c86353 862bc930 00000000 867c8850 nt!MmUnlockPages+0x73f
9388f2a8 8239cd6b 85093280 867c8850 00000000 nt!IopfCompleteRequest+0x388
9388f2d0 8238f983 00000001 00000001 84e2b36c Wdf01000!FxRequest::CompleteInternal+0x379
9388f2e8 8b7e76cd 00000000 867c8850 00000001 Wdf01000!imp_WdfRequestCompleteWithInformation+0x114
********************************

Completing irps at DIRQL is undefined, it is not guaranteed to bugcheck the first time. Analyzing the crash you have is pointless, you fixed the underlying problem. You can complete io at dispatch_level in a dpc

d

dent from a phpne with no keynoard

-----Original Message-----
From: xxxxx@hcl.in
Sent: June 23, 2010 7:13 PM
To: Windows System Software Devs Interest List
Subject: [ntdev] Bugcheck in WDF completion routine

Hi All,

I was calling the completion routine of WDF in my ISR. I know this is not the appropriate way of doing this, but this is what I had. After several I/Os, kernel bugchecks with code 0x0A (see below). Not able to find much information on the KeAcquireQueuedSpinLockRaiseToSynch, to understand the situation better. Now I am changing the code to call the completion routine in DPC.

I have some questions in this regard.

1. If calling a completion routine in DIRQL is a problem, why the kernel didn’t bugcheck for the first I/O? I am getting this bugcheck after several I/O completions.

2. Is this problem different from calling completion routine in ISR?

3. If my understanding is correct, is it appropriate to call completion routine from DPC or shuold I call it in PASSIVE_LEVEL?

4. Is there any document on I/O completion routine path? Or can you explain this scenario?


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: 000083b4, memory referenced
Arg2: 00000002, IRQL
Arg3: 00000001, 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: 81c1d073, address which referenced memory

Debugging Details:
------------------

WRITE_ADDRESS: 000083b4

CURRENT_IRQL: 2

FAULTING_IP:
hal!KeAcquireQueuedSpinLockRaiseToSynch+33
81c1d073 8902 mov dword ptr [edx],eax

DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT

BUGCHECK_STR: 0xA

PROCESS_NAME: Dynamo.exe

TRAP_FRAME: 9388f1bc – (.trap 0xffffffff9388f1bc)
ErrCode = 00000002
eax=83b48548 ebx=00000001 ecx=81d84d42 edx=000083b4 esi=00000000 edi=81d48580
eip=81c1d073 esp=9388f230 ebp=9388f27c iopl=0 nv up ei ng nz na po nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010282
hal!KeAcquireQueuedSpinLockRaiseToSynch+0x33:
81c1d073 8902 mov dword ptr [edx],eax ds:0023:000083b4=???
Resetting default scope

LAST_CONTROL_TRANSFER: from 81d192d7 to 81d04514

STACK_TEXT:
9388ed7c 81d192d7 00000003 f4fa7a1e 00000000 nt!RtlpBreakWithStatusInstruction
9388edcc 81d19dbd 00000003 000083b4 81c1d073 nt!KiBugCheckDebugBreak+0x1c
9388f19c 81ca6d84 0000000a 000083b4 00000002 nt!KeBugCheck2+0x66d
9388f19c 81c1d073 0000000a 000083b4 00000002 nt!KiTrap0E+0x2ac
9388f230 81cc058c 862bc930 86763b38 00000000 hal!KeAcquireQueuedSpinLockRaiseToSynch+0x33
9388f27c 81c86353 862bc930 00000000 867c8850 nt!MmUnlockPages+0x73f
9388f2a8 8239cd6b 85093280 867c8850 00000000 nt!IopfCompleteRequest+0x388
9388f2d0 8238f983 00000001 00000001 84e2b36c Wdf01000!FxRequest::CompleteInternal+0x379
9388f2e8 8b7e76cd 00000000 867c8850 00000001 Wdf01000!imp_WdfRequestCompleteWithInformation+0x114



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

Your driver is part of the OS. As such, it’s trusted to ALWAYS “do the right thing” – The OS doesn’t validate every operation your driver performs. So, when you do something that’s not allowed (like calling WdfRequestComplete at IRQL > DISPATCH_LEVEL) the OS *might* work sometimes, it might take a long while to crash as a result, or it might crash immediately. This doesn’t change whether or not the operation is allowed. Architecturally, you are NOT allowed to EVER complete requests at IRQLs > DISPATCH_LEVEL. Period. Full stop. End of story. Bas.

Note that the IRQLs at which functions can be called appears in the documentation. You must follow these rules. They are not recommendations, they are the definition of the contract and are thus absolute.

The most common place to call WdfRequestComplete or IoCompleteRequest is from your DpcForIsr, which runs at IRQL DISPATCH_LEVEL.

I/O Completion is a surprisingly complex topic in Windows. Much of the annoyance and ugliness is hidden from you by KMDF, which is a very good thing, and another great reason to use KMDF. The base model for I/O Completion handling is described here:

http://www.osronline.com/article.cfm?id=83

Peter
OSR