Deadlock problem and NTFS ERESOURCE

Hi all!
I have a deadlock problem in my minifilter and I really do not know how to solve:

In PreCreate and in PreRead I acquire an ERESOURCE called myRes to not allow them execute at the same time. But the following scenario occurs:

PreCreate acquires myRes and later calls FltSetInformation() which blocks the thread when it tries to acquire another ERESOURCE from the NTFS filesystem (I suppose).

Concurrently, PreRead is called, and when it tries to acquire myRes it blocks (obviously), but the interesting thing is that this thread had already acquired the NTFS ERESOURCE I mentioned, so a deadlock happens.

My question is Does anybody know why this happens? Or how could I find more information about the NTFS ERESOURCE acquired?

I attach the thread stacks in case they could help. The PreCreate thread is 88442030 and PreRead is 873bf030. tsdlp is my filter?s name.

Thank you very much!

Santi

kd> !thread 873bf030
THREAD 873bf030 Cid 0508.0fb4 Teb: 7ffd3000 Win32Thread: 00000000 WAIT: (WrResource) KernelMode Non-Alertable
871c8958 SynchronizationEvent
873bf0b8 NotificationTimer
IRP List:
a8294e48: (0006,01b4) Flags: 40060a00 Mdl: 00000000
Not impersonating
DeviceMap 9321a078
Owning Process 87268d90 Image: WINWORD.EXE
Attached Process N/A Image: N/A
Wait Start TickCount 119182 Ticks: 239 (0:00:00:02.393)
Context Switch Count 58
UserTime 00:00:00.090
KernelTime 00:00:00.160
Win32 Start Address 0x67b5700a
Stack Init 957cc000 Current 957cb4c8 Base 957cc000 Limit 957c9000 Call 0
Priority 10 BasePriority 8 PriorityDecrement 2 IoPriority 2 PagePriority 5
ChildEBP RetAddr Args to Child
957cb4e0 81887943 873bf030 873bf0b8 8190beb0 nt!KiSwapContext+0x26 (FPO: [Uses EBP] [0,0,4])
957cb524 81870c5b 873bf030 a79a0fc8 873bf030 nt!KiSwapThread+0x433
957cb57c 8189abcc 871c8958 0000001b 00000000 nt!KeWaitForSingleObject+0x492
957cb5b4 81862995 871c8958 8a6507e8 81bc9214 nt!ExpWaitForResource+0xbd
957cb5dc 94dc4997 a79a0fc8 00000001 957cb64c nt!ExAcquireResourceExclusiveLite+0x96
957cb5ec 94dcb388 a79a0fc8 01a2fd79 8a6507e8 tsdlp!AcquireResourceExclusive+0x17 (FPO: [Non-Fpo]) (CONV: stdcall)
957cb64c 837bc34c 87591698 957cb6ac 957cb6cc tsdlp!DlpFilterPreRead+0xe8 (FPO: [Non-Fpo]) (CONV: stdcall)
957cb68c 83799809 00591698 957cb6ac 957cb6cc fltmgr!FltvPreOperation+0x60 (FPO: [Non-Fpo])
957cb6e8 8379bff8 957cb730 00000000 957cb730 fltmgr!FltpPerformPreCallbacks+0x2e5 (FPO: [Non-Fpo])
957cb6fc 8379c8f7 957cb730 00000000 877ec7f8 fltmgr!FltpPassThroughInternal+0x32 (FPO: [Non-Fpo])
957cb718 8379cd53 957cb700 a8214e48 877ec7f8 fltmgr!FltpPassThrough+0x1a3 (FPO: [Non-Fpo])
957cb748 81af16be 877ec7f8 a8214e48 00000000 fltmgr!FltpDispatch+0xb1 (FPO: [Non-Fpo])
957cb76c 81862164 a8214fd8 00000000 877ec7f8 nt!IovCallDriver+0x23f
957cb780 818b6999 873bf030 9747365c 97473628 nt!IofCallDriver+0x1b
957cb79c 81897806 00000043 873bf030 97473668 nt!IoPageRead+0x172
957cb848 8188d7be 8b0c0000 a00223f0 00000000 nt!MiDispatchFault+0xbd6
957cb8b8 818ada12 00000000 8b0c0000 00000000 nt!MmAccessFault+0xdca
957cb900 818b2ab6 8b0c0000 00000000 9779c3c2 nt!MmCheckCachedPageState+0x6a6
957cb98c 818afdc6 87398b68 04bf3b84 957cb9d4 nt!CcMapAndCopy+0x259
957cba18 83b059bd 8730b720 007cbb18 000001eb nt!CcCopyWrite+0x334
957cbb40 83b03914 88414ee8 a8294e48 16ce518f Ntfs!NtfsCommonWrite+0x1fe1 (FPO: [Non-Fpo])
957cbbb8 81af16be 877f6020 a8294e48 00000000 Ntfs!NtfsFsdWrite+0x2dc (FPO: [Non-Fpo])
957cbbdc 81862164 a8294fb4 a8294e48 877f6020 nt!IovCallDriver+0x23f
957cbbf0 8379cba7 877ec7f8 a8294e48 00000000 nt!IofCallDriver+0x1b
957cbc14 8379cd64 957cbc34 877ec7f8 00000000 fltmgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x251 (FPO: [Non-Fpo])
957cbc4c 81af16be 877ec7f8 a8294e48 8730b720 fltmgr!FltpDispatch+0xc2 (FPO: [Non-Fpo])
957cbc70 81862164 a8294fd8 a8294e48 877ec7f8 nt!IovCallDriver+0x23f
957cbc84 81a0ef64 8730b74c a8294e48 a8294fd8 nt!IofCallDriver+0x1b
957cbca4 81a19040 877ec7f8 8730b720 00000001 nt!IopSynchronousServiceTail+0x1d9
957cbd38 818739aa 877ec7f8 00000000 00000000 nt!NtWriteFile+0x6fc
957cbd38 77a29a94 877ec7f8 00000000 00000000 nt!KiFastCallEntry+0x12a (FPO: [0,3] TrapFrame @ 957cbd64)
WARNING: Frame IP not in any known module. Following frames may be wrong.
05e942e4 00000000 00000000 00000000 00000000 0x77a29a94

kd> !thread 88442030
THREAD 88442030 Cid 0508.0348 Teb: 7ffd6000 Win32Thread: fe604d30 WAIT: (WrResource) KernelMode Non-Alertable
871ca070 SynchronizationEvent
884420b8 NotificationTimer
IRP List:
a82bce48: (0006,01b4) Flags: 40000884 Mdl: 00000000
Not impersonating
DeviceMap 9321a078
Owning Process 87268d90 Image: WINWORD.EXE
Attached Process N/A Image: N/A
Wait Start TickCount 119179 Ticks: 242 (0:00:00:02.423)
Context Switch Count 262
UserTime 00:00:00.350
KernelTime 00:00:01.081
Win32 Start Address 0x67b5700a
Stack Init 91938000 Current 91937190 Base 91938000 Limit 91935000 Call 0
Priority 10 BasePriority 8 PriorityDecrement 2 IoPriority 2 PagePriority 5
ChildEBP RetAddr Args to Child
919371a8 81887943 88442030 884420b8 8190be98 nt!KiSwapContext+0x26 (FPO: [Uses EBP] [0,0,4])
919371ec 81870c5b 88442030 87502b70 88442030 nt!KiSwapThread+0x433
91937244 8189abcc 871ca070 0000001b 00000000 nt!KeWaitForSingleObject+0x492
9193727c 81862995 871ca070 00000014 a001f0f8 nt!ExpWaitForResource+0xbd
919372a0 83b08eee 87502b70 00000001 91937320 nt!ExAcquireResourceExclusiveLite+0x96
919372b0 83b9fdf9 873af3e8 a001f008 00000001 Ntfs!NtfsAcquirePagingResourceExclusive+0x29 (FPO: [Non-Fpo])
91937320 83b0ca54 873af3e8 a8176e48 122199bb Ntfs!NtfsCommonSetInformation+0x461 (FPO: [Non-Fpo])
9193738c 81af16be 877f6020 a8176e48 00000000 Ntfs!NtfsFsdSetInformation+0x104 (FPO: [Non-Fpo])
919373b0 81862164 a8176fb4 a8176e48 877f6020 nt!IovCallDriver+0x23f
919373c4 8379cba7 00000000 871ddba0 00000000 nt!IofCallDriver+0x1b
919373e8 8379d7c7 91937408 877ec7f8 00000000 fltmgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x251 (FPO: [Non-Fpo])
91937420 837b2772 8709f070 81bc9214 8a6507d0 fltmgr!FltPerformSynchronousIo+0xb9 (FPO: [Non-Fpo])
9193743c 94dceecd 8709f070 87506880 919374c8 fltmgr!FltSetInformationFile+0xc2 (FPO: [Non-Fpo])
91937988 837bc34c 88490f18 919379e8 91937a08 tsdlp!DlpFilterPreCreate+0xda (FPO: [Non-Fpo]) (CONV: stdcall)
919379c8 83799809 00490f18 919379e8 91937a08 fltmgr!FltvPreOperation+0x60 (FPO: [Non-Fpo])
91937a24 8379bff8 91937a64 00000000 a82bcfd8 fltmgr!FltpPerformPreCallbacks+0x2e5 (FPO: [Non-Fpo])
91937a38 837aefc0 91937a64 837ad88c 00000000 fltmgr!FltpPassThroughInternal+0x32 (FPO: [Non-Fpo])
91937a4c 837af631 91937a64 877ec7f8 88687410 fltmgr!FltpCreateInternal+0x24 (FPO: [Non-Fpo])
91937a90 81af16be 877ec7f8 877ec380 8844225c fltmgr!FltpCreate+0x28f (FPO: [Non-Fpo])
91937ab4 81862164 a82bcfd8 8721b7f4 877ec7f8 nt!IovCallDriver+0x23f
91937ac8 81a159dc 939601d6 872afdc4 87771668 nt!IofCallDriver+0x1b
91937b98 81a0f5cc 87771680 00000000 872afd20 nt!IopParseDevice+0xf61
91937c28 81a0fb5c 00000000 91937c80 00000040 nt!ObpLookupObjectName+0x5a8
91937c88 81a16927 047e4568 00000000 81a0ce01 nt!ObOpenObjectByName+0x13c
91937cfc 81a3d664 047e45b0 00010080 047e4568 nt!IopCreateFile+0x63b
91937d44 818739aa 047e45b0 00010080 047e4568 nt!NtOpenFile+0x2a
91937d44 77a29a94 047e45b0 00010080 047e4568 nt!KiFastCallEntry+0x12a (FPO: [0,3] TrapFrame @ 91937d64)
WARNING: Frame IP not in any known module. Following frames may be wrong.
047e45b8 00000000 00000000 00000000 00000000 0x77a29a94

To use ERESOURCE’s you need to disable KernelAPc’s, to call
FltSetInformation you need to enable APC’s. In general it is a bad idea to
be holding any lock when calling out of your driver.

Don Burn
Windows Filesystem and Driver Consulting
Website: http://www.windrvr.com
Blog: http://msmvps.com/blogs/WinDrvr

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of
xxxxx@gmail.com
Sent: Thursday, November 10, 2011 9:19 AM
To: Kernel Debugging Interest List
Subject: [windbg] Deadlock problem and NTFS ERESOURCE

Hi all!
I have a deadlock problem in my minifilter and I really do not know how to
solve:

In PreCreate and in PreRead I acquire an ERESOURCE called myRes to not allow
them execute at the same time. But the following scenario occurs:

PreCreate acquires myRes and later calls FltSetInformation() which blocks
the thread when it tries to acquire another ERESOURCE from the NTFS
filesystem (I suppose).

Concurrently, PreRead is called, and when it tries to acquire myRes it
blocks (obviously), but the interesting thing is that this thread had
already acquired the NTFS ERESOURCE I mentioned, so a deadlock happens.

My question is Does anybody know why this happens? Or how could I find more
information about the NTFS ERESOURCE acquired?

I attach the thread stacks in case they could help. The PreCreate thread is
88442030 and PreRead is 873bf030. tsdlp is my filter4s name.

Thank you very much!

Santi

kd> !thread 873bf030
THREAD 873bf030 Cid 0508.0fb4 Teb: 7ffd3000 Win32Thread: 00000000 WAIT:
(WrResource) KernelMode Non-Alertable
871c8958 SynchronizationEvent
873bf0b8 NotificationTimer
IRP List:
a8294e48: (0006,01b4) Flags: 40060a00 Mdl: 00000000 Not impersonating
DeviceMap 9321a078
Owning Process 87268d90 Image: WINWORD.EXE
Attached Process N/A Image: N/A
Wait Start TickCount 119182 Ticks: 239 (0:00:00:02.393)
Context Switch Count 58
UserTime 00:00:00.090
KernelTime 00:00:00.160
Win32 Start Address 0x67b5700a
Stack Init 957cc000 Current 957cb4c8 Base 957cc000 Limit 957c9000 Call 0
Priority 10 BasePriority 8 PriorityDecrement 2 IoPriority 2 PagePriority 5
ChildEBP RetAddr Args to Child
957cb4e0 81887943 873bf030 873bf0b8 8190beb0 nt!KiSwapContext+0x26 (FPO:
[Uses EBP] [0,0,4])
957cb524 81870c5b 873bf030 a79a0fc8 873bf030 nt!KiSwapThread+0x433 957cb57c
8189abcc 871c8958 0000001b 00000000 nt!KeWaitForSingleObject+0x492
957cb5b4 81862995 871c8958 8a6507e8 81bc9214 nt!ExpWaitForResource+0xbd
957cb5dc 94dc4997 a79a0fc8 00000001 957cb64c
nt!ExAcquireResourceExclusiveLite+0x96
957cb5ec 94dcb388 a79a0fc8 01a2fd79 8a6507e8
tsdlp!AcquireResourceExclusive+0x17 (FPO: [Non-Fpo]) (CONV: stdcall)
957cb64c 837bc34c 87591698 957cb6ac 957cb6cc tsdlp!DlpFilterPreRead+0xe8
(FPO: [Non-Fpo]) (CONV: stdcall) 957cb68c 83799809 00591698 957cb6ac
957cb6cc fltmgr!FltvPreOperation+0x60 (FPO: [Non-Fpo])
957cb6e8 8379bff8 957cb730 00000000 957cb730
fltmgr!FltpPerformPreCallbacks+0x2e5 (FPO: [Non-Fpo]) 957cb6fc 8379c8f7
957cb730 00000000 877ec7f8 fltmgr!FltpPassThroughInternal+0x32 (FPO:
[Non-Fpo])
957cb718 8379cd53 957cb700 a8214e48 877ec7f8 fltmgr!FltpPassThrough+0x1a3
(FPO: [Non-Fpo])
957cb748 81af16be 877ec7f8 a8214e48 00000000 fltmgr!FltpDispatch+0xb1 (FPO:
[Non-Fpo]) 957cb76c 81862164 a8214fd8 00000000 877ec7f8
nt!IovCallDriver+0x23f
957cb780 818b6999 873bf030 9747365c 97473628 nt!IofCallDriver+0x1b 957cb79c
81897806 00000043 873bf030 97473668 nt!IoPageRead+0x172
957cb848 8188d7be 8b0c0000 a00223f0 00000000 nt!MiDispatchFault+0xbd6
957cb8b8 818ada12 00000000 8b0c0000 00000000 nt!MmAccessFault+0xdca
957cb900 818b2ab6 8b0c0000 00000000 9779c3c2 nt!MmCheckCachedPageState+0x6a6
957cb98c 818afdc6 87398b68 04bf3b84 957cb9d4 nt!CcMapAndCopy+0x259
957cba18 83b059bd 8730b720 007cbb18 000001eb nt!CcCopyWrite+0x334
957cbb40 83b03914 88414ee8 a8294e48 16ce518f Ntfs!NtfsCommonWrite+0x1fe1
(FPO: [Non-Fpo])
957cbbb8 81af16be 877f6020 a8294e48 00000000 Ntfs!NtfsFsdWrite+0x2dc (FPO:
[Non-Fpo]) 957cbbdc 81862164 a8294fb4 a8294e48 877f6020
nt!IovCallDriver+0x23f
957cbbf0 8379cba7 877ec7f8 a8294e48 00000000 nt!IofCallDriver+0x1b
957cbc14 8379cd64 957cbc34 877ec7f8 00000000
fltmgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x251 (FPO: [Non-Fpo])
957cbc4c 81af16be 877ec7f8 a8294e48 8730b720 fltmgr!FltpDispatch+0xc2 (FPO:
[Non-Fpo])
957cbc70 81862164 a8294fd8 a8294e48 877ec7f8 nt!IovCallDriver+0x23f
957cbc84 81a0ef64 8730b74c a8294e48 a8294fd8 nt!IofCallDriver+0x1b
957cbca4 81a19040 877ec7f8 8730b720 00000001
nt!IopSynchronousServiceTail+0x1d9
957cbd38 818739aa 877ec7f8 00000000 00000000 nt!NtWriteFile+0x6fc
957cbd38 77a29a94 877ec7f8 00000000 00000000 nt!KiFastCallEntry+0x12a (FPO:
[0,3] TrapFrame @ 957cbd64)
WARNING: Frame IP not in any known module. Following frames may be wrong.
05e942e4 00000000 00000000 00000000 00000000 0x77a29a94

kd> !thread 88442030
THREAD 88442030 Cid 0508.0348 Teb: 7ffd6000 Win32Thread: fe604d30 WAIT:
(WrResource) KernelMode Non-Alertable
871ca070 SynchronizationEvent
884420b8 NotificationTimer
IRP List:
a82bce48: (0006,01b4) Flags: 40000884 Mdl: 00000000 Not impersonating
DeviceMap 9321a078
Owning Process 87268d90 Image: WINWORD.EXE
Attached Process N/A Image: N/A
Wait Start TickCount 119179 Ticks: 242 (0:00:00:02.423)
Context Switch Count 262
UserTime 00:00:00.350
KernelTime 00:00:01.081
Win32 Start Address 0x67b5700a
Stack Init 91938000 Current 91937190 Base 91938000 Limit 91935000 Call 0
Priority 10 BasePriority 8 PriorityDecrement 2 IoPriority 2 PagePriority 5
ChildEBP RetAddr Args to Child
919371a8 81887943 88442030 884420b8 8190be98 nt!KiSwapContext+0x26 (FPO:
[Uses EBP] [0,0,4]) 919371ec 81870c5b 88442030 87502b70 88442030
nt!KiSwapThread+0x433
91937244 8189abcc 871ca070 0000001b 00000000 nt!KeWaitForSingleObject+0x492
9193727c 81862995 871ca070 00000014 a001f0f8 nt!ExpWaitForResource+0xbd
919372a0 83b08eee 87502b70 00000001 91937320
nt!ExAcquireResourceExclusiveLite+0x96
919372b0 83b9fdf9 873af3e8 a001f008 00000001
Ntfs!NtfsAcquirePagingResourceExclusive+0x29 (FPO: [Non-Fpo])
91937320 83b0ca54 873af3e8 a8176e48 122199bb
Ntfs!NtfsCommonSetInformation+0x461 (FPO: [Non-Fpo]) 9193738c 81af16be
877f6020 a8176e48 00000000 Ntfs!NtfsFsdSetInformation+0x104 (FPO: [Non-Fpo])
919373b0 81862164 a8176fb4 a8176e48 877f6020 nt!IovCallDriver+0x23f
919373c4 8379cba7 00000000 871ddba0 00000000 nt!IofCallDriver+0x1b
919373e8 8379d7c7 91937408 877ec7f8 00000000
fltmgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x251 (FPO: [Non-Fpo])
91937420 837b2772 8709f070 81bc9214 8a6507d0
fltmgr!FltPerformSynchronousIo+0xb9 (FPO: [Non-Fpo]) 9193743c 94dceecd
8709f070 87506880 919374c8 fltmgr!FltSetInformationFile+0xc2 (FPO:
[Non-Fpo])
91937988 837bc34c 88490f18 919379e8 91937a08 tsdlp!DlpFilterPreCreate+0xda
(FPO: [Non-Fpo]) (CONV: stdcall)
919379c8 83799809 00490f18 919379e8 91937a08 fltmgr!FltvPreOperation+0x60
(FPO: [Non-Fpo])
91937a24 8379bff8 91937a64 00000000 a82bcfd8
fltmgr!FltpPerformPreCallbacks+0x2e5 (FPO: [Non-Fpo])
91937a38 837aefc0 91937a64 837ad88c 00000000
fltmgr!FltpPassThroughInternal+0x32 (FPO: [Non-Fpo]) 91937a4c 837af631
91937a64 877ec7f8 88687410 fltmgr!FltpCreateInternal+0x24 (FPO: [Non-Fpo])
91937a90 81af16be 877ec7f8 877ec380 8844225c fltmgr!FltpCreate+0x28f (FPO:
[Non-Fpo])
91937ab4 81862164 a82bcfd8 8721b7f4 877ec7f8 nt!IovCallDriver+0x23f
91937ac8 81a159dc 939601d6 872afdc4 87771668 nt!IofCallDriver+0x1b
91937b98 81a0f5cc 87771680 00000000 872afd20 nt!IopParseDevice+0xf61
91937c28 81a0fb5c 00000000 91937c80 00000040 nt!ObpLookupObjectName+0x5a8
91937c88 81a16927 047e4568 00000000 81a0ce01 nt!ObOpenObjectByName+0x13c
91937cfc 81a3d664 047e45b0 00010080 047e4568 nt!IopCreateFile+0x63b
91937d44 818739aa 047e45b0 00010080 047e4568 nt!NtOpenFile+0x2a
91937d44 77a29a94 047e45b0 00010080 047e4568 nt!KiFastCallEntry+0x12a (FPO:
[0,3] TrapFrame @ 91937d64)
WARNING: Frame IP not in any known module. Following frames may be wrong.
047e45b8 00000000 00000000 00000000 00000000 0x77a29a94


WINDBG is sponsored by OSR

For our schedule of WDF, WDM, debugging and other seminars 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

Thank you very much for your reply. Now I am a bit confused, as I can?t imagine how I could call external functions inside my critical section.

I know critical sections should be as short as possible, but in my case I want to serialize PreCreate operations, and inside PreCreate dispatcher I need to call several Fltxxx() functions.

How can that be achieved?? Thank you!!