Puzzled with verifier bugcheck

Hi guys,

I have a filter driver that for some IRPs requires some extra work after driver below has completed IRP handling. For that I set completion routine which always returns STATUS_MORE_PROCESSING_REQUIRED:

Can you spot an error here:

// My IRP dispatcher
NTSTATUS MyIRPDispatch(PIRP irp) {
IoCopyCurrentIrpStackLocationToNext(irp);

//
// ... Change some parameters.
//

KEVENT sync_event;
KeInitializeEvent(&sync_event, NotificationEvent, FALSE);
IoSetCompletionRoutine(irp, CompletionSync, &sync_event, TRUE, TRUE, TRUE);
status = IoCallDriver(device_to_call, irp);
KeWaitForSingleObject(&sync_event, Executive, KernelMode, FALSE, NULL);

//
// ... Do whatever I need to do after IRP was completed by driver bellow
//

irp->IoStatus.Status = my_completion_status;
irp->IoStatus.Information = my_completion_info;
IoCompleteRequest(irp, IO_NO_INCREMENT);
return my_completion_status;
}

// Completion routine
NTSTATUS CompletionSync(PDEVICE_OBJECT device_object, PIRP irp, PVOID context) {
PKEVENT event_to_set = (PKEVENT)context;
if (irp->PendingReturned) {
//
// ... Do nothing here, since my driver will
// never return STATUS_PENDING for that IRP.
//
}
KeSetEvent(event_to_set, IO_NO_INCREMENT, FALSE);

return STATUS_MORE_PROCESSING_REQUIRED;
}

At some point I'm getting a verifier bugcheck (I have turned on all verifier options, except for "low resources"):

*** Fatal System Error: 0x000000cc
(0xFFFFF9801A42EC12,0x0000000000000000,0xFFFFF8000372303F,0x0000000000000000)

Break instruction exception - code 80000003 (first chance)

A fatal system error has occurred.
Debugger entered on first try; Bugcheck callbacks have not been invoked.

A fatal system error has occurred.

Connected to Windows 7 7600 x64 target at (Mon Mar 7 14:00:33.593 2011 (UTC - 8:00)), ptr64 TRUE
Loading Kernel Symbols

BugCheck CC, {fffff9801a42ec12, 0, fffff8000372303f, 0}

Probably caused by : ntkrnlmp.exe ( nt!IovCompleteRequest+3f )

Followup: MachineOwner

nt!DbgBreakPointWithStatus:
fffff800`0327a7a0 cc int 3
1: kd> !analyze -v
ERROR: FindPlugIns 8007007b

PAGE_FAULT_IN_FREED_SPECIAL_POOL (cc)
Memory was referenced after it was freed.
This cannot be protected by try-except.
When possible, the guilty driver's name (Unicode string) is printed on
the bugcheck screen and saved in KiBugCheckDriver.
Arguments:
Arg1: fffff9801a42ec12, memory referenced
Arg2: 0000000000000000, value 0 = read operation, 1 = write operation
Arg3: fffff8000372303f, if non-zero, the address which referenced memory.
Arg4: 0000000000000000, Mm internal code.

Debugging Details:

READ_ADDRESS: fffff9801a42ec12 Special pool

FAULTING_IP:
nt!IovCompleteRequest+3f
fffff800`0372303f 8a4342 mov al,byte ptr [rbx+42h]

MM_INTERNAL_CODE: 0

DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT

BUGCHECK_STR: 0xCC

PROCESS_NAME: System

CURRENT_IRQL: 2

TRAP_FRAME: fffff88003708a60 -- (.trap 0xfffff88003708a60)
NOTE: The trap frame does not contain all registers.
Some register values may be zeroed or incorrect.
rax=fffffa8009ebe200 rbx=0000000000000000 rcx=0000000000000000
rdx=0000000000000004 rsi=0000000000000000 rdi=0000000000000000
rip=fffff8000372303f rsp=fffff88003708bf0 rbp=fffff9801a42efb8
r8=000000000000002c r9=fffff800034b77e0 r10=fffff88003708d40
r11=0000000000000000 r12=0000000000000000 r13=0000000000000000
r14=0000000000000000 r15=0000000000000000
iopl=0 nv up ei pl zr na po nc
nt!IovCompleteRequest+0x3f:
fffff800`0372303f 8a4342 mov al,byte ptr [rbx+42h] ds:e200:0042=??
Resetting default scope

LAST_CONTROL_TRANSFER: from fffff800033796d2 to fffff8000327a7a0

STACK_TEXT:
fffff88003708188 fffff800033796d2 : fffff9801a42ec12 fffffa8009deb660 0000000000000065 fffff800032c0c24 : nt!DbgBreakPointWithStatus
fffff88003708190 fffff8000337a4be : fffff88000000003 fffff88003708a60 fffff800032bd7f0 00000000000000cc : nt!KiBugCheckDebugBreak+0x12
fffff880037081f0 fffff80003282844 : 0000000000000000 0000000000000000 0000000000000000 fffff80003728340 : nt!KeBugCheck2+0x71e
fffff880037088c0 fffff80003302f14 : 0000000000000050 fffff9801a42ec12 0000000000000000 fffff88003708a60 : nt!KeBugCheckEx+0x104
fffff88003708900 fffff8000328082e : 0000000000000000 fffff9801a42ebd0 0000000000000000 fffffa8009cd1578 : nt! ?? ::FNODOBFM::string'+0x42837 fffff88003708a60 fffff8000372303f : 0000000000000000 0000000000000000 fffffa800ba40640 fffffa800ba40748 : nt!KiPageFault+0x16e fffff88003708bf0 fffff80003728300 : fffffa800adace30 fffff9801a42ebd0 fffffa800b027400 fffff9801a42ebd0 : nt!IovCompleteRequest+0x3f fffff88003708cc0 fffff8000372836c : fffff80003430540 0000000000000080 fffffa8009da26f0 0000000000000100 : nt!ViPendingCompleteAfterWait+0x90 fffff88003708d00 fffff800035257c6 : 0000000000000000 0000000000000000 0000000000000000 0000000000000000 : nt!ViPendingWorkerThread+0x2c fffff88003708d40 fffff80003260c26 : fffff880009ce180 fffffa8009deb660 fffff880009d90c0 0000000000000000 : nt!PspSystemThreadStartup+0x5a fffff88003708d80 0000000000000000 : fffff88003709000 fffff88003703000 fffff88003708a60 00000000`00000000 : nt!KxStartSystemThread+0x16

STACK_COMMAND: kb

FOLLOWUP_IP:
nt!IovCompleteRequest+3f
fffff800`0372303f 8a4342 mov al,byte ptr [rbx+42h]

SYMBOL_STACK_INDEX: 6

SYMBOL_NAME: nt!IovCompleteRequest+3f

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: nt

IMAGE_NAME: ntkrnlmp.exe

DEBUG_FLR_IMAGE_TIMESTAMP: 4cc791bd

FAILURE_BUCKET_ID: X64_0xCC_VRF_nt!IovCompleteRequest+3f

BUCKET_ID: X64_0xCC_VRF_nt!IovCompleteRequest+3f

Followup: MachineOwner

The faulty address belongs to the IRP that just went through MyIRPDispatch, and has been completed there. Looks like verifier is trying to complete that IRP (if I'm not mostaken) which causes a BSOD.

So, what am I doing wrong in my dispatch / completion?

TIA.

Vladimir

You’re sure my_completion_status can NEVER be STATUS_PENDING by mistake?

Right. For one thing, you’re not propagating the pending bit from the lower stack location in the irp (sri… Hard to type a good answer from my iPad).

Peter
OSR

Peter,

If you return STATUS_MORE_PROCESSING_REQUIRED, you should NOT pay attention to PendingReturned in your completion routine.

IoMarkIrpPending should match what YOUR dispatch routine returns. If you hold the IRP, call IoCompleteRequest, and return non-pending status, IoMarkIrpPending should not be called for your stack location.

Sorry guys, my code posted here was misleading (the actual code is a bit more complex). The bottom line is that my completion routine randomly returned status other than “more processing required”, which lead to two attempts to complete the IRP.

Yes, agreed.

Peter
OSR

> [quote]

If you hold the IRP, call IoCompleteRequest, and return non-pending status,
IoMarkIrpPending
should not be called for your stack location.
[/quote]

Yes, agreed.

This also applies to calling the lower driver synchronously (which was my point). The OP doesn’t need to do IoMarkIrpPending.

In fact, it’s not that he doesn’t NEED to do IoMarkIrpPending… it’s that he CAN’T do IoMarkIrpPending, unless he DOES return STATUS_PENDING.

He needs to follow the rules, plain and simple,

Peter
OSR