Io Completion routine not getting called

I’m making a call to IoCallDriver(), and it returns STATUS_PENDING. But, the
specified IO completion routine never gets called. What should I be looking
for to determine the cause of this? This only happens to my filter when the
file activity comes through srv.sys.

Thank you for any help on this.

Brad


You are currently subscribed to ntfsd as: $subst(‘Recip.EmailAddr’)
To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com

Brad,

I’m assuming you have a debugger hooked up.

First, try to find the IRP. If you can find it, try to determine its state.
It is probably waiting for something to finish below.

Are you changing anything in the IRP? A classic problem of this type is
that you change the MDL but not the UserBuffer address (which MUST match the
VA in the MDL.)

You may also find that a worker thread is blocked waiting on a lock (this
would be the worker thread trying to process the IRP.) This could be an NT
4.0 problem related to work queues (you don’t mention which OS version.)

Just some general suggestions - the more detailed your own description of
what you are seeing, the more likely that someone here can provide
additional insight.

Regards,

Tony Mason
Consulting Partner
OSR Open Systems Resources, Inc.
http://www.osr.com

-----Original Message-----
From: Brad Sahr [mailto:xxxxx@macromedia.com]
Sent: Wednesday, February 28, 2001 11:46 AM
To: File Systems Developers
Subject: [ntfsd] Io Completion routine not getting called

I’m making a call to IoCallDriver(), and it returns STATUS_PENDING. But, the
specified IO completion routine never gets called. What should I be looking
for to determine the cause of this? This only happens to my filter when the
file activity comes through srv.sys.

Thank you for any help on this.

Brad


You are currently subscribed to ntfsd as: xxxxx@osr.com
To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com


You are currently subscribed to ntfsd as: $subst(‘Recip.EmailAddr’)
To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com

Brad,
Are you holding any locks when you send the irp down?
Can you find the irp via the !irp command in WinDbg (and observe its
state)?
Are all of your ‘InvokeOn…’ flags in IoSetCompletionRoutine TRUE?
Are you stepping on your completion routine registration (copying
down the stack after registering the routine)
What IRP MajorFunction is this occurring on?
If you can distill your dispatch routine’s code to the bare minimum
required to trigger this problem someone could probably figure it out fairly
easily.

-Joel

-----Original Message-----
From: Brad Sahr [mailto:xxxxx@macromedia.com]
Sent: Wednesday, February 28, 2001 11:46 AM
To: File Systems Developers
Subject: [ntfsd] Io Completion routine not getting called

I’m making a call to IoCallDriver(), and it returns STATUS_PENDING. But, the
specified IO completion routine never gets called. What should I be looking
for to determine the cause of this? This only happens to my filter when the
file activity comes through srv.sys.

Thank you for any help on this.

Brad


You are currently subscribed to ntfsd as: xxxxx@ntpsoftware.com
To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com


You are currently subscribed to ntfsd as: $subst(‘Recip.EmailAddr’)
To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com

Thank you for the responses, and my apologies for not getting back to this
for so long.
Here are some quick answers to some of the questions:

Are you holding any locks when you send the irp down?
No.
Can you find the irp via the !irp command in WinDbg (and observe its state)?
See Below.
Are all of your ‘InvokeOn…’ flags in IoSetCompletionRoutine TRUE?
Yes.
Are you stepping on your completion routine registration?
No.
What IRP MajorFunction is this occurring on?
Read IRP is hanging during handling of Create IRP.
Are you changing anything in the IRP?
I’m rolling my own Read IRP, and not currently modifying the Create IRP.
OS Version?
Win2k.

Here’s a more detailed description of what the filter create dispatch
routine is doing:

  1. Detect an IRP_MJ_CREATE of interest
  2. Using ZwOpenFile, open the file about to be opened,
    ZwQueryInformationFile to get file attributes, leave the file open
  3. Using ZwCreateFile, open a second file
  4. Get the file object from the handle of file opened in step #2
  5. Rolling my own read IRPs, attempt to read data from the file object from
    step#4, IRP_MJ_READ never completes.

As previously mentioned, the READ not completing only occurs when the file
access is coming via srv.sys. This sequence works fine when the file access
is initiated at the local machine via explorer or some other application.

I have also learned that this problem occurs when the client is NT4 SP5, but
does not occur when the client is NT4 SP6 or Win2k. The filter is running on
Win2k. Let me know if there is some additional information that is needed to
determine why the READ is not completing.

I’m beginning to suspect that the read IRP isn’t completing because it is
queued to the same thread that is processing the original create IRP (and of
course the filter is blocking the create IRP from completing), but this
simple explanation doesn’t seem to account for the observed client dependent
differences.

Thanks again for the help.

Brad

Here’s what the debugger is telling me about the IRP that is not completing.

** READ IRP prior to IoCallDriver **

kd> !irp fca13e90
Irp is active with 7 stacks 8 is current (= 0xfca13ffc)
No Mdl Thread 87fa6da0: Irp is completed.
cmd flg cl Device File Completion-Context
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[3, 0] 0 e0 00000000 81158768 eed89cd0-00000000 Success Error Cancel
c0000005 Exception in kdextx86.irp debugger extension.
PC: 00491b3b VA: 00157817 R/W: 1 Parameter: 0001003f

** READ IRP after call to IoCallDriver returns STATUS_PENDING **

kd> !irp fca13e90 1
Irp is active with 7 stacks 7 is current (= 0xfca13fd8)
Mdl = 8116b7e8 Thread 87fa6da0: Irp stack trace.
Flags = 40000000
ThreadListEntry.Flink = fca13ea0
ThreadListEntry.Blink = fca13ea0
IoStatus.Status = 00000000
IoStatus.Information = e1c55a08
RequestorMode = 00000000
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = eefde478
UserEvent = eefde420
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 8041d713
UserBuffer = ff8ad000
&Tail.Overlay.DeviceQueueEntry = 00e6d6fc
Tail.Overlay.Thread = 87fa6da0
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = fca13fd8
Tail.Overlay.OriginalFileObject = 81158768
Tail.Apc = 00000000
Tail.CompletionKey = 00000000
cmd flg cl Device File Completion-Context
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 10 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000

[3, 0] 0 e1 81318400 81158768 eed89cd0-00000000 Success Error Cancel
pending
Name paged outc0000005 Exception in kdextx86.irp debugger extension.
PC: 00491b3b VA: 01206007 R/W: 1 Parameter: 0001003f

** Information about the associated FileObject (target of READ IRP) **

kd> !object 81158768
Object: 81158768 Type: (814229a0) File
ObjectHeader: 81158750
HandleCount: 1 PointerCount: 2
Directory Object: 00000000 Name: (*** Name not accessable ***)
{(e1305e68: name not accessable)}

** CREATE IRP info - after call to IoCallDriver returns STATUS_PENDING for
the READ IRP **

kd> !irp f9997e70 1
Irp is active with 8 stacks 8 is current (= 0xf9997fdc)
No Mdl Thread 87fa6da0: Irp stack trace.
Flags = 40000884
ThreadListEntry.Flink = 87fa6fac
ThreadListEntry.Blink = 87fa6fac
IoStatus.Status = 00000000
IoStatus.Information = 00000000
RequestorMode = 00000000
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = eefde8b4
UserEvent = 00000000
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000
UserBuffer = 00000000
&Tail.Overlay.DeviceQueueEntry = 00e6d6fc
Tail.Overlay.Thread = 87fa6da0
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = f9997fdc
Tail.Overlay.OriginalFileObject = 811baba8
Tail.Apc = 00000000
Tail.CompletionKey = 00000000
cmd flg cl Device File Completion-Context
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[0, 0] 1 0 811db3e0 811baba8 00000000-00000000
Name paged out
Args: eefde8f4 05000144 00000020 00000000

[0, 0] 1 0 811db3e0 811baba8 00000000-00000000
Name paged out
Args: eefde8f4 05000144 00000020 00000000


You are currently subscribed to ntfsd as: $subst(‘Recip.EmailAddr’)
To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com

How might I design around an oplock? It looks like the file that is being
opened for modification already has an oplock, which is preventing me from
reading data from the file. And apparently the open that I’m blocking must
complete in order for the oplock to be released so that I can read data out
of the file?

This looks like catch-22 to me. The client has an oplock on the file and
then opened the file with the OVERWRITE flag. At this point, it appears
there is no way to read the contents of the file before the open completes
and sets the file size to zero. What other design options are there for
reading file contents prior to the completion of a ‘destructive’ create?

Would this best be accomplished by hijacking the IRP_MJ_CREATE, clearing out
the OVERWRITE flags, etc? This looks to me like the same deadlock issue
would still exist here as the create is still being blocked and the client
still has the oplock.

Is there some way to break the client oplock while not allowing a
‘destructive’ create to proceed so my filter can capture the contents of the
file prior to it disappearing?

Brad

-----Original Message-----
From: Rob Fuller [mailto:xxxxx@NSISW.COM]
Sent: Monday, March 05, 2001 9:10 AM
To: ‘Brad Sahr’
Subject: RE: [ntfsd] RE: Io Completion routine not getting called

FWIW, I’ve seen behavior like this before with SRV’s IRP_MJ_CREATE.
Specifically, you cannot block the thread performing the thread performing
the create when the FILE_COMPLETE_IF_OPLOCKED flag is set. This
flag seems
to exist for the sole purpose of resolving deadlocks. I suggest
your design
accomodate this.

> -----Original Message-----
> From: Brad Sahr [mailto:xxxxx@macromedia.com]
> Sent: Sunday, March 04, 2001 7:03 PM
> To: File Systems Developers
> Subject: [ntfsd] RE: Io Completion routine not getting called
>
>
> Thank you for the responses, and my apologies for not getting
> back to this
> for so long.
> Here are some quick answers to some of the questions:
>
> Are you holding any locks when you send the irp down?
> No.
> Can you find the irp via the !irp command in WinDbg (and
> observe its state)?
> See Below.
> Are all of your ‘InvokeOn…’ flags in IoSetCompletionRoutine TRUE?
> Yes.
> Are you stepping on your completion routine registration?
> No.
> What IRP MajorFunction is this occurring on?
> Read IRP is hanging during handling of Create IRP.
> Are you changing anything in the IRP?
> I’m rolling my own Read IRP, and not currently
> modifying the Create IRP.
> OS Version?
> Win2k.
>
> Here’s a more detailed description of what the filter create dispatch
> routine is doing:
> 1. Detect an IRP_MJ_CREATE of interest
> 2. Using ZwOpenFile, open the file about to be opened,
> ZwQueryInformationFile to get file attributes, leave the file open
> 3. Using ZwCreateFile, open a second file
> 4. Get the file object from the handle of file opened in step #2
> 5. Rolling my own read IRPs, attempt to read data from the
> file object from
> step#4, IRP_MJ_READ never completes.
>
> As previously mentioned, the READ not completing only occurs
> when the file
> access is coming via srv.sys. This sequence works fine when
> the file access
> is initiated at the local machine via explorer or some other
> application.
>
> I have also learned that this problem occurs when the client
> is NT4 SP5, but
> does not occur when the client is NT4 SP6 or Win2k. The
> filter is running on
> Win2k. Let me know if there is some additional information
> that is needed to
> determine why the READ is not completing.
>
> I’m beginning to suspect that the read IRP isn’t completing
> because it is
> queued to the same thread that is processing the original
> create IRP (and of
> course the filter is blocking the create IRP from
> completing), but this
> simple explanation doesn’t seem to account for the observed
> client dependent
> differences.
>
> Thanks again for the help.
>
> Brad
>
>
> Here’s what the debugger is telling me about the IRP that is
> not completing.
>
> ** READ IRP prior to IoCallDriver **
>
> kd> !irp fca13e90
> Irp is active with 7 stacks 8 is current (= 0xfca13ffc)
> No Mdl Thread 87fa6da0: Irp is completed.
> cmd flg cl Device File Completion-Context
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [3, 0] 0 e0 00000000 81158768 eed89cd0-00000000 Success
> Error Cancel
> c0000005 Exception in kdextx86.irp debugger extension.
> PC: 00491b3b VA: 00157817 R/W: 1 Parameter: 0001003f
>
> ** READ IRP after call to IoCallDriver returns STATUS_PENDING **
>
> kd> !irp fca13e90 1
> Irp is active with 7 stacks 7 is current (= 0xfca13fd8)
> Mdl = 8116b7e8 Thread 87fa6da0: Irp stack trace.
> Flags = 40000000
> ThreadListEntry.Flink = fca13ea0
> ThreadListEntry.Blink = fca13ea0
> IoStatus.Status = 00000000
> IoStatus.Information = e1c55a08
> RequestorMode = 00000000
> Cancel = 00
> CancelIrql = 0
> ApcEnvironment = 00
> UserIosb = eefde478
> UserEvent = eefde420
> Overlay.AsynchronousParameters.UserApcRoutine = 00000000
> Overlay.AsynchronousParameters.UserApcContext = 00000000
> Overlay.AllocationSize = 00000000 - 00000000
> CancelRoutine = 8041d713
> UserBuffer = ff8ad000
> &Tail.Overlay.DeviceQueueEntry = 00e6d6fc
> Tail.Overlay.Thread = 87fa6da0
> Tail.Overlay.AuxiliaryBuffer = 00000000
> Tail.Overlay.ListEntry.Flink = 00000000
> Tail.Overlay.ListEntry.Blink = 00000000
> Tail.Overlay.CurrentStackLocation = fca13fd8
> Tail.Overlay.OriginalFileObject = 81158768
> Tail.Apc = 00000000
> Tail.CompletionKey = 00000000
> cmd flg cl Device File Completion-Context
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 10 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> >[3, 0] 0 e1 81318400 81158768 eed89cd0-00000000 Success
> Error Cancel
> pending
> Name paged outc0000005 Exception in kdextx86.irp
> debugger extension.
> PC: 00491b3b VA: 01206007 R/W: 1 Parameter: 0001003f
>
> ** Information about the associated FileObject (target of READ IRP) **
>
> kd> !object 81158768
> Object: 81158768 Type: (814229a0) File
> ObjectHeader: 81158750
> HandleCount: 1 PointerCount: 2
> Directory Object: 00000000 Name: (*** Name not accessable ***)
> {(e1305e68: name not accessable)}
>
> ** CREATE IRP info - after call to IoCallDriver returns
> STATUS_PENDING for
> the READ IRP **
>
> kd> !irp f9997e70 1
> Irp is active with 8 stacks 8 is current (= 0xf9997fdc)
> No Mdl Thread 87fa6da0: Irp stack trace.
> Flags = 40000884
> ThreadListEntry.Flink = 87fa6fac
> ThreadListEntry.Blink = 87fa6fac
> IoStatus.Status = 00000000
> IoStatus.Information = 00000000
> RequestorMode = 00000000
> Cancel = 00
> CancelIrql = 0
> ApcEnvironment = 00
> UserIosb = eefde8b4
> UserEvent = 00000000
> Overlay.AsynchronousParameters.UserApcRoutine = 00000000
> Overlay.AsynchronousParameters.UserApcContext = 00000000
> Overlay.AllocationSize = 00000000 - 00000000
> CancelRoutine = 00000000
> UserBuffer = 00000000
> &Tail.Overlay.DeviceQueueEntry = 00e6d6fc
> Tail.Overlay.Thread = 87fa6da0
> Tail.Overlay.AuxiliaryBuffer = 00000000
> Tail.Overlay.ListEntry.Flink = 00000000
> Tail.Overlay.ListEntry.Blink = 00000000
> Tail.Overlay.CurrentStackLocation = f9997fdc
> Tail.Overlay.OriginalFileObject = 811baba8
> Tail.Apc = 00000000
> Tail.CompletionKey = 00000000
> cmd flg cl Device File Completion-Context
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 1 0 811db3e0 811baba8 00000000-00000000
> Name paged out
> Args: eefde8f4 05000144 00000020 00000000
> >[0, 0] 1 0 811db3e0 811baba8 00000000-00000000
> Name paged out
> Args: eefde8f4 05000144 00000020 00000000
>
>
>
> —
> You are currently subscribed to ntfsd as: xxxxx@nsisw.com
> To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com
>


You are currently subscribed to ntfsd as: $subst(‘Recip.EmailAddr’)
To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com

Have you tried FILE_COMPLETE_IF_OPLOCKED flag in the create options?

-----Original Message-----
From: Brad Sahr [mailto:xxxxx@macromedia.com]
Sent: Thursday, March 08, 2001 9:59 AM
To: File Systems Developers
Subject: [ntfsd] RE: Io Completion routine not getting called

How might I design around an oplock? It looks like the file that is being
opened for modification already has an oplock, which is preventing me from
reading data from the file. And apparently the open that I’m blocking must
complete in order for the oplock to be released so that I can read data out
of the file?

This looks like catch-22 to me. The client has an oplock on the file and
then opened the file with the OVERWRITE flag. At this point, it appears
there is no way to read the contents of the file before the open completes
and sets the file size to zero. What other design options are there for
reading file contents prior to the completion of a ‘destructive’ create?

Would this best be accomplished by hijacking the IRP_MJ_CREATE, clearing out
the OVERWRITE flags, etc? This looks to me like the same deadlock issue
would still exist here as the create is still being blocked and the client
still has the oplock.

Is there some way to break the client oplock while not allowing a
‘destructive’ create to proceed so my filter can capture the contents of the
file prior to it disappearing?

Brad

-----Original Message-----
From: Rob Fuller [mailto:xxxxx@NSISW.COM]
Sent: Monday, March 05, 2001 9:10 AM
To: ‘Brad Sahr’
Subject: RE: [ntfsd] RE: Io Completion routine not getting called

FWIW, I’ve seen behavior like this before with SRV’s IRP_MJ_CREATE.
Specifically, you cannot block the thread performing the thread performing
the create when the FILE_COMPLETE_IF_OPLOCKED flag is set. This
flag seems
to exist for the sole purpose of resolving deadlocks. I suggest
your design
accomodate this.

> -----Original Message-----
> From: Brad Sahr [mailto:xxxxx@macromedia.com]
> Sent: Sunday, March 04, 2001 7:03 PM
> To: File Systems Developers
> Subject: [ntfsd] RE: Io Completion routine not getting called
>
>
> Thank you for the responses, and my apologies for not getting
> back to this
> for so long.
> Here are some quick answers to some of the questions:
>
> Are you holding any locks when you send the irp down?
> No.
> Can you find the irp via the !irp command in WinDbg (and
> observe its state)?
> See Below.
> Are all of your ‘InvokeOn…’ flags in IoSetCompletionRoutine TRUE?
> Yes.
> Are you stepping on your completion routine registration?
> No.
> What IRP MajorFunction is this occurring on?
> Read IRP is hanging during handling of Create IRP.
> Are you changing anything in the IRP?
> I’m rolling my own Read IRP, and not currently
> modifying the Create IRP.
> OS Version?
> Win2k.
>
> Here’s a more detailed description of what the filter create dispatch
> routine is doing:
> 1. Detect an IRP_MJ_CREATE of interest
> 2. Using ZwOpenFile, open the file about to be opened,
> ZwQueryInformationFile to get file attributes, leave the file open
> 3. Using ZwCreateFile, open a second file
> 4. Get the file object from the handle of file opened in step #2
> 5. Rolling my own read IRPs, attempt to read data from the
> file object from
> step#4, IRP_MJ_READ never completes.
>
> As previously mentioned, the READ not completing only occurs
> when the file
> access is coming via srv.sys. This sequence works fine when
> the file access
> is initiated at the local machine via explorer or some other
> application.
>
> I have also learned that this problem occurs when the client
> is NT4 SP5, but
> does not occur when the client is NT4 SP6 or Win2k. The
> filter is running on
> Win2k. Let me know if there is some additional information
> that is needed to
> determine why the READ is not completing.
>
> I’m beginning to suspect that the read IRP isn’t completing
> because it is
> queued to the same thread that is processing the original
> create IRP (and of
> course the filter is blocking the create IRP from
> completing), but this
> simple explanation doesn’t seem to account for the observed
> client dependent
> differences.
>
> Thanks again for the help.
>
> Brad
>
>
> Here’s what the debugger is telling me about the IRP that is
> not completing.
>
> ** READ IRP prior to IoCallDriver **
>
> kd> !irp fca13e90
> Irp is active with 7 stacks 8 is current (= 0xfca13ffc)
> No Mdl Thread 87fa6da0: Irp is completed.
> cmd flg cl Device File Completion-Context
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [3, 0] 0 e0 00000000 81158768 eed89cd0-00000000 Success
> Error Cancel
> c0000005 Exception in kdextx86.irp debugger extension.
> PC: 00491b3b VA: 00157817 R/W: 1 Parameter: 0001003f
>
> ** READ IRP after call to IoCallDriver returns STATUS_PENDING **
>
> kd> !irp fca13e90 1
> Irp is active with 7 stacks 7 is current (= 0xfca13fd8)
> Mdl = 8116b7e8 Thread 87fa6da0: Irp stack trace.
> Flags = 40000000
> ThreadListEntry.Flink = fca13ea0
> ThreadListEntry.Blink = fca13ea0
> IoStatus.Status = 00000000
> IoStatus.Information = e1c55a08
> RequestorMode = 00000000
> Cancel = 00
> CancelIrql = 0
> ApcEnvironment = 00
> UserIosb = eefde478
> UserEvent = eefde420
> Overlay.AsynchronousParameters.UserApcRoutine = 00000000
> Overlay.AsynchronousParameters.UserApcContext = 00000000
> Overlay.AllocationSize = 00000000 - 00000000
> CancelRoutine = 8041d713
> UserBuffer = ff8ad000
> &Tail.Overlay.DeviceQueueEntry = 00e6d6fc
> Tail.Overlay.Thread = 87fa6da0
> Tail.Overlay.AuxiliaryBuffer = 00000000
> Tail.Overlay.ListEntry.Flink = 00000000
> Tail.Overlay.ListEntry.Blink = 00000000
> Tail.Overlay.CurrentStackLocation = fca13fd8
> Tail.Overlay.OriginalFileObject = 81158768
> Tail.Apc = 00000000
> Tail.CompletionKey = 00000000
> cmd flg cl Device File Completion-Context
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 10 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> >[3, 0] 0 e1 81318400 81158768 eed89cd0-00000000 Success
> Error Cancel
> pending
> Name paged outc0000005 Exception in kdextx86.irp
> debugger extension.
> PC: 00491b3b VA: 01206007 R/W: 1 Parameter: 0001003f
>
> ** Information about the associated FileObject (target of READ IRP) **
>
> kd> !object 81158768
> Object: 81158768 Type: (814229a0) File
> ObjectHeader: 81158750
> HandleCount: 1 PointerCount: 2
> Directory Object: 00000000 Name: (*** Name not accessable ***)
> {(e1305e68: name not accessable)}
>
> ** CREATE IRP info - after call to IoCallDriver returns
> STATUS_PENDING for
> the READ IRP **
>
> kd> !irp f9997e70 1
> Irp is active with 8 stacks 8 is current (= 0xf9997fdc)
> No Mdl Thread 87fa6da0: Irp stack trace.
> Flags = 40000884
> ThreadListEntry.Flink = 87fa6fac
> ThreadListEntry.Blink = 87fa6fac
> IoStatus.Status = 00000000
> IoStatus.Information = 00000000
> RequestorMode = 00000000
> Cancel = 00
> CancelIrql = 0
> ApcEnvironment = 00
> UserIosb = eefde8b4
> UserEvent = 00000000
> Overlay.AsynchronousParameters.UserApcRoutine = 00000000
> Overlay.AsynchronousParameters.UserApcContext = 00000000
> Overlay.AllocationSize = 00000000 - 00000000
> CancelRoutine = 00000000
> UserBuffer = 00000000
> &Tail.Overlay.DeviceQueueEntry = 00e6d6fc
> Tail.Overlay.Thread = 87fa6da0
> Tail.Overlay.AuxiliaryBuffer = 00000000
> Tail.Overlay.ListEntry.Flink = 00000000
> Tail.Overlay.ListEntry.Blink = 00000000
> Tail.Overlay.CurrentStackLocation = f9997fdc
> Tail.Overlay.OriginalFileObject = 811baba8
> Tail.Apc = 00000000
> Tail.CompletionKey = 00000000
> cmd flg cl Device File Completion-Context
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 0 0 00000000 00000000 00000000-00000000
> Args: 00000000 00000000 00000000 00000000
> [0, 0] 1 0 811db3e0 811baba8 00000000-00000000
> Name paged out
> Args: eefde8f4 05000144 00000020 00000000
> >[0, 0] 1 0 811db3e0 811baba8 00000000-00000000
> Name paged out
> Args: eefde8f4 05000144 00000020 00000000
>
>
>
> —
> You are currently subscribed to ntfsd as: xxxxx@nsisw.com
> To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com
>


You are currently subscribed to ntfsd as: xxxxx@otg.com
To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com


You are currently subscribed to ntfsd as: $subst(‘Recip.EmailAddr’)
To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com

RE: [ntfsd] RE: Io Completion routine not getting calledYes. This does allow
the create to complete. You can even query for attributes about the file,
but reading file data will block.
-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com]On Behalf Of Bob Depelteau
Sent: Thursday, March 08, 2001 9:10 AM
To: File Systems Developers
Subject: [ntfsd] RE: Io Completion routine not getting called

Have you tried FILE_COMPLETE_IF_OPLOCKED flag in the create options?

-----Original Message-----
From: Brad Sahr [mailto:xxxxx@macromedia.com]
Sent: Thursday, March 08, 2001 9:59 AM
To: File Systems Developers
Subject: [ntfsd] RE: Io Completion routine not getting called

How might I design around an oplock? It looks like the file that is being
opened for modification already has an oplock, which is preventing me from
reading data from the file. And apparently the open that I’m blocking must
complete in order for the oplock to be released so that I can read data
out
of the file?

This looks like catch-22 to me. The client has an oplock on the file and
then opened the file with the OVERWRITE flag. At this point, it appears
there is no way to read the contents of the file before the open completes
and sets the file size to zero. What other design options are there for
reading file contents prior to the completion of a ‘destructive’ create?

Would this best be accomplished by hijacking the IRP_MJ_CREATE, clearing
out
the OVERWRITE flags, etc? This looks to me like the same deadlock issue
would still exist here as the create is still being blocked and the client
still has the oplock.

Is there some way to break the client oplock while not allowing a
‘destructive’ create to proceed so my filter can capture the contents of
the
file prior to it disappearing?

Brad

-----Original Message-----
> From: Rob Fuller [mailto:xxxxx@NSISW.COM]
> Sent: Monday, March 05, 2001 9:10 AM
> To: ‘Brad Sahr’
> Subject: RE: [ntfsd] RE: Io Completion routine not getting called
>
>
> FWIW, I’ve seen behavior like this before with SRV’s IRP_MJ_CREATE.
> Specifically, you cannot block the thread performing the thread
performing
> the create when the FILE_COMPLETE_IF_OPLOCKED flag is set. This
> flag seems
> to exist for the sole purpose of resolving deadlocks. I suggest
> your design
> accomodate this.
>
> > -----Original Message-----
> > From: Brad Sahr [mailto:xxxxx@macromedia.com]
> > Sent: Sunday, March 04, 2001 7:03 PM
> > To: File Systems Developers
> > Subject: [ntfsd] RE: Io Completion routine not getting called
> >
> >
> > Thank you for the responses, and my apologies for not getting
> > back to this
> > for so long.
> > Here are some quick answers to some of the questions:
> >
> > Are you holding any locks when you send the irp down?
> > No.
> > Can you find the irp via the !irp command in WinDbg (and
> > observe its state)?
> > See Below.
> > Are all of your ‘InvokeOn…’ flags in IoSetCompletionRoutine TRUE?
> > Yes.
> > Are you stepping on your completion routine registration?
> > No.
> > What IRP MajorFunction is this occurring on?
> > Read IRP is hanging during handling of Create IRP.
> > Are you changing anything in the IRP?
> > I’m rolling my own Read IRP, and not currently
> > modifying the Create IRP.
> > OS Version?
> > Win2k.
> >
> > Here’s a more detailed description of what the filter create dispatch
> > routine is doing:
> > 1. Detect an IRP_MJ_CREATE of interest
> > 2. Using ZwOpenFile, open the file about to be opened,
> > ZwQueryInformationFile to get file attributes, leave the file open
> > 3. Using ZwCreateFile, open a second file
> > 4. Get the file object from the handle of file opened in step #2
> > 5. Rolling my own read IRPs, attempt to read data from the
> > file object from
> > step#4, IRP_MJ_READ never completes.
> >
> > As previously mentioned, the READ not completing only occurs
> > when the file
> > access is coming via srv.sys. This sequence works fine when
> > the file access
> > is initiated at the local machine via explorer or some other
> > application.
> >
> > I have also learned that this problem occurs when the client
> > is NT4 SP5, but
> > does not occur when the client is NT4 SP6 or Win2k. The
> > filter is running on
> > Win2k. Let me know if there is some additional information
> > that is needed to
> > determine why the READ is not completing.
> >
> > I’m beginning to suspect that the read IRP isn’t completing
> > because it is
> > queued to the same thread that is processing the original
> > create IRP (and of
> > course the filter is blocking the create IRP from
> > completing), but this
> > simple explanation doesn’t seem to account for the observed
> > client dependent
> > differences.
> >
> > Thanks again for the help.
> >
> > Brad
> >
> >
> > Here’s what the debugger is telling me about the IRP that is
> > not completing.
> >
> > ** READ IRP prior to IoCallDriver **
> >
> > kd> !irp fca13e90
> > Irp is active with 7 stacks 8 is current (= 0xfca13ffc)
> > No Mdl Thread 87fa6da0: Irp is completed.
> > cmd flg cl Device File Completion-Context
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [3, 0] 0 e0 00000000 81158768 eed89cd0-00000000 Success
> > Error Cancel
> > c0000005 Exception in kdextx86.irp debugger extension.
> > PC: 00491b3b VA: 00157817 R/W: 1 Parameter: 0001003f
> >
> > ** READ IRP after call to IoCallDriver returns STATUS_PENDING **
> >
> > kd> !irp fca13e90 1
> > Irp is active with 7 stacks 7 is current (= 0xfca13fd8)
> > Mdl = 8116b7e8 Thread 87fa6da0: Irp stack trace.
> > Flags = 40000000
> > ThreadListEntry.Flink = fca13ea0
> > ThreadListEntry.Blink = fca13ea0
> > IoStatus.Status = 00000000
> > IoStatus.Information = e1c55a08
> > RequestorMode = 00000000
> > Cancel = 00
> > CancelIrql = 0
> > ApcEnvironment = 00
> > UserIosb = eefde478
> > UserEvent = eefde420
> > Overlay.AsynchronousParameters.UserApcRoutine = 00000000
> > Overlay.AsynchronousParameters.UserApcContext = 00000000
> > Overlay.AllocationSize = 00000000 - 00000000
> > CancelRoutine = 8041d713
> > UserBuffer = ff8ad000
> > &Tail.Overlay.DeviceQueueEntry = 00e6d6fc
> > Tail.Overlay.Thread = 87fa6da0
> > Tail.Overlay.AuxiliaryBuffer = 00000000
> > Tail.Overlay.ListEntry.Flink = 00000000
> > Tail.Overlay.ListEntry.Blink = 00000000
> > Tail.Overlay.CurrentStackLocation = fca13fd8
> > Tail.Overlay.OriginalFileObject = 81158768
> > Tail.Apc = 00000000
> > Tail.CompletionKey = 00000000
> > cmd flg cl Device File Completion-Context
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 10 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > >[3, 0] 0 e1 81318400 81158768 eed89cd0-00000000 Success
> > Error Cancel
> > pending
> > Name paged outc0000005 Exception in kdextx86.irp
> > debugger extension.
> > PC: 00491b3b VA: 01206007 R/W: 1 Parameter: 0001003f
> >
> > ** Information about the associated FileObject (target of READ IRP) **
> >
> > kd> !object 81158768
> > Object: 81158768 Type: (814229a0) File
> > ObjectHeader: 81158750
> > HandleCount: 1 PointerCount: 2
> > Directory Object: 00000000 Name: (*** Name not accessable ***)
> > {(e1305e68: name not accessable)}
> >
> > ** CREATE IRP info - after call to IoCallDriver returns
> > STATUS_PENDING for
> > the READ IRP **
> >
> > kd> !irp f9997e70 1
> > Irp is active with 8 stacks 8 is current (= 0xf9997fdc)
> > No Mdl Thread 87fa6da0: Irp stack trace.
> > Flags = 40000884
> > ThreadListEntry.Flink = 87fa6fac
> > ThreadListEntry.Blink = 87fa6fac
> > IoStatus.Status = 00000000
> > IoStatus.Information = 00000000
> > RequestorMode = 00000000
> > Cancel = 00
> > CancelIrql = 0
> > ApcEnvironment = 00
> > UserIosb = eefde8b4
> > UserEvent = 00000000
> > Overlay.AsynchronousParameters.UserApcRoutine = 00000000
> > Overlay.AsynchronousParameters.UserApcContext = 00000000
> > Overlay.AllocationSize = 00000000 - 00000000
> > CancelRoutine = 00000000
> > UserBuffer = 00000000
> > &Tail.Overlay.DeviceQueueEntry = 00e6d6fc
> > Tail.Overlay.Thread = 87fa6da0
> > Tail.Overlay.AuxiliaryBuffer = 00000000
> > Tail.Overlay.ListEntry.Flink = 00000000
> > Tail.Overlay.ListEntry.Blink = 00000000
> > Tail.Overlay.CurrentStackLocation = f9997fdc
> > Tail.Overlay.OriginalFileObject = 811baba8
> > Tail.Apc = 00000000
> > Tail.CompletionKey = 00000000
> > cmd flg cl Device File Completion-Context
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 0 0 00000000 00000000 00000000-00000000
> > Args: 00000000 00000000 00000000 00000000
> > [0, 0] 1 0 811db3e0 811baba8 00000000-00000000
> > Name paged out
> > Args: eefde8f4 05000144 00000020 00000000
> > >[0, 0] 1 0 811db3e0 811baba8 00000000-00000000
> > Name paged out
> > Args: eefde8f4 05000144 00000020 00000000
> >
> >
> >
> > —
> > You are currently subscribed to ntfsd as: xxxxx@nsisw.com
> > To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com
> >
>


You are currently subscribed to ntfsd as: xxxxx@otg.com
To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com


You are currently subscribed to ntfsd as: xxxxx@macromedia.com
To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com


You are currently subscribed to ntfsd as: $subst(‘Recip.EmailAddr’)
To unsubscribe send a blank email to leave-ntfsd-$subst(‘Recip.MemberIDChar’)@lists.osr.com