Hanging at Calling FltClose at Pended Post Read Operation

OSR_Community_User · November 7, 2009, 8:09pm

Hello! All,

I am writing a minifilter driver and my driver will pend post read operation (only for paging IO). The worker thread, which handles the pened operation, opens the same file (using FltCreateFile), reads some data out (using FltReadFile), and then closes the file (using FltClose). I am using notepad to test my driver. When I open an exisiting file, type some data and save the file, the notepad hangs.

I ran some windbg commands to analyze the hanging. The result is at the end of the message.

My worker thread (86250c28) is stuck at FltClose call and this calls seems to waiting for the resource held by notepad (86089da8). While, notepad is waiting MM to page in some data. Then, the deadlock happens because the worker thread is stuck and can’t handle any pended post read operation.

I wonder what the resource that notepad is holding but needed by my worker thread’s FltClose. In another way, what is the root cause of the deadlock? It seems to me that FltClose shouldn’t be affected by NtWrite. How to fix this deadlock?

I have been stuck by this pending post read matter for several days. Please DO help!

Thank you very much beforehead.

=========================================================================
kd> !stacks
Proc.Thread .Thread Ticks ThreadState Blocker

Max cache size is : 1048576 bytes (0x400 KB)
Total memory in cache : 0 bytes (0 KB)
Number of regions cached: 0
0 full reads broken into 0 partial reads
counts: 0 cached/0 uncached, 0.00% cached
bytes : 0 cached/0 uncached, 0.00% cached
** Prototype PTEs are implicitly decoded
[863b5660 System]
4.000014 863b4b30 00000e6 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
4.000020 863b43c8 000002b Blocked Ntfs!NtfsAcquireExclusiveVcb+0x23
4.00007c 86250c28 000007f Blocked Ntfs!NtfsCommonCleanup+0x18e
4.000670 860b2828 000001f Blocked vmmemctl+0x3cd
4.0003a4 86012020 00001ac Blocked HTTP!UlpScavengerThread+0x5d

[862dd280 smss.exe]

[8618a430 csrss.exe]
298.0002a8 8618cae8 0000234 Blocked nt!KiFastCallEntry+0xf8
298.0002d0 862cc890 0000002 Blocked win32k!xxxMsgWaitForMultipleObjects+0xb0

[86253c28 winlogon.exe]
2b0.0004b8 860e4a18 0000026 Blocked Ntfs!NtfsAcquireSharedVcb+0x23

[861a8388 services.exe]
2e4.000330 86159338 00000aa Blocked nt!KiFastCallEntry+0xf8
2e4.0006d0 860b6c70 0000135 Blocked nt!KiFastCallEntry+0xf8
2e4.0000e4 86071320 0000135 Blocked nt!KiFastCallEntry+0xf8
2e4.000f6c 86048020 0000135 Blocked nt!KiFastCallEntry+0xf8

[8625f020 lsass.exe]
2f0.00033c 8619c620 0000457 Blocked nt!KiFastCallEntry+0xf8
2f0.000790 8607c4e8 000001f Blocked nt!KiFastCallEntry+0xf8
2f0.000868 86042b30 0000457 Blocked nt!KiFastCallEntry+0xf8

[861a5b28 svchost.exe]

[862ca3e0 svchost.exe]
400.000420 861766e0 00000e9 Blocked nt!KiFastCallEntry+0xf8
400.00085c 86046260 0000205 Blocked nt!KiFastCallEntry+0xf8

[860e7da0 svchost.exe]
480.00048c 860e7640 0000234 Blocked nt!KiFastCallEntry+0xf8
480.0005b0 860ceda8 0000099 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
480.0005e0 861a13c8 000003e Blocked Ntfs!NtfsAcquireSharedVcb+0x23
480.000658 860b7b30 00000f2 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
480.000160 86058800 0000457 Blocked nt!KiFastCallEntry+0xf8
480.000f48 8600a3e0 0000194 Blocked nt!KiFastCallEntry+0xf8
480.000f54 85fe6020 0000019 Blocked nt!KiFastCallEntry+0xf8
480.000840 8617ab80 000000f Blocked Ntfs!NtfsAcquireSharedVcb+0x23
480.000878 862061c8 0000234 Blocked nt!KiFastCallEntry+0xf8
480.000894 860d0020 0000234 Blocked nt!KiFastCallEntry+0xf8

[86251020 svchost.exe]

[862ca970 svchost.exe]
510.000880 8603e938 000024f Blocked nt!KiFastCallEntry+0xf8

[860ce510 spoolsv.exe]
5d0.000474 8620cda8 0000038 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
5d0.000728 86059b30 000001f Blocked nt!KiFastCallEntry+0xf8

[860afa20 sqlservr.exe]
6a0.000770 860819f0 00000be Blocked nt!KiFastCallEntry+0xf8
6a0.0000ac 8607d7d8 00000be Blocked nt!KiFastCallEntry+0xf8

[8617e4f8 VMwareService.e]
708.00072c 86085020 00000f6 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
708.00073c 86082da8 00000eb Blocked Ntfs!NtfsAcquireSharedVcb+0x23

[86074bc0 alg.exe]

[860bf400 wuauclt.exe]
36c.0002f4 861864f8 0000070 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
36c.000468 86215c58 0000124 Blocked nt!KiFastCallEntry+0xf8
36c.0004b0 86210330 00002dd Blocked nt!KiFastCallEntry+0xf8
36c.0004bc 861fc020 0000019 Blocked nt!KiFastCallEntry+0xf8

[8606a020 wscntfy.exe]

[86217a60 explorer.exe]
628.000638 861fd8c8 00000da Blocked Ntfs!NtfsAcquireSharedVcb+0x23
628.000598 86017020 00000f1 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
628.0001d0 8603ebb0 0000385 Blocked nt!KiFastCallEntry+0xf8
628.0001e0 860387a0 000007e Blocked Ntfs!NtfsAcquireSharedVcb+0x23

[86040da0 VMwareTray.exe]

[86047da0 VMwareUser.exe]
84.000088 86252478 00000e1 Blocked Ntfs!NtfsAcquireSharedVcb+0x23

[8603dda0 GrooveMonitor.e]
6b0.0000e8 86040638 0000026 Blocked Ntfs!NtfsAcquireSharedVcb+0x23

[8603e488 jusched.exe]
2e8.000864 86009308 0000003 Blocked Ntfs!NtfsAcquireSharedVcb+0x23

[86044560 reader_sl.exe]
f8.000148 86090500 0000016 Blocked Ntfs!NtfsAcquireSharedVcb+0x23

[86090780 ctfmon.exe]

[8600ada0 cmd.exe]

[86027820 notepad.exe]
6e0.000190 86089da8 000749f Blocked nt!MiWaitForInPageComplete+0x1a

Threads Processed: 335

Max cache size is : 1048576 bytes (0x400 KB)
Total memory in cache : 0 bytes (0 KB)
Number of regions cached: 0
0 full reads broken into 0 partial reads
counts: 0 cached/0 uncached, 0.00% cached
bytes : 0 cached/0 uncached, 0.00% cached
** Transition PTEs are implicitly decoded
** Prototype PTEs are implicitly decoded

kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****
KD: Scanning for held locks…

Resource @ Ntfs!NtfsData (0xbad95190) Shared 1 owning threads
Threads: 863b4b30-01<*>
KD: Scanning for held locks.

Resource @ 0x86378514 Shared 1 owning threads
Contention Count = 97
NumberOfSharedWaiters = 17
NumberOfExclusiveWaiters = 1
Threads: 86250c28-01<*> 86017020-01 86252478-01 860387a0-01
86082da8-01 86085020-01 860b7b30-01 861fd8c8-01
8617ab80-01 863b4b30-01 860e4a18-01 860ceda8-01
86040638-01 86009308-01 861864f8-01 86090500-01
8620cda8-01 861a13c8-01
Threads Waiting On Exclusive Access:
863b43c8

KD: Scanning for held locks…

Resource @ 0x85fed408 Shared 1 owning threads
Contention Count = 1
NumberOfExclusiveWaiters = 1
Threads: 86089da8-01<*>
Threads Waiting On Exclusive Access:
86250c28

KD: Scanning for held locks…

Resource @ 0x86181dd0 Shared 1 owning threads
Threads: 863b48bb-01<*> *** Actual Thread 863b48b8
KD: Scanning for held locks.
2614 total locks, 4 locks currently held

kd> !thread 86089da8
THREAD 86089da8 Cid 06e0.0190 Teb: 7ffde000 Win32Thread: e1a1d008 WAIT: (WrPageIn) KernelMode Non-Alertable
86378dc8 NotificationEvent
IRP List:
86c80e48: (0006,01b4) Flags: 40000a00 Mdl: 00000000
Not impersonating
DeviceMap e1cec6a8
Owning Process 0 Image:
Attached Process 86027820 Image: notepad.exe
Wait Start TickCount 15885 Ticks: 29855 (0:00:07:46.484)
Context Switch Count 2082 LargeStack
UserTime 00:00:00.078
KernelTime 00:00:03.015
Win32 Start Address 0x0100739d
Start Address 0x7c8106f5
Stack Init f5674000 Current f5673648 Base f5674000 Limit f566f000 Call 0
Priority 14 BasePriority 8 PriorityDecrement 5 DecrementCount 16
ChildEBP RetAddr Args to Child
f5673660 80500ce6 86089e18 86089da8 804f9d72 nt!KiSwapContext+0x2e (FPO: [Uses EBP] [0,0,4])
f567366c 804f9d72 86378dc8 86378dc8 00000000 nt!KiSwapThread+0x46 (FPO: [0,0,0])
f5673694 805128d4 00000000 00000009 00000000 nt!KeWaitForSingleObject+0x1c2 (FPO: [5,5,4])
f56736c4 805135a7 812ed148 e110f010 e0f45000 nt!MiWaitForInPageComplete+0x1a (FPO: [6,2,4])
f5673744 8051cb2c e110f010 e0f45000 c0707a28 nt!MiDispatchFault+0x2b5 (FPO: [6,21,4])
f56737a8 80517c88 00000000 e0f45000 00000000 nt!MmAccessFault+0x7b4 (FPO: [4,14,4])
f5673804 804e2dd8 e0f45000 00000000 86216870 nt!MmCheckCachedPageState+0x56c (FPO: [2,14,4])
f5673888 804e0b12 86216870 000bb0a8 f56738cc nt!CcMapAndCopy+0x210 (FPO: [Non-Fpo])
f5673914 bad79f83 860ce3c0 f5673ae0 000051a0 nt!CcCopyWrite+0x28e (FPO: [Non-Fpo])
f5673b04 bad76c18 860e3b10 86c80e48 86378020 Ntfs!NtfsCommonWrite+0x1d21 (FPO: [Non-Fpo])
f5673b68 804ee129 86378020 86c80e48 806d22e8 Ntfs!NtfsFsdWrite+0xf3 (FPO: [Non-Fpo])
f5673b78 8064d6a8 86c80e48 863b9bf0 86379a08 nt!IopfCallDriver+0x31 (FPO: [0,0,0])
f5673b9c bae193ca 86379950 86170800 f5673be0 nt!IovCallDriver+0xa0 (FPO: [0,4,0])
f5673bac 804ee129 86379950 e20dfcf8 806d22e8 sr!SrWrite+0xaa (FPO: [2,0,4])
f5673bbc 8064d6a8 00000000 86c80e48 86170898 nt!IopfCallDriver+0x31 (FPO: [0,0,0])
f5673be0 bae2ee9b 85feb6b8 86c80e48 86010660 nt!IovCallDriver+0xa0 (FPO: [0,4,0])
f5673c04 bae2f06b f5673c24 85feb6b8 00000000 fltMgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x20b (FPO: [3,4,4])
f5673c3c 804ee129 85feb6b8 86c80e48 806d22e8 fltMgr!FltpDispatch+0x11f (FPO: [2,6,0])
f5673c4c 8064d6a8 860ce3c0 806d22d0 86c80e48 nt!IopfCallDriver+0x31 (FPO: [0,0,0])
f5673c70 80574dde 86c80fd8 00000000 86c80e48 nt!IovCallDriver+0xa0 (FPO: [0,4,0])
f5673c84 805728ca 85feb6b8 86c80e48 860ce3c0 nt!IopSynchronousServiceTail+0x70 (FPO: [7,0,4])
f5673d38 8053d648 000000c0 00000000 00000000 nt!NtWriteFile+0x602 (FPO: [Non-Fpo])
f5673d38 7c90e4f4 000000c0 00000000 00000000 nt!KiFastCallEntry+0xf8 (FPO: [0,0] TrapFrame @ f5673d64)
0007fac8 00000000 00000000 00000000 00000000 ntdll!KiFastSystemCallRet (FPO: [0,0,0])

kd> !thread 86250c28
THREAD 86250c28 Cid 0004.007c Teb: 00000000 Win32Thread: 00000000 WAIT: (Executive) KernelMode Non-Alertable
86210cd0 SynchronizationEvent
86250d18 NotificationTimer
IRP List:
869fce48: (0006,01b4) Flags: 40000404 Mdl: 00000000
87868f68: (0006,0094) Flags: 40000000 Mdl: 00000000
Not impersonating
DeviceMap e1004440
Owning Process 0 Image:
Attached Process 863b5660 Image: System
Wait Start TickCount 45613 Ticks: 127 (0:00:00:01.984)
Context Switch Count 4161
UserTime 00:00:00.000
KernelTime 00:00:02.093
Start Address nt!ExpWorkerThread (0x80534b12)
Stack Init f7953000 Current f79525dc Base f7953000 Limit f7950000 Call 0
Priority 14 BasePriority 12 PriorityDecrement 2 DecrementCount 16
ChildEBP RetAddr Args to Child
f79525f4 80500ce6 86250c98 86250c28 804f9d72 nt!KiSwapContext+0x2e (FPO: [Uses EBP] [0,0,4])
f7952600 804f9d72 00000000 85fed408 86250c28 nt!KiSwapThread+0x46 (FPO: [0,0,0])
f7952628 80532398 00000000 00000000 00000000 nt!KeWaitForSingleObject+0x1c2 (FPO: [5,5,4])
f7952664 805327f7 e10c1008 f795289c f7952880 nt!ExpWaitForResource+0xd2 (FPO: [0,5,0])
f7952674 bad9a851 85fed408 00000001 00000000 nt!ExAcquireResourceExclusiveLite+0x6f (FPO: [2,0,0])
f7952880 bad9ad4d f795289c 869fce48 86378020 Ntfs!NtfsCommonCleanup+0x18e (FPO: [Non-Fpo])
f79529f8 804ee129 86378020 869fce48 806d22e8 Ntfs!NtfsFsdCleanup+0xcf (FPO: [Non-Fpo])
f7952a08 8064d6a8 86379a08 863b9bf0 869fce48 nt!IopfCallDriver+0x31 (FPO: [0,0,0])
f7952a2c bae1dbbf 86379950 86010600 f7952a70 nt!IovCallDriver+0xa0 (FPO: [0,4,0])
f7952a3c 804ee129 86379950 869fce48 806d22e8 sr!SrCleanup+0xb3 (FPO: [2,0,4])
f7952a4c 8064d6a8 85feb6b8 869fce48 86010660 nt!IopfCallDriver+0x31 (FPO: [0,0,0])
f7952a70 bae2f09e 869fce00 863ba528 85feb6b8 nt!IovCallDriver+0xa0 (FPO: [0,4,0])
f7952a9c 804ee129 85feb6b8 869fce48 806d22e8 fltMgr!FltpDispatch+0x152 (FPO: [2,6,0])
f7952aac 8064d6a8 860bc8a8 869fce48 869fce58 nt!IopfCallDriver+0x31 (FPO: [0,0,0])
f7952ad0 80578dbc 860bc890 863a14b8 860bc8a8 nt!IovCallDriver+0xa0 (FPO: [0,4,0])
f7952b04 805b21e0 863b5660 85feb6b8 00120089 nt!IopCloseFile+0x27c (FPO: [5,8,0])
f7952b34 805b1b0d 863b5660 00000001 863a14b8 nt!ObpDecrementHandleCount+0xd4 (FPO: [4,2,4])
f7952b5c 805b1bab e1000cc0 860bc8a8 00000878 nt!ObpCloseHandleTableEntry+0x14d (FPO: [6,1,0])
f7952ba4 805b1ce3 00000878 00000000 00000000 nt!ObpCloseHandle+0x87 (FPO: [3,7,4])
f7952bb8 8053d648 80000878 f7952cac 804fdfad nt!NtClose+0x1d (FPO: [1,0,0])
f7952bb8 804fdfad 80000878 f7952cac 804fdfad nt!KiFastCallEntry+0xf8 (FPO: [0,0] TrapFrame @ f7952bc4)
f7952c34 f60631d3 80000878 01935e45 861708f4 nt!ZwClose+0x11 (FPO: [1,0,0])
f7952cac f6063493 861708f4 f56731dc 00001000 myMini!MyMiniReadAtPostRead+0x331
f7952d00 f606211d 861708f4 f56731dc 8620d308 myMini!MyMiniPendedPostRead+0x105
f7952d20 f6060f17 86157ba0 861708f4 01935fb5 myMini!MyMiniHandlePendedIO+0x8f
f7952d5c bae42dc6 8603d990 862041a8 862041a8 myMini!MyMiniPendingIOWorkItemRoutine+0x7d
f7952d74 80534c12 8603d990 00000000 86250c28 fltMgr!FltpProcessGenericWorkItem+0x14 (FPO: [1,0,4])
f7952dac 805c61ec 8603d990 00000000 00000000 nt!ExpWorkerThread+0x100 (FPO: [1,8,0])
f7952ddc 80541de2 80534b12 80000001 00000000 nt!PspSystemThreadStartup+0x34 (FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16

========================================================================

David_J_Craig · November 7, 2009, 8:25pm

Did you bother to read the IFS FAQ on osronline.com? You design will not
work. You may NOT pend paging I/O. You may not switch context/thread for
paging I/O. Forget about it. As has been mentioned in this newsgroup many
times there are cases where you can get a technique to work with FAT but it
won’t work with NTFS. Toss in CDFS and remote filesystems and there are far
too many variations of how each uses the Memory Manager and Cache Manager.
You could write your own filesystem that would permit this type of activity,
but it would be interesting getting it stable on all the variations of
Windows.

If you have OS source you might get it to work in some cases by using
undocumented internals, but this should not be done by anyone other than
Microsoft. I suspect they won’t do it either since it could limit the
ability to improve their own filesystems.

wrote in message news:xxxxx@ntfsd…
> Hello! All,
>
> I am writing a minifilter driver and my driver will pend post read
> operation (only for paging IO). The worker thread, which handles the pened
> operation, opens the same file (using FltCreateFile), reads some data out
> (using FltReadFile), and then closes the file (using FltClose). I am using
> notepad to test my driver. When I open an exisiting file, type some data
> and save the file, the notepad hangs.
>
> I ran some windbg commands to analyze the hanging. The result is at the
> end of the message.
>
> My worker thread (86250c28) is stuck at FltClose call and this calls seems
> to waiting for the resource held by notepad (86089da8). While, notepad is
> waiting MM to page in some data. Then, the deadlock happens because the
> worker thread is stuck and can’t handle any pended post read operation.
>
> I wonder what the resource that notepad is holding but needed by my worker
> thread’s FltClose. In another way, what is the root cause of the deadlock?
> It seems to me that FltClose shouldn’t be affected by NtWrite. How to fix
> this deadlock?
>
> I have been stuck by this pending post read matter for several days.
> Please DO help!
>
> Thank you very much beforehead.
>
> =========================================================================
> kd> !stacks
> Proc.Thread .Thread Ticks ThreadState Blocker
>
> Max cache size is : 1048576 bytes (0x400 KB)
> Total memory in cache : 0 bytes (0 KB)
> Number of regions cached: 0
> 0 full reads broken into 0 partial reads
> counts: 0 cached/0 uncached, 0.00% cached
> bytes : 0 cached/0 uncached, 0.00% cached
> Prototype PTEs are implicitly decoded
> [863b5660 System]
> 4.000014 863b4b30 00000e6 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
> 4.000020 863b43c8 000002b Blocked Ntfs!NtfsAcquireExclusiveVcb+0x23
> 4.00007c 86250c28 000007f Blocked Ntfs!NtfsCommonCleanup+0x18e
> 4.000670 860b2828 000001f Blocked vmmemctl+0x3cd
> 4.0003a4 86012020 00001ac Blocked HTTP!UlpScavengerThread+0x5d
>
> [862dd280 smss.exe]
>
> [8618a430 csrss.exe]
> 298.0002a8 8618cae8 0000234 Blocked nt!KiFastCallEntry+0xf8
> 298.0002d0 862cc890 0000002 Blocked
> win32k!xxxMsgWaitForMultipleObjects+0xb0
>
> [86253c28 winlogon.exe]
> 2b0.0004b8 860e4a18 0000026 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
>
> [861a8388 services.exe]
> 2e4.000330 86159338 00000aa Blocked nt!KiFastCallEntry+0xf8
> 2e4.0006d0 860b6c70 0000135 Blocked nt!KiFastCallEntry+0xf8
> 2e4.0000e4 86071320 0000135 Blocked nt!KiFastCallEntry+0xf8
> 2e4.000f6c 86048020 0000135 Blocked nt!KiFastCallEntry+0xf8
>
> [8625f020 lsass.exe]
> 2f0.00033c 8619c620 0000457 Blocked nt!KiFastCallEntry+0xf8
> 2f0.000790 8607c4e8 000001f Blocked nt!KiFastCallEntry+0xf8
> 2f0.000868 86042b30 0000457 Blocked nt!KiFastCallEntry+0xf8
>
> [861a5b28 svchost.exe]
>
> [862ca3e0 svchost.exe]
> 400.000420 861766e0 00000e9 Blocked nt!KiFastCallEntry+0xf8
> 400.00085c 86046260 0000205 Blocked nt!KiFastCallEntry+0xf8
>
> [860e7da0 svchost.exe]
> 480.00048c 860e7640 0000234 Blocked nt!KiFastCallEntry+0xf8
> 480.0005b0 860ceda8 0000099 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
> 480.0005e0 861a13c8 000003e Blocked Ntfs!NtfsAcquireSharedVcb+0x23
> 480.000658 860b7b30 00000f2 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
> 480.000160 86058800 0000457 Blocked nt!KiFastCallEntry+0xf8
> 480.000f48 8600a3e0 0000194 Blocked nt!KiFastCallEntry+0xf8
> 480.000f54 85fe6020 0000019 Blocked nt!KiFastCallEntry+0xf8
> 480.000840 8617ab80 000000f Blocked Ntfs!NtfsAcquireSharedVcb+0x23
> 480.000878 862061c8 0000234 Blocked nt!KiFastCallEntry+0xf8
> 480.000894 860d0020 0000234 Blocked nt!KiFastCallEntry+0xf8
>
> [86251020 svchost.exe]
>
> [862ca970 svchost.exe]
> 510.000880 8603e938 000024f Blocked nt!KiFastCallEntry+0xf8
>
> [860ce510 spoolsv.exe]
> 5d0.000474 8620cda8 0000038 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
> 5d0.000728 86059b30 000001f Blocked nt!KiFastCallEntry+0xf8
>
> [860afa20 sqlservr.exe]
> 6a0.000770 860819f0 00000be Blocked nt!KiFastCallEntry+0xf8
> 6a0.0000ac 8607d7d8 00000be Blocked nt!KiFastCallEntry+0xf8
>
> [8617e4f8 VMwareService.e]
> 708.00072c 86085020 00000f6 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
> 708.00073c 86082da8 00000eb Blocked Ntfs!NtfsAcquireSharedVcb+0x23
>
> [86074bc0 alg.exe]
>
> [860bf400 wuauclt.exe]
> 36c.0002f4 861864f8 0000070 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
> 36c.000468 86215c58 0000124 Blocked nt!KiFastCallEntry+0xf8
> 36c.0004b0 86210330 00002dd Blocked nt!KiFastCallEntry+0xf8
> 36c.0004bc 861fc020 0000019 Blocked nt!KiFastCallEntry+0xf8
>
> [8606a020 wscntfy.exe]
>
> [86217a60 explorer.exe]
> 628.000638 861fd8c8 00000da Blocked Ntfs!NtfsAcquireSharedVcb+0x23
> 628.000598 86017020 00000f1 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
> 628.0001d0 8603ebb0 0000385 Blocked nt!KiFastCallEntry+0xf8
> 628.0001e0 860387a0 000007e Blocked Ntfs!NtfsAcquireSharedVcb+0x23
>
> [86040da0 VMwareTray.exe]
>
> [86047da0 VMwareUser.exe]
> 84.000088 86252478 00000e1 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
>
> [8603dda0 GrooveMonitor.e]
> 6b0.0000e8 86040638 0000026 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
>
> [8603e488 jusched.exe]
> 2e8.000864 86009308 0000003 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
>
> [86044560 reader_sl.exe]
> f8.000148 86090500 0000016 Blocked Ntfs!NtfsAcquireSharedVcb+0x23
>
> [86090780 ctfmon.exe]
>
> [8600ada0 cmd.exe]
>
> [86027820 notepad.exe]
> 6e0.000190 86089da8 000749f Blocked nt!MiWaitForInPageComplete+0x1a
>
>
> Threads Processed: 335
>
> Max cache size is : 1048576 bytes (0x400 KB)
> Total memory in cache : 0 bytes (0 KB)
> Number of regions cached: 0
> 0 full reads broken into 0 partial reads
> counts: 0 cached/0 uncached, 0.00% cached
> bytes : 0 cached/0 uncached, 0.00% cached
> Transition PTEs are implicitly decoded
> Prototype PTEs are implicitly decoded
>
>
> kd> !locks
>** DUMP OF ALL RESOURCE OBJECTS
> KD: Scanning for held locks…
>
> Resource @ Ntfs!NtfsData (0xbad95190) Shared 1 owning threads
> Threads: 863b4b30-01<>
> KD: Scanning for held locks.
>
> Resource @ 0x86378514 Shared 1 owning threads
> Contention Count = 97
> NumberOfSharedWaiters = 17
> NumberOfExclusiveWaiters = 1
> Threads: 86250c28-01<> 86017020-01 86252478-01 860387a0-01
> 86082da8-01 86085020-01 860b7b30-01 861fd8c8-01
> 8617ab80-01 863b4b30-01 860e4a18-01 860ceda8-01
> 86040638-01 86009308-01 861864f8-01 86090500-01
> 8620cda8-01 861a13c8-01
> Threads Waiting On Exclusive Access:
> 863b43c8
>
> KD: Scanning for held
> locks…
>
> Resource @ 0x85fed408 Shared 1 owning threads
> Contention Count = 1
> NumberOfExclusiveWaiters = 1
> Threads: 86089da8-01<>
> Threads Waiting On Exclusive Access:
> 86250c28
>
> KD: Scanning for held locks…
>
> Resource @ 0x86181dd0 Shared 1 owning threads
> Threads: 863b48bb-01<>*** Actual Thread 863b48b8
> KD: Scanning for held locks.
> 2614 total locks, 4 locks currently held
>
> kd> !thread 86089da8
> THREAD 86089da8 Cid 06e0.0190 Teb: 7ffde000 Win32Thread: e1a1d008 WAIT:
> (WrPageIn) KernelMode Non-Alertable
> 86378dc8 NotificationEvent
> IRP List:
> 86c80e48: (0006,01b4) Flags: 40000a00 Mdl: 00000000
> Not impersonating
> DeviceMap e1cec6a8
> Owning Process 0 Image:
> Attached Process 86027820 Image: notepad.exe
> Wait Start TickCount 15885 Ticks: 29855 (0:00:07:46.484)
> Context Switch Count 2082 LargeStack
> UserTime 00:00:00.078
> KernelTime 00:00:03.015
> Win32 Start Address 0x0100739d
> Start Address 0x7c8106f5
> Stack Init f5674000 Current f5673648 Base f5674000 Limit f566f000 Call 0
> Priority 14 BasePriority 8 PriorityDecrement 5 DecrementCount 16
> ChildEBP RetAddr Args to Child
> f5673660 80500ce6 86089e18 86089da8 804f9d72 nt!KiSwapContext+0x2e (FPO:
> [Uses EBP] [0,0,4])
> f567366c 804f9d72 86378dc8 86378dc8 00000000 nt!KiSwapThread+0x46 (FPO:
> [0,0,0])
> f5673694 805128d4 00000000 00000009 00000000
> nt!KeWaitForSingleObject+0x1c2 (FPO: [5,5,4])
> f56736c4 805135a7 812ed148 e110f010 e0f45000
> nt!MiWaitForInPageComplete+0x1a (FPO: [6,2,4])
> f5673744 8051cb2c e110f010 e0f45000 c0707a28 nt!MiDispatchFault+0x2b5
> (FPO: [6,21,4])
> f56737a8 80517c88 00000000 e0f45000 00000000 nt!MmAccessFault+0x7b4 (FPO:
> [4,14,4])
> f5673804 804e2dd8 e0f45000 00000000 86216870
> nt!MmCheckCachedPageState+0x56c (FPO: [2,14,4])
> f5673888 804e0b12 86216870 000bb0a8 f56738cc nt!CcMapAndCopy+0x210 (FPO:
> [Non-Fpo])
> f5673914 bad79f83 860ce3c0 f5673ae0 000051a0 nt!CcCopyWrite+0x28e (FPO:
> [Non-Fpo])
> f5673b04 bad76c18 860e3b10 86c80e48 86378020 Ntfs!NtfsCommonWrite+0x1d21
> (FPO: [Non-Fpo])
> f5673b68 804ee129 86378020 86c80e48 806d22e8 Ntfs!NtfsFsdWrite+0xf3 (FPO:
> [Non-Fpo])
> f5673b78 8064d6a8 86c80e48 863b9bf0 86379a08 nt!IopfCallDriver+0x31 (FPO:
> [0,0,0])
> f5673b9c bae193ca 86379950 86170800 f5673be0 nt!IovCallDriver+0xa0 (FPO:
> [0,4,0])
> f5673bac 804ee129 86379950 e20dfcf8 806d22e8 sr!SrWrite+0xaa (FPO:
> [2,0,4])
> f5673bbc 8064d6a8 00000000 86c80e48 86170898 nt!IopfCallDriver+0x31 (FPO:
> [0,0,0])
> f5673be0 bae2ee9b 85feb6b8 86c80e48 86010660 nt!IovCallDriver+0xa0 (FPO:
> [0,4,0])
> f5673c04 bae2f06b f5673c24 85feb6b8 00000000
> fltMgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x20b (FPO: [3,4,4])
> f5673c3c 804ee129 85feb6b8 86c80e48 806d22e8 fltMgr!FltpDispatch+0x11f
> (FPO: [2,6,0])
> f5673c4c 8064d6a8 860ce3c0 806d22d0 86c80e48 nt!IopfCallDriver+0x31 (FPO:
> [0,0,0])
> f5673c70 80574dde 86c80fd8 00000000 86c80e48 nt!IovCallDriver+0xa0 (FPO:
> [0,4,0])
> f5673c84 805728ca 85feb6b8 86c80e48 860ce3c0
> nt!IopSynchronousServiceTail+0x70 (FPO: [7,0,4])
> f5673d38 8053d648 000000c0 00000000 00000000 nt!NtWriteFile+0x602 (FPO:
> [Non-Fpo])
> f5673d38 7c90e4f4 000000c0 00000000 00000000 nt!KiFastCallEntry+0xf8 (FPO:
> [0,0] TrapFrame @ f5673d64)
> 0007fac8 00000000 00000000 00000000 00000000 ntdll!KiFastSystemCallRet
> (FPO: [0,0,0])
>
> kd> !thread 86250c28
> THREAD 86250c28 Cid 0004.007c Teb: 00000000 Win32Thread: 00000000 WAIT:
> (Executive) KernelMode Non-Alertable
> 86210cd0 SynchronizationEvent
> 86250d18 NotificationTimer
> IRP List:
> 869fce48: (0006,01b4) Flags: 40000404 Mdl: 00000000
> 87868f68: (0006,0094) Flags: 40000000 Mdl: 00000000
> Not impersonating
> DeviceMap e1004440
> Owning Process 0 Image:
> Attached Process 863b5660 Image: System
> Wait Start TickCount 45613 Ticks: 127 (0:00:00:01.984)
> Context Switch Count 4161
> UserTime 00:00:00.000
> KernelTime 00:00:02.093
> Start Address nt!ExpWorkerThread (0x80534b12)
> Stack Init f7953000 Current f79525dc Base f7953000 Limit f7950000 Call 0
> Priority 14 BasePriority 12 PriorityDecrement 2 DecrementCount 16
> ChildEBP RetAddr Args to Child
> f79525f4 80500ce6 86250c98 86250c28 804f9d72 nt!KiSwapContext+0x2e (FPO:
> [Uses EBP] [0,0,4])
> f7952600 804f9d72 00000000 85fed408 86250c28 nt!KiSwapThread+0x46 (FPO:
> [0,0,0])
> f7952628 80532398 00000000 00000000 00000000
> nt!KeWaitForSingleObject+0x1c2 (FPO: [5,5,4])
> f7952664 805327f7 e10c1008 f795289c f7952880 nt!ExpWaitForResource+0xd2
> (FPO: [0,5,0])
> f7952674 bad9a851 85fed408 00000001 00000000
> nt!ExAcquireResourceExclusiveLite+0x6f (FPO: [2,0,0])
> f7952880 bad9ad4d f795289c 869fce48 86378020 Ntfs!NtfsCommonCleanup+0x18e
> (FPO: [Non-Fpo])
> f79529f8 804ee129 86378020 869fce48 806d22e8 Ntfs!NtfsFsdCleanup+0xcf
> (FPO: [Non-Fpo])
> f7952a08 8064d6a8 86379a08 863b9bf0 869fce48 nt!IopfCallDriver+0x31 (FPO:
> [0,0,0])
> f7952a2c bae1dbbf 86379950 86010600 f7952a70 nt!IovCallDriver+0xa0 (FPO:
> [0,4,0])
> f7952a3c 804ee129 86379950 869fce48 806d22e8 sr!SrCleanup+0xb3 (FPO:
> [2,0,4])
> f7952a4c 8064d6a8 85feb6b8 869fce48 86010660 nt!IopfCallDriver+0x31 (FPO:
> [0,0,0])
> f7952a70 bae2f09e 869fce00 863ba528 85feb6b8 nt!IovCallDriver+0xa0 (FPO:
> [0,4,0])
> f7952a9c 804ee129 85feb6b8 869fce48 806d22e8 fltMgr!FltpDispatch+0x152
> (FPO: [2,6,0])
> f7952aac 8064d6a8 860bc8a8 869fce48 869fce58 nt!IopfCallDriver+0x31 (FPO:
> [0,0,0])
> f7952ad0 80578dbc 860bc890 863a14b8 860bc8a8 nt!IovCallDriver+0xa0 (FPO:
> [0,4,0])
> f7952b04 805b21e0 863b5660 85feb6b8 00120089 nt!IopCloseFile+0x27c (FPO:
> [5,8,0])
> f7952b34 805b1b0d 863b5660 00000001 863a14b8
> nt!ObpDecrementHandleCount+0xd4 (FPO: [4,2,4])
> f7952b5c 805b1bab e1000cc0 860bc8a8 00000878
> nt!ObpCloseHandleTableEntry+0x14d (FPO: [6,1,0])
> f7952ba4 805b1ce3 00000878 00000000 00000000 nt!ObpCloseHandle+0x87 (FPO:
> [3,7,4])
> f7952bb8 8053d648 80000878 f7952cac 804fdfad nt!NtClose+0x1d (FPO:
> [1,0,0])
> f7952bb8 804fdfad 80000878 f7952cac 804fdfad nt!KiFastCallEntry+0xf8 (FPO:
> [0,0] TrapFrame @ f7952bc4)
> f7952c34 f60631d3 80000878 01935e45 861708f4 nt!ZwClose+0x11 (FPO:
> [1,0,0])
> f7952cac f6063493 861708f4 f56731dc 00001000
> myMini!MyMiniReadAtPostRead+0x331
> f7952d00 f606211d 861708f4 f56731dc 8620d308
> myMini!MyMiniPendedPostRead+0x105
> f7952d20 f6060f17 86157ba0 861708f4 01935fb5
> myMini!MyMiniHandlePendedIO+0x8f
> f7952d5c bae42dc6 8603d990 862041a8 862041a8
> myMini!MyMiniPendingIOWorkItemRoutine+0x7d
> f7952d74 80534c12 8603d990 00000000 86250c28
> fltMgr!FltpProcessGenericWorkItem+0x14 (FPO: [1,0,4])
> f7952dac 805c61ec 8603d990 00000000 00000000 nt!ExpWorkerThread+0x100
> (FPO: [1,8,0])
> f7952ddc 80541de2 80534b12 80000001 00000000
> nt!PspSystemThreadStartup+0x34 (FPO: [Non-Fpo])
> 00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16
>
> ========================================================================
>
>
>

OSR_Community_User · November 7, 2009, 9:22pm

My bad that I didn’t read FQA thouroughly. One time, I tried but stopped by the time I read Q10 (something like that). I usually use search on this site before I post my question to avoid duplicated questions.

I just search through FQA and it seems Q50 is the one which is matter with my question. Still diagest it and your answer. What do you mean “it could limit the ability to improve their own filesystems.”

I might let you think that I am stuborn. However, I still wonder what the resource that notepad is holding but needed by my worker thread’s FltClose.

Instead of just taking the fact that “may Not pend paging I/O”, I like to know more about the technicle reason. Any further explainations including a URL to the previous post are appreciated very much.

Heidi

David_J_Craig · November 7, 2009, 9:57pm

Take OSR’s File Systems class and you can ask Tony. The locking of the
various objects and the state of APCs during paging I/O do NOT permit the
rules to be violated with other than partial success. Remember that paging
I/O is used by the OS (mostly Memory Manager) to get needed pages of code
and data into memory when needed. If anything prevents this from happening
the OS will deadlock or the violation will be detected and a BSOD will
occur. Also remember that all file system I/O other than paging require the
use of APCs to get the system back into the correct context so that the data
can be delivered to the correct process. The threads you see in the IRPs
doing I/O have a memory (process) context that must be correct to prevent
data from being incorrectly delivered. Also note that although Win32 does
not require a ‘overlapped’ context, the base OS always works with
asynchronous behavior so that the storage stack can switch threads when
getting the data. This all has to come together in the IoManager to get the
data and thread together so it works. Working in the storage stack lately
the original thread may be seen during the StorPortStartIo call into the
miniport, but the requirement is that all subsequent phases of processing
such as interrupts and DPCs can be in any context. Someone has to put this
all back together.

As to improvements: Think about transactions and the ability to roll back
thousands of writes to many files and the registry. Trying to maintain
stability of the file system with all this going on is difficult enough
without filters or minifilters breaking the contract.

Think about the rules for StorPort miniports. It is not permitted for one
of those drivers to wait on an interrupt to occur due to issuing a command
to the host controller for a specific drive. When StorPortStartIo is
called, the interrupt spinlock is held so that no interrupt will ever be
seen until that routine returns to StorPort. This design is for high
performance with minimal CPU utilization as all those functions are called
at DISPATCH_LEVEL or higher.

Driver Verifier has a trick to call it at DIRQL to prevent any StorPort
miniport from using non-StorPort OS calls. When DV checks the IRQL for
functions that run at DISPATCH_LEVEL or lower it generates a BSOD since it
is too high, but if you use approved calls it lowers the IRQL to allow them
to pass correctly. Very sneaky stuff. I know, I tried to get around the
rules once or twice in the past. No DV you do not get past DTM and
therefore no WHQL signature or logo.

wrote in message news:xxxxx@ntfsd…
> My bad that I didn’t read FQA thouroughly. One time, I tried but stopped
> by the time I read Q10 (something like that). I usually use search on
> this site before I post my question to avoid duplicated questions.
>
> I just search through FQA and it seems Q50 is the one which is matter with
> my question. Still diagest it and your answer. What do you mean “it could
> limit the ability to improve their own filesystems.”
>
> I might let you think that I am stuborn. However, I still wonder what the
> resource that notepad is holding but needed by my worker thread’s
> FltClose.
>
> Instead of just taking the fact that “may Not pend paging I/O”, I like to
> know more about the technicle reason. Any further explainations including
> a URL to the previous post are appreciated very much.
>
> Heidi
>

OSR_Community_User · November 8, 2009, 12:49am

Then does it mean that the function FltDoCompletionProcessingWhenSafe (used in DDK example swapbuffer) belongs to those “approved calls”? Therefore, it can post the operation to a worker thread like the swapbuffer example does in post read operation.

Best regards!

Heidi

p.s. Not everyone can afford OSR $3500 class. I am trying to learn from OSROnline. I have been very grateful for what I have learned from it.

----- Original Message ----
From: David Craig
To: Windows File Systems Devs Interest List
Sent: Sat, November 7, 2009 6:57:11 PM
Subject: Re:[ntfsd] Hanging at Calling FltClose at Pended Post Read Operation

Take OSR’s File Systems class and you can ask Tony. The locking of the
various objects and the state of APCs during paging I/O do NOT permit the
rules to be violated with other than partial success. Remember that paging
I/O is used by the OS (mostly Memory Manager) to get needed pages of code
and data into memory when needed. If anything prevents this from happening
the OS will deadlock or the violation will be detected and a BSOD will
occur. Also remember that all file system I/O other than paging require the
use of APCs to get the system back into the correct context so that the data
can be delivered to the correct process. The threads you see in the IRPs
doing I/O have a memory (process) context that must be correct to prevent
data from being incorrectly delivered. Also note that although Win32 does
not require a ‘overlapped’ context, the base OS always works with
asynchronous behavior so that the storage stack can switch threads when
getting the data. This all has to come together in the IoManager to get the
data and thread together so it works. Working in the storage stack lately
the original thread may be seen during the StorPortStartIo call into the
miniport, but the requirement is that all subsequent phases of processing
such as interrupts and DPCs can be in any context. Someone has to put this
all back together.

As to improvements: Think about transactions and the ability to roll back
thousands of writes to many files and the registry. Trying to maintain
stability of the file system with all this going on is difficult enough
without filters or minifilters breaking the contract.

Think about the rules for StorPort miniports. It is not permitted for one
of those drivers to wait on an interrupt to occur due to issuing a command
to the host controller for a specific drive. When StorPortStartIo is
called, the interrupt spinlock is held so that no interrupt will ever be
seen until that routine returns to StorPort. This design is for high
performance with minimal CPU utilization as all those functions are called
at DISPATCH_LEVEL or higher.

Driver Verifier has a trick to call it at DIRQL to prevent any StorPort
miniport from using non-StorPort OS calls. When DV checks the IRQL for
functions that run at DISPATCH_LEVEL or lower it generates a BSOD since it
is too high, but if you use approved calls it lowers the IRQL to allow them
to pass correctly. Very sneaky stuff. I know, I tried to get around the
rules once or twice in the past. No DV you do not get past DTM and
therefore no WHQL signature or logo.

wrote in message news:xxxxx@ntfsd…
> My bad that I didn’t read FQA thouroughly. One time, I tried but stopped
> by the time I read Q10 (something like that). I usually use search on
> this site before I post my question to avoid duplicated questions.
>
> I just search through FQA and it seems Q50 is the one which is matter with
> my question. Still diagest it and your answer. What do you mean “it could
> limit the ability to improve their own filesystems.”
>
> I might let you think that I am stuborn. However, I still wonder what the
> resource that notepad is holding but needed by my worker thread’s
> FltClose.
>
> Instead of just taking the fact that “may Not pend paging I/O”, I like to
> know more about the technicle reason. Any further explainations including
> a URL to the previous post are appreciated very much.
>
> Heidi
>

—
NTFSD is sponsored by OSR

For our schedule of debugging and file system seminars
(including our new fs mini-filter seminar) visit:
http://www.osr.com/seminars

To unsubscribe, visit the List Server section of OSR Online at http://www.osronline.com/page.cfm?name=ListServer

__________________________________________________
Do You Yahoo!?
Tired of spam? Yahoo! Mail has the best spam protection around
http://mail.yahoo.com