NTFS/FltCreateFile Hang

NTFSD
1

Scenario: In a specific folder, when any file is opened, the filter
will open another file (and keep it open) for validation.
This causes a hang in NTFS extremely fast (on the first open even).
The filter opens the validation file and does nothing else until
post-create. During post create it reads the OPENED file and,
optionally, sets the EoF and VDL based on the validation file. (it
should read the validation file to determine whether to set the EoF/VDL,
but for testing, it just sets the EoF/VDL regardless to a predefined
value)

The simplest hang occurs when Explorer opens the file and another
program tries to open the file at a very close point in time. The
Explorer’s thread also hangs on the open then. Note that the hang
sometimes occurs during the FltCreateFile call for the validation file
(i.e. the open of the validation file hangs) and sometimes it hangs on
the open for the actual file (the open of the validation file succeeds).

This is a local folder, and the validation files are also local.
Neither folders are shared. (I did try setting FILE_COMPLETE_IF_OPLOCKED
during FltCreateFile call just to try, but it made no difference of
course)

What in the world is NTFS waiting for? (the thread’s
NotificationEvent is on the stack, and is the one from NtfsFsdCreate
stack)
Stacks for both processes where the file and validation files are
accessed are the same essentially:
(this is the output when the threads both hang on the main file
open)

THREAD 85ad9498 Cid 0448.04b8 Teb: 7ffd7000 Win32Thread: e19f8b70
WAIT: (Executive) UserMode Non-Alertable
ee4d18e4 NotificationEvent
IRP List:
85a5cac8: (0006,01b4) Flags: 00000884 Mdl: 00000000
Not impersonating
DeviceMap e1968c68
Owning Process 0 Image:
Attached Process 85adbda0 Image: explorer.exe
Wait Start TickCount 3275 Ticks: 4459 (0:00:01:09.671)
Context Switch Count 1470 NoStackSwap LargeStack
UserTime 00:00:00.125
KernelTime 00:00:00.453
Win32 Start Address ntdll!RtlpWorkerThread (0x7c910250)
Start Address 0x7c8106f9
Stack Init ee4d2000 Current ee4d184c Base ee4d2000 Limit ee4ce000 Call 0

Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 16
ChildEBP RetAddr Args to Child
ee4d1864 80500cf0 85ad9508 85ad9498 804f9d72 nt!KiSwapContext+0x2e (FPO:
[Uses EBP] [0,0,4])
ee4d1870 804f9d72 804f9bb0 00000000 85a5cac8 nt!KiSwapThread+0x46 (FPO:
[0,0,0])
ee4d1898 f7326246 00000000 00000000 00000001
nt!KeWaitForSingleObject+0x1c2 (FPO: [Non-Fpo])
ee4d1980 804ee129 8670c770 85a5cac8 85a62248 Ntfs!NtfsFsdCreate+0x291
(FPO: [Non-Fpo])
ee4d1990 f73af876 00000000 86605910 85ae33c0 nt!IopfCallDriver+0x31
(FPO: [0,0,0])
ee4d19dc 804ee129 8670c0d8 00000001 85a5cac8 sr!SrCreate+0x150 (FPO:
[Non-Fpo])
ee4d19ec f73bfe9b 00000000 85a5cac8 85a5cc58 nt!IopfCallDriver+0x31
(FPO: [0,0,0])
ee4d1a10 f73cc754 ee4d1a30 8638b860 00000000
fltMgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x20b (FPO:
[Non-Fpo])
ee4d1a4c 804ee129 8638b860 85a5cac8 85a5cac8 fltMgr!FltpCreate+0x26a
(FPO: [Non-Fpo])
ee4d1a5c 80578728 864528e8 85b2c7e4 ee4d1c04 nt!IopfCallDriver+0x31
(FPO: [0,0,0])
ee4d1b3c 805b4e10 86452900 00000000 85b2c740 nt!IopParseDevice+0xa12
(FPO: [Non-Fpo])
ee4d1bc4 805b11b9 00000000 ee4d1c04 00000040
nt!ObpLookupObjectName+0x56a (FPO: [Non-Fpo])
ee4d1c18 8056b333 00000000 00000000 b7e05801 nt!ObOpenObjectByName+0xeb
(FPO: [Non-Fpo])
ee4d1c94 8056bcaa 0202e6e8 00120089 0202e6ac nt!IopCreateFile+0x407
(FPO: [Non-Fpo])
ee4d1cf0 8056e3bc 0202e6e8 00120089 0202e6ac nt!IoCreateFile+0x8e (FPO:
[Non-Fpo])
ee4d1d30 8053d6d8 0202e6e8 00120089 0202e6ac nt!NtCreateFile+0x30 (FPO:
[Non-Fpo])
ee4d1d30 7c90e514 0202e6e8 00120089 0202e6ac nt!KiFastCallEntry+0xf8
(FPO: [0,0] TrapFrame @ ee4d1d64)
0202e6dc 00000000 00000000 00000000 00000000 ntdll!KiFastSystemCallRet
(FPO: [0,0,0])

THREAD 859f8ca0 Cid 06b4.058c Teb: 7ffdf000 Win32Thread: e1fd2338
WAIT: (Executive) UserMode Non-Alertable
ee2c68e4 NotificationEvent
IRP List:
859f6008: (0006,01b4) Flags: 00000884 Mdl: 00000000
Not impersonating
DeviceMap e1968c68
Owning Process 0 Image:
Attached Process 859f6a20 Image: notepad.exe
Wait Start TickCount 3456 Ticks: 4278 (0:00:01:06.843)
Context Switch Count 91 NoStackSwap LargeStack
UserTime 00:00:00.015
KernelTime 00:00:00.015
Win32 Start Address 0x0100739d
Start Address 0x7c810705
Stack Init ee2c7000 Current ee2c684c Base ee2c7000 Limit ee2c2000 Call 0

Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 0
ChildEBP RetAddr Args to Child
ee2c6864 80500cf0 859f8d10 859f8ca0 804f9d72 nt!KiSwapContext+0x2e (FPO:
[Uses EBP] [0,0,4])
ee2c6870 804f9d72 804f9bb0 00000000 859f6008 nt!KiSwapThread+0x46 (FPO:
[0,0,0])
ee2c6898 f7326246 00000000 00000000 00000001
nt!KeWaitForSingleObject+0x1c2 (FPO: [Non-Fpo])
ee2c6980 804ee129 8670c770 859f6008 85a02f90 Ntfs!NtfsFsdCreate+0x291
(FPO: [Non-Fpo])
ee2c6990 f73af876 00000000 86605910 85a1aa78 nt!IopfCallDriver+0x31
(FPO: [0,0,0])
ee2c69dc 804ee129 8670c0d8 00000001 859f6008 sr!SrCreate+0x150 (FPO:
[Non-Fpo])
ee2c69ec f73bfe9b 00000000 859f6008 859f6198 nt!IopfCallDriver+0x31
(FPO: [0,0,0])
ee2c6a10 f73cc754 ee2c6a30 8638b860 00000000
fltMgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x20b (FPO:
[Non-Fpo])
ee2c6a4c 804ee129 8638b860 859f6008 859f6008 fltMgr!FltpCreate+0x26a
(FPO: [Non-Fpo])
ee2c6a5c 80578728 864528e8 85ae5e2c ee2c6c04 nt!IopfCallDriver+0x31
(FPO: [0,0,0])
ee2c6b3c 805b4e10 86452900 00000000 85ae5d88 nt!IopParseDevice+0xa12
(FPO: [Non-Fpo])
ee2c6bc4 805b11b9 00000000 ee2c6c04 00000040
nt!ObpLookupObjectName+0x56a (FPO: [Non-Fpo])
ee2c6c18 8056b333 00000000 00000000 5b6b4301 nt!ObOpenObjectByName+0xeb
(FPO: [Non-Fpo])
ee2c6c94 8056bcaa 0007fe0c 80100080 0007fdac nt!IopCreateFile+0x407
(FPO: [Non-Fpo])
ee2c6cf0 8056e3bc 0007fe0c 80100080 0007fdac nt!IoCreateFile+0x8e (FPO:
[Non-Fpo])
ee2c6d30 8053d6d8 0007fe0c 80100080 0007fdac nt!NtCreateFile+0x30 (FPO:
[Non-Fpo])
ee2c6d30 7c90e514 0007fe0c 80100080 0007fdac nt!KiFastCallEntry+0xf8
(FPO: [0,0] TrapFrame @ ee2c6d64)
0007fe04 00000000 00000000 00000000 00000000 ntdll!KiFastSystemCallRet
(FPO: [0,0,0])

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.

2

Any chance the create was posted? Anything interesting going on in the
System process?

-scott

–
Scott Noone
Consulting Associate and Chief System Problem Analyst
OSR Open Systems Resources, Inc.
http://www.osronline.com

“Dejan Maksimovic” wrote in message news:xxxxx@ntfsd…

Scenario: In a specific folder, when any file is opened, the filter
will open another file (and keep it open) for validation.
This causes a hang in NTFS extremely fast (on the first open even).
The filter opens the validation file and does nothing else until
post-create. During post create it reads the OPENED file and,
optionally, sets the EoF and VDL based on the validation file. (it
should read the validation file to determine whether to set the EoF/VDL,
but for testing, it just sets the EoF/VDL regardless to a predefined
value)

The simplest hang occurs when Explorer opens the file and another
program tries to open the file at a very close point in time. The
Explorer’s thread also hangs on the open then. Note that the hang
sometimes occurs during the FltCreateFile call for the validation file
(i.e. the open of the validation file hangs) and sometimes it hangs on
the open for the actual file (the open of the validation file succeeds).

This is a local folder, and the validation files are also local.
Neither folders are shared. (I did try setting FILE_COMPLETE_IF_OPLOCKED
during FltCreateFile call just to try, but it made no difference of
course)

What in the world is NTFS waiting for? (the thread’s
NotificationEvent is on the stack, and is the one from NtfsFsdCreate
stack)
Stacks for both processes where the file and validation files are
accessed are the same essentially:
(this is the output when the threads both hang on the main file
open)

THREAD 85ad9498 Cid 0448.04b8 Teb: 7ffd7000 Win32Thread: e19f8b70
WAIT: (Executive) UserMode Non-Alertable
ee4d18e4 NotificationEvent
IRP List:
85a5cac8: (0006,01b4) Flags: 00000884 Mdl: 00000000
Not impersonating
DeviceMap e1968c68
Owning Process 0 Image:
Attached Process 85adbda0 Image: explorer.exe
Wait Start TickCount 3275 Ticks: 4459 (0:00:01:09.671)
Context Switch Count 1470 NoStackSwap LargeStack
UserTime 00:00:00.125
KernelTime 00:00:00.453
Win32 Start Address ntdll!RtlpWorkerThread (0x7c910250)
Start Address 0x7c8106f9
Stack Init ee4d2000 Current ee4d184c Base ee4d2000 Limit ee4ce000 Call 0

Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 16
ChildEBP RetAddr Args to Child
ee4d1864 80500cf0 85ad9508 85ad9498 804f9d72 nt!KiSwapContext+0x2e (FPO:
[Uses EBP] [0,0,4])
ee4d1870 804f9d72 804f9bb0 00000000 85a5cac8 nt!KiSwapThread+0x46 (FPO:
[0,0,0])
ee4d1898 f7326246 00000000 00000000 00000001
nt!KeWaitForSingleObject+0x1c2 (FPO: [Non-Fpo])
ee4d1980 804ee129 8670c770 85a5cac8 85a62248 Ntfs!NtfsFsdCreate+0x291
(FPO: [Non-Fpo])
ee4d1990 f73af876 00000000 86605910 85ae33c0 nt!IopfCallDriver+0x31
(FPO: [0,0,0])
ee4d19dc 804ee129 8670c0d8 00000001 85a5cac8 sr!SrCreate+0x150 (FPO:
[Non-Fpo])
ee4d19ec f73bfe9b 00000000 85a5cac8 85a5cc58 nt!IopfCallDriver+0x31
(FPO: [0,0,0])
ee4d1a10 f73cc754 ee4d1a30 8638b860 00000000
fltMgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x20b (FPO:
[Non-Fpo])
ee4d1a4c 804ee129 8638b860 85a5cac8 85a5cac8 fltMgr!FltpCreate+0x26a
(FPO: [Non-Fpo])
ee4d1a5c 80578728 864528e8 85b2c7e4 ee4d1c04 nt!IopfCallDriver+0x31
(FPO: [0,0,0])
ee4d1b3c 805b4e10 86452900 00000000 85b2c740 nt!IopParseDevice+0xa12
(FPO: [Non-Fpo])
ee4d1bc4 805b11b9 00000000 ee4d1c04 00000040
nt!ObpLookupObjectName+0x56a (FPO: [Non-Fpo])
ee4d1c18 8056b333 00000000 00000000 b7e05801 nt!ObOpenObjectByName+0xeb
(FPO: [Non-Fpo])
ee4d1c94 8056bcaa 0202e6e8 00120089 0202e6ac nt!IopCreateFile+0x407
(FPO: [Non-Fpo])
ee4d1cf0 8056e3bc 0202e6e8 00120089 0202e6ac nt!IoCreateFile+0x8e (FPO:
[Non-Fpo])
ee4d1d30 8053d6d8 0202e6e8 00120089 0202e6ac nt!NtCreateFile+0x30 (FPO:
[Non-Fpo])
ee4d1d30 7c90e514 0202e6e8 00120089 0202e6ac nt!KiFastCallEntry+0xf8
(FPO: [0,0] TrapFrame @ ee4d1d64)
0202e6dc 00000000 00000000 00000000 00000000 ntdll!KiFastSystemCallRet
(FPO: [0,0,0])

THREAD 859f8ca0 Cid 06b4.058c Teb: 7ffdf000 Win32Thread: e1fd2338
WAIT: (Executive) UserMode Non-Alertable
ee2c68e4 NotificationEvent
IRP List:
859f6008: (0006,01b4) Flags: 00000884 Mdl: 00000000
Not impersonating
DeviceMap e1968c68
Owning Process 0 Image:
Attached Process 859f6a20 Image: notepad.exe
Wait Start TickCount 3456 Ticks: 4278 (0:00:01:06.843)
Context Switch Count 91 NoStackSwap LargeStack
UserTime 00:00:00.015
KernelTime 00:00:00.015
Win32 Start Address 0x0100739d
Start Address 0x7c810705
Stack Init ee2c7000 Current ee2c684c Base ee2c7000 Limit ee2c2000 Call 0

Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 0
ChildEBP RetAddr Args to Child
ee2c6864 80500cf0 859f8d10 859f8ca0 804f9d72 nt!KiSwapContext+0x2e (FPO:
[Uses EBP] [0,0,4])
ee2c6870 804f9d72 804f9bb0 00000000 859f6008 nt!KiSwapThread+0x46 (FPO:
[0,0,0])
ee2c6898 f7326246 00000000 00000000 00000001
nt!KeWaitForSingleObject+0x1c2 (FPO: [Non-Fpo])
ee2c6980 804ee129 8670c770 859f6008 85a02f90 Ntfs!NtfsFsdCreate+0x291
(FPO: [Non-Fpo])
ee2c6990 f73af876 00000000 86605910 85a1aa78 nt!IopfCallDriver+0x31
(FPO: [0,0,0])
ee2c69dc 804ee129 8670c0d8 00000001 859f6008 sr!SrCreate+0x150 (FPO:
[Non-Fpo])
ee2c69ec f73bfe9b 00000000 859f6008 859f6198 nt!IopfCallDriver+0x31
(FPO: [0,0,0])
ee2c6a10 f73cc754 ee2c6a30 8638b860 00000000
fltMgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x20b (FPO:
[Non-Fpo])
ee2c6a4c 804ee129 8638b860 859f6008 859f6008 fltMgr!FltpCreate+0x26a
(FPO: [Non-Fpo])
ee2c6a5c 80578728 864528e8 85ae5e2c ee2c6c04 nt!IopfCallDriver+0x31
(FPO: [0,0,0])
ee2c6b3c 805b4e10 86452900 00000000 85ae5d88 nt!IopParseDevice+0xa12
(FPO: [Non-Fpo])
ee2c6bc4 805b11b9 00000000 ee2c6c04 00000040
nt!ObpLookupObjectName+0x56a (FPO: [Non-Fpo])
ee2c6c18 8056b333 00000000 00000000 5b6b4301 nt!ObOpenObjectByName+0xeb
(FPO: [Non-Fpo])
ee2c6c94 8056bcaa 0007fe0c 80100080 0007fdac nt!IopCreateFile+0x407
(FPO: [Non-Fpo])
ee2c6cf0 8056e3bc 0007fe0c 80100080 0007fdac nt!IoCreateFile+0x8e (FPO:
[Non-Fpo])
ee2c6d30 8053d6d8 0007fe0c 80100080 0007fdac nt!NtCreateFile+0x30 (FPO:
[Non-Fpo])
ee2c6d30 7c90e514 0007fe0c 80100080 0007fdac nt!KiFastCallEntry+0xf8
(FPO: [0,0] TrapFrame @ ee2c6d64)
0007fe04 00000000 00000000 00000000 00000000 ntdll!KiFastSystemCallRet
(FPO: [0,0,0])

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.

3

Doesn’t seem so. All system threads are typical (ending with KiSwapContext or alike)

Scott Noone wrote:

Any chance the create was posted? Anything interesting going on in the System process?

“Dejan Maksimovic” wrote in message news:xxxxx@ntfsd…

Scenario: In a specific folder, when any file is opened, the filter
will open another file (and keep it open) for validation.
This causes a hang in NTFS extremely fast (on the first open even).
The filter opens the validation file and does nothing else until
post-create. During post create it reads the OPENED file and,
optionally, sets the EoF and VDL based on the validation file. (it
should read the validation file to determine whether to set the EoF/VDL,
but for testing, it just sets the EoF/VDL regardless to a predefined
value)

The simplest hang occurs when Explorer opens the file and another
program tries to open the file at a very close point in time. The
Explorer’s thread also hangs on the open then. Note that the hang
sometimes occurs during the FltCreateFile call for the validation file
(i.e. the open of the validation file hangs) and sometimes it hangs on
the open for the actual file (the open of the validation file succeeds).

This is a local folder, and the validation files are also local.
Neither folders are shared. (I did try setting FILE_COMPLETE_IF_OPLOCKED
during FltCreateFile call just to try, but it made no difference of
course)

What in the world is NTFS waiting for? (the thread’s
NotificationEvent is on the stack, and is the one from NtfsFsdCreate
stack)
Stacks for both processes where the file and validation files are
accessed are the same essentially:
(this is the output when the threads both hang on the main file
open)

THREAD 85ad9498 Cid 0448.04b8 Teb: 7ffd7000 Win32Thread: e19f8b70
WAIT: (Executive) UserMode Non-Alertable
ee4d18e4 NotificationEvent
IRP List:
85a5cac8: (0006,01b4) Flags: 00000884 Mdl: 00000000
Not impersonating
DeviceMap e1968c68
Owning Process 0 Image:
> Attached Process 85adbda0 Image: explorer.exe
> Wait Start TickCount 3275 Ticks: 4459 (0:00:01:09.671)
> Context Switch Count 1470 NoStackSwap LargeStack
> UserTime 00:00:00.125
> KernelTime 00:00:00.453
> Win32 Start Address ntdll!RtlpWorkerThread (0x7c910250)
> Start Address 0x7c8106f9
> Stack Init ee4d2000 Current ee4d184c Base ee4d2000 Limit ee4ce000 Call 0
>
> Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 16
> ChildEBP RetAddr Args to Child
> ee4d1864 80500cf0 85ad9508 85ad9498 804f9d72 nt!KiSwapContext+0x2e (FPO:
> [Uses EBP] [0,0,4])
> ee4d1870 804f9d72 804f9bb0 00000000 85a5cac8 nt!KiSwapThread+0x46 (FPO:
> [0,0,0])
> ee4d1898 f7326246 00000000 00000000 00000001
> nt!KeWaitForSingleObject+0x1c2 (FPO: [Non-Fpo])
> ee4d1980 804ee129 8670c770 85a5cac8 85a62248 Ntfs!NtfsFsdCreate+0x291
> (FPO: [Non-Fpo])
> ee4d1990 f73af876 00000000 86605910 85ae33c0 nt!IopfCallDriver+0x31
> (FPO: [0,0,0])
> ee4d19dc 804ee129 8670c0d8 00000001 85a5cac8 sr!SrCreate+0x150 (FPO:
> [Non-Fpo])
> ee4d19ec f73bfe9b 00000000 85a5cac8 85a5cc58 nt!IopfCallDriver+0x31
> (FPO: [0,0,0])
> ee4d1a10 f73cc754 ee4d1a30 8638b860 00000000
> fltMgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x20b (FPO:
> [Non-Fpo])
> ee4d1a4c 804ee129 8638b860 85a5cac8 85a5cac8 fltMgr!FltpCreate+0x26a
> (FPO: [Non-Fpo])
> ee4d1a5c 80578728 864528e8 85b2c7e4 ee4d1c04 nt!IopfCallDriver+0x31
> (FPO: [0,0,0])
> ee4d1b3c 805b4e10 86452900 00000000 85b2c740 nt!IopParseDevice+0xa12
> (FPO: [Non-Fpo])
> ee4d1bc4 805b11b9 00000000 ee4d1c04 00000040
> nt!ObpLookupObjectName+0x56a (FPO: [Non-Fpo])
> ee4d1c18 8056b333 00000000 00000000 b7e05801 nt!ObOpenObjectByName+0xeb
> (FPO: [Non-Fpo])
> ee4d1c94 8056bcaa 0202e6e8 00120089 0202e6ac nt!IopCreateFile+0x407
> (FPO: [Non-Fpo])
> ee4d1cf0 8056e3bc 0202e6e8 00120089 0202e6ac nt!IoCreateFile+0x8e (FPO:
> [Non-Fpo])
> ee4d1d30 8053d6d8 0202e6e8 00120089 0202e6ac nt!NtCreateFile+0x30 (FPO:
> [Non-Fpo])
> ee4d1d30 7c90e514 0202e6e8 00120089 0202e6ac nt!KiFastCallEntry+0xf8
> (FPO: [0,0] TrapFrame @ ee4d1d64)
> 0202e6dc 00000000 00000000 00000000 00000000 ntdll!KiFastSystemCallRet
> (FPO: [0,0,0])
>
> THREAD 859f8ca0 Cid 06b4.058c Teb: 7ffdf000 Win32Thread: e1fd2338
> WAIT: (Executive) UserMode Non-Alertable
> ee2c68e4 NotificationEvent
> IRP List:
> 859f6008: (0006,01b4) Flags: 00000884 Mdl: 00000000
> Not impersonating
> DeviceMap e1968c68
> Owning Process 0 Image:
> Attached Process 859f6a20 Image: notepad.exe
> Wait Start TickCount 3456 Ticks: 4278 (0:00:01:06.843)
> Context Switch Count 91 NoStackSwap LargeStack
> UserTime 00:00:00.015
> KernelTime 00:00:00.015
> Win32 Start Address 0x0100739d
> Start Address 0x7c810705
> Stack Init ee2c7000 Current ee2c684c Base ee2c7000 Limit ee2c2000 Call 0
>
> Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 0
> ChildEBP RetAddr Args to Child
> ee2c6864 80500cf0 859f8d10 859f8ca0 804f9d72 nt!KiSwapContext+0x2e (FPO:
> [Uses EBP] [0,0,4])
> ee2c6870 804f9d72 804f9bb0 00000000 859f6008 nt!KiSwapThread+0x46 (FPO:
> [0,0,0])
> ee2c6898 f7326246 00000000 00000000 00000001
> nt!KeWaitForSingleObject+0x1c2 (FPO: [Non-Fpo])
> ee2c6980 804ee129 8670c770 859f6008 85a02f90 Ntfs!NtfsFsdCreate+0x291
> (FPO: [Non-Fpo])
> ee2c6990 f73af876 00000000 86605910 85a1aa78 nt!IopfCallDriver+0x31
> (FPO: [0,0,0])
> ee2c69dc 804ee129 8670c0d8 00000001 859f6008 sr!SrCreate+0x150 (FPO:
> [Non-Fpo])
> ee2c69ec f73bfe9b 00000000 859f6008 859f6198 nt!IopfCallDriver+0x31
> (FPO: [0,0,0])
> ee2c6a10 f73cc754 ee2c6a30 8638b860 00000000
> fltMgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x20b (FPO:
> [Non-Fpo])
> ee2c6a4c 804ee129 8638b860 859f6008 859f6008 fltMgr!FltpCreate+0x26a
> (FPO: [Non-Fpo])
> ee2c6a5c 80578728 864528e8 85ae5e2c ee2c6c04 nt!IopfCallDriver+0x31
> (FPO: [0,0,0])
> ee2c6b3c 805b4e10 86452900 00000000 85ae5d88 nt!IopParseDevice+0xa12
> (FPO: [Non-Fpo])
> ee2c6bc4 805b11b9 00000000 ee2c6c04 00000040
> nt!ObpLookupObjectName+0x56a (FPO: [Non-Fpo])
> ee2c6c18 8056b333 00000000 00000000 5b6b4301 nt!ObOpenObjectByName+0xeb
> (FPO: [Non-Fpo])
> ee2c6c94 8056bcaa 0007fe0c 80100080 0007fdac nt!IopCreateFile+0x407
> (FPO: [Non-Fpo])
> ee2c6cf0 8056e3bc 0007fe0c 80100080 0007fdac nt!IoCreateFile+0x8e (FPO:
> [Non-Fpo])
> ee2c6d30 8053d6d8 0007fe0c 80100080 0007fdac nt!NtCreateFile+0x30 (FPO:
> [Non-Fpo])
> ee2c6d30 7c90e514 0007fe0c 80100080 0007fdac nt!KiFastCallEntry+0xf8
> (FPO: [0,0] TrapFrame @ ee2c6d64)
> 0007fe04 00000000 00000000 00000000 00000000 ntdll!KiFastSystemCallRet
> (FPO: [0,0,0])

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.

4

SWAG:

If NTFS is waiting for an event in create it could be oplock breaks or (in
>= longhorn, but see you are in XP) because the stack has been swapped.

Specify COMPLETE_IF_OPLOCKED and see whether that make a difference…

5

I did specify it, the stack is with the COMPLETE_IF_OPLOCKED flag set. Without it, it hangs as well, just on the
verification file and not on the main file. With the flag, it hangs on the main file. (i.e. on this stack, the
FltCreateFile is not the one that hangs but the associated open of the main file that proceeds after it)
The IRPs sent down by FltMgr are currently on the NtfsCreateCompletion routine, and both are pending, obviously.

Rod Widdowson wrote:

SWAG:

If NTFS is waiting for an event in create it could be oplock breaks or (in
>= longhorn, but see you are in XP) because the stack has been swapped.

Specify COMPLETE_IF_OPLOCKED and see whether that make a difference…

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.

6

Plus, why would an oplock apply to a local file?

Rod Widdowson wrote:

SWAG:

If NTFS is waiting for an event in create it could be oplock breaks or (in
>= longhorn, but see you are in XP) because the stack has been swapped.

Specify COMPLETE_IF_OPLOCKED and see whether that make a difference…

NTFSD is sponsored by OSR

For our schedule of debugging and file system 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

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.

7

Oplocks can apply to local files, they are increasingly used by local applications that perform some sort of scanning that should to be transparent to other apps (they want to be able to close their handles and get out of the way if someone else tries to open the files), such as content indexing apps or anti-virus and such.

Have you tried this without SR.sys in the picture ? This would be where I would start the investigation…

Thanks,
Alex.

8

Not an option; SR will definitely be present in any production environment, so it has to work there, from the start.
This is a vanilla XP system (updated fully), absolutely nothing other than our test filter and Office is installed.

Just for fun, I tried adding FILE_COMPLETE_IF_OPLOCKED to the MAIN file open (i.e. I modified the FLT_CALLBACK_DATA->Iopb->Parameters.Create.Options of the original call, not just my FltCreateFile call), and I didn’t get any hang yet. I did get a sharing violation during one open, which I presume is a result of the added
flag.
This is not something I would want to do in a production filter, though, so I need to figure why it blocks, and what is it waiting on?

xxxxx@gmail.com wrote:

Oplocks can apply to local files, they are increasingly used by local applications that perform some sort of scanning that should to be transparent to other apps (they want to be able to close their handles and get out of the way if someone else tries to open the files), such as content indexing apps or anti-virus and such.

Have you tried this without SR.sys in the picture ? This would be where I would start the investigation…

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.

9

>Oplocks can apply to local files, they are increasingly used by local

applications that perform some sort of scanning that should to be
transparent to >other apps…such as content indexing apps or anti-virus
and such.

There is even at least one in box component that does this. I tripped over a
problem that was a result of the, “tracking.log” file in the SVI folder
having an oplock on it from a local service.

-scott

–
Scott Noone
Consulting Associate and Chief System Problem Analyst
OSR Open Systems Resources, Inc.
http://www.osronline.com

wrote in message news:xxxxx@ntfsd…

Oplocks can apply to local files, they are increasingly used by local
applications that perform some sort of scanning that should to be
transparent to other apps (they want to be able to close their handles and
get out of the way if someone else tries to open the files), such as content
indexing apps or anti-virus and such.

Have you tried this without SR.sys in the picture ? This would be where I
would start the investigation…

Thanks,
Alex.

10

So what causes the oplock hang in such a case?

Scott Noone wrote:

>Oplocks can apply to local files, they are increasingly used by local
>applications that perform some sort of scanning that should to be
>transparent to >other apps…such as content indexing apps or anti-virus
>and such.

There is even at least one in box component that does this. I tripped over a
problem that was a result of the, “tracking.log” file in the SVI folder
having an oplock on it from a local service.

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.

11

Hi Dejan,

I think you misunderstood me. I didn’t mean to imply you should ship your driver requiring that SR be disabled, I simply suggested to disable it to see if SR.sys has anything to do with it, which might give you more information. I’ve seen such cases where SR.sys did trigger a problem and once I figured that out I looked at what SR.sys was doing (as opposed to what NTFS is doing or what my filter was doing) and it was easier to figure out what the problem was (and after that I changed things in my filter so that it worked with SR).

For example, what if in your case SR.sys adds something to the create or changes something ?

Thanks,
Alex.

12

Are you seeing the hang happen on tracking.log as well? After much digging
my suspicion in that case was that I was provoking the application into a
buggy path where it never acknowledged the oplock break. Seemed reasonable
enough because most people don’t go poking around the SVI folder and the
problem didn’t always happen, usually the oplock was broken immediately as a
result of a cleanup. Killing the application would also (obviously)
“unstick” my blocking thread.

Luckily for me (and possibly unfortunately for you :)) I was able to give up
on the problem at that point because it wasn’t critical to what I was
working
on.

-scott

–
Scott Noone
Consulting Associate and Chief System Problem Analyst
OSR Open Systems Resources, Inc.
http://www.osronline.com

“Dejan Maksimovic” wrote in message news:xxxxx@ntfsd…

So what causes the oplock hang in such a case?

Scott Noone wrote:

>Oplocks can apply to local files, they are increasingly used by local
>applications that perform some sort of scanning that should to be
>transparent to >other apps…such as content indexing apps or anti-virus
>and such.

There is even at least one in box component that does this. I tripped over
a
problem that was a result of the, “tracking.log” file in the SVI folder
having an oplock on it from a local service.

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.

13

No, I see this on any folder that we would “monitor”. I noticed the same thing happens on SVI folder, but that
is not the case for me.

Scott Noone wrote:

Are you seeing the hang happen on tracking.log as well? After much digging
my suspicion in that case was that I was provoking the application into a
buggy path where it never acknowledged the oplock break. Seemed reasonable
enough because most people don’t go poking around the SVI folder and the
problem didn’t always happen, usually the oplock was broken immediately as a
result of a cleanup. Killing the application would also (obviously)
“unstick” my blocking thread.

Luckily for me (and possibly unfortunately for you :)) I was able to give up
on the problem at that point because it wasn’t critical to what I was
working
on.

-scott

–
Scott Noone
Consulting Associate and Chief System Problem Analyst
OSR Open Systems Resources, Inc.
http://www.osronline.com

“Dejan Maksimovic” wrote in message news:xxxxx@ntfsd…

So what causes the oplock hang in such a case?

Scott Noone wrote:

> >Oplocks can apply to local files, they are increasingly used by local
> >applications that perform some sort of scanning that should to be
> >transparent to >other apps…such as content indexing apps or anti-virus
> >and such.
>
> There is even at least one in box component that does this. I tripped over
> a
> problem that was a result of the, “tracking.log” file in the SVI folder
> having an oplock on it from a local service.

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.

NTFSD is sponsored by OSR

For our schedule of debugging and file system 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

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.

14

I’ve disabled SR - the exact same issue occurs.
I see that Explorer is issuing a FSCTL_OPLOCK_REQUEST_FILTER, which
succeeds.
That explains the oplocks, but I don’t see a reason for it to work when
my filter does not access the files, and hang otherwise. I am not
requesting an open on the files that hang, rather I am reusing the file
object that Explorer opened - but I am not doing so as it hangs before I
get a chance to get to post-create :slight_smile:

xxxxx@gmail.com wrote:

Hi Dejan,

I think you misunderstood me. I didn’t mean to imply you should ship your driver requiring that SR be disabled, I simply suggested to disable it to see if SR.sys has anything to do with it, which might give you more information. I’ve seen such cases where SR.sys did trigger a problem and once I figured that out I looked at what SR.sys was doing (as opposed to what NTFS is doing or what my filter was doing) and it was easier to figure out what the problem was (and after that I changed things in my filter so that it worked with SR).

For example, what if in your case SR.sys adds something to the create or changes something ?

Thanks,
Alex.

NTFSD is sponsored by OSR

For our schedule of debugging and file system 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

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.

15

What is the behaviour of FAT in such scenario? This may be an indicator, too.

16

At this point I’m convinced it has something to do with oplocks because COMPLETE_IF_OPLOCKED changes the behavior. When you set COMPLETE_IF_OPLOCKED do you get STATUS_OPLOCK_BREAK_IN_PROGRESS (actually do you ever see this returned in any case) ? You should not block a thread where you receive this status (either from your FltCreateFile call or from the original IRP_MJ_CREATE from below).

Do you pass the IFSTests for oplocks ? (this might require some special setup if you only process certain folders because the IFS tests use special folders).

Thanks,
Alex.

17

> At this point I’m convinced it has something to do with oplocks because COMPLETE_IF_OPLOCKED changes the behavior. When you set COMPLETE_IF_OPLOCKED do you get STATUS_OPLOCK_BREAK_IN_PROGRESS (actually do you ever see this returned in any case) ?

No. I get a sharing violation sometimes.

You should not block a thread where you receive this status (either from your FltCreateFile call or from the original IRP_MJ_CREATE from below).

I do not break it other than waiting for the FltCreateFile to complete.

Do you pass the IFSTests for oplocks ? (this might require some special setup if you only process certain folders because the IFS tests use special folders).

Yeah, we only process specific folders, but I could set it to do the same on the IFS test folders.

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.

18

Well, Pete helped (off the list) to figure the issue is definitely an oplock hang and the problem specifically is that I added request for WRITE access to Explorer’s second open of the file.
Explorer does:

  • Open foo.dat
  • Request Oplock on foo.dat
  • Open foo.dat again (without closing it first)
    I didn’t have time to check if pending the IRP and calling FltCreateFile on foo.dat from a worker thread would help (but since Open will be synced by IoMgr, it will most likely mean that Explorer won’t ack the oplock break, because the same thread that requested the oplock is now waiting for a pended IRP_MJ_CREATE to complete).

At this time, I thought of two other options:

  • Add FILE_COMPLETE_IF_OPLOCKED to Explorer’s open (which is definitely not a good idea in general)
  • Deny FSCTL_REQUEST_OPLOCK_xxx calls to foo.dat (any file that my filter is interested in). We have a limited subset of apps that are supposed to have access to the files, that we care for, so offhand I don’t see any issue with this.
    Any other ideas?

Strangely, I don’t see Explorer requesting oplock on W7/x64.

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.

19

“Dejan Maksimovic” wrote in message news:xxxxx@ntfsd…

Well, Pete helped (off the list)

Scott Noone helped, not Pete Scott :slight_smile: This is what happens when you get one
person with a last name that sounds made up and another with two first names
on the same list :stuck_out_tongue:

-scott

–
Scott Noone
Consulting Associate and Chief System Problem Analyst
OSR Open Systems Resources, Inc.
http://www.osronline.com

“Dejan Maksimovic” wrote in message news:xxxxx@ntfsd…

Well, Pete helped (off the list) to figure the issue is definitely an
oplock hang and the problem specifically is that I added request for WRITE
access to Explorer’s second open of the file.
Explorer does:

  • Open foo.dat
  • Request Oplock on foo.dat
  • Open foo.dat again (without closing it first)
    I didn’t have time to check if pending the IRP and calling FltCreateFile
    on foo.dat from a worker thread would help (but since Open will be synced by
    IoMgr, it will most likely mean that Explorer won’t ack the oplock break,
    because the same thread that requested the oplock is now waiting for a
    pended IRP_MJ_CREATE to complete).

At this time, I thought of two other options:

  • Add FILE_COMPLETE_IF_OPLOCKED to Explorer’s open (which is definitely
    not a good idea in general)
  • Deny FSCTL_REQUEST_OPLOCK_xxx calls to foo.dat (any file that my
    filter is interested in). We have a limited subset of apps that are supposed
    to have access to the files, that we care for, so offhand I don’t see any
    issue with this.
    Any other ideas?

Strangely, I don’t see Explorer requesting oplock on W7/x64.

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.

20

For Pete’s sake :smiley: I think Gary Little’s post about Mac is to blame rather, but who knows :slight_smile: Thanks… Pete :slight_smile:

Scott Noone wrote:

“Dejan Maksimovic” wrote in message news:xxxxx@ntfsd…
>Well, Pete helped (off the list)

Scott Noone helped, not Pete Scott :slight_smile: This is what happens when you get one
person with a last name that sounds made up and another with two first names
on the same list :stuck_out_tongue:

–
Kind regards, Dejan (MSN support: xxxxx@alfasp.com)
http://www.alfasp.com
File system audit, security and encryption kits.