Verifier's bugcheck - Invalid IOSB in IRP at APC IoCompleteRequest

Hi, all

Please, could you help me with the following problem ?

In the filter driver, I’m intercepting a special call of
IRP_MJ_DEVICE_CONTROL (Ioctl code = 140FD3).
I change the handle stored in the data structure,
copy the stack location to next, initialize an event,
set completion routine (for signaling the event)
and call the next lower driver (quite normal scenario).
After return, the driver returns STATUS_PENDING,
so I wait for the event.

Then, Driver Verifier bugchecks with “Invalid IOSB
in IRP at APC IoCompleteRequest (appears to be
on stack that was unwound”. The Irp->UserIosb
was set to some user mode address when it went down.
I don’t change the field, in fact I don’t even touch it
before call to KeWaitForSingleObject
(the moment when the bugcheck occurs)

I made a breakpoint inside IoCompleteRequest,
and it seems that it’s been called with completely wrong
IRP, or that the IRP has been changed. or something like that.

Could you give me any clue what I am doing wrong ?
Below the stack text is the source of involved routines.

*** Here is the stack trace

DRIVER_VERIFIER_IOMANAGER_VIOLATION (c9)
The IO manager has caught a misbehaving driver.
Arguments:
Arg1: 0000000c, Invalid IOSB in IRP at APC IopCompleteRequest (appears to be
on
stack that was unwound)
Arg2: f078f790, the IOSB pointer , 3/4 - 0
Arg3: 00000000
Arg4: 00000000

STACK_TEXT:
f078f94c 8067191f 000000c9 0000000c f078f790 nt!KeBugCheckEx+0x1b
f078f968 80523978 82740f88 f078fa04 f078fa08 nt!IovpCompleteRequest+0x4c
f078f9c0 804f415a 82740f88 f078fa0c f078fa00 nt!IopCompleteRequest+0x39
f078fa10 804f4199 00000000 00000000 00000000 nt!KiDeliverApc+0xb3
f078fa28 804e36f2 00000000 f078faf0 82a82f00 nt!KiSwapThread+0x64
f078fa50 80672756 00000000 00000000 00000000 nt!KeWaitForSingleObject+0x1c2
f078fa78 baeac631 f078faf0 00000000 00000000
nt!VerifierKeWaitForSingleObject+0x56
f078fb1c baed21f8 ff51a978 82a82f48 f078fbe4
MyFilter!MyFilterMrxSmbCopyChunk+0x30c
f078fb68 baeb97ac ff51a978 82a82f48 ff51a978
MyFilter!MyFilterDeviceControl+0xd2
f078fc10 804ead77 ff51a978 82a82f48 806f42a4 MyFilter!MyFilterDispatch+0x409
f078fc20 806712c5 ff422240 806f4070 82a82f48 nt!IopfCallDriver+0x31
f078fc44 805719ab 82a82fdc ff4fadc0 82a82f48 nt!IovCallDriver+0xa0
f078fc58 805849f7 ff51a978 82a82f48 ff4fadc0
nt!IopSynchronousServiceTail+0x60
f078fd00 80586bfa 00000248 00000000 00000000 nt!IopXxxControlFile+0x611
f078fd34 804e606b 00000248 00000000 00000000 nt!NtDeviceIoControlFile+0x2a

*** Here is the handler of IRP_MJ_DEVICE_CONTROL:

switch(IrpSp->Parameters.DeviceIoControl.IoControlCode)
{
// This is an undocumented IOCTL.
// Don’t ask me why I need to deal with this call :-))
case IOCTL_MRXSMB_COPY_CHUNK: // BUGBUG: 140FD3 Really that IOCTL name
?
Status = MyFilterMrxSmbCopyChunk(FilterDevice, Irp);
break;

*** In the MyFilterMrxSmbCopyChunk:

NTSTATUS
MyFilterMrxSmbCopyChunk(
IN PFILTER_DEVICE_OBJECT FilterDevice,
IN PIRP Irp)
{
__try {

CopyChunkData = (PMRXSMB_COPY_CHUNK_DATA)Irp->UserBuffer;

if(CopyChunkData != NULL && OutputBufferLength >=
sizeof(MRXSMB_COPY_CHUNK_DATA))
{
// Replace the handle in CopyChunkData->FileHandle
// Prepare the stack location
IoCopyCurrentIrpStackLocationToNext(Irp);
KeInitializeEvent(&Event, NotificationEvent, FALSE);
IoSetCompletionRoutine(Irp,
MyFilterCopyChunkCompletion,
&Event,
TRUE,
TRUE,
TRUE);

// Call the lower driver
Status = IoCallDriver(DeviceObject->Vcb.NextLowerDevice, Irp);

if(Status == STATUS_PENDING)
{
// When waiting starts, the bugcheck comes.
// The completion routine is never called
KeWaitForSingleObject(Event, Executive,
KernelMode, FALSE, NULL);
Status = IoStatus->Status;
}
}
}
__finally
{
// Restore the file handle in the CopyChunkData
}

return Status;
}

NTSTATUS
MyFilterCopyChunkCompletion(
IN PDEVICE_OBJECT DeviceObject,
IN PIRP Irp,
IN PVOID Context
)
{
// Never gets here :-((
KeSetEvent((PKEVENT)Context, IO_NO_INCREMENT, FALSE);

if (Irp->PendingReturned)
IoMarkIrpPending( Irp );

return STATUS_SUCCESS;
}

L.

Ladislav,

I see some potential issues based on what code is missing from your
snippet. Generally when filters synchronize an operation back to their
dispatch routine they return STATUS_MORE_PROCESSING_REQUIRED from their
completion routine and then call IoCompleteRequest from their dispatch
routine when they have finished their work. When you do it this way you
should NOT call IoMarkIrpPending

What exactly are you doing after you wait for the event to be signaled
in your dispatch routine? The way it is currently coded you can not
touch anything having to do with the IRP including the CopyChunkData
(since it is the user’s buffer) because it may have already been freed.
Take a look at SfCreate in the sfilter IFSKit sample (use an XP or later
kit) and see what it doee to synchronize an operation back to its
dispatch routine.

I gave a detailed description a few months ago of a way this bug check
can occur if someone generates and IRP and sets the OriginalFileObject
field. This problem only manifests itself on remote file systems (which
matches your description) with DFS. I have attached a copy of that
description below.

Neal Christiansen
Microsoft File System Filter Group Lead
This posting is provided “AS IS” with no warranties, and confers no
rights

You have seen my recent comments that it is wrong for filters to set the
OriginalFileObject field when generating their own IRP. Following is a
description of a bug I tracked down last year which was caused by a 3rd
party file system filter setting this field. Of course the filter
involved will remain anonymous.

A customer was seeing 3-4 server crashes a day in their data center.
They were running Server 2003 but this issue was not dependent on the OS
version.

I analyzed several different crashes but the most telling was the
following driver verifier failure:

DRIVER_VERIFIER_IOMANAGER_VIOLATION (c9)
The IO manager has caught a misbehaving driver.
Arguments:
Arg1: 0000000c, Invalid IOSB in IRP at APC IopCompleteRequest
(appears to be on a stack that was unwound)
Arg2: b380c5bc, the IOSB pointer, 3/4 - 0
Arg3: 00000000
Arg4: 00000000

The system was processing a create IRP when the failure occurred.

The bug ended up being an interaction between The FILTER, DFS and how
create IRPs are processed. This is the description of the bug:

  • The IOManager routine IopParseDevice processes all create operations.
    One of the things is does when it initializes a create IRP is set the
    address of a stack local IoStatusBlock structure into the UserIosb field
    of the IRP.

  • The create operation was then sent to MUP who forwarded it to The
    FILTER who forwarded it to MrxSmb, the SMB redirector.

  • The redirector completed the operation and returned.

  • The FILTER synchronized the completion of the create IRP back to their
    create dispatch routine so they could do their post operation processing
    in the context of the originating thread.

  • The FILTER generated a query file information IRP using the file
    object from the successful create and sent it down. This is a common
    operation that many filters do. The thing this FILTER did that was
    different is they used KsQueryInformationFile (from the kernel streaming
    library) to generate the IRP. Unfortunately this routine wrongly sets
    the OriginalFileObject field in the generated IRP.

  • The way the IOManager is designed, when an operation completes for a
    synchronous file object (FO_SYNCHRONOUS_IO flag is set) and the
    OriginalFileObject field is set, the inline event in the
    OriginalFileObject field is signaled. In this particular case since the
    OriginalFileObject field was set with the file object from the create
    operation, that file object had its inline event set to the signaled
    state.

  • The FILTER returned from their create dispatch routine which returned
    back to MUP.

  • MUP returned STATUS_PENDING for the create IRP and did additional
    processing asynchronously in a worker thread.

  • Since the create IRP was pended the thread was supposed to wait in
    IopParseDevice until a special kernel APC is executed which completes
    the processing of the Create IRP and signals the file object’s inline
    event.

  • When MUP returned back to the IOManager the IOManager did not wait
    (because the inline event was already signaled) and returned back to
    user mode.

  • The user mode application (excel in this case) immediately sent down
    another operation.

  • At some later point MUP completed the create IRP.

  • The thread processing the create IRP is supposed to be waiting in the
    IO Manager. It is not.

  • Completing the IRP queues a special kernel APC which among other
    things sets the correct error code and information values into what is
    pointed to by the UserIosb field in the IRP.

  • Unfortunately the UserIosb field points to a stack location that was
    in the frame of IopParseDevice which has since been unwound.

  • This stack location is in use processing some other operation and we
    end writing data to the kernel stack, corrupting it.

  • It is this stack corruption that causes unusual random failures.

There are a couple of things that all of us should learn from this. They
are:

  • A filter should never set the OriginalFileObject field when generating
    an IRP. Some of you may say that this only occurs under a specific set
    of circumstances and you would be correct but there is no beneficial
    reason for a filter to ever set this value so the rule is, don’t set it.

  • A file system filter should not blindly use APIs just because they are
    documented in the IFSKit. The IFSKit is a superset of the DDK and there
    are things documented and available that filters shouldn’t use. We will
    try to make this clearer in the documentation in the future but in the
    meantime you should use the following rule:

In general you should only link your filter with the following IFSKit
libraries:
ntoskrnl.lib
hal.lib
fltmgr.lib (only if you are a mini-filter)

If your filter links with other IFSKit libraries you need to evaluate if
what you are doing is correct.

I know this was a long detailed explanation and I appreciate the
patience of those who waded through it. I believe it helps when people
understand the reasons for the rules that are defined.

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Ladislav Zezula
Sent: Friday, October 15, 2004 5:47 AM
To: Windows File Systems Devs Interest List
Subject: [ntfsd] Verifier’s bugcheck - Invalid IOSB in IRP at APC
IoCompleteRequest

Hi, all

Please, could you help me with the following problem ?

In the filter driver, I’m intercepting a special call of
IRP_MJ_DEVICE_CONTROL (Ioctl code = 140FD3).
I change the handle stored in the data structure,
copy the stack location to next, initialize an event,
set completion routine (for signaling the event)
and call the next lower driver (quite normal scenario).
After return, the driver returns STATUS_PENDING,
so I wait for the event.

Then, Driver Verifier bugchecks with “Invalid IOSB
in IRP at APC IoCompleteRequest (appears to be
on stack that was unwound”. The Irp->UserIosb
was set to some user mode address when it went down.
I don’t change the field, in fact I don’t even touch it
before call to KeWaitForSingleObject
(the moment when the bugcheck occurs)

I made a breakpoint inside IoCompleteRequest,
and it seems that it’s been called with completely wrong
IRP, or that the IRP has been changed. or something like that.

Could you give me any clue what I am doing wrong ?
Below the stack text is the source of involved routines.

*** Here is the stack trace

DRIVER_VERIFIER_IOMANAGER_VIOLATION (c9)
The IO manager has caught a misbehaving driver.
Arguments:
Arg1: 0000000c, Invalid IOSB in IRP at APC IopCompleteRequest (appears
to be
on
stack that was unwound)
Arg2: f078f790, the IOSB pointer , 3/4 - 0
Arg3: 00000000
Arg4: 00000000

STACK_TEXT:
f078f94c 8067191f 000000c9 0000000c f078f790 nt!KeBugCheckEx+0x1b
f078f968 80523978 82740f88 f078fa04 f078fa08 nt!IovpCompleteRequest+0x4c
f078f9c0 804f415a 82740f88 f078fa0c f078fa00 nt!IopCompleteRequest+0x39
f078fa10 804f4199 00000000 00000000 00000000 nt!KiDeliverApc+0xb3
f078fa28 804e36f2 00000000 f078faf0 82a82f00 nt!KiSwapThread+0x64
f078fa50 80672756 00000000 00000000 00000000
nt!KeWaitForSingleObject+0x1c2
f078fa78 baeac631 f078faf0 00000000 00000000
nt!VerifierKeWaitForSingleObject+0x56
f078fb1c baed21f8 ff51a978 82a82f48 f078fbe4
MyFilter!MyFilterMrxSmbCopyChunk+0x30c
f078fb68 baeb97ac ff51a978 82a82f48 ff51a978
MyFilter!MyFilterDeviceControl+0xd2
f078fc10 804ead77 ff51a978 82a82f48 806f42a4
MyFilter!MyFilterDispatch+0x409
f078fc20 806712c5 ff422240 806f4070 82a82f48 nt!IopfCallDriver+0x31
f078fc44 805719ab 82a82fdc ff4fadc0 82a82f48 nt!IovCallDriver+0xa0
f078fc58 805849f7 ff51a978 82a82f48 ff4fadc0
nt!IopSynchronousServiceTail+0x60
f078fd00 80586bfa 00000248 00000000 00000000 nt!IopXxxControlFile+0x611
f078fd34 804e606b 00000248 00000000 00000000
nt!NtDeviceIoControlFile+0x2a

*** Here is the handler of IRP_MJ_DEVICE_CONTROL:

switch(IrpSp->Parameters.DeviceIoControl.IoControlCode)
{
// This is an undocumented IOCTL.
// Don’t ask me why I need to deal with this call :-))
case IOCTL_MRXSMB_COPY_CHUNK: // BUGBUG: 140FD3 Really that IOCTL
name
?
Status = MyFilterMrxSmbCopyChunk(FilterDevice, Irp);
break;

*** In the MyFilterMrxSmbCopyChunk:

NTSTATUS
MyFilterMrxSmbCopyChunk(
IN PFILTER_DEVICE_OBJECT FilterDevice,
IN PIRP Irp)
{
__try {

CopyChunkData = (PMRXSMB_COPY_CHUNK_DATA)Irp->UserBuffer;

if(CopyChunkData != NULL && OutputBufferLength >=
sizeof(MRXSMB_COPY_CHUNK_DATA))
{
// Replace the handle in CopyChunkData->FileHandle
// Prepare the stack location
IoCopyCurrentIrpStackLocationToNext(Irp);
KeInitializeEvent(&Event, NotificationEvent, FALSE);
IoSetCompletionRoutine(Irp,

MyFilterCopyChunkCompletion,
&Event,
TRUE,
TRUE,
TRUE);

// Call the lower driver
Status = IoCallDriver(DeviceObject->Vcb.NextLowerDevice,
Irp);

if(Status == STATUS_PENDING)
{
// When waiting starts, the bugcheck comes.
// The completion routine is never called
KeWaitForSingleObject(Event, Executive,
KernelMode, FALSE, NULL);
Status = IoStatus->Status;
}
}
}
__finally
{
// Restore the file handle in the CopyChunkData
}

return Status;
}

NTSTATUS
MyFilterCopyChunkCompletion(
IN PDEVICE_OBJECT DeviceObject,
IN PIRP Irp,
IN PVOID Context
)
{
// Never gets here :-((
KeSetEvent((PKEVENT)Context, IO_NO_INCREMENT, FALSE);

if (Irp->PendingReturned)
IoMarkIrpPending( Irp );

return STATUS_SUCCESS;
}

L.


Questions? First check the IFS FAQ at
https://www.osronline.com/article.cfm?id=17

You are currently subscribed to ntfsd as: xxxxx@windows.microsoft.com
To unsubscribe send a blank email to xxxxx@lists.osr.com

Hi, Neal,

first of all, thank for your response.

Generally when filters synchronize an operation back to their
dispatch routine they return STATUS_MORE_PROCESSING_REQUIRED from their
completion routine and then call IoCompleteRequest from their dispatch

Well, I’ll write it that way.

What exactly are you doing after you wait for the event to be signaled
in your dispatch routine? The way it is currently coded you can not
touch anything having to do with the IRP including the CopyChunkData
(since it is the user’s buffer) because it may have already been freed.

After the wait, I do nothing (yet), because the verifier bugchecks “inside”
the
KeWaitForSingleObject. (So, sooner than my completion
routine begins at all). I will restore the original handle and return.
I know that I cannot touch the IRP, but the user buffer :-o ?
It can be freed too ? It is the output buffer that is given
by the calling application in this case (?).

Take a look at SfCreate in the sfilter IFSKit sample

I did and rewrote, but the result effect is still the same. It doesn’t
even return from KeWaitForSingleObject.

What makes me wonder, is the call stack. It seems the IoCompleteRequest
is called directly from VerifierKeWaitForSingleObject, is it possible ?
If yes, why then the parameters of IoCompleteRequest are both
completely wrong (the first one is not an IRP, and the second
one is something that is far far away from IO_NO_INCREMENT.
(this is actually why the verifier bugchecks, if the Irp is wrong,
then the Irp->UserIosb will be wrong too).

If I look at the address that is at the top of the stack (the return
address),
there is a call with four previous pushes (I expect two before the call of
IoCompleteRequest).

I gave a detailed description a few months ago of a way this bug check
can occur if someone generates and IRP and sets the OriginalFileObject
field.

Although the OriginalFileObject is non-NULL in this case, I’m afraid
this is not the problem. I remember your description
about that bugcheck, but it occurs if a filter generates its own IRP
(doesn’t it ?). The IRP request is not generated by my filter,
it comes from IopXxxControlFile (See call stack in my
previous mail). And the file system is not DFS.
So I don’t care about the OriginalFileObject in the IRP (should I ?).

L.

VerifierKeWaitForSingleObject does not call IoCompleteRequest. This is
probably an anomaly having to do either with mismatched symbols or an
issue with the public symbols you are using. The bugcheck might be
showing bad information as well (I seem to recall this when I was
investigating this issue).

For IRPs generated by the IoManager it is OK to have the
OriginalFileObject field set. You were correct, the issues is only with
filter generated IRPs.

Have you fixed your filter to synchronize like the sfilter sample? Do
that work and see if this bugcheck goes away.

Neal Christiansen
Microsoft File System Filter Group Lead
This posting is provided “AS IS” with no warranties, and confers no
rights

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Ladislav Zezula
Sent: Monday, October 18, 2004 12:10 AM
To: Windows File Systems Devs Interest List
Subject: Re: [ntfsd] Verifier’s bugcheck - Invalid IOSB in IRP at APC
IoCompleteRequest

Hi, Neal,

first of all, thank for your response.

Generally when filters synchronize an operation back to their
dispatch routine they return STATUS_MORE_PROCESSING_REQUIRED from
their
completion routine and then call IoCompleteRequest from their dispatch

Well, I’ll write it that way.

What exactly are you doing after you wait for the event to be signaled
in your dispatch routine? The way it is currently coded you can not
touch anything having to do with the IRP including the CopyChunkData
(since it is the user’s buffer) because it may have already been
freed.

After the wait, I do nothing (yet), because the verifier bugchecks
“inside”
the
KeWaitForSingleObject. (So, sooner than my completion
routine begins at all). I will restore the original handle and return.
I know that I cannot touch the IRP, but the user buffer :-o ?
It can be freed too ? It is the output buffer that is given
by the calling application in this case (?).

Take a look at SfCreate in the sfilter IFSKit sample

I did and rewrote, but the result effect is still the same. It doesn’t
even return from KeWaitForSingleObject.

What makes me wonder, is the call stack. It seems the IoCompleteRequest
is called directly from VerifierKeWaitForSingleObject, is it possible ?
If yes, why then the parameters of IoCompleteRequest are both
completely wrong (the first one is not an IRP, and the second
one is something that is far far away from IO_NO_INCREMENT.
(this is actually why the verifier bugchecks, if the Irp is wrong,
then the Irp->UserIosb will be wrong too).

If I look at the address that is at the top of the stack (the return
address),
there is a call with four previous pushes (I expect two before the call
of
IoCompleteRequest).

I gave a detailed description a few months ago of a way this bug check
can occur if someone generates and IRP and sets the OriginalFileObject
field.

Although the OriginalFileObject is non-NULL in this case, I’m afraid
this is not the problem. I remember your description
about that bugcheck, but it occurs if a filter generates its own IRP
(doesn’t it ?). The IRP request is not generated by my filter,
it comes from IopXxxControlFile (See call stack in my
previous mail). And the file system is not DFS.
So I don’t care about the OriginalFileObject in the IRP (should I ?).

L.


Questions? First check the IFS FAQ at
https://www.osronline.com/article.cfm?id=17

You are currently subscribed to ntfsd as: xxxxx@windows.microsoft.com
To unsubscribe send a blank email to xxxxx@lists.osr.com

Hi, Neal,

VerifierKeWaitForSingleObject does not call IoCompleteRequest. This is
probably an anomaly having to do either with mismatched symbols or an

OK.

Have you fixed your filter to synchronize like the sfilter sample? Do
that work and see if this bugcheck goes away.

Yes, I did. As I wrote in the previous mail, the
result is still the same. With Driver Verifier, it bugchecks,
without DV it hangs (IoCompleteRequest probably
rejects the call because of invalid parameter and the
event is never set).

L.