A hanging problem caused by our filter driver and McAfee driver

NTFSD
1

Recently I saw a hanging problem when I install my encrypt driver
and McAfee on the same machine. I guess there is a deadlock, but
I cannot figure out how it happens.

The detail information is:
OS: Windows 7 32 bit or 64 bit
Software: Office 2010
McAfee VirusScan Enterprise 8.7i
Our Encryption Driver (nl_SysEncryption.sys and nl_SysEncryptionFW.sys)
Our User Mode Services

Step to reproduce:
Open folder “C:\temp\doc”, right click on any word file.

Result:
Windows Explorer hangs. But after about two and half minutes,
Explorer comes back.

I did some debugging, and found that two threads in explorer try to open the same file:
–> ??\C:\Users\gye\AppData\Roaming\Microsoft\Windows\Libraries\Documents.library-ms

One thing is suspicious in THREAD 83f6f030 is that it stops in McAfee driver mfehidk.sys.
Because our driver is lower, the request should be passed to our driver (See thread 8438ad48).
But in this thread, it doesn’t, this is abnormal.

So I check the lock, the lock is currently held by another thread 8584cb68 in process Mcshield.exe.
That thread also open the same file (??\C:\Users\gye\AppData\Roaming\Microsoft\Windows\Libraries\Documents.library-ms)

But I haven’t figure out why the thread 8584cb68 in process Mcshield.exe doesn’t release the lock.
There should be another lock cause the dead lock. :frowning:

Do you have any suggestion?
Thanks!

<– WinDBG Information –>

THREAD 83f6f030 Cid 0a08.0ae8 Teb: 7ffd3000 Win32Thread: fe79d3b8 WAIT: (Executive) KernelMode Non-Alertable
93a17824 NotificationEvent
IRP List:
84084328: (0006,01fc) Flags: 00000884 Mdl: 00000000
Not impersonating
DeviceMap 91eac648
Owning Process 85ca8198 Image: explorer.exe
Attached Process N/A Image: N/A
Wait Start TickCount 7339 Ticks: 5071 (0:00:01:19.234)
Context Switch Count 106
UserTime 00:00:00.000
KernelTime 00:00:00.171
Win32 Start Address ntdll!TppWorkerThread (0x774dd63e)
Stack Init 93a17fd0 Current 93a176e0 Base 93a18000 Limit 93a15000 Call 0
Priority 9 BasePriority 8 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
ChildEBP RetAddr Args to Child
93a176f8 8266eb15 83f6f030 00000000 82729d20 nt!KiSwapContext+0x26 (FPO: [Uses EBP] [0,0,4])
93a17730 8266d403 83f6f0f0 83f6f030 93a17824 nt!KiSwapThread+0x266
93a17758 826672cf 83f6f030 83f6f0f0 0000002b nt!KiCommitThreadWait+0x1df
93a177d0 8723b491 93a17824 00000000 00000000 nt!KeWaitForSingleObject+0x393
93a177fc 8723e1b7 000249f0 8409d008 8409a2d8 mfehidk+0x491
93a1786c 939c8103 93a178a4 00004e20 000249f0 mfehidk+0x31b7
93a1791c 939c5b76 84064328 851edd20 851edd94 mfeavfk+0x4103
93a17968 8724bef5 00000000 00000001 851edd94 mfeavfk+0x1b76
93a17984 87244751 00000002 851edd20 851edd94 mfehidk+0x10ef5
93a179b0 87244e91 00000002 84084500 8573d1b8 mfehidk+0x9751
93a17a48 8725fd87 00000000 84cb96f8 84cb96f8 mfehidk+0x9e91
93a17a70 8263c4bc 84cb96f8 84084328 8573d214 mfehidk!DEVICEDISPATCH::DispatchPassThrough+0x48
93a17a88 8284062d e61e130d 93a17c30 00000000 nt!IofCallDriver+0x63
93a17b60 828211d7 84dfc138 85fcf588 85b6b540 nt!IopParseDevice+0xed7
93a17bdc 8284724d 00000000 93a17c30 00000040 nt!ObpLookupObjectName+0x4fa
93a17c38 8283f5ab 03dfccfc 83fcf588 93a17c01 nt!ObOpenObjectByName+0x159
93a17cb4 8284aeb6 03dfcd2c 80000000 03dfccfc nt!IopCreateFile+0x673
93a17d00 8264342a 03dfcd2c 80000000 03dfccfc nt!NtCreateFile+0x34
(??\C:\Users\gye\AppData\Roaming\Microsoft\Windows\Libraries\Documents.library-ms)
93a17d00 774f64f4 03dfcd2c 80000000 03dfccfc nt!KiFastCallEntry+0x12a (FPO: [0,3] TrapFrame @ 93a17d34)
03dfcd24 00000000 00000000 00000000 00000000 ntdll!KiFastSystemCallRet (FPO: [0,0,0])

THREAD 8438ad48 Cid 0a08.0f44 Teb: 7ff9b000 Win32Thread: fe771550 WAIT: (Executive) UserMode Non-Alertable
96baac74 NotificationEvent
IRP List:
84123820: (0006,01d8) Flags: 00000884 Mdl: 00000000
840b1c20: (0006,01d8) Flags: 00000884 Mdl: 00000000
841b8e00: (0006,01fc) Flags: 00000884 Mdl: 00000000
Not impersonating
DeviceMap 91eac648
Owning Process 85ca8198 Image: explorer.exe
Attached Process N/A Image: N/A
Wait Start TickCount 11465 Ticks: 945 (0:00:00:14.765)
Context Switch Count 226 NoStackSwap
UserTime 00:00:00.000
KernelTime 00:00:00.046
Win32 Start Address ntdll!TppWorkerThread (0x774dd63e)
Stack Init 96babfd0 Current 96baab10 Base 96bac000 Limit 96ba9000 Call 0
Priority 10 BasePriority 8 UnusualBoost 0 ForegroundBoost 2 IoPriority 2 PagePriority 5
ChildEBP RetAddr Args to Child
96baab28 8266eb15 8438ad48 00000000 82729d20 nt!KiSwapContext+0x26 (FPO: [Uses EBP] [0,0,4])
96baab60 8266d403 8438ae08 8438ad48 96baac74 nt!KiSwapThread+0x266
96baab88 826672cf 8438ad48 8438ae08 00000000 nt!KiCommitThreadWait+0x1df
96baac00 86d7259a 96baac74 00000000 00000001 nt!KeWaitForSingleObject+0x393
96baac30 86d5de04 84123820 96baac70 106a970a Ntfs!NtfsWaitForCreateEvent+0x5e (FPO: [Non-Fpo])
96baad28 8263c4bc 84e25020 84123820 84123820 Ntfs!NtfsFsdCreate+0x23c (FPO: [Non-Fpo])
96baad40 86c1f20c 84123820 00000000 841239d4 nt!IofCallDriver+0x63
96baad64 86c328c9 96baad84 84f09400 00000000 fltmgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x2aa (FPO: [Non-Fpo])
96baadb0 8263c4bc 84f09400 84f49008 85789ec4 fltmgr!FltpCreate+0x2db (FPO: [Non-Fpo])
96baadc8 8284062d e305c6cd 96baaf70 00000000 nt!IofCallDriver+0x63
96baaea0 828211d7 84dfc138 87fcf588 84097440 nt!IopParseDevice+0xed7
96baaf1c 8284724d 00000000 96baaf70 00000240 nt!ObpLookupObjectName+0x4fa
96baaf78 8283f5ab 96bab170 83fcf588 00010000 nt!ObOpenObjectByName+0x159
96baaff4 82876d99 96bab190 80000000 96bab170 nt!IopCreateFile+0x673
96bab050 86c34b62 96bab190 80000000 96bab170 nt!IoCreateFileEx+0x9e
(\Device\HarddiskVolume2\Users\gye\AppData\Roaming\Microsoft\Windows\Libraries\Documents.library-ms)
96bab0dc 86c34c84 84d3c798 84ef3c10 96bab190 fltmgr!FltCreateFileEx2+0xba (FPO: [Non-Fpo])
96bab124 86c62177 84d3c798 84ef3c10 96bab190 fltmgr!FltCreateFile+0x38 (FPO: [Non-Fpo])
96bab194 86c643b2 84d3c798 84ef3c10 00000200 nl_SysEncryption!NLSEGetFileAttributes+0x8b (FPO: [Non-Fpo]) (CONV: stdcall)
96bab214 86c1baeb 00000a08 96bab234 96bab260 nl_SysEncryption!NLFSEOpCallbackPreCreate+0x208 (FPO: [Non-Fpo]) (CONV: stdcall)
96bab280 86c1e9f0 96bab2c4 840b1c20 00000000 fltmgr!FltpPerformPreCallbacks+0x34d (FPO: [Non-Fpo])
96bab298 86c321fe 96bab2c4 86c35f3c 00000000 fltmgr!FltpPassThroughInternal+0x40 (FPO: [Non-Fpo])
96bab2ac 86c328b7 96bab2c4 840b1c20 84121038 fltmgr!FltpCreateInternal+0x24 (FPO: [Non-Fpo])
96bab2f0 8263c4bc 84f09400 84f49008 84121094 fltmgr!FltpCreate+0x2c9 (FPO: [Non-Fpo])
96bab308 8284062d e305db8d 96bab4b0 00000000 nt!IofCallDriver+0x63
96bab3e0 828211d7 84dfc138 87fcf588 85b8da38 nt!IopParseDevice+0xed7
96bab45c 8284724d 00000000 96bab4b0 00000240 nt!ObpLookupObjectName+0x4fa
96bab4bc 8283f5ab 96bab6f4 83fcf588 96bab500 nt!ObOpenObjectByName+0x159
96bab538 82876d99 96bab718 80000000 96bab6f4 nt!IopCreateFile+0x673
96bab594 86c34b62 96bab718 80000000 96bab6f4 nt!IoCreateFileEx+0x9e
(??\C:\Users\gye\AppData\Roaming\Microsoft\Windows\Libraries\Documents.library-ms)
96bab620 86c34c84 84d3f840 84f09dd8 96bab718 fltmgr!FltCreateFileEx2+0xba (FPO: [Non-Fpo])
96bab668 86cb97d2 84d3f840 84f09dd8 96bab718 fltmgr!FltCreateFile+0x38 (FPO: [Non-Fpo])
96bab724 86cb8dba 00bab7b8 84f09c90 84ed4d38 nl_SysEncryptionFW!NLFSECheckFileExist+0x9c (FPO: [Non-Fpo]) (CONV: stdcall)
96bab798 86c1baeb 8418ae40 96bab7b8 96bab7e4 nl_SysEncryptionFW!NLFSEOpCallbackPreCreate+0x2f2 (FPO: [Non-Fpo]) (CONV: stdcall)
96bab804 86c1e9f0 96bab848 841b8e00 00000000 fltmgr!FltpPerformPreCallbacks+0x34d (FPO: [Non-Fpo])
96bab81c 86c321fe 96bab848 86c35f3c 00000000 fltmgr!FltpPassThroughInternal+0x40 (FPO: [Non-Fpo])
96bab830 86c328b7 96bab848 00000000 841b8e00 fltmgr!FltpCreateInternal+0x24 (FPO: [Non-Fpo])
96bab874 8263c4bc 84f09400 84f49008 96bab998 fltmgr!FltpCreate+0x2c9 (FPO: [Non-Fpo])
96bab88c 87260b2a 96bab998 842e3d20 842e3d7c nt!IofCallDriver+0x63
96bab8cc 872446ea 96bab998 841b8fd8 84e79420 mfehidk!DEVICEDISPATCH::LowerDispatchPassThrough+0x51
96bab8f0 87244e91 00000002 841b8fd8 84144578 mfehidk+0x96ea

THREAD 8584cb68 Cid 01a4.090c Teb: 7ffa9000 Win32Thread: 00000000 WAIT: (Executive) UserMode Non-Alertable
94492c74 NotificationEvent
IRP List:
85715b08: (0006,01d8) Flags: 00000884 Mdl: 00000000
85b8ad48: (0006,01d8) Flags: 00000884 Mdl: 00000000
84078008: (0006,01fc) Flags: 00000884 Mdl: 00000000
Not impersonating
DeviceMap 87c08870
Owning Process 857b2030 Image: Mcshield.exe
Attached Process N/A Image: N/A
Wait Start TickCount 7339 Ticks: 5071 (0:00:01:19.234)
Context Switch Count 1865 NoStackSwap
UserTime 00:00:00.515
KernelTime 00:00:01.484
Win32 Start Address 0x66241a8b
Stack Init 94493fd0 Current 94492b10 Base 94494000 Limit 94491000 Call 0
Priority 14 BasePriority 13 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
ChildEBP RetAddr Args to Child
94492b28 8266eb15 8584cb68 00000000 82729d20 nt!KiSwapContext+0x26 (FPO: [Uses EBP] [0,0,4])
94492b60 8266d403 8584cc28 8584cb68 94492c74 nt!KiSwapThread+0x266
94492b88 826672cf 8584cb68 8584cc28 00000000 nt!KiCommitThreadWait+0x1df
94492c00 86d7259a 94492c74 00000000 00000001 nt!KeWaitForSingleObject+0x393
94492c30 86d5de04 85715b08 94492c70 1299170a Ntfs!NtfsWaitForCreateEvent+0x5e (FPO: [Non-Fpo])
94492d28 8263c4bc 84e25020 85715b08 85715b08 Ntfs!NtfsFsdCreate+0x23c (FPO: [Non-Fpo])
94492d40 86c1f20c 85715b08 00000000 85715cbc nt!IofCallDriver+0x63
94492d64 86c328c9 94492d84 84f09400 00000000 fltmgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x2aa (FPO: [Non-Fpo])
94492db0 8263c4bc 84f09400 84f49008 8409f3a4 fltmgr!FltpCreate+0x2db (FPO: [Non-Fpo])
94492dc8 8284062d e1f646cd 94492f70 00000000 nt!IofCallDriver+0x63
94492ea0 828211d7 84dfc138 87fcf588 840946a0 nt!IopParseDevice+0xed7
94492f1c 8284724d 00000000 94492f70 00000240 nt!ObpLookupObjectName+0x4fa
94492f78 8283f5ab 94493170 83fcf588 00010000 nt!ObOpenObjectByName+0x159
94492ff4 82876d99 94493190 80000000 94493170 nt!IopCreateFile+0x673
94493050 86c34b62 94493190 80000000 94493170 nt!IoCreateFileEx+0x9e
\Device\HarddiskVolume2\Users\gye\AppData\Roaming\Microsoft\Windows\Libraries\Documents.library-ms
944930dc 86c34c84 84d3c798 84ef3c10 94493190 fltmgr!FltCreateFileEx2+0xba (FPO: [Non-Fpo])
94493124 86c62177 84d3c798 84ef3c10 94493190 fltmgr!FltCreateFile+0x38 (FPO: [Non-Fpo])
94493194 86c643b2 84d3c798 84ef3c10 00000200 nl_SysEncryption!NLSEGetFileAttributes+0x8b (FPO: [Non-Fpo]) (CONV: stdcall)
94493214 86c1baeb 000001a4 94493234 94493260 nl_SysEncryption!NLFSEOpCallbackPreCreate+0x208 (FPO: [Non-Fpo]) (CONV: stdcall)
94493280 86c1e9f0 944932c4 85b8ad48 00000000 fltmgr!FltpPerformPreCallbacks+0x34d (FPO: [Non-Fpo])
94493298 86c321fe 944932c4 86c35f3c 00000000 fltmgr!FltpPassThroughInternal+0x40 (FPO: [Non-Fpo])
944932ac 86c328b7 944932c4 85b8ad48 851fe410 fltmgr!FltpCreateInternal+0x24 (FPO: [Non-Fpo])
944932f0 8263c4bc 84f09400 84f49008 851fe46c fltmgr!FltpCreate+0x2c9 (FPO: [Non-Fpo])
94493308 8284062d e1f65b8d 944934b0 00000000 nt!IofCallDriver+0x63
944933e0 828211d7 84dfc138 87fcf588 84de5008 nt!IopParseDevice+0xed7
9449345c 8284724d 00000000 944934b0 00000240 nt!ObpLookupObjectName+0x4fa
944934bc 8283f5ab 944936f4 83fcf588 94493500 nt!ObOpenObjectByName+0x159
94493538 82876d99 94493718 80000000 944936f4 nt!IopCreateFile+0x673
94493594 86c34b62 94493718 80000000 944936f4 nt!IoCreateFileEx+0x9e
(??\C:\Users\gye\AppData\Roaming\Microsoft\Windows\Libraries\Documents.library-ms)
94493620 86c34c84 84d3f840 84f09dd8 94493718 fltmgr!FltCreateFileEx2+0xba (FPO: [Non-Fpo])
94493668 86cb97d2 84d3f840 84f09dd8 94493718 fltmgr!FltCreateFile+0x38 (FPO: [Non-Fpo])
94493724 86cb8dba 004937b8 84f09c90 84f00b38 nl_SysEncryptionFW!NLFSECheckFileExist+0x9c (FPO: [Non-Fpo]) (CONV: stdcall)
94493798 86c1baeb 8407b640 944937b8 944937e4 nl_SysEncryptionFW!NLFSEOpCallbackPreCreate+0x2f2 (FPO: [Non-Fpo]) (CONV: stdcall)
94493804 86c1e9f0 94493848 84078008 00000000 fltmgr!FltpPerformPreCallbacks+0x34d (FPO: [Non-Fpo])
9449381c 86c321fe 94493848 86c35f3c 00000000 fltmgr!FltpPassThroughInternal+0x40 (FPO: [Non-Fpo])
94493830 86c328b7 94493848 00000000 84078008 fltmgr!FltpCreateInternal+0x24 (FPO: [Non-Fpo])
94493874 8263c4bc 84f09400 84f49008 94493998 fltmgr!FltpCreate+0x2c9 (FPO: [Non-Fpo])
9449388c 87260b2a 94493998 8407f940 8407f99c nt!IofCallDriver+0x63
944938cc 872446ea 94493998 840781e0 84e79420 mfehidk!DEVICEDISPATCH::LowerDispatchPassThrough+0x51
944938f0 87244e91 00000002 840781e0 8405f348 mfehidk+0x96ea

2

Finally, I found the cause, but I haven’t figure out how to resolve this problem. :frowning:

I think it is a deadlock caused by OpLock.

[Reproduce]
In Windows Explorer, open folder C:\temp\doc
Right click on 1.doc file quickly several times, explorer hangs.

[Analyze]


Find locks

kd> !locks
Resource @ 0x841a623c Exclusively owned
Threads: 840c5d48-01<>


Now, check the thread who own the resource 0x841a623c

THREAD 840c5d48 Cid 0c04.0dc8 Teb: 7ffae000 Win32Thread: ffa6e198 WAIT: (Executive) KernelMode Non-Alertable
88e37824 NotificationEvent
IRP List:
848c5008: (0006,01fc) Flags: 00000884 Mdl: 00000000
Not impersonating
DeviceMap 942cb610
Owning Process 840de870 Image: explorer.exe
Attached Process N/A Image: N/A
Wait Start TickCount 19621 Ticks: 1061 (0:00:00:16.578)
Context Switch Count 1110
UserTime 00:00:00.015
KernelTime 00:00:01.156
Win32 Start Address ntdll!TppWorkerThread (0x775ed63e)
Stack Init 88e37fd0 Current 88e376e0 Base 88e38000 Limit 88e35000 Call 0
Priority 11 BasePriority 8 UnusualBoost 0 ForegroundBoost 2 IoPriority 2 PagePriority 5
ChildEBP RetAddr
88e376f8 826a6b15 nt!KiSwapContext+0x26 (FPO: [Uses EBP] [0,0,4])
88e37730 826a5403 nt!KiSwapThread+0x266
88e37758 8269f2cf nt!KiCommitThreadWait+0x1df
88e377d0 87227491 nt!KeWaitForSingleObject+0x393
88e377fc 8722a1b7 mfehidk+0x491
88e3786c 93d99103 mfehidk+0x31b7
88e3791c 93d96b76 mfeavfk+0x4103
88e37968 87237ef5 mfeavfk+0x1b76
88e37984 87230751 mfehidk+0x10ef5
88e379b0 87230e91 mfehidk+0x9751
88e37a48 8724bd87 mfehidk+0x9e91
88e37a70 826744bc mfehidk!DEVICEDISPATCH::DispatchPassThrough+0x48
88e37a88 8287862d nt!IofCallDriver+0x63
88e37b60 828591d7 nt!IopParseDevice+0xed7
88e37bdc 8287f24d nt!ObpLookupObjectName+0x4fa
88e37c38 828775ab nt!ObOpenObjectByName+0x159
88e37cb4 82882eb6 nt!IopCreateFile+0x673
88e37d00 8267b42a nt!NtCreateFile+0x34 –> “??\C:\Temp\doc\1.doc”
88e37d00 776064f4 nt!KiFastCallEntry+0x12a (FPO: [0,3] TrapFrame @ 88e37d34)
03cfed60 00000000 ntdll!KiFastSystemCallRet (FPO: [0,0,0])


Good, we found a lock (88e37824), let’s show its information

kd> !locks 88e37824
Resource @ 0x88e37824 Shared 3221226067 owning threads
Contention Count = 1
NumberOfSharedWaiters = 2224356368
NumberOfExclusiveWaiters = 454
<< Too many shared waiters to determine owners >>
Threads: 858355d0-00<> Owner TableSize too large (0) - probably a bad resource.


Now, check the thread who owns the locks

kd> !thread 858355d0
THREAD 858355d0 Cid 0224.0920 Teb: 7ffaa000 Win32Thread: 00000000 WAIT: (Executive) UserMode Non-Alertable
94cab354 NotificationEvent
IRP List:
84e04e28: (0006,01d8) Flags: 00000884 Mdl: 00000000
Not impersonating
DeviceMap 87c08870
Owning Process 856a31c8 Image: Mcshield.exe
Attached Process N/A Image: N/A
Wait Start TickCount 19621 Ticks: 1061 (0:00:00:16.578)
Context Switch Count 4850 NoStackSwap
UserTime 00:00:02.250
KernelTime 00:00:05.968
Win32 Start Address 0x66241a8b
Stack Init 94cabfd0 Current 94cab1f0 Base 94cac000 Limit 94ca9000 Call 0
Priority 14 BasePriority 13 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
ChildEBP RetAddr
94cab208 826a6b15 nt!KiSwapContext+0x26 (FPO: [Uses EBP] [0,0,4])
94cab240 826a5403 nt!KiSwapThread+0x266
94cab268 8269f2cf nt!KiCommitThreadWait+0x1df
94cab2e0 86ebe59a nt!KeWaitForSingleObject+0x393
94cab310 86ea9e04 Ntfs!NtfsWaitForCreateEvent+0x5e (FPO: [Non-Fpo])
94cab408 826744bc Ntfs!NtfsFsdCreate+0x23c (FPO: [Non-Fpo])
94cab420 86c7020c nt!IofCallDriver+0x63
94cab444 86c838c9 fltmgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x2aa (FPO: [Non-Fpo])
94cab490 826744bc fltmgr!FltpCreate+0x2db (FPO: [Non-Fpo])
94cab4a8 8287862d nt!IofCallDriver+0x63
94cab580 828591d7 nt!IopParseDevice+0xed7
94cab5fc 8287f24d nt!ObpLookupObjectName+0x4fa
94cab658 828775ab nt!ObOpenObjectByName+0x159
94cab6d4 828aed99 nt!IopCreateFile+0x673
94cab730 86c85b62 nt!IoCreateFileEx+0x9e –> “\Device\HarddiskVolume2\Temp\doc\1.doc”
94cab7bc 86c85c84 fltmgr!FltCreateFileEx2+0xba (FPO: [Non-Fpo])
94cab804 86cb2c71 fltmgr!FltCreateFile+0x38 (FPO: [Non-Fpo])
94cab878 86cb3f85 nl_SysEncryption!NLSEIsEncryptedFile+0x73 (FPO: [Non-Fpo])
94cab8b8 86c6caeb nl_SysEncryption!NLFSEOpCallbackPreNwQueryOpen+0x1b9 (FPO: [Non-Fpo])
94cab924 86c6f17b fltmgr!FltpPerformPreCallbacks+0x34d (FPO: [Non-Fpo])
94cab93c 86c82f24 fltmgr!FltpPassThroughFastIo+0x3d (FPO: [Non-Fpo])
94cab980 8724c8c3 fltmgr!FltpFastIoQueryOpen+0xfc (FPO: [Non-Fpo])
94cab9bc 82878432 mfehidk!DEVICEDISPATCH::DispatchPassThrough+0xb84
94cabaa0 828591d7 nt!IopParseDevice+0xcdc
94cabb1c 8287f24d nt!ObpLookupObjectName+0x4fa
94cabb78 8289ac6a nt!ObOpenObjectByName+0x159
94cabd24 8267b42a nt!NtQueryAttributesFile+0x121
94cabd24 776064f4 nt!KiFastCallEntry+0x12a (FPO: [0,3] TrapFrame @ 94cabd34)
01e2f2d4 00000000 ntdll!KiFastSystemCallRet (FPO: [0,0,0])


Well, it is clear now.
Explorer (thread 840c5d48) is waiting for a lock owned by Mcshield.exe (Thread 858355d0).
Also, I notice these tow threads are trying to open the same file 1.doc (the file we right clicks on).
Mcshield.exe (Thread 858355d0) is stpped at Ntfs!NtfsFsdCreate, it is waiting for a event - 94cab354 NotificationEvent.
The command “!locks 94cab354” doesn’t show any useful information.
So I set a breakpoint on the event to find out who call KeSetEvent.

kd> ba w4 94cab354
kd> g


Thanks God, it break.

kd>Breakpoint 2 hit
nt!KeSetEvent+0x71:
8269f736 72d5 jb nt!KeSetEvent+0x48 (8269f70d)


Show thread information

kd> !teb
TEB at 7ffae000
ExceptionList: 03cfea10
StackBase: 03d00000
StackLimit: 03cee000
SubSystemTib: 00000000
FiberData: 00001e00
ArbitraryUserPointer: 00000000
Self: 7ffae000
EnvironmentPointer: 00000000
ClientId: 00000c04 . 00000dc8
RpcHandle: 00000000
Tls Storage: 7ffae02c
PEB Address: 7ffdf000
LastErrorValue: 0
LastStatusValue: 0
Count Owned Locks: 0
HardErrorMode: 0
kd> !thread
THREAD 840c5d48 Cid 0c04.0dc8 Teb: 7ffae000 Win32Thread: ffa6e198 RUNNING on processor 0
IRP List:
841e4b30: (0006,01fc) Flags: 00060800 Mdl: 00000000
Not impersonating
DeviceMap 942cb610
Owning Process 840de870 Image: explorer.exe
Attached Process N/A Image: N/A
Wait Start TickCount 29221 Ticks: 0
Context Switch Count 1111
UserTime 00:00:00.015
KernelTime 00:00:01.156
Win32 Start Address ntdll!TppWorkerThread (0x775ed63e)
Stack Init 88e37fd0 Current 88e376e0 Base 88e38000 Limit 88e35000 Call 0
Priority 11 BasePriority 8 UnusualBoost 0 ForegroundBoost 2 IoPriority 2 PagePriority 5
ChildEBP RetAddr
88e37974 86ece33c nt!KeSetEvent+0x71
88e37994 82702fd9 Ntfs!NtfsOplockComplete+0x91 (FPO: [Non-Fpo])
88e379a8 82659657 nt!FsRtlpRemoveAndCompleteWaitingIrp+0x45 (FPO: [0,0,2])
88e379f0 82823789 nt!FsRtlpRequestExclusiveOplock+0xca
88e37a3c 86e7d326 nt!FsRtlOplockFsctrlEx+0x2a5
88e37aa8 86eb0da0 Ntfs!NtfsOplockRequest+0x3ed (FPO: [Non-Fpo])
88e37ac0 86ebcded Ntfs!NtfsUserFsRequest+0x4c5 (FPO: [Non-Fpo])
88e37adc 86ebd8fe Ntfs!NtfsCommonFileSystemControl+0x91 (FPO: [Non-Fpo])
88e37b4c 826744bc Ntfs!NtfsFsdFileSystemControl+0x164 (FPO: [Non-Fpo])
88e37b64 86c7020c nt!IofCallDriver+0x63
88e37b88 86c83ce8 fltmgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x2aa (FPO: [Non-Fpo])
88e37bc0 826744bc fltmgr!FltpFsControl+0xe8 (FPO: [Non-Fpo])
88e37bd8 8724bdbf nt!IofCallDriver+0x63
88e37bfc 826744bc mfehidk!DEVICEDISPATCH::DispatchPassThrough+0x80
88e37c14 82875eee nt!IofCallDriver+0x63
88e37c34 82892cd1 nt!IopSynchronousServiceTail+0x1f8
88e37cd0 8289bd08 nt!IopXxxControlFile+0x6aa
88e37d04 8267b42a nt!NtFsControlFile+0x2a
88e37d04 776064f4 nt!KiFastCallEntry+0x12a (FPO: [0,3] TrapFrame @ 88e37d34)
03cfe9bc 77604e5c ntdll!KiFastSystemCallRet (FPO: [0,0,0])
03cfe9c0 75798446 ntdll!ZwFsControlFile+0xc (FPO: [10,0,0])
03cfea20 760dec25 0x75798446
03cfea4c 10048cac 0x760dec25
03cfedb0 77617579 0x10048cac
03cfedbc 003a0043 ntdll!RtlRunOnceExecuteOnce+0x15 (FPO: [Non-Fpo])
03cfedd0 005c0063 0x3a0043
03cfedd4 002e0031 0x5c0063
03cfedd8 006f0064 0x2e0031
03cfeddc 00000000 0x6f0064


Well, it is the thread 840c5d48 who is waiting for lock 88e37824 (owned by thread 858355d0).
Now we know there is a deadlock.
Workflow is:

1. Thread 840c5d48 try to open file (c:\temp\doc\1.doc),
mfehidk.sys does some work and waits for Mcshield.exe.
mfehidk.sys is McAfee’s FsFilter driver, I guess it send
target file path to Mcshield.exe, and wait for scan result.

2. Mcshield.exe try to open the same file to scan

3. nl_SysEncryption catch CREATE Irp, so it call FltCreateFile to
open that file which issue a new CREATE request

4. The new CREATE request is sent to NTFS, but is blocked because of OpLock.
Unfortunately, the OpLock is held by Thread 840c5d48 mentioned in #1.

We got a deadlock.

5. The WaitForSingleObject in #1 has a timeout.
When #1 timeout, the OpLock is free, and Mcshield.exe thread 858355d0 will continue.
That’s why after about 2 minutes, explorer comes back.

3

I still don’t know how to avoid this deadlock.
Has anyone seen similar problem? Can you give me some guide?

Thanks!

4

You will need to understand oplocks pretty well, but COMPLETE_IF_OPLOCKED
can sometimes help

5

Thank you, Rod.
I will try.

6

When mfehidk is waiting in thread 840c5d48, is it waiting in pre- or post-create? I can’t tell from the stack, since it is apparently a legacy filter.

What are the IrpSp->Parameters.Create.Options flags for the create from explorer?

Christian [MSFT]
This posting is provided “AS IS” with no warranties, and confers no rights.

7

Hi Christian,

mfehidk in thread 840c5d48 is waiting in pre-create.
I didn’t check the flag, because I resolve this problem by adding FILE_COMPLETE_IF_OPLOCKED flag in our driver.

But I think you are right, I need to handle it differently base on the flags.
Maybe I can do more test in next release.