Deadlock with PagingIoResource

Jonathon · April 7, 2004, 5:24pm

This is my third attempt to post. Third time lucky…

I’m struggling with what appears to be a deadlock issue with the
PagingIoResource. My filter first blocks a certain user mode application
read in the Read Dispatch then reads from this same file in a worker thread.
It never returns from the worker thread ZwReadFile call. Using the !process
command on the user mode app and the system process and comparing the thread
values with the !locks output seems to show a match:

kd> !locks
Resource @ 0x81dc3968 Shared 2 owning threads
Threads: 81d88020-01<*> 822999f0-01<*>

The PagingIoResource for the file being read is 0x81dc3968, the user mode
app thread is 81d88020 and my system thread is 822999f0. My questions are:

How do I fix this? Can I issue a read in such a way that there won’t be a
deadlock? Would it help to create my own IRPs instead of using ZwReadFile in
the worker thread? How about attaching to the dispatch read process from the
worker thread (with KeStackAttachProcess) and then issuing the read?
Why does this only happen when I block certain files? I’ve used this
method to block and then read from files before and it always worked fine.
What could it be about this user mode read that is special?

OSR_Community_User · April 7, 2004, 5:51pm

It reminds me similar issue I had several years before. Is file on FAT or NTFS partition? Which OS version? I guess there are two file handles used; on opened from application and one from system thread. Right?

Best regards,

Michal Vodicka
UPEK, Inc.
[xxxxx@upek.com, http:://www.upek.com]

From: xxxxx@lists.osr.com[SMTP:xxxxx@lists.osr.com] on behalf of Jonathon[SMTP:xxxxx@kraptastic.com]
Reply To: Windows File Systems Devs Interest List
Sent: Wednesday, April 07, 2004 11:23 PM
To: Windows File Systems Devs Interest List
Subject: [ntfsd] Deadlock with PagingIoResource

This is my third attempt to post. Third time lucky…

I’m struggling with what appears to be a deadlock issue with the
PagingIoResource. My filter first blocks a certain user mode application
read in the Read Dispatch then reads from this same file in a worker thread.
It never returns from the worker thread ZwReadFile call. Using the !process
command on the user mode app and the system process and comparing the thread
values with the !locks output seems to show a match:

kd> !locks
Resource @ 0x81dc3968 Shared 2 owning threads
Threads: 81d88020-01<*> 822999f0-01<*>

The PagingIoResource for the file being read is 0x81dc3968, the user mode
app thread is 81d88020 and my system thread is 822999f0. My questions are:

How do I fix this? Can I issue a read in such a way that there won’t be a
deadlock? Would it help to create my own IRPs instead of using ZwReadFile in
the worker thread? How about attaching to the dispatch read process from the
worker thread (with KeStackAttachProcess) and then issuing the read?

Why does this only happen when I block certain files? I’ve used this
method to block and then read from files before and it always worked fine.
What could it be about this user mode read that is special?

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

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

Jonathon · April 7, 2004, 6:01pm

RE: [ntfsd] Deadlock with PagingIoResourceI’m currently developing with XP
on NTFS. Yes, there are two file handles.

“Michal Vodicka” wrote in message
news:xxxxx@ntfsd…
It reminds me similar issue I had several years before. Is file on FAT or
NTFS partition? Which OS version? I guess there are two file handles used;
on opened from application and one from system thread. Right?
Best regards,
Michal Vodicka
UPEK, Inc.
[xxxxx@upek.com, http:://www.upek.com]
----------
From:
xxxxx@lists.osr.com[SMTP:xxxxx@lists.osr.com] on
behalf of Jonathon[SMTP:xxxxx@kraptastic.com]
Reply To: Windows File Systems Devs Interest List
Sent: Wednesday, April 07, 2004 11:23 PM
To: Windows File Systems Devs Interest List
Subject: [ntfsd] Deadlock with PagingIoResource
This is my third attempt to post. Third time lucky…
I’m struggling with what appears to be a deadlock issue with the
PagingIoResource. My filter first blocks a certain user mode application
read in the Read Dispatch then reads from this same file in a worker thread.
It never returns from the worker thread ZwReadFile call. Using the !process
command on the user mode app and the system process and comparing the thread
values with the !locks output seems to show a match:
kd> !locks
Resource @ 0x81dc3968 Shared 2 owning threads
Threads: 81d88020-01<> 822999f0-01<>
The PagingIoResource for the file being read is 0x81dc3968, the user mode
app thread is 81d88020 and my system thread is 822999f0. My questions are:
1) How do I fix this? Can I issue a read in such a way that there won’t be a
deadlock? Would it help to create my own IRPs instead of using ZwReadFile in
the worker thread? How about attaching to the dispatch read process from the
worker thread (with KeStackAttachProcess) and then issuing the read?
2) Why does this only happen when I block certain files? I’ve used this
method to block and then read from files before and it always worked fine.
What could it be about this user mode read that is special?

—
Questions? First check the IFS FAQ at
https://www.osronline.com/article.cfm?id=17
You are currently subscribed to ntfsd as: xxxxx@upek.com
To unsubscribe send a blank email to xxxxx@lists.osr.com

OSR_Community_User · April 7, 2004, 6:05pm

> ----------

From: xxxxx@lists.osr.com[SMTP:xxxxx@lists.osr.com] on behalf of Jonathon[SMTP:xxxxx@kraptastic.com]
Reply To: Windows File Systems Devs Interest List
Sent: Thursday, April 08, 2004 12:00 AM
To: Windows File Systems Devs Interest List
Subject: Re:[ntfsd] Deadlock with PagingIoResource

Yes, there are two file handles.

And the rest? It is important. You can’t expect reasonable answer when don’t provide basic information.

Best regards,

Michal Vodicka
UPEK, Inc.
[xxxxx@upek.com, http:://www.upek.com]

Alexei_Jelvis-2 · April 7, 2004, 10:27pm

If you hold non-paging IRP_MJ_READ in the filter I don’t see how it can
possibly affect ZwReadFile on another handle from another thread.
Are you sure that the IRP you are blocking doesn’t have IRP_PAGING_IO flag
set?

From the information you provided it seems that you are blocking the thread
that already acquired resource.
The only way it can happen is the resource was pre-acquired by memory
manager which is now performing paging IO.
Basically you can’t expect ZwReadFile (or IRP_MJ_READ if this matter) to
complete when there is outstanding paging io for the file. If ZwReadFile
uses cached IO and the page is in the memory already then ZwReadFile will
complete, otherwise it will be blocked waiting for paging IO.

To better understand what is going on you need to type in debugger !thread
81d88020 and !thread 822999f0 and look at the call stacks of those threads.
I don’t know what you are trying to achieve but you can’t see any reason why
you may want to block paging IO. Probably your problem will be fixed if you
let paging IO to go through your filter and block only regular IRPs.

Alexei.

“Jonathon” wrote in message news:xxxxx@ntfsd…
> This is my third attempt to post. Third time lucky…
>
> I’m struggling with what appears to be a deadlock issue with the
> PagingIoResource. My filter first blocks a certain user mode application
> read in the Read Dispatch then reads from this same file in a worker
thread.
> It never returns from the worker thread ZwReadFile call. Using the
!process
> command on the user mode app and the system process and comparing the
thread
> values with the !locks output seems to show a match:
>
> kd> !locks
> Resource @ 0x81dc3968 Shared 2 owning threads
> Threads: 81d88020-01<> 822999f0-01<>
>
> The PagingIoResource for the file being read is 0x81dc3968, the user mode
> app thread is 81d88020 and my system thread is 822999f0. My questions are:
>
> 1) How do I fix this? Can I issue a read in such a way that there won’t be
a
> deadlock? Would it help to create my own IRPs instead of using ZwReadFile
in
> the worker thread? How about attaching to the dispatch read process from
the
> worker thread (with KeStackAttachProcess) and then issuing the read?
>
> 2) Why does this only happen when I block certain files? I’ve used this
> method to block and then read from files before and it always worked fine.
> What could it be about this user mode read that is special?
>
>
>
>

OSR_Community_User · April 8, 2004, 1:52am

Hi Jonathan,

What is the system IRQL at, when you are blocking the initial
IRP_MJ_READ, is it APC_LEVEL? Also I can’t see how the PagingIOResource
is causing the dead-lock since in your original mail both threads have
managed to acquire the paging io resource shared…? (or am I missing
something?)

-Thanks
-Anurag

-----Original Message-----
From: Alexei Jelvis [mailto:xxxxx@rogers.com]
Sent: Wednesday, April 07, 2004 7:27 PM
To: Windows File Systems Devs Interest List
Subject: Re:[ntfsd] Deadlock with PagingIoResource

If you hold non-paging IRP_MJ_READ in the filter I don’t see how it can
possibly affect ZwReadFile on another handle from another thread.
Are you sure that the IRP you are blocking doesn’t have IRP_PAGING_IO
flag
set?

From the information you provided it seems that you are blocking the
thread
that already acquired resource.
The only way it can happen is the resource was pre-acquired by memory
manager which is now performing paging IO.
Basically you can’t expect ZwReadFile (or IRP_MJ_READ if this matter) to
complete when there is outstanding paging io for the file. If ZwReadFile
uses cached IO and the page is in the memory already then ZwReadFile
will
complete, otherwise it will be blocked waiting for paging IO.

To better understand what is going on you need to type in debugger
!thread
81d88020 and !thread 822999f0 and look at the call stacks of those
threads.
I don’t know what you are trying to achieve but you can’t see any reason
why
you may want to block paging IO. Probably your problem will be fixed if
you
let paging IO to go through your filter and block only regular IRPs.

Alexei.

“Jonathon” wrote in message
news:xxxxx@ntfsd…
> This is my third attempt to post. Third time lucky…
>
> I’m struggling with what appears to be a deadlock issue with the
> PagingIoResource. My filter first blocks a certain user mode
application
> read in the Read Dispatch then reads from this same file in a worker
thread.
> It never returns from the worker thread ZwReadFile call. Using the
!process
> command on the user mode app and the system process and comparing the
thread
> values with the !locks output seems to show a match:
>
> kd> !locks
> Resource @ 0x81dc3968 Shared 2 owning threads
> Threads: 81d88020-01<> 822999f0-01<>
>
> The PagingIoResource for the file being read is 0x81dc3968, the user
mode
> app thread is 81d88020 and my system thread is 822999f0. My questions
are:
>
> 1) How do I fix this? Can I issue a read in such a way that there
won’t be
a
> deadlock? Would it help to create my own IRPs instead of using
ZwReadFile
in
> the worker thread? How about attaching to the dispatch read process
from
the
> worker thread (with KeStackAttachProcess) and then issuing the read?
>
> 2) Why does this only happen when I block certain files? I’ve used
this
> method to block and then read from files before and it always worked
fine.
> What could it be about this user mode read that is special?
>
>
>
>

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

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

This electronic transmission (and any attached documents) is for the sole use of the individual or entity to whom it is addressed. It is confidential and may be privileged. Any further distribution or copying of this message is strictly prohibited. If you received this message in error, please notify GreenBorder immediately by telephone at (650) 625.0601 and destroy the message (and all attached documents), immediately.

OSR_Community_User · April 8, 2004, 2:20am

Hi,

Actually I take back my first statement. The initial read coming in at APC_LEVEL shouldn’t necessarily cause a problem, since you are issuing the ZwReadFile on another thread… (which should hopefully be running at passive_level when you issue the ZwReadFile call?).

-Thanks
-Anurag

-----Original Message-----
From: Anurag Sharma
Sent: Wednesday, April 07, 2004 10:54 PM
To: Windows File Systems Devs Interest List
Subject: RE: [ntfsd] Deadlock with PagingIoResource

Hi Jonathan,

What is the system IRQL at, when you are blocking the initial
IRP_MJ_READ, is it APC_LEVEL? Also I can’t see how the PagingIOResource
is causing the dead-lock since in your original mail both threads have
managed to acquire the paging io resource shared…? (or am I missing
something?)

-Thanks
-Anurag

-----Original Message-----
From: Alexei Jelvis [mailto:xxxxx@rogers.com]
Sent: Wednesday, April 07, 2004 7:27 PM
To: Windows File Systems Devs Interest List
Subject: Re:[ntfsd] Deadlock with PagingIoResource

If you hold non-paging IRP_MJ_READ in the filter I don’t see how it can
possibly affect ZwReadFile on another handle from another thread.
Are you sure that the IRP you are blocking doesn’t have IRP_PAGING_IO
flag
set?

From the information you provided it seems that you are blocking the
thread
that already acquired resource.
The only way it can happen is the resource was pre-acquired by memory
manager which is now performing paging IO.
Basically you can’t expect ZwReadFile (or IRP_MJ_READ if this matter) to
complete when there is outstanding paging io for the file. If ZwReadFile
uses cached IO and the page is in the memory already then ZwReadFile
will
complete, otherwise it will be blocked waiting for paging IO.

To better understand what is going on you need to type in debugger
!thread
81d88020 and !thread 822999f0 and look at the call stacks of those
threads.
I don’t know what you are trying to achieve but you can’t see any reason
why
you may want to block paging IO. Probably your problem will be fixed if
you
let paging IO to go through your filter and block only regular IRPs.

Alexei.

“Jonathon” wrote in message
news:xxxxx@ntfsd…
> This is my third attempt to post. Third time lucky…
>
> I’m struggling with what appears to be a deadlock issue with the
> PagingIoResource. My filter first blocks a certain user mode
application
> read in the Read Dispatch then reads from this same file in a worker
thread.
> It never returns from the worker thread ZwReadFile call. Using the
!process
> command on the user mode app and the system process and comparing the
thread
> values with the !locks output seems to show a match:
>
> kd> !locks
> Resource @ 0x81dc3968 Shared 2 owning threads
> Threads: 81d88020-01<> 822999f0-01<>
>
> The PagingIoResource for the file being read is 0x81dc3968, the user
mode
> app thread is 81d88020 and my system thread is 822999f0. My questions
are:
>
> 1) How do I fix this? Can I issue a read in such a way that there
won’t be
a
> deadlock? Would it help to create my own IRPs instead of using
ZwReadFile
in
> the worker thread? How about attaching to the dispatch read process
from
the
> worker thread (with KeStackAttachProcess) and then issuing the read?
>
> 2) Why does this only happen when I block certain files? I’ve used
this
> method to block and then read from files before and it always worked
fine.
> What could it be about this user mode read that is special?
>
>
>
>

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

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

This electronic transmission (and any attached documents) is for the sole use of the individual or entity to whom it is addressed. It is confidential and may be privileged. Any further distribution or copying of this message is strictly prohibited. If you received this message in error, please notify GreenBorder immediately by telephone at (650) 625.0601 and destroy the message (and all attached documents), immediately.
Bç¶*°X²×yÉ…âHPjØ¶›ÿ
¢ÊžXyÊýª‰Éqùtb®¶¹®vµjº‚u¢ºn‰zn‘Š•z±Ó–²

This electronic transmission (and any attached documents) is for the sole use of the individual or entity to whom it is addressed. It is confidential and may be privileged. Any further distribution or copying of this message is strictly prohibited. If you received this message in error, please notify GreenBorder immediately by telephone at (650) 625.0601 and destroy the message (and all attached documents), immediately.

OSR_Community_User · April 8, 2004, 8:50am

There’s no deadlock, based upon the information you have provided. For
there to be a deadlock of the type you describe (on the
PagingIoResource) one of the threads would have to be blocked waiting
for the resource - but in this case the debugger shows a resource OWNED
by two threads.

As Alexei suggested, you need to provide us with the stack traces of
these two threads and perhaps we can suggest something else as the root
cause of this problem.

Regards,

Tony

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

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Jonathon
Sent: Wednesday, April 07, 2004 5:23 PM
To: ntfsd redirect
Subject: [ntfsd] Deadlock with PagingIoResource

This is my third attempt to post. Third time lucky…

I’m struggling with what appears to be a deadlock issue with the
PagingIoResource. My filter first blocks a certain user mode application
read in the Read Dispatch then reads from this same file in a worker
thread.
It never returns from the worker thread ZwReadFile call. Using the
!process
command on the user mode app and the system process and comparing the
thread
values with the !locks output seems to show a match:

kd> !locks
Resource @ 0x81dc3968 Shared 2 owning threads
Threads: 81d88020-01<*> 822999f0-01<*>

The PagingIoResource for the file being read is 0x81dc3968, the user
mode
app thread is 81d88020 and my system thread is 822999f0. My questions
are:

How do I fix this? Can I issue a read in such a way that there won’t
be a
deadlock? Would it help to create my own IRPs instead of using
ZwReadFile in
the worker thread? How about attaching to the dispatch read process from
the
worker thread (with KeStackAttachProcess) and then issuing the read?
Why does this only happen when I block certain files? I’ve used this
method to block and then read from files before and it always worked
fine.
What could it be about this user mode read that is special?

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

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

Jonathon · April 8, 2004, 12:01pm

Thanks everyone for your help. I’ve probably got this all wrong. I’m new to
this. Yes, the PagingIoResource is successfully acquired shared so a
deadlock is probably not the problem. The !locks command:

Resource @ 0x81e0e2f8 Shared 2 owning threads
Threads: 81db2da8-01<> 82299da8-01<>
KD: Scanning for held locks.

My worker thread (running at passive level) that never returns from the
synchronous ZwReadFile call:

status = ZwReadFile( hFile,
NULL,
NULL,
NULL,
&ioStatusBlock,
pContigMem,
uiSegmentLength,
&liReadOffset,
NULL );

THREAD 82299da8 Cid 0004.006c Teb: 00000000 Win32Thread: 00000000 WAIT:
(Executive) KernelMode Non-Alertable
f8926608 NotificationEvent
IRP List:
82452e28: (0006,01d8) Flags: 40000900 Mdl: 00000000
Not impersonating
DeviceMap e1004498
Owning Process 822ce838
Wait Start TickCount 9396 Elapsed Ticks: 236
Context Switch Count 204
UserTime 00:00:00.0000
KernelTime 00:00:04.0468
Start Address 0xbaf5f6a0
Stack Init f8927000 Current f892658c Base f8927000 Limit f8924000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 0
ChildEBP RetAddr Args to Child
f89265a4 804fafe4 82299e18 82299da8 804f50ec nt!KiSwapContext+0x2e (FPO:
[EBP 0xf89265d8] [0,0,4])
f89265b0 804f50ec 00000000 e253c588 81e1a3c8 nt!KiSwapThread+0x44 (FPO:
[0,0,2])
f89265d8 baefb2d9 00000000 00000000 00000000 nt!KeWaitForSingleObject+0x1c0
(FPO: [Non-Fpo])
WARNING: Frame IP not in any known module. Following frames may be wrong.
f8926618 baec59a1 e253c588 baedb358 00000000 0xbaefb2d9
f89266e8 baec016f 81e1a3c8 82452e28 00000001 0xbaec59a1
f8926788 804ea221 82258020 82452e28 806ad1a8 0xbaec016f
f8926798 8062c190 822d4dd0 8226b2d0 82452e00 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
f89267bc baf6d42d 804ea221 822d4dd0 82452e28 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f89267f4 baf5ba59 baf5b5ae 00000001 00000001 0xbaf6d42d
f8926a74 804ea221 822b4e80 82452e28 806ad1a8 0xbaf5ba59
f8926a84 8062c190 82299fb8 806ad190 82452e28 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
f8926aa8 8055d0fe 82452fdc 82452e28 820de2a8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f8926abc 8055a3bf 822b4e80 82452e28 820de2a8
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f8926b64 8052d571 800004c8 00000000 00000000 nt!NtReadFile+0x559
f8926b64 804f926d 800004c8 00000000 00000000 nt!KiSystemService+0xc4 (FPO:
[0,0] TrapFrame @ f8926b90)
f8926c3c 8062d029 8053a5f0 00000000 00000000 nt!ZwReadFile+0x11 (FPO:
[9,0,0])
f8926d00 baf5f891 bac32000 81dd6420 00000418
nt!VerifierExReleaseResourceLite+0x59 (FPO: [Non-Fpo])
f8926dac 805aa2b6 baf63224 00000000 00000000 0xbaf5f891
f8926ddc 805319c6 baf5f6a0 baf63224 00000000 nt!PspSystemThreadStartup+0x34
(FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16

The app that I block in the read dispatch:

KeWaitForSingleObject( &myEvent,
Executive,
KernelMode,
FALSE,
NULL );

THREAD 81db2da8 Cid 0574.05a8 Teb: 7ffde000 Win32Thread: e104e5e0 WAIT:
(Executive) KernelMode Non-Alertable
baf63420 NotificationEvent
IRP List:
82742e28: (0006,01d8) Flags: 40000900 Mdl: 00000000
Not impersonating
DeviceMap e2173d20
Owning Process 81e43650
Wait Start TickCount 9238 Elapsed Ticks: 394
Context Switch Count 123 LargeStack
UserTime 00:00:00.0015
KernelTime 00:00:00.0687
Start Address 0x77e8149f
Win32 Start Address 0x004b64d9
Stack Init f4d2d000 Current f4d2c2ec Base f4d2d000 Limit f4d28000 Call 0
Priority 10 BasePriority 8 PriorityDecrement 2 DecrementCount 16
ChildEBP RetAddr Args to Child
f4d2c304 804fafe4 81db2e18 81db2da8 804f50ec nt!KiSwapContext+0x2e (FPO:
[EBP 0xf4d2c338] [0,0,4])
f4d2c310 804f50ec 00000000 baf63420 82134401 nt!KiSwapThread+0x44 (FPO:
[0,0,2])
f4d2c338 8062d3ac 00000000 00000000 00000000 nt!KeWaitForSingleObject+0x1c0
(FPO: [Non-Fpo])
f4d2c360 baf5bb80 baf63420 00000000 00000000
nt!VerifierKeWaitForSingleObject+0x54 (FPO: [Non-Fpo])
WARNING: Frame IP not in any known module. Following frames may be wrong.
f4d2c5f4 804ea221 822b4e80 82692e28 806ad1a8 0xbaf5bb80
f4d2c604 8062c190 81df7a90 1fe33000 82134458 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
f4d2c628 804eab1a 00000000 82134448 00000000 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f4d2c63c 804eab3b 822b4e80 8213440a 82134460 nt!IopPageReadInternal+0xf2
(FPO: [Non-Fpo])
f4d2c65c 8050a326 81df7a90 82134480 82134460 nt!IoPageRead+0x19 (FPO:
[Non-Fpo])
f4d2c6cc 80511a33 82134448 d37b329d c034decc nt!MiDispatchFault+0x270 (FPO:
[Non-Fpo])
f4d2c71c 8050d988 00000000 d37b329d 00000000 nt!MmAccessFault+0x5bb (FPO:
[Non-Fpo])
f4d2c754 80547e5a d37b329d 00000000 82742e40 nt!MmCheckCachedPageState+0x308
(FPO: [Non-Fpo])
f4d2c7e0 baebffc7 81df7a90 f4d2c86c 00000404 nt!CcCopyRead+0x3da (FPO:
[Non-Fpo])
f4d2c8bc baec016f 81f02008 82742e28 00000001 0xbaebffc7
f4d2c95c 804ea221 82258020 82742e28 806ad1a8 0xbaec016f
f4d2c96c 8062c190 822d4dd0 8226b2d0 82742e00 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
f4d2c990 baf6d42d 804ea221 822d4dd0 82742e28 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f4d2c9c8 baf5bbac baf5b5ae 00000001 00000001 0xbaf6d42d
f4d2cc48 804ea221 822b4e80 82742e28 806ad1a8 0xbaf5bbac
f4d2cc58 8062c190 81db2fb8 806ad190 82742e28 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
f4d2cc7c 8055d0fe 82742fdc 82742e28 81df7a90 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f4d2cc90 8055a3bf 822b4e80 82742e28 81df7a90
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f4d2cd38 8052d571 0000006c 00000000 00000000 nt!NtReadFile+0x559
f4d2cd38 7ffe0304 0000006c 00000000 00000000 nt!KiSystemService+0xc4 (FPO:
[0,0] TrapFrame @ f4d2cd64)
01e1eb48 00000000 00000000 00000000 00000000
SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])

OSR_Community_User · April 8, 2004, 12:59pm

Jonathon,

Are those your drivers with the missing symbols (I’m assuming that is
the case)? If so, fix your debugger to point to the symbols for your
driver (try “.sympath+ ” so you can see your
routines on the stack.

I suspect this is a problem with the IRP handling. I see your worker
thread is blocked waiting for a stack-based event object. Are you
setting this in your completion routine?

Can you give us the output from “!irp 82452e28” (the IRP in your worker
thread) so we can see where the IRP is currently being processed?

Did you tell us which OS this is on? I suppose I could go back and look
at the old e-mail…

Regards,

Tony

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

Hope to see you at the next OSR file systems class in Boston, MA, March
29, 2004!

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Jonathon
Sent: Thursday, April 08, 2004 12:01 PM
To: ntfsd redirect
Subject: Re:[ntfsd] Deadlock with PagingIoResource

Thanks everyone for your help. I’ve probably got this all wrong. I’m new
to
this. Yes, the PagingIoResource is successfully acquired shared so a
deadlock is probably not the problem. The !locks command:

-----------------------------------------------------
Resource @ 0x81e0e2f8 Shared 2 owning threads
Threads: 81db2da8-01<> 82299da8-01<>
KD: Scanning for held locks.
-----------------------------------------------------

My worker thread (running at passive level) that never returns from the
synchronous ZwReadFile call:

status = ZwReadFile( hFile,
NULL,
NULL,
NULL,
&ioStatusBlock,
pContigMem,
uiSegmentLength,
&liReadOffset,
NULL );

-----------------------------------------------------
THREAD 82299da8 Cid 0004.006c Teb: 00000000 Win32Thread: 00000000
WAIT:
(Executive) KernelMode Non-Alertable
f8926608 NotificationEvent
IRP List:
82452e28: (0006,01d8) Flags: 40000900 Mdl: 00000000
Not impersonating
DeviceMap e1004498
Owning Process 822ce838
Wait Start TickCount 9396 Elapsed Ticks: 236
Context Switch Count 204
UserTime 00:00:00.0000
KernelTime 00:00:04.0468
Start Address 0xbaf5f6a0
Stack Init f8927000 Current f892658c Base f8927000 Limit f8924000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 0
ChildEBP RetAddr Args to Child
f89265a4 804fafe4 82299e18 82299da8 804f50ec nt!KiSwapContext+0x2e (FPO:
[EBP 0xf89265d8] [0,0,4])
f89265b0 804f50ec 00000000 e253c588 81e1a3c8 nt!KiSwapThread+0x44 (FPO:
[0,0,2])
f89265d8 baefb2d9 00000000 00000000 00000000
nt!KeWaitForSingleObject+0x1c0
(FPO: [Non-Fpo])
WARNING: Frame IP not in any known module. Following frames may be
wrong.
f8926618 baec59a1 e253c588 baedb358 00000000 0xbaefb2d9
f89266e8 baec016f 81e1a3c8 82452e28 00000001 0xbaec59a1
f8926788 804ea221 82258020 82452e28 806ad1a8 0xbaec016f
f8926798 8062c190 822d4dd0 8226b2d0 82452e00 nt!IopfCallDriver+0x31
(FPO:
[0,0,1])
f89267bc baf6d42d 804ea221 822d4dd0 82452e28 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f89267f4 baf5ba59 baf5b5ae 00000001 00000001 0xbaf6d42d
f8926a74 804ea221 822b4e80 82452e28 806ad1a8 0xbaf5ba59
f8926a84 8062c190 82299fb8 806ad190 82452e28 nt!IopfCallDriver+0x31
(FPO:
[0,0,1])
f8926aa8 8055d0fe 82452fdc 82452e28 820de2a8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f8926abc 8055a3bf 822b4e80 82452e28 820de2a8
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f8926b64 8052d571 800004c8 00000000 00000000 nt!NtReadFile+0x559
f8926b64 804f926d 800004c8 00000000 00000000 nt!KiSystemService+0xc4
(FPO:
[0,0] TrapFrame @ f8926b90)
f8926c3c 8062d029 8053a5f0 00000000 00000000 nt!ZwReadFile+0x11 (FPO:
[9,0,0])
f8926d00 baf5f891 bac32000 81dd6420 00000418
nt!VerifierExReleaseResourceLite+0x59 (FPO: [Non-Fpo])
f8926dac 805aa2b6 baf63224 00000000 00000000 0xbaf5f891
f8926ddc 805319c6 baf5f6a0 baf63224 00000000
nt!PspSystemThreadStartup+0x34
(FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16
-----------------------------------------------------

The app that I block in the read dispatch:

KeWaitForSingleObject( &myEvent,
Executive,
KernelMode,
FALSE,
NULL );

-----------------------------------------------------
THREAD 81db2da8 Cid 0574.05a8 Teb: 7ffde000 Win32Thread: e104e5e0
WAIT:
(Executive) KernelMode Non-Alertable
baf63420 NotificationEvent
IRP List:
82742e28: (0006,01d8) Flags: 40000900 Mdl: 00000000
Not impersonating
DeviceMap e2173d20
Owning Process 81e43650
Wait Start TickCount 9238 Elapsed Ticks: 394
Context Switch Count 123 LargeStack
UserTime 00:00:00.0015
KernelTime 00:00:00.0687
Start Address 0x77e8149f
Win32 Start Address 0x004b64d9
Stack Init f4d2d000 Current f4d2c2ec Base f4d2d000 Limit f4d28000 Call 0
Priority 10 BasePriority 8 PriorityDecrement 2 DecrementCount 16
ChildEBP RetAddr Args to Child
f4d2c304 804fafe4 81db2e18 81db2da8 804f50ec nt!KiSwapContext+0x2e (FPO:
[EBP 0xf4d2c338] [0,0,4])
f4d2c310 804f50ec 00000000 baf63420 82134401 nt!KiSwapThread+0x44 (FPO:
[0,0,2])
f4d2c338 8062d3ac 00000000 00000000 00000000
nt!KeWaitForSingleObject+0x1c0
(FPO: [Non-Fpo])
f4d2c360 baf5bb80 baf63420 00000000 00000000
nt!VerifierKeWaitForSingleObject+0x54 (FPO: [Non-Fpo])
WARNING: Frame IP not in any known module. Following frames may be
wrong.
f4d2c5f4 804ea221 822b4e80 82692e28 806ad1a8 0xbaf5bb80
f4d2c604 8062c190 81df7a90 1fe33000 82134458 nt!IopfCallDriver+0x31
(FPO:
[0,0,1])
f4d2c628 804eab1a 00000000 82134448 00000000 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f4d2c63c 804eab3b 822b4e80 8213440a 82134460 nt!IopPageReadInternal+0xf2
(FPO: [Non-Fpo])
f4d2c65c 8050a326 81df7a90 82134480 82134460 nt!IoPageRead+0x19 (FPO:
[Non-Fpo])
f4d2c6cc 80511a33 82134448 d37b329d c034decc nt!MiDispatchFault+0x270
(FPO:
[Non-Fpo])
f4d2c71c 8050d988 00000000 d37b329d 00000000 nt!MmAccessFault+0x5bb
(FPO:
[Non-Fpo])
f4d2c754 80547e5a d37b329d 00000000 82742e40
nt!MmCheckCachedPageState+0x308
(FPO: [Non-Fpo])
f4d2c7e0 baebffc7 81df7a90 f4d2c86c 00000404 nt!CcCopyRead+0x3da (FPO:
[Non-Fpo])
f4d2c8bc baec016f 81f02008 82742e28 00000001 0xbaebffc7
f4d2c95c 804ea221 82258020 82742e28 806ad1a8 0xbaec016f
f4d2c96c 8062c190 822d4dd0 8226b2d0 82742e00 nt!IopfCallDriver+0x31
(FPO:
[0,0,1])
f4d2c990 baf6d42d 804ea221 822d4dd0 82742e28 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f4d2c9c8 baf5bbac baf5b5ae 00000001 00000001 0xbaf6d42d
f4d2cc48 804ea221 822b4e80 82742e28 806ad1a8 0xbaf5bbac
f4d2cc58 8062c190 81db2fb8 806ad190 82742e28 nt!IopfCallDriver+0x31
(FPO:
[0,0,1])
f4d2cc7c 8055d0fe 82742fdc 82742e28 81df7a90 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f4d2cc90 8055a3bf 822b4e80 82742e28 81df7a90
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f4d2cd38 8052d571 0000006c 00000000 00000000 nt!NtReadFile+0x559
f4d2cd38 7ffe0304 0000006c 00000000 00000000 nt!KiSystemService+0xc4
(FPO:
[0,0] TrapFrame @ f4d2cd64)
01e1eb48 00000000 00000000 00000000 00000000
SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])
-----------------------------------------------------

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

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

Jonathon · April 8, 2004, 1:36pm

Thanks Tony. Sorry about the symbols. I’ve used a monospace font to clean up the output. I’m running XP SP1 on NTFS.

“I see your worker thread is blocked waiting for a stack-based event object. Are you setting this in your completion routine?”

I’m not sure I understand. The worker thread is blocked on a synchronous ZwReadFile. I believe it’s supposed to return when the filehandle is signalled. I don’t have a completion routine for this read in my worker thread.

Loading User Symbols
kd> !thread 82299DA8
THREAD 82299da8 Cid 0004.006c Teb: 00000000 Win32Thread: 00000000 WAIT: (Executive) KernelMode Non-Alertable
f8926608 NotificationEvent
IRP List:
82576e28: (0006,01d8) Flags: 40000900 Mdl: 00000000
Not impersonating
DeviceMap e1004498
Owning Process 822ce838
Wait Start TickCount 8618 Elapsed Ticks: 198
Context Switch Count 201
UserTime 00:00:00.0000
KernelTime 00:00:04.0906
Start Address Sfilter!SFilterWorkerThreadMaster (0xbaf5f6a0)
Stack Init f8927000 Current f892658c Base f8927000 Limit f8924000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 0
ChildEBP RetAddr Args to Child
f89265a4 804fafe4 82299e18 82299da8 804f50ec nt!KiSwapContext+0x2e (FPO: [EBP 0xf89265d8] [0,0,4])
f89265b0 804f50ec 00000000 e262c590 81db96a0 nt!KiSwapThread+0x44 (FPO: [0,0,2])
f89265d8 baefb2d9 00000000 00000000 00000000 nt!KeWaitForSingleObject+0x1c0 (FPO: [Non-Fpo])
f8926618 baec59a1 e262c590 baedb358 00000000 Ntfs!NtfsWaitForIoAtEof+0x48 (FPO: [Non-Fpo])
f89266e8 baec016f 81db96a0 82576e28 00000001 Ntfs!NtfsCommonRead+0xca6
f8926788 804ea221 82258020 82576e28 806ad1a8 Ntfs!NtfsFsdRead+0x22d
f8926798 8062c190 822d4dd0 8226b2d0 82576e00 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f89267bc baf6d42d 804ea221 822d4dd0 82576e28 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f89267c0 804ea221 822d4dd0 82576e28 806ad1a8 sr!SrPassThrough+0x2f (FPO: [2,0,0])
f89267d0 8062c190 822b4e80 82269040 82576e00 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f89267f4 baf5ba59 baf5b5ae 00000001 00000001 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f8926a74 804ea221 822b4e80 82576e28 806ad1a8 Sfilter!SfRead+0x379 (CONV: stdcall) [c:\code\warbird\driver\sfilter.c @ 1867]
f8926a84 8062c190 82299fb8 806ad190 82576e28 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f8926aa8 8055d0fe 82576fdc 82576e28 81e5c0e8 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f8926abc 8055a3bf 822b4e80 82576e28 81e5c0e8 nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f8926b64 8052d571 800004bc 00000000 00000000 nt!NtReadFile+0x559
f8926b64 804f926d 800004bc 00000000 00000000 nt!KiSystemService+0xc4 (FPO: [0,0] TrapFrame @ f8926b90)
f8926c00 baf607d4 800004bc 00000000 00000000 nt!ZwReadFile+0x11 (FPO: [9,0,0])
f8926d00 baf5f891 bac32000 81e4c550 000004b8 Sfilter!PreloadDataFiles+0x534 (CONV: stdcall) [c:\code\warbird\driver\sfilterwthread.c @ 874]
f8926dac 805aa2b6 baf630a4 00000000 00000000 Sfilter!SFilterWorkerThreadMaster+0x1f1 (CONV: stdcall) [c:\code\warbird\driver\sfilterwthread.c @ 264]
f8926ddc 805319c6 baf5f6a0 baf630a4 00000000 nt!PspSystemThreadStartup+0x34 (FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16

kd> !irp 82576e28
Irp is active with 10 stacks 8 is current (= 0x82576f94)
No Mdl Thread 82299da8: Irp stack trace.
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 10 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000

[3, 0] 0 e0 82258020 81e5c0e8 8063879c-82576fb8 Success Error Cancel
\FileSystem\Ntfs nt!IovpInternalCompletionTrap
Args: 00000100 00000000 00000000 00000000
[3, 0] 0 e0 822d4dd0 81e5c0e8 8063879c-82576fdc Success Error Cancel
\FileSystem\sr nt!IovpInternalCompletionTrap
Args: 00000100 00000000 00000000 00000000
[3, 0] 0 0 822b4e80 81e5c0e8 00000000-00000000
\FileSystem\Sfilter
Args: 00000100 00000000 00000000 00000000

OSR_Community_User · April 8, 2004, 1:56pm

Jonathon,

The missing piece here is that the driver without symbols in the first
case ALSO included NTFS - and now I think I suspect the problem is you
are hitting some serialization between NTFS and yourself. Notice that
“WaitForIoAtEof” in NTFS? You don’t give us the other thread trace with
the NTFS symbols, but my guess is that you’re extending the EOF in that
initial thread and NTFS is serializing against itself - waiting for the
first thread to signal to the second thread that it can proceed.

Nothing like running the debugger over e-mail!

Regards,

Tony

Tony Mason

Consulting Partner

OSR Open Systems Resources, Inc.

http://www.osr.com http:

Hope to see you at the next OSR file systems class in Boston, MA, March
29, 2004!

________________________________

From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Jonathon
Sent: Thursday, April 08, 2004 1:37 PM
To: ntfsd redirect
Subject: Re:[ntfsd] Deadlock with PagingIoResource

Thanks Tony. Sorry about the symbols. I’ve used a monospace font to
clean up the output. I’m running XP SP1 on NTFS.

“I see your worker thread is blocked waiting for a stack-based event
object. Are you setting this in your completion routine?”

I’m not sure I understand. The worker thread is blocked on a synchronous
ZwReadFile. I believe it’s supposed to return when the filehandle is
signalled. I don’t have a completion routine for this read in my worker
thread.

---------------------------------------------------------

Loading User Symbols
kd> !thread 82299DA8
THREAD 82299da8 Cid 0004.006c Teb: 00000000 Win32Thread: 00000000
WAIT: (Executive) KernelMode Non-Alertable
f8926608 NotificationEvent
IRP List:
82576e28: (0006,01d8) Flags: 40000900 Mdl: 00000000
Not impersonating
DeviceMap e1004498
Owning Process 822ce838
Wait Start TickCount 8618 Elapsed Ticks: 198
Context Switch Count 201
UserTime 00:00:00.0000
KernelTime 00:00:04.0906
Start Address Sfilter!SFilterWorkerThreadMaster (0xbaf5f6a0)
Stack Init f8927000 Current f892658c Base f8927000 Limit f8924000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 0
ChildEBP RetAddr Args to Child
f89265a4 804fafe4 82299e18 82299da8 804f50ec nt!KiSwapContext+0x2e (FPO:
[EBP 0xf89265d8] [0,0,4])
f89265b0 804f50ec 00000000 e262c590 81db96a0 nt!KiSwapThread+0x44 (FPO:
[0,0,2])
f89265d8 baefb2d9 00000000 00000000 00000000
nt!KeWaitForSingleObject+0x1c0 (FPO: [Non-Fpo])
f8926618 baec59a1 e262c590 baedb358 00000000
Ntfs!NtfsWaitForIoAtEof+0x48 (FPO: [Non-Fpo])
f89266e8 baec016f 81db96a0 82576e28 00000001 Ntfs!NtfsCommonRead+0xca6
f8926788 804ea221 82258020 82576e28 806ad1a8 Ntfs!NtfsFsdRead+0x22d
f8926798 8062c190 822d4dd0 8226b2d0 82576e00 nt!IopfCallDriver+0x31
(FPO: [0,0,1])
f89267bc baf6d42d 804ea221 822d4dd0 82576e28 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f89267c0 804ea221 822d4dd0 82576e28 806ad1a8 sr!SrPassThrough+0x2f (FPO:
[2,0,0])
f89267d0 8062c190 822b4e80 82269040 82576e00 nt!IopfCallDriver+0x31
(FPO: [0,0,1])
f89267f4 baf5ba59 baf5b5ae 00000001 00000001 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f8926a74 804ea221 822b4e80 82576e28 806ad1a8 Sfilter!SfRead+0x379 (CONV:
stdcall) [c:\code\warbird\driver\sfilter.c @ 1867]
f8926a84 8062c190 82299fb8 806ad190 82576e28 nt!IopfCallDriver+0x31
(FPO: [0,0,1])
f8926aa8 8055d0fe 82576fdc 82576e28 81e5c0e8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f8926abc 8055a3bf 822b4e80 82576e28 81e5c0e8
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f8926b64 8052d571 800004bc 00000000 00000000 nt!NtReadFile+0x559
f8926b64 804f926d 800004bc 00000000 00000000 nt!KiSystemService+0xc4
(FPO: [0,0] TrapFrame @ f8926b90)
f8926c00 baf607d4 800004bc 00000000 00000000 nt!ZwReadFile+0x11 (FPO:
[9,0,0])
f8926d00 baf5f891 bac32000 81e4c550 000004b8
Sfilter!PreloadDataFiles+0x534 (CONV: stdcall)
[c:\code\warbird\driver\sfilterwthread.c @ 874]
f8926dac 805aa2b6 baf630a4 00000000 00000000
Sfilter!SFilterWorkerThreadMaster+0x1f1 (CONV: stdcall)
[c:\code\warbird\driver\sfilterwthread.c @ 264]
f8926ddc 805319c6 baf5f6a0 baf630a4 00000000
nt!PspSystemThreadStartup+0x34 (FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16

---------------------------------------------------------

kd> !irp 82576e28
Irp is active with 10 stacks 8 is current (= 0x82576f94)
No Mdl Thread 82299da8: Irp stack trace.
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] 0 10 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
>[3, 0] 0 e0 82258020 81e5c0e8 8063879c-82576fb8 Success Error
Cancel
\FileSystem\Ntfs nt!IovpInternalCompletionTrap
Args: 00000100 00000000 00000000 00000000
[3, 0] 0 e0 822d4dd0 81e5c0e8 8063879c-82576fdc Success Error
Cancel
\FileSystem\sr nt!IovpInternalCompletionTrap
Args: 00000100 00000000 00000000 00000000
[3, 0] 0 0 822b4e80 81e5c0e8 00000000-00000000
\FileSystem\Sfilter
Args: 00000100 00000000 00000000 00000000

---------------------------------------------------------

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

You are currently subscribed to ntfsd as: xxxxx@osr.com
To unsubscribe send a blank email to xxxxx@lists.osr.com</http:>

Jonathon · April 8, 2004, 2:27pm

Thanks again Tony. This has been really helpful.

I tried looking up that WaitForIoAtEof but couldn’t figure out what it was
doing. The user-mode-application-read that I block isn’t under my control
but I assume that it is somehow special since I have no problem blocking
other file reads. Is there a way that I can get around this? In other words
is there a way to read from a blocked file that is in the process of
“extending the EOF”? Would it be possible for me to stop that app from
“extending the EOF” temporarily?

I’ve included output for everything with symbols and with more detail for
the IRPs.

Pended user-mode read:

kd> !thread 81e36020
THREAD 81e36020 Cid 0514.02cc Teb: 7ffde000 Win32Thread: e1125008 WAIT:
(Executive) KernelMode Non-Alertable
baf632a0 NotificationEvent
IRP List:
825f8e28: (0006,01d8) Flags: 40000900 Mdl: 00000000
Not impersonating
DeviceMap e1f5bd20
Owning Process 81db4020
Wait Start TickCount 8425 Elapsed Ticks: 391
Context Switch Count 120 LargeStack
UserTime 00:00:00.0000
KernelTime 00:00:00.0718
Start Address 0x77e8149f
Win32 Start Address 0x004b64d9
Stack Init f4ea5000 Current f4ea42ec Base f4ea5000 Limit f4ea0000 Call 0
Priority 10 BasePriority 8 PriorityDecrement 2 DecrementCount 16
ChildEBP RetAddr Args to Child
f4ea4304 804fafe4 81e36090 81e36020 804f50ec nt!KiSwapContext+0x2e (FPO:
[EBP 0xf4ea4338] [0,0,4])
f4ea4310 804f50ec 00000000 baf632a0 8213d001 nt!KiSwapThread+0x44 (FPO:
[0,0,2])
f4ea4338 8062d3ac 00000000 00000000 00000000 nt!KeWaitForSingleObject+0x1c0
(FPO: [Non-Fpo])
f4ea4360 baf5bb80 baf632a0 00000000 00000000
nt!VerifierKeWaitForSingleObject+0x54 (FPO: [Non-Fpo])
f4ea45f4 804ea221 822b4e80 82754e28 806ad1a8 Sfilter!SfRead+0x4a0 (CONV:
stdcall) [c:\code\warbird\driver\sfilter.c @ 1941]
f4ea4604 8062c190 81e2abe0 1fe33000 8213d0c8 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
f4ea4628 804eab1a 00000000 8213d0b8 00000000 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f4ea463c 804eab3b 822b4e80 8213d00a 8213d0d0 nt!IopPageReadInternal+0xf2
(FPO: [Non-Fpo])
f4ea465c 8050a326 81e2abe0 8213d0f0 8213d0d0 nt!IoPageRead+0x19 (FPO:
[Non-Fpo])
f4ea46cc 80511a33 8213d0b8 d403329d c03500cc nt!MiDispatchFault+0x270 (FPO:
[Non-Fpo])
f4ea471c 8050d988 00000000 d403329d 00000000 nt!MmAccessFault+0x5bb (FPO:
[Non-Fpo])
f4ea4754 80547e5a d403329d 00000000 825f8e40 nt!MmCheckCachedPageState+0x308
(FPO: [Non-Fpo])
f4ea47e0 baebffc7 81e2abe0 f4ea486c 00000404 nt!CcCopyRead+0x3da (FPO:
[Non-Fpo])
f4ea48bc baec016f 81e65788 825f8e28 00000001 Ntfs!NtfsCommonRead+0xd29
f4ea495c 804ea221 82258020 825f8e28 806ad1a8 Ntfs!NtfsFsdRead+0x22d
f4ea496c 8062c190 822d4dd0 8226b2d0 825f8e00 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
f4ea4990 baf6d42d 804ea221 822d4dd0 825f8e28 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f4ea4994 804ea221 822d4dd0 825f8e28 806ad1a8 sr!SrPassThrough+0x2f (FPO:
[2,0,0])
f4ea49a4 8062c190 822b4e80 82269040 825f8e00 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
f4ea49c8 baf5bbac baf5b5ae 00000001 00000001 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f4ea4c48 804ea221 822b4e80 825f8e28 806ad1a8 Sfilter!SfRead+0x4cc (CONV:
stdcall) [c:\code\warbird\driver\sfilter.c @ 1943]
f4ea4c58 8062c190 81e36230 806ad190 825f8e28 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
f4ea4c7c 8055d0fe 825f8fdc 825f8e28 81e2abe0 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f4ea4c90 8055a3bf 822b4e80 825f8e28 81e2abe0
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f4ea4d38 8052d571 0000006c 00000000 00000000 nt!NtReadFile+0x559
f4ea4d38 7ffe0304 0000006c 00000000 00000000 nt!KiSystemService+0xc4 (FPO:
[0,0] TrapFrame @ f4ea4d64)
01e1eb48 00000000 00000000 00000000 00000000
SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])

kd> !irp 825f8e28 1
Irp is active with 10 stacks 8 is current (= 0x825f8f94)
No Mdl Thread 81e36020: Irp stack trace.
Flags = 40000900
ThreadListEntry.Flink = 81e36230
ThreadListEntry.Blink = 81e36230
IoStatus.Status = 00000000
IoStatus.Information = 00000000
RequestorMode = 00000001
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = 01e1eb18
UserEvent = 00000000
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000
UserBuffer = 003ee370
&Tail.Overlay.DeviceQueueEntry = 825f8e68
Tail.Overlay.Thread = 81e36020
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = 825f8f94
Tail.Overlay.OriginalFileObject = 81e2abe0
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 10 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000

[3, 0] 0 e0 82258020 81e2abe0 8063879c-825f8fb8 Success Error Cancel
\FileSystem\Ntfs nt!IovpInternalCompletionTrap
Args: 00001000 00000000 1fe3329d 00000000
[3, 0] 0 e0 822d4dd0 81e2abe0 8063879c-825f8fdc Success Error Cancel
\FileSystem\sr nt!IovpInternalCompletionTrap
Args: 00001000 00000000 1fe3329d 00000000
[3, 0] 0 0 822b4e80 81e2abe0 00000000-00000000
\FileSystem\Sfilter
Args: 00001000 00000000 1fe3329d 00000000

Worker thread ZwReadFile which doesn’t return:

kd> !thread 82299DA8
THREAD 82299da8 Cid 0004.006c Teb: 00000000 Win32Thread: 00000000 WAIT:
(Executive) KernelMode Non-Alertable
f8926608 NotificationEvent
IRP List:
82576e28: (0006,01d8) Flags: 40000900 Mdl: 00000000
Not impersonating
DeviceMap e1004498
Owning Process 822ce838
Wait Start TickCount 8618 Elapsed Ticks: 198
Context Switch Count 201
UserTime 00:00:00.0000
KernelTime 00:00:04.0906
Start Address Sfilter!SFilterWorkerThreadMaster (0xbaf5f6a0)
Stack Init f8927000 Current f892658c Base f8927000 Limit f8924000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 0
ChildEBP RetAddr Args to Child
f89265a4 804fafe4 82299e18 82299da8 804f50ec nt!KiSwapContext+0x2e (FPO:
[EBP 0xf89265d8] [0,0,4])
f89265b0 804f50ec 00000000 e262c590 81db96a0 nt!KiSwapThread+0x44 (FPO:
[0,0,2])
f89265d8 baefb2d9 00000000 00000000 00000000 nt!KeWaitForSingleObject+0x1c0
(FPO: [Non-Fpo])
f8926618 baec59a1 e262c590 baedb358 00000000 Ntfs!NtfsWaitForIoAtEof+0x48
(FPO: [Non-Fpo])
f89266e8 baec016f 81db96a0 82576e28 00000001 Ntfs!NtfsCommonRead+0xca6
f8926788 804ea221 82258020 82576e28 806ad1a8 Ntfs!NtfsFsdRead+0x22d
f8926798 8062c190 822d4dd0 8226b2d0 82576e00 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
f89267bc baf6d42d 804ea221 822d4dd0 82576e28 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f89267c0 804ea221 822d4dd0 82576e28 806ad1a8 sr!SrPassThrough+0x2f (FPO:
[2,0,0])
f89267d0 8062c190 822b4e80 82269040 82576e00 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
f89267f4 baf5ba59 baf5b5ae 00000001 00000001 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f8926a74 804ea221 822b4e80 82576e28 806ad1a8 Sfilter!SfRead+0x379 (CONV:
stdcall) [c:\code\warbird\driver\sfilter.c @ 1867]
f8926a84 8062c190 82299fb8 806ad190 82576e28 nt!IopfCallDriver+0x31 (FPO:
[0,0,1])
f8926aa8 8055d0fe 82576fdc 82576e28 81e5c0e8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f8926abc 8055a3bf 822b4e80 82576e28 81e5c0e8
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f8926b64 8052d571 800004bc 00000000 00000000 nt!NtReadFile+0x559
f8926b64 804f926d 800004bc 00000000 00000000 nt!KiSystemService+0xc4 (FPO:
[0,0] TrapFrame @ f8926b90)
f8926c00 baf607d4 800004bc 00000000 00000000 nt!ZwReadFile+0x11 (FPO:
[9,0,0])
f8926d00 baf5f891 bac32000 81e4c550 000004b8 Sfilter!PreloadDataFiles+0x534
(CONV: stdcall) [c:\code\warbird\driver\sfilterwthread.c @ 874]
f8926dac 805aa2b6 baf630a4 00000000 00000000
Sfilter!SFilterWorkerThreadMaster+0x1f1 (CONV: stdcall)
[c:\code\warbird\driver\sfilterwthread.c @ 264]
f8926ddc 805319c6 baf5f6a0 baf630a4 00000000 nt!PspSystemThreadStartup+0x34
(FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16

kd> !irp 82576e28 1
Irp is active with 10 stacks 8 is current (= 0x82576f94)
No Mdl Thread 82299da8: Irp stack trace.
Flags = 40000900
ThreadListEntry.Flink = 82299fb8
ThreadListEntry.Blink = 82299fb8
IoStatus.Status = 00000000
IoStatus.Information = 00000000
RequestorMode = 00000000
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = f8926c58
UserEvent = 00000000
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000
UserBuffer = bac32000
&Tail.Overlay.DeviceQueueEntry = 82576e68
Tail.Overlay.Thread = 82299da8
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = 82576f94
Tail.Overlay.OriginalFileObject = 81e5c0e8
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 10 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000

[3, 0] 0 e0 82258020 81e5c0e8 8063879c-82576fb8 Success Error Cancel
\FileSystem\Ntfs nt!IovpInternalCompletionTrap
Args: 00000100 00000000 00000000 00000000
[3, 0] 0 e0 822d4dd0 81e5c0e8 8063879c-82576fdc Success Error Cancel
\FileSystem\sr nt!IovpInternalCompletionTrap
Args: 00000100 00000000 00000000 00000000
[3, 0] 0 0 822b4e80 81e5c0e8 00000000-00000000
\FileSystem\Sfilter
Args: 00000100 00000000 00000000 00000000

“Tony Mason” wrote in message news:xxxxx@ntfsd…
Jonathon,

The missing piece here is that the driver without symbols in the first case
ALSO included NTFS - and now I think I suspect the problem is you are
hitting some serialization between NTFS and yourself. Notice that
“WaitForIoAtEof” in NTFS? You don’t give us the other thread trace with the
NTFS symbols, but my guess is that you’re extending the EOF in that initial
thread and NTFS is serializing against itself - waiting for the first thread
to signal to the second thread that it can proceed.

Nothing like running the debugger over e-mail!

Regards,

Tony

Tony Mason

Consulting Partner

OSR Open Systems Resources, Inc.

http://www.osr.com

Hope to see you at the next OSR file systems class in Boston, MA, March 29,
2004!

Jonathon · April 8, 2004, 2:55pm

Ugh. Outlook sent my last message in plain text and it’s a mess. I’m reposting it. It suddenly occurs to me that I’ve left out one important fact about the file that I’m pending. It’s a ZIP file. Does it matter if a user-mode app reads from a compressed file?

Pended user-mode read:

kd> !thread 81e36020
THREAD 81e36020 Cid 0514.02cc Teb: 7ffde000 Win32Thread: e1125008 WAIT: (Executive) KernelMode Non-Alertable
baf632a0 NotificationEvent
IRP List:
825f8e28: (0006,01d8) Flags: 40000900 Mdl: 00000000
Not impersonating
DeviceMap e1f5bd20
Owning Process 81db4020
Wait Start TickCount 8425 Elapsed Ticks: 391
Context Switch Count 120 LargeStack
UserTime 00:00:00.0000
KernelTime 00:00:00.0718
Start Address 0x77e8149f
Win32 Start Address 0x004b64d9
Stack Init f4ea5000 Current f4ea42ec Base f4ea5000 Limit f4ea0000 Call 0
Priority 10 BasePriority 8 PriorityDecrement 2 DecrementCount 16
ChildEBP RetAddr Args to Child
f4ea4304 804fafe4 81e36090 81e36020 804f50ec nt!KiSwapContext+0x2e (FPO: [EBP 0xf4ea4338] [0,0,4])
f4ea4310 804f50ec 00000000 baf632a0 8213d001 nt!KiSwapThread+0x44 (FPO: [0,0,2])
f4ea4338 8062d3ac 00000000 00000000 00000000 nt!KeWaitForSingleObject+0x1c0 (FPO: [Non-Fpo])
f4ea4360 baf5bb80 baf632a0 00000000 00000000 nt!VerifierKeWaitForSingleObject+0x54 (FPO: [Non-Fpo])
f4ea45f4 804ea221 822b4e80 82754e28 806ad1a8 Sfilter!SfRead+0x4a0 (CONV: stdcall) [c:\code\warbird\driver\sfilter.c @ 1941]
f4ea4604 8062c190 81e2abe0 1fe33000 8213d0c8 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f4ea4628 804eab1a 00000000 8213d0b8 00000000 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f4ea463c 804eab3b 822b4e80 8213d00a 8213d0d0 nt!IopPageReadInternal+0xf2 (FPO: [Non-Fpo])
f4ea465c 8050a326 81e2abe0 8213d0f0 8213d0d0 nt!IoPageRead+0x19 (FPO: [Non-Fpo])
f4ea46cc 80511a33 8213d0b8 d403329d c03500cc nt!MiDispatchFault+0x270 (FPO: [Non-Fpo])
f4ea471c 8050d988 00000000 d403329d 00000000 nt!MmAccessFault+0x5bb (FPO: [Non-Fpo])
f4ea4754 80547e5a d403329d 00000000 825f8e40 nt!MmCheckCachedPageState+0x308 (FPO: [Non-Fpo])
f4ea47e0 baebffc7 81e2abe0 f4ea486c 00000404 nt!CcCopyRead+0x3da (FPO: [Non-Fpo])
f4ea48bc baec016f 81e65788 825f8e28 00000001 Ntfs!NtfsCommonRead+0xd29
f4ea495c 804ea221 82258020 825f8e28 806ad1a8 Ntfs!NtfsFsdRead+0x22d
f4ea496c 8062c190 822d4dd0 8226b2d0 825f8e00 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f4ea4990 baf6d42d 804ea221 822d4dd0 825f8e28 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f4ea4994 804ea221 822d4dd0 825f8e28 806ad1a8 sr!SrPassThrough+0x2f (FPO: [2,0,0])
f4ea49a4 8062c190 822b4e80 82269040 825f8e00 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f4ea49c8 baf5bbac baf5b5ae 00000001 00000001 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f4ea4c48 804ea221 822b4e80 825f8e28 806ad1a8 Sfilter!SfRead+0x4cc (CONV: stdcall) [c:\code\warbird\driver\sfilter.c @ 1943]
f4ea4c58 8062c190 81e36230 806ad190 825f8e28 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f4ea4c7c 8055d0fe 825f8fdc 825f8e28 81e2abe0 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f4ea4c90 8055a3bf 822b4e80 825f8e28 81e2abe0 nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f4ea4d38 8052d571 0000006c 00000000 00000000 nt!NtReadFile+0x559
f4ea4d38 7ffe0304 0000006c 00000000 00000000 nt!KiSystemService+0xc4 (FPO: [0,0] TrapFrame @ f4ea4d64)
01e1eb48 00000000 00000000 00000000 00000000 SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])

kd> !irp 825f8e28 1
Irp is active with 10 stacks 8 is current (= 0x825f8f94)
No Mdl Thread 81e36020: Irp stack trace.
Flags = 40000900
ThreadListEntry.Flink = 81e36230
ThreadListEntry.Blink = 81e36230
IoStatus.Status = 00000000
IoStatus.Information = 00000000
RequestorMode = 00000001
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = 01e1eb18
UserEvent = 00000000
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000
UserBuffer = 003ee370
&Tail.Overlay.DeviceQueueEntry = 825f8e68
Tail.Overlay.Thread = 81e36020
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = 825f8f94
Tail.Overlay.OriginalFileObject = 81e2abe0
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 10 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000

[3, 0] 0 e0 82258020 81e2abe0 8063879c-825f8fb8 Success Error Cancel
\FileSystem\Ntfs nt!IovpInternalCompletionTrap
Args: 00001000 00000000 1fe3329d 00000000
[3, 0] 0 e0 822d4dd0 81e2abe0 8063879c-825f8fdc Success Error Cancel
\FileSystem\sr nt!IovpInternalCompletionTrap
Args: 00001000 00000000 1fe3329d 00000000
[3, 0] 0 0 822b4e80 81e2abe0 00000000-00000000
\FileSystem\Sfilter
Args: 00001000 00000000 1fe3329d 00000000

Worker thread ZwReadFile which doesn’t return:

kd> !thread 82299DA8
THREAD 82299da8 Cid 0004.006c Teb: 00000000 Win32Thread: 00000000 WAIT: (Executive) KernelMode Non-Alertable
f8926608 NotificationEvent
IRP List:
82576e28: (0006,01d8) Flags: 40000900 Mdl: 00000000
Not impersonating
DeviceMap e1004498
Owning Process 822ce838
Wait Start TickCount 8618 Elapsed Ticks: 198
Context Switch Count 201
UserTime 00:00:00.0000
KernelTime 00:00:04.0906
Start Address Sfilter!SFilterWorkerThreadMaster (0xbaf5f6a0)
Stack Init f8927000 Current f892658c Base f8927000 Limit f8924000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 0
ChildEBP RetAddr Args to Child
f89265a4 804fafe4 82299e18 82299da8 804f50ec nt!KiSwapContext+0x2e (FPO: [EBP 0xf89265d8] [0,0,4])
f89265b0 804f50ec 00000000 e262c590 81db96a0 nt!KiSwapThread+0x44 (FPO: [0,0,2])
f89265d8 baefb2d9 00000000 00000000 00000000 nt!KeWaitForSingleObject+0x1c0 (FPO: [Non-Fpo])
f8926618 baec59a1 e262c590 baedb358 00000000 Ntfs!NtfsWaitForIoAtEof+0x48 (FPO: [Non-Fpo])
f89266e8 baec016f 81db96a0 82576e28 00000001 Ntfs!NtfsCommonRead+0xca6
f8926788 804ea221 82258020 82576e28 806ad1a8 Ntfs!NtfsFsdRead+0x22d
f8926798 8062c190 822d4dd0 8226b2d0 82576e00 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f89267bc baf6d42d 804ea221 822d4dd0 82576e28 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f89267c0 804ea221 822d4dd0 82576e28 806ad1a8 sr!SrPassThrough+0x2f (FPO: [2,0,0])
f89267d0 8062c190 822b4e80 82269040 82576e00 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f89267f4 baf5ba59 baf5b5ae 00000001 00000001 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f8926a74 804ea221 822b4e80 82576e28 806ad1a8 Sfilter!SfRead+0x379 (CONV: stdcall) [c:\code\warbird\driver\sfilter.c @ 1867]
f8926a84 8062c190 82299fb8 806ad190 82576e28 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f8926aa8 8055d0fe 82576fdc 82576e28 81e5c0e8 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f8926abc 8055a3bf 822b4e80 82576e28 81e5c0e8 nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f8926b64 8052d571 800004bc 00000000 00000000 nt!NtReadFile+0x559
f8926b64 804f926d 800004bc 00000000 00000000 nt!KiSystemService+0xc4 (FPO: [0,0] TrapFrame @ f8926b90)
f8926c00 baf607d4 800004bc 00000000 00000000 nt!ZwReadFile+0x11 (FPO: [9,0,0])
f8926d00 baf5f891 bac32000 81e4c550 000004b8 Sfilter!PreloadDataFiles+0x534 (CONV: stdcall) [c:\code\warbird\driver\sfilterwthread.c @ 874]
f8926dac 805aa2b6 baf630a4 00000000 00000000 Sfilter!SFilterWorkerThreadMaster+0x1f1 (CONV: stdcall) [c:\code\warbird\driver\sfilterwthread.c @ 264]
f8926ddc 805319c6 baf5f6a0 baf630a4 00000000 nt!PspSystemThreadStartup+0x34 (FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16

kd> !irp 82576e28 1
Irp is active with 10 stacks 8 is current (= 0x82576f94)
No Mdl Thread 82299da8: Irp stack trace.
Flags = 40000900
ThreadListEntry.Flink = 82299fb8
ThreadListEntry.Blink = 82299fb8
IoStatus.Status = 00000000
IoStatus.Information = 00000000
RequestorMode = 00000000
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = f8926c58
UserEvent = 00000000
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000
UserBuffer = bac32000
&Tail.Overlay.DeviceQueueEntry = 82576e68
Tail.Overlay.Thread = 82299da8
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = 82576f94
Tail.Overlay.OriginalFileObject = 81e5c0e8
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 10 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000

[3, 0] 0 e0 82258020 81e5c0e8 8063879c-82576fb8 Success Error Cancel
\FileSystem\Ntfs nt!IovpInternalCompletionTrap
Args: 00000100 00000000 00000000 00000000
[3, 0] 0 e0 822d4dd0 81e5c0e8 8063879c-82576fdc Success Error Cancel
\FileSystem\sr nt!IovpInternalCompletionTrap
Args: 00000100 00000000 00000000 00000000
[3, 0] 0 0 822b4e80 81e5c0e8 00000000-00000000
\FileSystem\Sfilter
Args: 00000100 00000000 00000000 00000000

OSR_Community_User · April 8, 2004, 3:50pm

Jonathon,

Here’s my theory:

NTFS is called by the user mode thread to read from a region of the file
that was not previously written (beyond valid data length). In the
process it sets the FSRTL_FLAG_EOF_ADVANCE_ACTIVE flag in the common
header block (Flags) - this gives you something else to confirm.

It performs a read from the cache (hence the call to CcCopyRead from
NtfsCommonRead). Since the data is not in the cache, this triggers a
page fault. The page fault irp is intercepted by your filter; you then
post a work item to the worker thread. The worker thread issues a
ZwReadFile on the same file and ALSO beyond the ValidDataLength of the
file, so this second thread blocks and waits for the EOF to be extended
by the first thread. Of course, the first thread won’t ever finish
because it is waiting for the second thread (the worker) to finish.

So now you’ll say “so, how do I prevent this from happening?” First,
before making some wild suggestions, I’ll note that I have no idea what
you are doing, or why you did it this way. What I CAN note is that this
form of EOF serialization doesn’t happen for paging I/O, which is why
you’d never see it in the “normal course of events”. I also suspect it
requires a file where the ValidDataLength < EOF and not on a page
boundary, requiring that the VM system pull in the data (hence the
paging I/O) rather than just return a zero-filled block of data. That
might explain why you only see it sometimes.

My first suggestion would be: don’t use ZwReadFile. That’s just asking
for trouble here. If you must do this in a worker thread (and again, I
don’t know why you are doing this) you should do this with an IRP. Of
course, if my theory above is correct, even a garden variety IRP_MJ_READ
is going to hang as well on the growth of ValidDataLength. Only a
paging I/O IRP is not going to do that - and building paging I/O IRPs
can be done but the I/O Manager handles them quite a bit differently
(completion processing is very different for paging I/O operations.)

So, perhaps better understanding what you are trying to achieve, I or
someone else can suggest an alternative approach.

Regards,

Tony

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

Hope to see you at the next OSR file systems class in Boston, MA, March
29, 2004!

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Jonathon
Sent: Thursday, April 08, 2004 2:26 PM
To: ntfsd redirect
Subject: Re:[ntfsd] Deadlock with PagingIoResource

Thanks again Tony. This has been really helpful.

I tried looking up that WaitForIoAtEof but couldn’t figure out what it
was
doing. The user-mode-application-read that I block isn’t under my
control
but I assume that it is somehow special since I have no problem blocking
other file reads. Is there a way that I can get around this? In other
words
is there a way to read from a blocked file that is in the process of
“extending the EOF”? Would it be possible for me to stop that app from
“extending the EOF” temporarily?

I’ve included output for everything with symbols and with more detail
for
the IRPs.

Pended user-mode read:

kd> !thread 81e36020
THREAD 81e36020 Cid 0514.02cc Teb: 7ffde000 Win32Thread: e1125008
WAIT:
(Executive) KernelMode Non-Alertable
baf632a0 NotificationEvent
IRP List:
825f8e28: (0006,01d8) Flags: 40000900 Mdl: 00000000
Not impersonating
DeviceMap e1f5bd20
Owning Process 81db4020
Wait Start TickCount 8425 Elapsed Ticks: 391
Context Switch Count 120 LargeStack
UserTime 00:00:00.0000
KernelTime 00:00:00.0718
Start Address 0x77e8149f
Win32 Start Address 0x004b64d9
Stack Init f4ea5000 Current f4ea42ec Base f4ea5000 Limit f4ea0000 Call 0
Priority 10 BasePriority 8 PriorityDecrement 2 DecrementCount 16
ChildEBP RetAddr Args to Child
f4ea4304 804fafe4 81e36090 81e36020 804f50ec nt!KiSwapContext+0x2e (FPO:
[EBP 0xf4ea4338] [0,0,4])
f4ea4310 804f50ec 00000000 baf632a0 8213d001 nt!KiSwapThread+0x44 (FPO:
[0,0,2])
f4ea4338 8062d3ac 00000000 00000000 00000000
nt!KeWaitForSingleObject+0x1c0
(FPO: [Non-Fpo])
f4ea4360 baf5bb80 baf632a0 00000000 00000000
nt!VerifierKeWaitForSingleObject+0x54 (FPO: [Non-Fpo])
f4ea45f4 804ea221 822b4e80 82754e28 806ad1a8 Sfilter!SfRead+0x4a0 (CONV:
stdcall) [c:\code\warbird\driver\sfilter.c @ 1941]
f4ea4604 8062c190 81e2abe0 1fe33000 8213d0c8 nt!IopfCallDriver+0x31
(FPO:
[0,0,1])
f4ea4628 804eab1a 00000000 8213d0b8 00000000 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f4ea463c 804eab3b 822b4e80 8213d00a 8213d0d0 nt!IopPageReadInternal+0xf2
(FPO: [Non-Fpo])
f4ea465c 8050a326 81e2abe0 8213d0f0 8213d0d0 nt!IoPageRead+0x19 (FPO:
[Non-Fpo])
f4ea46cc 80511a33 8213d0b8 d403329d c03500cc nt!MiDispatchFault+0x270
(FPO:
[Non-Fpo])
f4ea471c 8050d988 00000000 d403329d 00000000 nt!MmAccessFault+0x5bb
(FPO:
[Non-Fpo])
f4ea4754 80547e5a d403329d 00000000 825f8e40
nt!MmCheckCachedPageState+0x308
(FPO: [Non-Fpo])
f4ea47e0 baebffc7 81e2abe0 f4ea486c 00000404 nt!CcCopyRead+0x3da (FPO:
[Non-Fpo])
f4ea48bc baec016f 81e65788 825f8e28 00000001 Ntfs!NtfsCommonRead+0xd29
f4ea495c 804ea221 82258020 825f8e28 806ad1a8 Ntfs!NtfsFsdRead+0x22d
f4ea496c 8062c190 822d4dd0 8226b2d0 825f8e00 nt!IopfCallDriver+0x31
(FPO:
[0,0,1])
f4ea4990 baf6d42d 804ea221 822d4dd0 825f8e28 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f4ea4994 804ea221 822d4dd0 825f8e28 806ad1a8 sr!SrPassThrough+0x2f (FPO:
[2,0,0])
f4ea49a4 8062c190 822b4e80 82269040 825f8e00 nt!IopfCallDriver+0x31
(FPO:
[0,0,1])
f4ea49c8 baf5bbac baf5b5ae 00000001 00000001 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f4ea4c48 804ea221 822b4e80 825f8e28 806ad1a8 Sfilter!SfRead+0x4cc (CONV:
stdcall) [c:\code\warbird\driver\sfilter.c @ 1943]
f4ea4c58 8062c190 81e36230 806ad190 825f8e28 nt!IopfCallDriver+0x31
(FPO:
[0,0,1])
f4ea4c7c 8055d0fe 825f8fdc 825f8e28 81e2abe0 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f4ea4c90 8055a3bf 822b4e80 825f8e28 81e2abe0
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f4ea4d38 8052d571 0000006c 00000000 00000000 nt!NtReadFile+0x559
f4ea4d38 7ffe0304 0000006c 00000000 00000000 nt!KiSystemService+0xc4
(FPO:
[0,0] TrapFrame @ f4ea4d64)
01e1eb48 00000000 00000000 00000000 00000000
SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])

kd> !irp 825f8e28 1
Irp is active with 10 stacks 8 is current (= 0x825f8f94)
No Mdl Thread 81e36020: Irp stack trace.
Flags = 40000900
ThreadListEntry.Flink = 81e36230
ThreadListEntry.Blink = 81e36230
IoStatus.Status = 00000000
IoStatus.Information = 00000000
RequestorMode = 00000001
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = 01e1eb18
UserEvent = 00000000
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000
UserBuffer = 003ee370
&Tail.Overlay.DeviceQueueEntry = 825f8e68
Tail.Overlay.Thread = 81e36020
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = 825f8f94
Tail.Overlay.OriginalFileObject = 81e2abe0
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 10 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000

[3, 0] 0 e0 82258020 81e2abe0 8063879c-825f8fb8 Success Error
Cancel
\FileSystem\Ntfs nt!IovpInternalCompletionTrap
Args: 00001000 00000000 1fe3329d 00000000
[3, 0] 0 e0 822d4dd0 81e2abe0 8063879c-825f8fdc Success Error
Cancel
\FileSystem\sr nt!IovpInternalCompletionTrap
Args: 00001000 00000000 1fe3329d 00000000
[3, 0] 0 0 822b4e80 81e2abe0 00000000-00000000
\FileSystem\Sfilter
Args: 00001000 00000000 1fe3329d 00000000

Worker thread ZwReadFile which doesn’t return:

kd> !thread 82299DA8
THREAD 82299da8 Cid 0004.006c Teb: 00000000 Win32Thread: 00000000
WAIT:
(Executive) KernelMode Non-Alertable
f8926608 NotificationEvent
IRP List:
82576e28: (0006,01d8) Flags: 40000900 Mdl: 00000000
Not impersonating
DeviceMap e1004498
Owning Process 822ce838
Wait Start TickCount 8618 Elapsed Ticks: 198
Context Switch Count 201
UserTime 00:00:00.0000
KernelTime 00:00:04.0906
Start Address Sfilter!SFilterWorkerThreadMaster (0xbaf5f6a0)
Stack Init f8927000 Current f892658c Base f8927000 Limit f8924000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 0
ChildEBP RetAddr Args to Child
f89265a4 804fafe4 82299e18 82299da8 804f50ec nt!KiSwapContext+0x2e (FPO:
[EBP 0xf89265d8] [0,0,4])
f89265b0 804f50ec 00000000 e262c590 81db96a0 nt!KiSwapThread+0x44 (FPO:
[0,0,2])
f89265d8 baefb2d9 00000000 00000000 00000000
nt!KeWaitForSingleObject+0x1c0
(FPO: [Non-Fpo])
f8926618 baec59a1 e262c590 baedb358 00000000
Ntfs!NtfsWaitForIoAtEof+0x48
(FPO: [Non-Fpo])
f89266e8 baec016f 81db96a0 82576e28 00000001 Ntfs!NtfsCommonRead+0xca6
f8926788 804ea221 82258020 82576e28 806ad1a8 Ntfs!NtfsFsdRead+0x22d
f8926798 8062c190 822d4dd0 8226b2d0 82576e00 nt!IopfCallDriver+0x31
(FPO:
[0,0,1])
f89267bc baf6d42d 804ea221 822d4dd0 82576e28 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f89267c0 804ea221 822d4dd0 82576e28 806ad1a8 sr!SrPassThrough+0x2f (FPO:
[2,0,0])
f89267d0 8062c190 822b4e80 82269040 82576e00 nt!IopfCallDriver+0x31
(FPO:
[0,0,1])
f89267f4 baf5ba59 baf5b5ae 00000001 00000001 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f8926a74 804ea221 822b4e80 82576e28 806ad1a8 Sfilter!SfRead+0x379 (CONV:
stdcall) [c:\code\warbird\driver\sfilter.c @ 1867]
f8926a84 8062c190 82299fb8 806ad190 82576e28 nt!IopfCallDriver+0x31
(FPO:
[0,0,1])
f8926aa8 8055d0fe 82576fdc 82576e28 81e5c0e8 nt!IovCallDriver+0x9e (FPO:
[Non-Fpo])
f8926abc 8055a3bf 822b4e80 82576e28 81e5c0e8
nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f8926b64 8052d571 800004bc 00000000 00000000 nt!NtReadFile+0x559
f8926b64 804f926d 800004bc 00000000 00000000 nt!KiSystemService+0xc4
(FPO:
[0,0] TrapFrame @ f8926b90)
f8926c00 baf607d4 800004bc 00000000 00000000 nt!ZwReadFile+0x11 (FPO:
[9,0,0])
f8926d00 baf5f891 bac32000 81e4c550 000004b8
Sfilter!PreloadDataFiles+0x534
(CONV: stdcall) [c:\code\warbird\driver\sfilterwthread.c @ 874]
f8926dac 805aa2b6 baf630a4 00000000 00000000
Sfilter!SFilterWorkerThreadMaster+0x1f1 (CONV: stdcall)
[c:\code\warbird\driver\sfilterwthread.c @ 264]
f8926ddc 805319c6 baf5f6a0 baf630a4 00000000
nt!PspSystemThreadStartup+0x34
(FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16

kd> !irp 82576e28 1
Irp is active with 10 stacks 8 is current (= 0x82576f94)
No Mdl Thread 82299da8: Irp stack trace.
Flags = 40000900
ThreadListEntry.Flink = 82299fb8
ThreadListEntry.Blink = 82299fb8
IoStatus.Status = 00000000
IoStatus.Information = 00000000
RequestorMode = 00000000
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = f8926c58
UserEvent = 00000000
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000
UserBuffer = bac32000
&Tail.Overlay.DeviceQueueEntry = 82576e68
Tail.Overlay.Thread = 82299da8
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = 82576f94
Tail.Overlay.OriginalFileObject = 81e5c0e8
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 10 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000

[3, 0] 0 e0 82258020 81e5c0e8 8063879c-82576fb8 Success Error
Cancel
\FileSystem\Ntfs nt!IovpInternalCompletionTrap
Args: 00000100 00000000 00000000 00000000
[3, 0] 0 e0 822d4dd0 81e5c0e8 8063879c-82576fdc Success Error
Cancel
\FileSystem\sr nt!IovpInternalCompletionTrap
Args: 00000100 00000000 00000000 00000000
[3, 0] 0 0 822b4e80 81e5c0e8 00000000-00000000
\FileSystem\Sfilter
Args: 00000100 00000000 00000000 00000000

“Tony Mason” wrote in message news:xxxxx@ntfsd…
Jonathon,

The missing piece here is that the driver without symbols in the first
case
ALSO included NTFS - and now I think I suspect the problem is you are
hitting some serialization between NTFS and yourself. Notice that
“WaitForIoAtEof” in NTFS? You don’t give us the other thread trace with
the
NTFS symbols, but my guess is that you’re extending the EOF in that
initial
thread and NTFS is serializing against itself - waiting for the first
thread
to signal to the second thread that it can proceed.

Nothing like running the debugger over e-mail!

Regards,

Tony

Tony Mason

Consulting Partner

OSR Open Systems Resources, Inc.

http://www.osr.com

Hope to see you at the next OSR file systems class in Boston, MA, March
29,
2004!

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

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

Jonathon · April 8, 2004, 6:17pm

Tony,

Thanks again for your reply. You are correct the
FSRTL_FLAG_EOF_ADVANCE_ACTIVE flag is being set for this file. Only for this
file - I saw no other files with this flag enabled. Is this because the file
that the user-mode app is reading is compressed? There are other reads on
this file which do not have this bit set. If I block them the ZwReadFile
does not hang but I do deadlock in the worker thread on the
PagingIoResource(81e16738) when I close the file:

Resource @ 0x81e16738 Shared 1 owning threads
Contention Count = 1
NumberOfExclusiveWaiters = 1
Threads: 81dcfda8-01<*>
Threads Waiting On Exclusive Access:
82299da8

I can get around this (perhaps by delaying the close) but I’m sure there are
better ways of doing what I’m trying to do. I am trying to cache a short
list of files when I see a particular read. Sometimes I will cache data from
the file that signalled the caching. I’m using ZwReadFile in a worker thread
because I thought it would be the simplest way to make it work. I plan to
use asynchronous worker-thread generated IRPs later. Is this a good idea? Is
there another approach that is simpler, more efficient or will make it
easier to overcome my current problem?

Alexei_Jelvis-2 · April 9, 2004, 2:30pm

According to this stack you pass through regular read request. This IRP comes to ntfs that calls CcCopyRead which caused page fault. Another IRP is generated to read the page into the cache and you are blocking this IRP.
I would suggest you to stop blocking paging requests at all. Data returned to the application via normal read, there is really no point in blocking paging IO, you need make decision when processing regular read requests.
In terms of your call stack:

At this point you can make a decision to block the read request; you decided to pass it through:
f4ea4c48 804ea221 822b4e80 825f8e28 806ad1a8 Sfilter!SfRead+0x4cc (CONV: stdcall) [c:\code\warbird\driver\sfilter.c @ 1943]
f4ea4c58 8062c190 81e36230 806ad190 825f8e28 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f4ea4c7c 8055d0fe 825f8fdc 825f8e28 81e2abe0 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f4ea4c90 8055a3bf 822b4e80 825f8e28 81e2abe0 nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f4ea4d38 8052d571 0000006c 00000000 00000000 nt!NtReadFile+0x559

And you have descided to block a read request here, when paging IO is in progress:
f4ea4338 8062d3ac 00000000 00000000 00000000 nt!KeWaitForSingleObject+0x1c0 (FPO: [Non-Fpo])
f4ea4360 baf5bb80 baf632a0 00000000 00000000 nt!VerifierKeWaitForSingleObject+0x54 (FPO: [Non-Fpo])
f4ea45f4 804ea221 822b4e80 82754e28 806ad1a8 Sfilter!SfRead+0x4a0 (CONV: stdcall) [c:\code\warbird\driver\sfilter.c @ 1941]
f4ea4604 8062c190 81e2abe0 1fe33000 8213d0c8 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f4ea4628 804eab1a 00000000 8213d0b8 00000000 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f4ea463c 804eab3b 822b4e80 8213d00a 8213d0d0 nt!IopPageReadInternal+0xf2 (FPO: [Non-Fpo])
f4ea465c 8050a326 81e2abe0 8213d0f0 8213d0d0 nt!IoPageRead+0x19 (FPO: [Non-Fpo])

Alexei.
“Jonathon” wrote in message news:xxxxx@ntfsd…

Ugh. Outlook sent my last message in plain text and it’s a mess. I’m reposting it. It suddenly occurs to me that I’ve left out one important fact about the file that I’m pending. It’s a ZIP file. Does it matter if a user-mode app reads from a compressed file?

Pended user-mode read:

-------------------------------------------------------

kd> !thread 81e36020
THREAD 81e36020 Cid 0514.02cc Teb: 7ffde000 Win32Thread: e1125008 WAIT: (Executive) KernelMode Non-Alertable
baf632a0 NotificationEvent
IRP List:
825f8e28: (0006,01d8) Flags: 40000900 Mdl: 00000000
Not impersonating
DeviceMap e1f5bd20
Owning Process 81db4020
Wait Start TickCount 8425 Elapsed Ticks: 391
Context Switch Count 120 LargeStack
UserTime 00:00:00.0000
KernelTime 00:00:00.0718
Start Address 0x77e8149f
Win32 Start Address 0x004b64d9
Stack Init f4ea5000 Current f4ea42ec Base f4ea5000 Limit f4ea0000 Call 0
Priority 10 BasePriority 8 PriorityDecrement 2 DecrementCount 16
ChildEBP RetAddr Args to Child
f4ea4304 804fafe4 81e36090 81e36020 804f50ec nt!KiSwapContext+0x2e (FPO: [EBP 0xf4ea4338] [0,0,4])
f4ea4310 804f50ec 00000000 baf632a0 8213d001 nt!KiSwapThread+0x44 (FPO: [0,0,2])
f4ea4338 8062d3ac 00000000 00000000 00000000 nt!KeWaitForSingleObject+0x1c0 (FPO: [Non-Fpo])
f4ea4360 baf5bb80 baf632a0 00000000 00000000 nt!VerifierKeWaitForSingleObject+0x54 (FPO: [Non-Fpo])
f4ea45f4 804ea221 822b4e80 82754e28 806ad1a8 Sfilter!SfRead+0x4a0 (CONV: stdcall) [c:\code\warbird\driver\sfilter.c @ 1941]
f4ea4604 8062c190 81e2abe0 1fe33000 8213d0c8 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f4ea4628 804eab1a 00000000 8213d0b8 00000000 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f4ea463c 804eab3b 822b4e80 8213d00a 8213d0d0 nt!IopPageReadInternal+0xf2 (FPO: [Non-Fpo])
f4ea465c 8050a326 81e2abe0 8213d0f0 8213d0d0 nt!IoPageRead+0x19 (FPO: [Non-Fpo])
f4ea46cc 80511a33 8213d0b8 d403329d c03500cc nt!MiDispatchFault+0x270 (FPO: [Non-Fpo])
f4ea471c 8050d988 00000000 d403329d 00000000 nt!MmAccessFault+0x5bb (FPO: [Non-Fpo])
f4ea4754 80547e5a d403329d 00000000 825f8e40 nt!MmCheckCachedPageState+0x308 (FPO: [Non-Fpo])
f4ea47e0 baebffc7 81e2abe0 f4ea486c 00000404 nt!CcCopyRead+0x3da (FPO: [Non-Fpo])
f4ea48bc baec016f 81e65788 825f8e28 00000001 Ntfs!NtfsCommonRead+0xd29
f4ea495c 804ea221 82258020 825f8e28 806ad1a8 Ntfs!NtfsFsdRead+0x22d
f4ea496c 8062c190 822d4dd0 8226b2d0 825f8e00 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f4ea4990 baf6d42d 804ea221 822d4dd0 825f8e28 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f4ea4994 804ea221 822d4dd0 825f8e28 806ad1a8 sr!SrPassThrough+0x2f (FPO: [2,0,0])
f4ea49a4 8062c190 822b4e80 82269040 825f8e00 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f4ea49c8 baf5bbac baf5b5ae 00000001 00000001 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f4ea4c48 804ea221 822b4e80 825f8e28 806ad1a8 Sfilter!SfRead+0x4cc (CONV: stdcall) [c:\code\warbird\driver\sfilter.c @ 1943]
f4ea4c58 8062c190 81e36230 806ad190 825f8e28 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f4ea4c7c 8055d0fe 825f8fdc 825f8e28 81e2abe0 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f4ea4c90 8055a3bf 822b4e80 825f8e28 81e2abe0 nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f4ea4d38 8052d571 0000006c 00000000 00000000 nt!NtReadFile+0x559
f4ea4d38 7ffe0304 0000006c 00000000 00000000 nt!KiSystemService+0xc4 (FPO: [0,0] TrapFrame @ f4ea4d64)
01e1eb48 00000000 00000000 00000000 00000000 SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])

-------------------------------------------------------

kd> !irp 825f8e28 1
Irp is active with 10 stacks 8 is current (= 0x825f8f94)
No Mdl Thread 81e36020: Irp stack trace.
Flags = 40000900
ThreadListEntry.Flink = 81e36230
ThreadListEntry.Blink = 81e36230
IoStatus.Status = 00000000
IoStatus.Information = 00000000
RequestorMode = 00000001
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = 01e1eb18
UserEvent = 00000000
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000
UserBuffer = 003ee370
&Tail.Overlay.DeviceQueueEntry = 825f8e68
Tail.Overlay.Thread = 81e36020
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = 825f8f94
Tail.Overlay.OriginalFileObject = 81e2abe0
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] 0 10 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
>[3, 0] 0 e0 82258020 81e2abe0 8063879c-825f8fb8 Success Error Cancel
\FileSystem\Ntfs nt!IovpInternalCompletionTrap
Args: 00001000 00000000 1fe3329d 00000000
[3, 0] 0 e0 822d4dd0 81e2abe0 8063879c-825f8fdc Success Error Cancel
\FileSystem\sr nt!IovpInternalCompletionTrap
Args: 00001000 00000000 1fe3329d 00000000
[3, 0] 0 0 822b4e80 81e2abe0 00000000-00000000
\FileSystem\Sfilter
Args: 00001000 00000000 1fe3329d 00000000

-------------------------------------------------------

Worker thread ZwReadFile which doesn’t return:

-------------------------------------------------------

kd> !thread 82299DA8
THREAD 82299da8 Cid 0004.006c Teb: 00000000 Win32Thread: 00000000 WAIT: (Executive) KernelMode Non-Alertable
f8926608 NotificationEvent
IRP List:
82576e28: (0006,01d8) Flags: 40000900 Mdl: 00000000
Not impersonating
DeviceMap e1004498
Owning Process 822ce838
Wait Start TickCount 8618 Elapsed Ticks: 198
Context Switch Count 201
UserTime 00:00:00.0000
KernelTime 00:00:04.0906
Start Address Sfilter!SFilterWorkerThreadMaster (0xbaf5f6a0)
Stack Init f8927000 Current f892658c Base f8927000 Limit f8924000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 0
ChildEBP RetAddr Args to Child
f89265a4 804fafe4 82299e18 82299da8 804f50ec nt!KiSwapContext+0x2e (FPO: [EBP 0xf89265d8] [0,0,4])
f89265b0 804f50ec 00000000 e262c590 81db96a0 nt!KiSwapThread+0x44 (FPO: [0,0,2])
f89265d8 baefb2d9 00000000 00000000 00000000 nt!KeWaitForSingleObject+0x1c0 (FPO: [Non-Fpo])
f8926618 baec59a1 e262c590 baedb358 00000000 Ntfs!NtfsWaitForIoAtEof+0x48 (FPO: [Non-Fpo])
f89266e8 baec016f 81db96a0 82576e28 00000001 Ntfs!NtfsCommonRead+0xca6
f8926788 804ea221 82258020 82576e28 806ad1a8 Ntfs!NtfsFsdRead+0x22d
f8926798 8062c190 822d4dd0 8226b2d0 82576e00 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f89267bc baf6d42d 804ea221 822d4dd0 82576e28 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f89267c0 804ea221 822d4dd0 82576e28 806ad1a8 sr!SrPassThrough+0x2f (FPO: [2,0,0])
f89267d0 8062c190 822b4e80 82269040 82576e00 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f89267f4 baf5ba59 baf5b5ae 00000001 00000001 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f8926a74 804ea221 822b4e80 82576e28 806ad1a8 Sfilter!SfRead+0x379 (CONV: stdcall) [c:\code\warbird\driver\sfilter.c @ 1867]
f8926a84 8062c190 82299fb8 806ad190 82576e28 nt!IopfCallDriver+0x31 (FPO: [0,0,1])
f8926aa8 8055d0fe 82576fdc 82576e28 81e5c0e8 nt!IovCallDriver+0x9e (FPO: [Non-Fpo])
f8926abc 8055a3bf 822b4e80 82576e28 81e5c0e8 nt!IopSynchronousServiceTail+0x5e (FPO: [Non-Fpo])
f8926b64 8052d571 800004bc 00000000 00000000 nt!NtReadFile+0x559
f8926b64 804f926d 800004bc 00000000 00000000 nt!KiSystemService+0xc4 (FPO: [0,0] TrapFrame @ f8926b90)
f8926c00 baf607d4 800004bc 00000000 00000000 nt!ZwReadFile+0x11 (FPO: [9,0,0])
f8926d00 baf5f891 bac32000 81e4c550 000004b8 Sfilter!PreloadDataFiles+0x534 (CONV: stdcall) [c:\code\warbird\driver\sfilterwthread.c @ 874]
f8926dac 805aa2b6 baf630a4 00000000 00000000 Sfilter!SFilterWorkerThreadMaster+0x1f1 (CONV: stdcall) [c:\code\warbird\driver\sfilterwthread.c @ 264]
f8926ddc 805319c6 baf5f6a0 baf630a4 00000000 nt!PspSystemThreadStartup+0x34 (FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16

-------------------------------------------------------

kd> !irp 82576e28 1
Irp is active with 10 stacks 8 is current (= 0x82576f94)
No Mdl Thread 82299da8: Irp stack trace.
Flags = 40000900
ThreadListEntry.Flink = 82299fb8
ThreadListEntry.Blink = 82299fb8
IoStatus.Status = 00000000
IoStatus.Information = 00000000
RequestorMode = 00000000
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = f8926c58
UserEvent = 00000000
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000
UserBuffer = bac32000
&Tail.Overlay.DeviceQueueEntry = 82576e68
Tail.Overlay.Thread = 82299da8
Tail.Overlay.AuxiliaryBuffer = 00000000
Tail.Overlay.ListEntry.Flink = 00000000
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = 82576f94
Tail.Overlay.OriginalFileObject = 81e5c0e8
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] 0 10 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
>[3, 0] 0 e0 82258020 81e5c0e8 8063879c-82576fb8 Success Error Cancel
\FileSystem\Ntfs nt!IovpInternalCompletionTrap
Args: 00000100 00000000 00000000 00000000
[3, 0] 0 e0 822d4dd0 81e5c0e8 8063879c-82576fdc Success Error Cancel
\FileSystem\sr nt!IovpInternalCompletionTrap
Args: 00000100 00000000 00000000 00000000
[3, 0] 0 0 822b4e80 81e5c0e8 00000000-00000000
\FileSystem\Sfilter
Args: 00000100 00000000 00000000 00000000

-------------------------------------------------------

Deadlock with PagingIoResource

Resource @ 0x81e0e2f8 Shared 2 owning threads Threads: 81db2da8-01<*> 82299da8-01<*> KD: Scanning for held locks.

Resource @ 0x81e0e2f8 Shared 2 owning threads
Threads: 81db2da8-01<> 82299da8-01<>
KD: Scanning for held locks.