[newbie question]doing I/O in instancesetupcallback

Hi,
I am new to file system filter driver development and this my first post on OSR. I am seeing a hang where there are 2 minifilters and a legacy filter. So the file system stack is like this.

Minifilter1
Legacy Filter
Minifilter2

Minifilter1 is calling FltpGetVolumeFromName from its instancesetupcallback. This results in an IO on \Windows directory which is seen by the legacy filter driver below minifilter1. Now this legacy filter does some IO as part of its init(it’s opening a file) which goes to minifilter2 which is scanning the file. This scanning has been posted to a worker thread(by Fltmgr due to low stack space) which waits forever as instancesetupcallback is not complete.

As far as I know legacy filter has no way to know that it has been called during instancesetupcallback so it can’t avoid that IO(the opening of a file).

My question is:

  1. Is it ok for minifilters to do IO from their instancesetupcallbacks as I have read in a blog that this leads to some known hangs.

Thanks

Yes, it is ok for minifilters to do IO in their instance setup callbacks,
as long as they don’t violate layering.

I’m surprised to hear that FltMgr posted something to a different thread
that is waiting forever. Could you please post a stack ?

Thanks,
Alex.

On Thu, Apr 17, 2014 at 6:02 AM, wrote:

> Hi,
> I am new to file system filter driver development and this my first post
> on OSR. I am seeing a hang where there are 2 minifilters and a legacy
> filter. So the file system stack is like this.
>
> Minifilter1
> Legacy Filter
> Minifilter2
>
> Minifilter1 is calling FltpGetVolumeFromName from its
> instancesetupcallback. This results in an IO on \Windows directory which is
> seen by the legacy filter driver below minifilter1. Now this legacy filter
> does some IO as part of its init(it’s opening a file) which goes to
> minifilter2 which is scanning the file. This scanning has been posted to a
> worker thread(by Fltmgr due to low stack space) which waits forever as
> instancesetupcallback is not complete.
>
> As far as I know legacy filter has no way to know that it has been called
> during instancesetupcallback so it can’t avoid that IO(the opening of a
> file).
>
> My question is:
> 1. Is it ok for minifilters to do IO from their instancesetupcallbacks as
> I have read in a blog that this leads to some known hangs.
>
> Thanks
>
> —
> NTFSD is sponsored by OSR
>
> OSR is hiring!! Info at http://www.osr.com/careers
>
> 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
>

I can post the stack but right now I don’t have access to the dump, but yes
if I call this API KeExpandKernelStackAndCalloutEx from the legacy filter
driver before opening the “file” to expand the stack size things work fine
as Fltmgr does not post a worker thread.

Can I check in Legacy filter driver to not do IO on a volume which is not
mounted yet?

On Thu, Apr 17, 2014 at 8:02 PM, Alex Carp wrote:

> Yes, it is ok for minifilters to do IO in their instance setup callbacks,
> as long as they don’t violate layering.
>
> I’m surprised to hear that FltMgr posted something to a different thread
> that is waiting forever. Could you please post a stack ?
>
> Thanks,
> Alex.
>
>
> On Thu, Apr 17, 2014 at 6:02 AM, wrote:
>
>> Hi,
>> I am new to file system filter driver development and this my first post
>> on OSR. I am seeing a hang where there are 2 minifilters and a legacy
>> filter. So the file system stack is like this.
>>
>> Minifilter1
>> Legacy Filter
>> Minifilter2
>>
>> Minifilter1 is calling FltpGetVolumeFromName from its
>> instancesetupcallback. This results in an IO on \Windows directory which is
>> seen by the legacy filter driver below minifilter1. Now this legacy filter
>> does some IO as part of its init(it’s opening a file) which goes to
>> minifilter2 which is scanning the file. This scanning has been posted to a
>> worker thread(by Fltmgr due to low stack space) which waits forever as
>> instancesetupcallback is not complete.
>>
>> As far as I know legacy filter has no way to know that it has been called
>> during instancesetupcallback so it can’t avoid that IO(the opening of a
>> file).
>>
>> My question is:
>> 1. Is it ok for minifilters to do IO from their instancesetupcallbacks as
>> I have read in a blog that this leads to some known hangs.
>>
>> Thanks
>>
>> —
>> NTFSD is sponsored by OSR
>>
>> OSR is hiring!! Info at http://www.osr.com/careers
>>
>> 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
>>
>
> — NTFSD is sponsored by OSR OSR is hiring!! Info at
> http://www.osr.com/careers 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
>

Well, I think the problem is that the volume is mounted and some filters
have been initialized (in your example, the file system and Minifilter2 are
initialized and ready to go) so it depends on who you ask… I can’t think
of anything a legacy filter could do to figure out if minifilters above it
have completed instance setup. Perhaps someone else on the list has done
more work in this space and might be able to offer better suggestions

When you get the stack, please do a “kb f 100” command to show all the
functions and their stack usage.

Thanks,
Alex.

On Thu, Apr 17, 2014 at 8:50 AM, Dhananjay Kumar > wrote:

> I can post the stack but right now I don’t have access to the dump, but
> yes if I call this API KeExpandKernelStackAndCalloutEx from the legacy
> filter driver before opening the “file” to expand the stack size things
> work fine as Fltmgr does not post a worker thread.
>
> Can I check in Legacy filter driver to not do IO on a volume which is not
> mounted yet?
>
>
> On Thu, Apr 17, 2014 at 8:02 PM, Alex Carp wrote:
>
>> Yes, it is ok for minifilters to do IO in their instance setup callbacks,
>> as long as they don’t violate layering.
>>
>> I’m surprised to hear that FltMgr posted something to a different thread
>> that is waiting forever. Could you please post a stack ?
>>
>> Thanks,
>> Alex.
>>
>>
>> On Thu, Apr 17, 2014 at 6:02 AM, wrote:
>>
>>> Hi,
>>> I am new to file system filter driver development and this my first post
>>> on OSR. I am seeing a hang where there are 2 minifilters and a legacy
>>> filter. So the file system stack is like this.
>>>
>>> Minifilter1
>>> Legacy Filter
>>> Minifilter2
>>>
>>> Minifilter1 is calling FltpGetVolumeFromName from its
>>> instancesetupcallback. This results in an IO on \Windows directory which is
>>> seen by the legacy filter driver below minifilter1. Now this legacy filter
>>> does some IO as part of its init(it’s opening a file) which goes to
>>> minifilter2 which is scanning the file. This scanning has been posted to a
>>> worker thread(by Fltmgr due to low stack space) which waits forever as
>>> instancesetupcallback is not complete.
>>>
>>> As far as I know legacy filter has no way to know that it has been
>>> called during instancesetupcallback so it can’t avoid that IO(the opening
>>> of a file).
>>>
>>> My question is:
>>> 1. Is it ok for minifilters to do IO from their instancesetupcallbacks
>>> as I have read in a blog that this leads to some known hangs.
>>>
>>> Thanks
>>>
>>> —
>>> NTFSD is sponsored by OSR
>>>
>>> OSR is hiring!! Info at http://www.osr.com/careers
>>>
>>> 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
>>>
>>
>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>> http://www.osr.com/careers 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
>>
>
> — NTFSD is sponsored by OSR OSR is hiring!! Info at
> http://www.osr.com/careers 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
>

Hi,

Here is the kb f output of the two deadlocked threads

Memory RetAddr : Args to Child
: Call Site
fffff80002c875d2 : fffff80002e37288 fffffa80024c6040 fffffa8000000000 fffff80002c87dde : nt!KiSwapContext+0x7a 140 fffff80002c9899f : fffff80002e37280 fffff80002c9d454
0000000000000000 fffff880009a6d38 : nt!KiCommitThreadWait+0x1d2
90 fffff880011a4d98 : 0000000000000000 fffff80000000000 fffff8a000000000 636e4d4601289700 : nt!KeWaitForSingleObject+0x19f a0 fffff8800119d071 : fffffa8002cc2510 0000000000000000
0000000000000016 00000000000007ff : fltmgr!FltpPostSyncOperation+0xc8
b0 fffff88001182b9d : c00000bb00000000 0000000000000000 fffffa8002cd5600 fffff880009aa000 : fltmgr! ?? ::NNGAKEGL::string’+0x2074
60 fffff8800117cbf6 : fffffa8002cb9df0 fffffa8002cb94b0 0000000000000016 fffff80002ce62cb : fltmgr!HandleStreamListNotSupported+0x15d 40 fffff88001183b44 : fffffa8002cd5600 0000000000000000
fffffa8002cb94b0 0000000001000101 : fltmgr! ?? ::FNODOBFM::string'+0x30f3 \*\*\* ERROR: Symbol file could not be found. Defaulted to export symbols for minifilter2.sys - 80 fffff8800127b181 : fffffa8002cc2510 fffffa8002cbed80
fffffa8002cb96d0 fffffa8002cbec30 : fltmgr!FltGetFileNameInformation+0x184
90 fffff880012406e6 : fffffa8002cbece0 fffff880009a7428 fffff88001000101 fffff8800128cc00 : minifilter2!GetHeader+0x43fbd a0 fffff8800125eff2 : fffffa8002cbece0 fffff880009a7428
fffff880009a7400 fffff8800129369c : minifilter2!GetHeader+0x9522
350 fffff88001174067 : fffffa8002cbece0 fffff880009a7428 fffff880009a7400 0000000000000000 : minifilter2!GetHeader+0x27e2e 60 fffff880011769aa : fffffa8002cd5600 fffffa8002cd0f00
fffffa8002d69900 fffffa8002c9e000 : fltmgr!FltpPerformPreCallbacks+0x2f7
100 fffff880011942a3 : fffffa8002cd56a0 fffffa8002cd56a0 fffffa8002cd56a0 fffffa800275a010 : fltmgr!FltpPassThroughInternal+0x4a 30 fffff880014368e2 : 0000000000000000 fffffa80024d4640
fffffa80024d91a0 0000000000000000 : fltmgr!FltpCreate+0x293
b0 fffff88001436d34 : fffffa8002cb6b00 0000000000000000 fffffa8002aa9040 fffffa8002cad890 : LegacyFilter+0x2c8e2 60 fffff880015d13e7 : fffffa8002cad890 fffffa8002cb31c8
0000000000000000 0000000000000000 : LegacyFilter+0x2cd34
40 fffff80002f92d5c : 0000000000000004 fffffa8002cd56a0 fffffa8002cd0f20 fffffa8002cd0fb8 : LegacyFilter+0x1c73e7 40 fffff80002f8e6d8 : fffffa8002cad890 fffff80000000000
fffffa8002cb3010 fffff80000000000 : nt!IopParseDevice+0x14d3
160 fffff80002f8f8f6 : 0000000000000000 fffffa8002cb3010 fffff880009a7bf0 fffffa80024d4640 : nt!ObpLookupObjectName+0x588 f0 fffff80002f911fc : 0075006c006f0056 0000000000000000
0000000000000200 fffff80002c9722a : nt!ObOpenObjectByName+0x306
d0 fffff80002f9c7f4 : fffffa8002cb5970 0000000080100004 fffff880009a7d70 fffffa8002cb5988 : nt!IopCreateFile+0x2bc a0 fffff80002c90e13 : 00000000c0000010 fffff80002f89e96
0000000100060000 fffff880009a7ad8 : nt!NtCreateFile+0x78
90 fffff80002c8d3d0 : fffff880014320ce 0000000000000000 00000000000000ba fffffa8002cb5930 : nt!KiSystemServiceCopyEnd+0x13 208 fffff880014320ce : 0000000000000000 00000000000000ba
fffffa8002cb5930 00000000000000ba : nt!KiServiceLinkage
8 fffff880014324e3 : 0000000000000000 fffffa8002cade78 0000000000000000 fffff880009a8160 : LegacyFilter+0x280ce 100 fffff880014326ea : 0000000000000000 0000000000000000
0000024000000000 0000000000000000 : LegacyFilter+0x284e3
30 fffff8800140cddd : fffff880009a7fa8 fffff88080100004 fffff880009a8088 0000000000000700 : LegacyFilter+0x286ea 100 fffff880014561e5 : fffff880009a8160 fffffa8002caa800
0000000002cb2000 fffff880009a8228 : LegacyFilter+0x2ddd
f0 fffff88001499a17 : 0000000000000003 fffff880009a8220 0000000080100004 fffff80002c77487 : LegacyFilter+0x4c1e5 100 fffff8800149664d : fffff88001596c80 000000000000000f
0000000000000000 0000000000000001 : LegacyFilter+0x8fa17
e0 fffff88001493690 : 0000000000000000 0000000000000001 fffff880014fe65c fffff8a0004f4010 : LegacyFilter+0x8c64d 30 fffff8800144ac9a : fffff880009a8300 0000000000000000
0000000000000000 fffff880009a8500 : LegacyFilter+0x89690
60 fffff8800144ae34 : fffffa8002a5e8a0 fffff8a0004f4010 0000000000000000 fffff88001509c50 : LegacyFilter+0x40c9a 50 fffff8800144b46f : 02b7efc261e318bf 02b7efc261e318bf
0000000000000001 fffff80002c86525 : LegacyFilter+0x40e34
50 fffff8800144b544 : fffffa8002a61d90 fffff880009a8500 0000000000000000 fffff88001414b1c : LegacyFilter+0x4146f 50 fffff8800144b5ae : fffff880009aa000 fffff880009a4000
fffffa8002a61d90 fffff88001453e2b : LegacyFilter+0x41544
40 fffff8800145c527 : fffffa8002caecb8 fffffa8002cb2010 0000000000000000 fffff8a0002729d0 : LegacyFilter+0x415ae 50 fffff88001413593 : fffffa8002a61d90 0000000000000000
fffffa8002cc0b00 0000000000000000 : LegacyFilter+0x52527
80 fffff8800140f377 : fffffa8002caec00 0000000000000000 fffffa8002cb27c0 0000000000000000 : LegacyFilter+0x9593 30 fffff8800141133a : fffffa8002caec00 fffff880009a8588
fffff880009a8570 fffffa8000000003 : LegacyFilter+0x5377
70 fffff88001411cd0 : fffffa8002aa9000 0000000000000300 fffff880009a8608 fffffa8000000003 : LegacyFilter+0x733a 70 fffff8800140a7f2 : fffffa8002cc0bd0 fffffa8002a4da10
0000000000000000 0000000000000000 : LegacyFilter+0x7cd0
80 fffff880015d14b1 : fffffa8002aa9040 fffff80000000000 fffff8a0001d5900 fffffa8002a4da10 : LegacyFilter+0x7f2 30 fffff80002f92d5c : 0000000000000004 fffffa8002cc0bd0
fffffa8002cb5760 fffffa8002cb57f8 : LegacyFilter+0x1c74b1
40 fffff80002f8e6d8 : fffffa8002a53060 fffff80000000000 fffffa8002ca4b10 fffff88000000000 : nt!IopParseDevice+0x14d3 160 fffff80002f8f8f6 : 0000000000000000 fffffa8002ca4b10
0000000000000240 fffffa80024d4640 : nt!ObpLookupObjectName+0x588
f0 fffff80002f911fc : fffff8a000006eb0 0000000000000000 0000000000f80000 fffffa8002455c90 : nt!ObOpenObjectByName+0x306 d0 fffff80002f9c7f4 : fffff880009a8d80 fffff8a000100001
fffff880009a8d30 fffff880009a8d20 : nt!IopCreateFile+0x2bc
a0 fffff80002c90e13 : fffffa800245bb30 0000000000000000 fffffa80024c6040 fffff80002f8a604 : nt!NtCreateFile+0x78 90 fffff80002c8d3d0 : fffff880011a0542 00000000000007ff
fffffa8002414000 0000000000000000 : nt!KiSystemServiceCopyEnd+0x13
208 fffff880011a0542 : 00000000000007ff fffffa8002414000 0000000000000000 fffff8800173925f : nt!KiServiceLinkage 8 fffff880011a2597 : 006c0075006d005c fffff880009a8e90
0073006900640029 002900300028006b :
fltmgr!FltpIoGetDeviceObjectPointer+0x72
*** ERROR: Symbol file could not be found. Defaulted to export symbols for
minifilter1.sys -
b0 fffff88001715b42 : fffffa8002cbd060 fffffa8002cbd060 fffffa8002cbd060 00000000000007ff : fltmgr!FltpGetVolumeFromName+0x47 f0 fffff88001714153 : 00000000000000a0 0000000000000040
fffff88000000040 0000000000000000 : minifilter1+0x5bb42
90 fffff8800119a116 : 0000000000000005 fffffa8002cb5bb0 fffffa8002c9e001 fffffa8002cb94c0 : minifilter1+0x5a153 60 fffff8800119911b : 0000000000000000 fffffa8002c9e010
0000000000000000 fffffa8002cb5bb0 :
fltmgr!FltpDoInstanceSetupNotification+0x86
60 fffff88001199ed1 : fffff8a00034e410 ffffffff800000f8 82ebc80c00000005 00000000000007ff : fltmgr!FltpInitInstance+0x27b 70 fffff8800119adab : fffff8a00020d9e0 0000000000000000
0000000000000050 0000000000000020 :
fltmgr!FltpCreateInstanceFromName+0x1d1
d0 fffff88001198dbc : fffffa8002941020 fffffa800275a010 fffffa8002941020 fffff8800000001e : fltmgr!FltpEnumerateRegistryInstances+0x15b a0 fffff880011943f0 : fffffa8002c9e010 fffffa8000000000
fffffa8002941020 fffffa800275a010 :
fltmgr!FltpDoFilterNotificationForNewVolume+0xec
70 fffff8800140a804 : fffffa8002caa420 fffffa8002a4da10 0000000000000000 0000000000000000 : fltmgr!FltpCreate+0x3e0 b0 fffff880015d14b1 : fffffa8002aa9040 fffff80000000000
fffff8a000383e00 fffffa8002a4da10 : LegacyFilter+0x804
30 fffff80002f92d5c : 0000000000000004 fffffa8002caa420 fffffa8002cb3df0 fffffa8002cb3e88 : LegacyFilter+0x1c74b1 40 fffff80002f8e6d8 : fffffa8002a53060 fffff80000000000
fffffa8002924b10 0000000000000000 : nt!IopParseDevice+0x14d3
160 fffff80002f8f8f6 : 0000000000000000 fffffa8002924b10 fffff8a0002092c0 fffffa80024d4640 : nt!ObpLookupObjectName+0x588 f0 fffff80002f911fc : 0000000000000000 0000000000000000
0000000000000000 0000000000000240 : nt!ObOpenObjectByName+0x306
d0 fffff80002f5325a : fffff880009a9868 00670061c0100000 fffff880009a9800 fffff880009a97f0 : nt!IopCreateFile+0x2bc a0 fffff800031ba9dd : fffff880009a99c0 0000000000000000
0000000000000000 0000000000000000 : nt!IoCreateFile+0x8a
90 fffff80002fc915c : 0000000000000000 00000000ffffffff 0000000000000000 0000000000000000 : nt!IopInitCrashDumpRegCallback+0xfd d0 fffff80002f4dcce : 00000000c0000023 0000000000000000
fffff880009a99c0 fffff80000812800 : nt! ?? ::NNGAKEGL::string'+0x13c01 80 fffff800031baa92 : fffff80000812800 0000000000000002
0000000000000000 fffff80000812800 : nt!RtlQueryRegistryValues+0x17e
d0 fffff800031c4367 : fffff80000812800 0000000000000000 0000000000000000 fffff80002e0ce80 : nt!IopInitCrashDumpDuringSysInit+0x72 b0 fffff800031c7515 : 0000000000000007 0000000000000010
ffffffff8000002c fffff8000081a0f0 : nt!IoInitSystem+0x837
100 fffff80003117169 : 0000000000000000 fffffa80024c6040 0000000000000080 fffffa800245bb30 : nt!Phase1InitializationDiscard+0x1275 1d0 fffff80002f2fbae : 0000000000000000 0000000000000080
0000000000000000 fffff80002c828b9 : nt!Phase1Initialization+0x9
30 fffff80002c828c6 : fffff80002e0ce80 fffffa80024c6040 fffff80002e1acc0 0000000000000000 : nt!PspSystemThreadStartup+0x5a 40 0000000000000000 : fffff880009aa000 fffff880009a4000
fffff880009b3aa0 0000000000000000 : nt!KiStartSystemThread+0x16

kbf 100
Memory RetAddr : Args to Child
: Call Site
fffff80002c875d2 : fffffa80024df660 fffffa80024df660 0000000000000000 fffff88000000008 : nt!KiSwapContext+0x7a 140 fffff80002c9899f : fffff8800359d268 fffff8800359d200
fffffa8000000036 fffffa8002cc5520 : nt!KiCommitThreadWait+0x1d2
90 fffff80002c71b0e : fffffa8002c9e600 fffffa800000001b 0000000000000000 fffff880009e9100 : nt!KeWaitForSingleObject+0x19f a0 fffff80002c96dbc : fffffffffd9da600 fffffa8002cb3b10
fffffa8002c9e6c8 0000000000000000 : nt!ExpWaitForResource+0xae
70 fffff88001198d1a : fffffa8002cc7010 fffffa8002cc7010 0000000000000000 fffff8800140fe5c : nt!ExAcquireResourceExclusiveLite+0x14f 70 fffff880011943f0 : fffffa8002c9e010 0000000000000000
fffffa8002c9e010 fffffa800275a010 :
fltmgr!FltpDoFilterNotificationForNewVolume+0x4a
70 fffff8800140a804 : fffffa8000000060 fffffa8002a4da10 fffffa8002cc2498 fffff8a0003753f0 : fltmgr!FltpCreate+0x3e0 b0 fffff880015d14b1 : fffffa8002aa9040 fffff80000000000
fffff8a0004f0200 fffffa8002a4da10 : LegacyFilter+0x804
30 fffff80002f92d5c : 0000000000000004 fffffa8002cc7010 fffffa8002ca18b0 fffffa8002ca1948 : LegacyFilter+0x1c74b1 40 fffff80002f8e6d8 : fffffa8002a53060 fffff80000000000
fffffa8002ccf550 fffff88000000000 : nt!IopParseDevice+0x14d3
160 fffff80002f8f8f6 : 0000000000000000 fffffa8002ccf550 0000000000000002 fffffa80024d4640 : nt!ObpLookupObjectName+0x588 f0 fffff80002f911fc : fffffa80024df660 0000000000000000
0000000000000200 0000000000000000 : nt!ObOpenObjectByName+0x306
d0 fffff80002f3947b : fffffa8002ccad10 fffffa8000100001 fffff8800359d870 fffff8800359d840 : nt!IopCreateFile+0x2bc a0 fffff880011a8ac5 : 0000000000000020 0000000000000000
fffffa8002ccac80 0000000000000000 : nt!IoCreateFileEx+0xfb
a0 fffff880011aa2fe : fffff8800359e000 fffff8800359001c fffffa8002cc2498 0000000000000000 : fltmgr!FltpExpandFilePathWorker+0x255 140 fffff8800119ced8 : 0000000000000000 fffff80002c86525
fffffa8002c9e010 fffff880009edec0 : fltmgr!FltpExpandFilePath+0x1e
30 fffff88001196e1e : fffffa8002ccac80 0000000000000000 0000000000000000 fffff80002d9c82e : fltmgr! ?? ::NNGAKEGL::string’+0x1ed8
40 fffff88001182b9d : c00000bb00000000 0000000000000000 0000000000000000 fffff8800359e000 : fltmgr!FltpCreateFileNameInformation+0xee 60 fffff8800117cbf6 : fffffa8002888080 0000000000000000
fffffa8002c9e108 fffff80002c94a8a :
fltmgr!HandleStreamListNotSupported+0x15d
40 fffff88001183b44 : 0000000000000000 0000000000000000 0000000000000000 0000000002000101 : fltmgr! ?? ::FNODOBFM::string’+0x30f3
80 fffff880012685e8 : fffffa8002ccac80 fffffa8002cc2510 0000000000000000 0000000000000000 : fltmgr!FltGetFileNameInformation+0x184 90 fffff88001197035 : fffffa8002cb94b0 fffffa8002cd0f20
fffffa8002cbece0 fffff80001000102 : minifilter2!GetHeader+0x31424
a0 fffff88001196ee7 : 0000000000000001 0000000000000000 fffffa8002cc2510 fffff880009a6d38 : fltmgr!FltpCallOpenedFileNameHandler+0x75 40 fffff880011aae7c : 0000000000000000 0000000000000000
fffff80002e37280 0000000000000001 :
fltmgr!FltpGetNormalizedFileNameWorker+0x27
40 fffff880011a2dcd : 0000000000000000 fffff80002e37280 fffffa80024df660 0000000000000001 : fltmgr!FltpGetNormalizedFileNameImpersonate+0x3c 40 fffff80002c9b261 : fffff880011a2da0 fffff80002e37201
fffffa80024df600 0000000000000003 : fltmgr!FltpSyncOpWorker+0x2d
40 fffff80002f2fbae : 0000000000000000 fffffa80024df660 0000000000000080 fffffa800245bb30 : nt!ExpWorkerThread+0x111 90 fffff80002c828c6 : fffff880009e9180 fffffa80024df660
fffffa80024dfb50 0000000000000000 : nt!PspSystemThreadStartup+0x5a
40 0000000000000000 : fffff8800359e000 fffff88003598000 fffff8800359d9e0 00000000`00000000 : nt!KiStartSystemThread+0x16

On Thu, Apr 17, 2014 at 10:12 PM, Alex Carp wrote:

> Well, I think the problem is that the volume is mounted and some filters
> have been initialized (in your example, the file system and Minifilter2 are
> initialized and ready to go) so it depends on who you ask… I can’t think
> of anything a legacy filter could do to figure out if minifilters above it
> have completed instance setup. Perhaps someone else on the list has done
> more work in this space and might be able to offer better suggestions
>
> When you get the stack, please do a “kb f 100” command to show all the
> functions and their stack usage.
>
> Thanks,
> Alex.
>
>
> On Thu, Apr 17, 2014 at 8:50 AM, Dhananjay Kumar <
> xxxxx@gmail.com> wrote:
>
>> I can post the stack but right now I don’t have access to the dump, but
>> yes if I call this API KeExpandKernelStackAndCalloutEx from the legacy
>> filter driver before opening the “file” to expand the stack size things
>> work fine as Fltmgr does not post a worker thread.
>>
>> Can I check in Legacy filter driver to not do IO on a volume which is not
>> mounted yet?
>>
>>
>> On Thu, Apr 17, 2014 at 8:02 PM, Alex Carp wrote:
>>
>>> Yes, it is ok for minifilters to do IO in their instance setup
>>> callbacks, as long as they don’t violate layering.
>>>
>>> I’m surprised to hear that FltMgr posted something to a different thread
>>> that is waiting forever. Could you please post a stack ?
>>>
>>> Thanks,
>>> Alex.
>>>
>>>
>>> On Thu, Apr 17, 2014 at 6:02 AM, wrote:
>>>
>>>> Hi,
>>>> I am new to file system filter driver development and this my first
>>>> post on OSR. I am seeing a hang where there are 2 minifilters and a legacy
>>>> filter. So the file system stack is like this.
>>>>
>>>> Minifilter1
>>>> Legacy Filter
>>>> Minifilter2
>>>>
>>>> Minifilter1 is calling FltpGetVolumeFromName from its
>>>> instancesetupcallback. This results in an IO on \Windows directory which is
>>>> seen by the legacy filter driver below minifilter1. Now this legacy filter
>>>> does some IO as part of its init(it’s opening a file) which goes to
>>>> minifilter2 which is scanning the file. This scanning has been posted to a
>>>> worker thread(by Fltmgr due to low stack space) which waits forever as
>>>> instancesetupcallback is not complete.
>>>>
>>>> As far as I know legacy filter has no way to know that it has been
>>>> called during instancesetupcallback so it can’t avoid that IO(the opening
>>>> of a file).
>>>>
>>>> My question is:
>>>> 1. Is it ok for minifilters to do IO from their instancesetupcallbacks
>>>> as I have read in a blog that this leads to some known hangs.
>>>>
>>>> Thanks
>>>>
>>>> —
>>>> NTFSD is sponsored by OSR
>>>>
>>>> OSR is hiring!! Info at http://www.osr.com/careers
>>>>
>>>> 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
>>>>
>>>
>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>> http://www.osr.com/careers 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
>>>
>>
>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>> http://www.osr.com/careers 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
>>
>
> — NTFSD is sponsored by OSR OSR is hiring!! Info at
> http://www.osr.com/careers 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
>

Thanks for posting the stack. This sucks… Basically, my reading of this
stack is that minifilter2 does a normalized FltGetFileNameInformation,
which is the one place the FltMgr violates layering (see my post here:
http://fsfilters.blogspot.com/2011/02/filter-layering-and-io-targeting-in_17.html(which
uses this post as a prerequisite
http://fsfilters.blogspot.com/2011/02/filter-layering-and-io-targeting-in.html)).
Because this happens to be first IO on the volume FltMgr will wait for the
volume to be “initialized” and that’s where you get the deadlock.

There are various things that might work as a workaround, but which one is
your filter ? Minifilter 1, 2 or the legacy ?

Thanks,
Alex.

On Mon, Apr 21, 2014 at 1:58 AM, Dhananjay Kumar > wrote:

> Hi,
>
> Here is the kb f output of the two deadlocked threads
>
> Memory RetAddr : Args to Child
> : Call Site
> fffff80002c875d2 : fffff80002e37288 fffffa80024c6040<br>&gt; fffffa8000000000 fffff80002c87dde : nt!KiSwapContext+0x7a<br>&gt; 140 fffff80002c9899f : fffff80002e37280 fffff80002c9d454
> 0000000000000000 fffff880009a6d38 : nt!KiCommitThreadWait+0x1d2
> 90 fffff880011a4d98 : 0000000000000000 fffff80000000000<br>&gt; fffff8a000000000 636e4d4601289700 : nt!KeWaitForSingleObject+0x19f<br>&gt; a0 fffff8800119d071 : fffffa8002cc2510 0000000000000000
> 0000000000000016 00000000000007ff : fltmgr!FltpPostSyncOperation+0xc8
> b0 fffff88001182b9d : c00000bb00000000 0000000000000000<br>&gt; fffffa8002cd5600 fffff880009aa000 : fltmgr! ?? ::NNGAKEGL::string’+0x2074
> 60 fffff8800117cbf6 : fffffa8002cb9df0 fffffa8002cb94b0<br>&gt; 0000000000000016 fffff80002ce62cb :<br>&gt; fltmgr!HandleStreamListNotSupported+0x15d<br>&gt; 40 fffff88001183b44 : fffffa8002cd5600 0000000000000000
> fffffa8002cb94b0 0000000001000101 : fltmgr! ?? ::FNODOBFM::string'+0x30f3<br>&gt; ***ERROR: Symbol file could not be found. Defaulted to export symbols<br>&gt; for minifilter2.sys -<br>&gt; 80 fffff8800127b181 : fffffa8002cc2510 fffffa8002cbed80
> fffffa8002cb96d0 fffffa8002cbec30 : fltmgr!FltGetFileNameInformation+0x184
> 90 fffff880012406e6 : fffffa8002cbece0 fffff880009a7428<br>&gt; fffff88001000101 fffff8800128cc00 : minifilter2!GetHeader+0x43fbd<br>&gt; a0 fffff8800125eff2 : fffffa8002cbece0 fffff880009a7428
> fffff880009a7400 fffff8800129369c : minifilter2!GetHeader+0x9522
> 350 fffff88001174067 : fffffa8002cbece0 fffff880009a7428<br>&gt; fffff880009a7400 0000000000000000 : minifilter2!GetHeader+0x27e2e<br>&gt; 60 fffff880011769aa : fffffa8002cd5600 fffffa8002cd0f00
> fffffa8002d69900 fffffa8002c9e000 : fltmgr!FltpPerformPreCallbacks+0x2f7
> 100 fffff880011942a3 : fffffa8002cd56a0 fffffa8002cd56a0<br>&gt; fffffa8002cd56a0 fffffa800275a010 : fltmgr!FltpPassThroughInternal+0x4a<br>&gt; 30 fffff880014368e2 : 0000000000000000 fffffa80024d4640
> fffffa80024d91a0 0000000000000000 : fltmgr!FltpCreate+0x293
> b0 fffff88001436d34 : fffffa8002cb6b00 0000000000000000<br>&gt; fffffa8002aa9040 fffffa8002cad890 : LegacyFilter+0x2c8e2<br>&gt; 60 fffff880015d13e7 : fffffa8002cad890 fffffa8002cb31c8
> 0000000000000000 0000000000000000 : LegacyFilter+0x2cd34
> 40 fffff80002f92d5c : 0000000000000004 fffffa8002cd56a0<br>&gt; fffffa8002cd0f20 fffffa8002cd0fb8 : LegacyFilter+0x1c73e7<br>&gt; 40 fffff80002f8e6d8 : fffffa8002cad890 fffff80000000000
> fffffa8002cb3010 fffff80000000000 : nt!IopParseDevice+0x14d3
> 160 fffff80002f8f8f6 : 0000000000000000 fffffa8002cb3010<br>&gt; fffff880009a7bf0 fffffa80024d4640 : nt!ObpLookupObjectName+0x588<br>&gt; f0 fffff80002f911fc : 0075006c006f0056 0000000000000000
> 0000000000000200 fffff80002c9722a : nt!ObOpenObjectByName+0x306
> d0 fffff80002f9c7f4 : fffffa8002cb5970 0000000080100004<br>&gt; fffff880009a7d70 fffffa8002cb5988 : nt!IopCreateFile+0x2bc<br>&gt; a0 fffff80002c90e13 : 00000000c0000010 fffff80002f89e96
> 0000000100060000 fffff880009a7ad8 : nt!NtCreateFile+0x78
> 90 fffff80002c8d3d0 : fffff880014320ce 0000000000000000<br>&gt; 00000000000000ba fffffa8002cb5930 : nt!KiSystemServiceCopyEnd+0x13<br>&gt; 208 fffff880014320ce : 0000000000000000 00000000000000ba
> fffffa8002cb5930 00000000000000ba : nt!KiServiceLinkage
> 8 fffff880014324e3 : 0000000000000000 fffffa8002cade78<br>&gt; 0000000000000000 fffff880009a8160 : LegacyFilter+0x280ce<br>&gt; 100 fffff880014326ea : 0000000000000000 0000000000000000
> 0000024000000000 0000000000000000 : LegacyFilter+0x284e3
> 30 fffff8800140cddd : fffff880009a7fa8 fffff88080100004<br>&gt; fffff880009a8088 0000000000000700 : LegacyFilter+0x286ea<br>&gt; 100 fffff880014561e5 : fffff880009a8160 fffffa8002caa800
> 0000000002cb2000 fffff880009a8228 : LegacyFilter+0x2ddd
> f0 fffff88001499a17 : 0000000000000003 fffff880009a8220<br>&gt; 0000000080100004 fffff80002c77487 : LegacyFilter+0x4c1e5<br>&gt; 100 fffff8800149664d : fffff88001596c80 000000000000000f
> 0000000000000000 0000000000000001 : LegacyFilter+0x8fa17
> e0 fffff88001493690 : 0000000000000000 0000000000000001<br>&gt; fffff880014fe65c fffff8a0004f4010 : LegacyFilter+0x8c64d<br>&gt; 30 fffff8800144ac9a : fffff880009a8300 0000000000000000
> 0000000000000000 fffff880009a8500 : LegacyFilter+0x89690
> 60 fffff8800144ae34 : fffffa8002a5e8a0 fffff8a0004f4010<br>&gt; 0000000000000000 fffff88001509c50 : LegacyFilter+0x40c9a<br>&gt; 50 fffff8800144b46f : 02b7efc261e318bf 02b7efc261e318bf
> 0000000000000001 fffff80002c86525 : LegacyFilter+0x40e34
> 50 fffff8800144b544 : fffffa8002a61d90 fffff880009a8500<br>&gt; 0000000000000000 fffff88001414b1c : LegacyFilter+0x4146f<br>&gt; 50 fffff8800144b5ae : fffff880009aa000 fffff880009a4000
> fffffa8002a61d90 fffff88001453e2b : LegacyFilter+0x41544
> 40 fffff8800145c527 : fffffa8002caecb8 fffffa8002cb2010<br>&gt; 0000000000000000 fffff8a0002729d0 : LegacyFilter+0x415ae<br>&gt; 50 fffff88001413593 : fffffa8002a61d90 0000000000000000
> fffffa8002cc0b00 0000000000000000 : LegacyFilter+0x52527
> 80 fffff8800140f377 : fffffa8002caec00 0000000000000000<br>&gt; fffffa8002cb27c0 0000000000000000 : LegacyFilter+0x9593<br>&gt; 30 fffff8800141133a : fffffa8002caec00 fffff880009a8588
> fffff880009a8570 fffffa8000000003 : LegacyFilter+0x5377
> 70 fffff88001411cd0 : fffffa8002aa9000 0000000000000300<br>&gt; fffff880009a8608 fffffa8000000003 : LegacyFilter+0x733a<br>&gt; 70 fffff8800140a7f2 : fffffa8002cc0bd0 fffffa8002a4da10
> 0000000000000000 0000000000000000 : LegacyFilter+0x7cd0
> 80 fffff880015d14b1 : fffffa8002aa9040 fffff80000000000<br>&gt; fffff8a0001d5900 fffffa8002a4da10 : LegacyFilter+0x7f2<br>&gt; 30 fffff80002f92d5c : 0000000000000004 fffffa8002cc0bd0
> fffffa8002cb5760 fffffa8002cb57f8 : LegacyFilter+0x1c74b1
> 40 fffff80002f8e6d8 : fffffa8002a53060 fffff80000000000<br>&gt; fffffa8002ca4b10 fffff88000000000 : nt!IopParseDevice+0x14d3<br>&gt; 160 fffff80002f8f8f6 : 0000000000000000 fffffa8002ca4b10
> 0000000000000240 fffffa80024d4640 : nt!ObpLookupObjectName+0x588
> f0 fffff80002f911fc : fffff8a000006eb0 0000000000000000<br>&gt; 0000000000f80000 fffffa8002455c90 : nt!ObOpenObjectByName+0x306<br>&gt; d0 fffff80002f9c7f4 : fffff880009a8d80 fffff8a000100001
> fffff880009a8d30 fffff880009a8d20 : nt!IopCreateFile+0x2bc
> a0 fffff80002c90e13 : fffffa800245bb30 0000000000000000<br>&gt; fffffa80024c6040 fffff80002f8a604 : nt!NtCreateFile+0x78<br>&gt; 90 fffff80002c8d3d0 : fffff880011a0542 00000000000007ff
> fffffa8002414000 0000000000000000 : nt!KiSystemServiceCopyEnd+0x13
> 208 fffff880011a0542 : 00000000000007ff fffffa8002414000<br>&gt; 0000000000000000 fffff8800173925f : nt!KiServiceLinkage<br>&gt; 8 fffff880011a2597 : 006c0075006d005c fffff880009a8e90
> 0073006900640029 002900300028006b :
> fltmgr!FltpIoGetDeviceObjectPointer+0x72
>*** ERROR: Symbol file could not be found. Defaulted to export symbols
> for minifilter1.sys -
> b0 fffff88001715b42 : fffffa8002cbd060 fffffa8002cbd060<br>&gt; fffffa8002cbd060 00000000000007ff : fltmgr!FltpGetVolumeFromName+0x47<br>&gt; f0 fffff88001714153 : 00000000000000a0 0000000000000040
> fffff88000000040 0000000000000000 : minifilter1+0x5bb42
> 90 fffff8800119a116 : 0000000000000005 fffffa8002cb5bb0<br>&gt; fffffa8002c9e001 fffffa8002cb94c0 : minifilter1+0x5a153<br>&gt; 60 fffff8800119911b : 0000000000000000 fffffa8002c9e010
> 0000000000000000 fffffa8002cb5bb0 :
> fltmgr!FltpDoInstanceSetupNotification+0x86
> 60 fffff88001199ed1 : fffff8a00034e410 ffffffff800000f8<br>&gt; 82ebc80c00000005 00000000000007ff : fltmgr!FltpInitInstance+0x27b<br>&gt; 70 fffff8800119adab : fffff8a00020d9e0 0000000000000000
> 0000000000000050 0000000000000020 :
> fltmgr!FltpCreateInstanceFromName+0x1d1
> d0 fffff88001198dbc : fffffa8002941020 fffffa800275a010<br>&gt; fffffa8002941020 fffff8800000001e :<br>&gt; fltmgr!FltpEnumerateRegistryInstances+0x15b<br>&gt; a0 fffff880011943f0 : fffffa8002c9e010 fffffa8000000000
> fffffa8002941020 fffffa800275a010 :
> fltmgr!FltpDoFilterNotificationForNewVolume+0xec
> 70 fffff8800140a804 : fffffa8002caa420 fffffa8002a4da10<br>&gt; 0000000000000000 0000000000000000 : fltmgr!FltpCreate+0x3e0<br>&gt; b0 fffff880015d14b1 : fffffa8002aa9040 fffff80000000000
> fffff8a000383e00 fffffa8002a4da10 : LegacyFilter+0x804
> 30 fffff80002f92d5c : 0000000000000004 fffffa8002caa420<br>&gt; fffffa8002cb3df0 fffffa8002cb3e88 : LegacyFilter+0x1c74b1<br>&gt; 40 fffff80002f8e6d8 : fffffa8002a53060 fffff80000000000
> fffffa8002924b10 0000000000000000 : nt!IopParseDevice+0x14d3
> 160 fffff80002f8f8f6 : 0000000000000000 fffffa8002924b10<br>&gt; fffff8a0002092c0 fffffa80024d4640 : nt!ObpLookupObjectName+0x588<br>&gt; f0 fffff80002f911fc : 0000000000000000 0000000000000000
> 0000000000000000 0000000000000240 : nt!ObOpenObjectByName+0x306
> d0 fffff80002f5325a : fffff880009a9868 00670061c0100000<br>&gt; fffff880009a9800 fffff880009a97f0 : nt!IopCreateFile+0x2bc<br>&gt; a0 fffff800031ba9dd : fffff880009a99c0 0000000000000000
> 0000000000000000 0000000000000000 : nt!IoCreateFile+0x8a
> 90 fffff80002fc915c : 0000000000000000 00000000ffffffff<br>&gt; 0000000000000000 0000000000000000 : nt!IopInitCrashDumpRegCallback+0xfd<br>&gt; d0 fffff80002f4dcce : 00000000c0000023 0000000000000000
> fffff880009a99c0 fffff80000812800 : nt! ?? ::NNGAKEGL::string'+0x13c01<br>&gt; 80 fffff800031baa92 : fffff80000812800 0000000000000002
> 0000000000000000 fffff80000812800 : nt!RtlQueryRegistryValues+0x17e
> d0 fffff800031c4367 : fffff80000812800 0000000000000000<br>&gt; 0000000000000000 fffff80002e0ce80 : nt!IopInitCrashDumpDuringSysInit+0x72<br>&gt; b0 fffff800031c7515 : 0000000000000007 0000000000000010
> ffffffff8000002c fffff8000081a0f0 : nt!IoInitSystem+0x837
> 100 fffff80003117169 : 0000000000000000 fffffa80024c6040<br>&gt; 0000000000000080 fffffa800245bb30 : nt!Phase1InitializationDiscard+0x1275<br>&gt; 1d0 fffff80002f2fbae : 0000000000000000 0000000000000080
> 0000000000000000 fffff80002c828b9 : nt!Phase1Initialization+0x9
> 30 fffff80002c828c6 : fffff80002e0ce80 fffffa80024c6040<br>&gt; fffff80002e1acc0 0000000000000000 : nt!PspSystemThreadStartup+0x5a<br>&gt; 40 0000000000000000 : fffff880009aa000 fffff880009a4000
> fffff880009b3aa0 0000000000000000 : nt!KiStartSystemThread+0x16
>
>
>
>
> kbf 100
> Memory RetAddr : Args to Child
> : Call Site
> fffff80002c875d2 : fffffa80024df660 fffffa80024df660<br>&gt; 0000000000000000 fffff88000000008 : nt!KiSwapContext+0x7a<br>&gt; 140 fffff80002c9899f : fffff8800359d268 fffff8800359d200
> fffffa8000000036 fffffa8002cc5520 : nt!KiCommitThreadWait+0x1d2
> 90 fffff80002c71b0e : fffffa8002c9e600 fffffa800000001b<br>&gt; 0000000000000000 fffff880009e9100 : nt!KeWaitForSingleObject+0x19f<br>&gt; a0 fffff80002c96dbc : fffffffffd9da600 fffffa8002cb3b10
> fffffa8002c9e6c8 0000000000000000 : nt!ExpWaitForResource+0xae
> 70 fffff88001198d1a : fffffa8002cc7010 fffffa8002cc7010<br>&gt; 0000000000000000 fffff8800140fe5c :<br>&gt; nt!ExAcquireResourceExclusiveLite+0x14f<br>&gt; 70 fffff880011943f0 : fffffa8002c9e010 0000000000000000
> fffffa8002c9e010 fffffa800275a010 :
> fltmgr!FltpDoFilterNotificationForNewVolume+0x4a
> 70 fffff8800140a804 : fffffa8000000060 fffffa8002a4da10<br>&gt; fffffa8002cc2498 fffff8a0003753f0 : fltmgr!FltpCreate+0x3e0<br>&gt; b0 fffff880015d14b1 : fffffa8002aa9040 fffff80000000000
> fffff8a0004f0200 fffffa8002a4da10 : LegacyFilter+0x804
> 30 fffff80002f92d5c : 0000000000000004 fffffa8002cc7010<br>&gt; fffffa8002ca18b0 fffffa8002ca1948 : LegacyFilter+0x1c74b1<br>&gt; 40 fffff80002f8e6d8 : fffffa8002a53060 fffff80000000000
> fffffa8002ccf550 fffff88000000000 : nt!IopParseDevice+0x14d3
> 160 fffff80002f8f8f6 : 0000000000000000 fffffa8002ccf550<br>&gt; 0000000000000002 fffffa80024d4640 : nt!ObpLookupObjectName+0x588<br>&gt; f0 fffff80002f911fc : fffffa80024df660 0000000000000000
> 0000000000000200 0000000000000000 : nt!ObOpenObjectByName+0x306
> d0 fffff80002f3947b : fffffa8002ccad10 fffffa8000100001<br>&gt; fffff8800359d870 fffff8800359d840 : nt!IopCreateFile+0x2bc<br>&gt; a0 fffff880011a8ac5 : 0000000000000020 0000000000000000
> fffffa8002ccac80 0000000000000000 : nt!IoCreateFileEx+0xfb
> a0 fffff880011aa2fe : fffff8800359e000 fffff8800359001c<br>&gt; fffffa8002cc2498 0000000000000000 : fltmgr!FltpExpandFilePathWorker+0x255<br>&gt; 140 fffff8800119ced8 : 0000000000000000 fffff80002c86525
> fffffa8002c9e010 fffff880009edec0 : fltmgr!FltpExpandFilePath+0x1e
> 30 fffff88001196e1e : fffffa8002ccac80 0000000000000000<br>&gt; 0000000000000000 fffff80002d9c82e : fltmgr! ?? ::NNGAKEGL::string’+0x1ed8
> 40 fffff88001182b9d : c00000bb00000000 0000000000000000<br>&gt; 0000000000000000 fffff8800359e000 :<br>&gt; fltmgr!FltpCreateFileNameInformation+0xee<br>&gt; 60 fffff8800117cbf6 : fffffa8002888080 0000000000000000
> fffffa8002c9e108 fffff80002c94a8a :
> fltmgr!HandleStreamListNotSupported+0x15d
> 40 fffff88001183b44 : 0000000000000000 0000000000000000<br>&gt; 0000000000000000 0000000002000101 : fltmgr! ?? ::FNODOBFM::string’+0x30f3
> 80 fffff880012685e8 : fffffa8002ccac80 fffffa8002cc2510<br>&gt; 0000000000000000 0000000000000000 : fltmgr!FltGetFileNameInformation+0x184<br>&gt; 90 fffff88001197035 : fffffa8002cb94b0 fffffa8002cd0f20
> fffffa8002cbece0 fffff80001000102 : minifilter2!GetHeader+0x31424
> a0 fffff88001196ee7 : 0000000000000001 0000000000000000<br>&gt; fffffa8002cc2510 fffff880009a6d38 :<br>&gt; fltmgr!FltpCallOpenedFileNameHandler+0x75<br>&gt; 40 fffff880011aae7c : 0000000000000000 0000000000000000
> fffff80002e37280 0000000000000001 :
> fltmgr!FltpGetNormalizedFileNameWorker+0x27
> 40 fffff880011a2dcd : 0000000000000000 fffff80002e37280<br>&gt; fffffa80024df660 0000000000000001 :<br>&gt; fltmgr!FltpGetNormalizedFileNameImpersonate+0x3c<br>&gt; 40 fffff80002c9b261 : fffff880011a2da0 fffff80002e37201
> fffffa80024df600 0000000000000003 : fltmgr!FltpSyncOpWorker+0x2d
> 40 fffff80002f2fbae : 0000000000000000 fffffa80024df660<br>&gt; 0000000000000080 fffffa800245bb30 : nt!ExpWorkerThread+0x111<br>&gt; 90 fffff80002c828c6 : fffff880009e9180 fffffa80024df660
> fffffa80024dfb50 0000000000000000 : nt!PspSystemThreadStartup+0x5a
> 40 0000000000000000 : fffff8800359e000 fffff88003598000<br>&gt; fffff8800359d9e0 00000000`00000000 : nt!KiStartSystemThread+0x16
>
>
> On Thu, Apr 17, 2014 at 10:12 PM, Alex Carp wrote:
>
>> Well, I think the problem is that the volume is mounted and some filters
>> have been initialized (in your example, the file system and Minifilter2 are
>> initialized and ready to go) so it depends on who you ask… I can’t think
>> of anything a legacy filter could do to figure out if minifilters above it
>> have completed instance setup. Perhaps someone else on the list has done
>> more work in this space and might be able to offer better suggestions
>>
>> When you get the stack, please do a “kb f 100” command to show all the
>> functions and their stack usage.
>>
>> Thanks,
>> Alex.
>>
>>
>> On Thu, Apr 17, 2014 at 8:50 AM, Dhananjay Kumar <
>> xxxxx@gmail.com> wrote:
>>
>>> I can post the stack but right now I don’t have access to the dump, but
>>> yes if I call this API KeExpandKernelStackAndCalloutEx from the legacy
>>> filter driver before opening the “file” to expand the stack size things
>>> work fine as Fltmgr does not post a worker thread.
>>>
>>> Can I check in Legacy filter driver to not do IO on a volume which is
>>> not mounted yet?
>>>
>>>
>>> On Thu, Apr 17, 2014 at 8:02 PM, Alex Carp >>> > wrote:
>>>
>>>> Yes, it is ok for minifilters to do IO in their instance setup
>>>> callbacks, as long as they don’t violate layering.
>>>>
>>>> I’m surprised to hear that FltMgr posted something to a different
>>>> thread that is waiting forever. Could you please post a stack ?
>>>>
>>>> Thanks,
>>>> Alex.
>>>>
>>>>
>>>> On Thu, Apr 17, 2014 at 6:02 AM, wrote:
>>>>
>>>>> Hi,
>>>>> I am new to file system filter driver development and this my first
>>>>> post on OSR. I am seeing a hang where there are 2 minifilters and a legacy
>>>>> filter. So the file system stack is like this.
>>>>>
>>>>> Minifilter1
>>>>> Legacy Filter
>>>>> Minifilter2
>>>>>
>>>>> Minifilter1 is calling FltpGetVolumeFromName from its
>>>>> instancesetupcallback. This results in an IO on \Windows directory which is
>>>>> seen by the legacy filter driver below minifilter1. Now this legacy filter
>>>>> does some IO as part of its init(it’s opening a file) which goes to
>>>>> minifilter2 which is scanning the file. This scanning has been posted to a
>>>>> worker thread(by Fltmgr due to low stack space) which waits forever as
>>>>> instancesetupcallback is not complete.
>>>>>
>>>>> As far as I know legacy filter has no way to know that it has been
>>>>> called during instancesetupcallback so it can’t avoid that IO(the opening
>>>>> of a file).
>>>>>
>>>>> My question is:
>>>>> 1. Is it ok for minifilters to do IO from their instancesetupcallbacks
>>>>> as I have read in a blog that this leads to some known hangs.
>>>>>
>>>>> Thanks
>>>>>
>>>>> —
>>>>> NTFSD is sponsored by OSR
>>>>>
>>>>> OSR is hiring!! Info at http://www.osr.com/careers
>>>>>
>>>>> 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
>>>>>
>>>>
>>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>>> http://www.osr.com/careers 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
>>>>
>>>
>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>> http://www.osr.com/careers 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
>>>
>>
>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>> http://www.osr.com/careers 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
>>
>
> — NTFSD is sponsored by OSR OSR is hiring!! Info at
> http://www.osr.com/careers 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
>

Hi Alex,

My filter driver is the LegacyFilter mentioned in the stack trace…

Thanks

Why in the world are you doing a legacy filter?

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 Dhananjay Kumar
Sent: Monday, April 21, 2014 12:44 PM
To: Windows File Systems Devs Interest List
Subject: Re: [ntfsd] [newbie question]doing I/O in instancesetupcallback

Hi Alex,

My filter driver is the LegacyFilter mentioned in the stack trace…

Thanks
— NTFSD is sponsored by OSR OSR is hiring!! Info at http://www.osr.com/careers 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

Don has a really good point, and if you’re writing this from scratch or
modifying it extensively, definitely do a minifilter.

However, if you can’t or won’t then there are some strategies you can do:

  1. Why do you issue an IRP_MJ_CREATE on both threads ? Do you do that for
    every create ? Your original post states “Now this legacy filter does some
    IO as part of its init(it’s opening a file)” which makes me think that you
    don’t really need to do this the second time around (on the second thread)
    and perhaps you could just let this IRP_MJ_CREATE from Minifilter2 slide…
    I’m not familiar enough with your design…
  2. I don’t understand why on the second thread your IRP_MJ_CREATE ends up
    in FltpDoFilterNotificationForNewVolume, because minifilter1 and
    minifilter2 should be in different frames and in general frames are
    independent filters, so frame0 (where minifilter2 is) should already be
    initialized so your IRP_MJ_CREATE shouldn’t need frame0 to call its
    FltpDoFilterNotificationForNewVolume function. Now, there are some cases
    where FltMgr will look at other frames and this might be one such case (and
    frankly I can’t tell without some serious debugging), but please verify
    that the IRP_MJ_CREATE you issue on the second thread is targeted properly
    and it’s not somehow getting sent to the top of the stack.
  3. Finally, you could change the load order of your filter to be above
    minifilter1 (or even below minifilter2). In general performance and stack
    usage improve when minifilters are all in the same frame (less converting
    between IRPs and FLT_CALLBACK_DATA and also the callback model saves some
    space).

I don’t know enough about your particular scenario (what does your filter
do, what do minifilter1 and minifilter2 do and whether the load order can
be changed without serious problems) so I’m not sure if any of these
suggests actually could work for you, but hopefully something will :).

Thanks,
Alex.

On Mon, Apr 21, 2014 at 9:48 AM, Don Burn wrote:

> Why in the world are you doing a legacy filter?
>
>
> 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 Dhananjay Kumar
> Sent: Monday, April 21, 2014 12:44 PM
> To: Windows File Systems Devs Interest List
> Subject: Re: [ntfsd] [newbie question]doing I/O in instancesetupcallback
>
> Hi Alex,
>
> My filter driver is the LegacyFilter mentioned in the stack trace…
>
> Thanks
> — NTFSD is sponsored by OSR OSR is hiring!! Info at
> http://www.osr.com/careers 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
>
>
> —
> NTFSD is sponsored by OSR
>
> OSR is hiring!! Info at http://www.osr.com/careers
>
> 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
>

Don, Alex,
Thank you for your patience in working with me. The legacy aspect of driver
is something that is not under my control this stuff is legacy.

  1. Why do you issue an IRP_MJ_CREATE on both threads ? Do you do that for
    every create ?
    There is no new create issued by the legacy driver in the second thread
    that thread is spawned by
    FLTMGR to get the normalized name as part of FltGetFilenameinformation and
    we are just passing it to the next driver.

In brief the problem is

As part of System initialization
IoInitSystem does a create on Pagefile.sys
which triggers an Acquisition of Instance setup lock and invocation of
Minifilter1.sys instancesetupcallback
this triggers a create on C:\windows, in context of this create,
lagacydriver will open a log file
(this is part of initialization and happens just once). This create of our
own log file will result in
the create being sent to Minifilter2 and it invokes
FltGetFilenameinformation which triggers it to be posted.

In thread2 we see the request has been posted to the top of the stack and
legacydriver simply lets the create go through.
No new creates by legacydriver on that thread.

  1. I don’t understand why on the second thread your IRP_MJ_CREATE ends up
    in FltpDoFilterNotificationForNewVolume, because minifilter1 and
    minifilter2 should be in different frames and in general frames are
    independent filters, so frame0 (where minifilter2 is) should already be
    initialized so your IRP_MJ_CREATE shouldn’t need frame0 to call its
    FltpDoFilterNotificationForNewVolume function.
    I wanted to clarify one part here,

!fltkd.filters

Filter List: fffffa8002758b70 “Frame 0”
FLT_FILTER: fffffa800291da30 “Minifilter1” “321XXX.00”
FLT_INSTANCE: fffffa8002b45bb0 “Minifilter1” “321XXX.00”
FLT_FILTER: fffffa80028f7010 “Minifilter2” “146XXX”
FLT_INSTANCE: fffffa8002a42010 “Minifilter2 Instance” “146XXX”
FLT_INSTANCE: fffffa8002b45010 “Minifilter2 Instance” “146XXX”
FLT_FILTER: fffffa800275c010 “FileInfo” “45000”
FLT_INSTANCE: fffffa8002a3a960 “FileInfo” “45000”
FLT_INSTANCE: fffffa8002a41bb0 “FileInfo” “45000”
FLT_INSTANCE: fffffa8002b46bb0 “FileInfo” “45000”
FLT_INSTANCE: fffffa8002b43bb0 “FileInfo” “45000”

and so the drivers are all below legacydriver.

LegacyFilter
Minifilter1
Minifilter2

Sorry for the misinformation earlier.

  1. Finally, you could change the load order of your filter to be above
    minifilter1 (or even below minifilter2). In general performance and stack
    usage improve when minifilters are all in the same frame (less converting
    between IRPs and FLT_CALLBACK_DATA and also the callback model saves some
    space).

We are already above, minifilter1 and we cant be below minifilter2 because
it is an encryption driver,
what we have in mind is to let the first create complete and do our
initialization once things are ‘stable’

Having said that, I was curious, I have always felt that taking a global
system wide lock and doing I/O is not a good idea(?) and can cause
re-entrency
issues. Do let me know what you think.

Regards,
Dhananjay

On Tue, Apr 22, 2014 at 8:10 PM, Alex Carp wrote:

> Don has a really good point, and if you’re writing this from scratch or
> modifying it extensively, definitely do a minifilter.
>
> However, if you can’t or won’t then there are some strategies you can do:
> 1. Why do you issue an IRP_MJ_CREATE on both threads ? Do you do that for
> every create ? Your original post states “Now this legacy filter does
> some IO as part of its init(it’s opening a file)” which makes me think
> that you don’t really need to do this the second time around (on the second
> thread) and perhaps you could just let this IRP_MJ_CREATE from Minifilter2
> slide… I’m not familiar enough with your design…
> 2. I don’t understand why on the second thread your IRP_MJ_CREATE ends up
> in FltpDoFilterNotificationForNewVolume, because minifilter1 and
> minifilter2 should be in different frames and in general frames are
> independent filters, so frame0 (where minifilter2 is) should already be
> initialized so your IRP_MJ_CREATE shouldn’t need frame0 to call its
> FltpDoFilterNotificationForNewVolume function. Now, there are some cases
> where FltMgr will look at other frames and this might be one such case (and
> frankly I can’t tell without some serious debugging), but please verify
> that the IRP_MJ_CREATE you issue on the second thread is targeted properly
> and it’s not somehow getting sent to the top of the stack.
> 3. Finally, you could change the load order of your filter to be above
> minifilter1 (or even below minifilter2). In general performance and stack
> usage improve when minifilters are all in the same frame (less converting
> between IRPs and FLT_CALLBACK_DATA and also the callback model saves some
> space).
>
> I don’t know enough about your particular scenario (what does your filter
> do, what do minifilter1 and minifilter2 do and whether the load order can
> be changed without serious problems) so I’m not sure if any of these
> suggests actually could work for you, but hopefully something will :).
>
> Thanks,
> Alex.
>
>
> On Mon, Apr 21, 2014 at 9:48 AM, Don Burn wrote:
>
>> Why in the world are you doing a legacy filter?
>>
>>
>> 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 Dhananjay Kumar
>> Sent: Monday, April 21, 2014 12:44 PM
>> To: Windows File Systems Devs Interest List
>> Subject: Re: [ntfsd] [newbie question]doing I/O in instancesetupcallback
>>
>> Hi Alex,
>>
>> My filter driver is the LegacyFilter mentioned in the stack trace…
>>
>> Thanks
>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>> http://www.osr.com/careers 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
>>
>>
>> —
>> NTFSD is sponsored by OSR
>>
>> OSR is hiring!! Info at http://www.osr.com/careers
>>
>> 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
>>
>
> — NTFSD is sponsored by OSR OSR is hiring!! Info at
> http://www.osr.com/careers 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
>

I’m still a little confused about what’s going on. You say that
LegacyFilter is on the top of the stack, above Minifilter1 and Minifilter2.
But you also said this:
“As part of System initialization
IoInitSystem does a create on Pagefile.sys
which triggers an Acquisition of Instance setup lock and invocation of
Minifilter1.sys instancesetupcallback
this triggers a create on C:\windows, in context of this create,
lagacydriver will open a log file
(this is part of initialization and happens just once). This create of our
own log file will result in
the create being sent to Minifilter2 and it invokes
FltGetFilenameinformation which triggers it to be posted.”

So the creation of the Pagefile should be the first operation LegacyFilter
sees. I don’t understand why "Minifilter1.sys instancesetupcallback
this triggers a create on C:\windows, in context of this create,
lagacydriver will open a log file ". Why does LegacyDriver see the create
on C:\windows that Minifilter1 issues ? If LegacyDriver is above
Minifilter1 then it shouldn’t see the create at all, unless Minifilter1
violates layering and sends the create to the top.

“I have always felt that taking a global system wide lock and doing I/O is
not a good idea(?) and can cause re-entrency issues.” - You’re absolutely
right. Unfortunately it is sometimes unavoidable, and in particular with
the InstanceSetup callbacks and serialization I feel that FltMgr decided to
swallow the complexity (or as much as possible) and offer the semantics
that filters want with respect to InstanceSetup (the ability to do IO from
it and the guarantee that no IO will pass by the filter before its instance
is set up).

Since you mention that the file LegacyDriver creates is a log file, perhaps
you could keep the log in memory and then just create the file once the
first create on the volume completes ? I guess this is the thing you meant
when you said “what we have in mind is to let the first create complete and
do our initialization once things are ‘stable’” and if all you need is
logging then this approach should work (with the caveat that your logging
infrastructure will be a little more complex with the extra buffer; on the
plus side it might be better for performance if you log to a buffer and
periodically flush it from memory in a low-priority thread).

Also, as an aside, your legacy filter is using a ridiculous amount of
stack, almost 3k…

Thanks,
Alex.

On Thu, Apr 24, 2014 at 8:17 AM, Dhananjay Kumar > wrote:

> Don, Alex,
> Thank you for your patience in working with me. The legacy aspect of
> driver is something that is not under my control this stuff is legacy.
>
> 1. Why do you issue an IRP_MJ_CREATE on both threads ? Do you do that for
> every create ?
> There is no new create issued by the legacy driver in the second thread
> that thread is spawned by
> FLTMGR to get the normalized name as part of FltGetFilenameinformation and
> we are just passing it to the next driver.
>
> In brief the problem is
>
> As part of System initialization
> IoInitSystem does a create on Pagefile.sys
> which triggers an Acquisition of Instance setup lock and invocation of
> Minifilter1.sys instancesetupcallback
> this triggers a create on C:\windows, in context of this create,
> lagacydriver will open a log file
> (this is part of initialization and happens just once). This create of our
> own log file will result in
> the create being sent to Minifilter2 and it invokes
> FltGetFilenameinformation which triggers it to be posted.
>
> In thread2 we see the request has been posted to the top of the stack and
> legacydriver simply lets the create go through.
> No new creates by legacydriver on that thread.
>
>
> 2. I don’t understand why on the second thread your IRP_MJ_CREATE ends up
> in FltpDoFilterNotificationForNewVolume, because minifilter1 and
> minifilter2 should be in different frames and in general frames are
> independent filters, so frame0 (where minifilter2 is) should already be
> initialized so your IRP_MJ_CREATE shouldn’t need frame0 to call its
> FltpDoFilterNotificationForNewVolume function.
> I wanted to clarify one part here,
>
> !fltkd.filters
>
> Filter List: fffffa8002758b70 “Frame 0”
> FLT_FILTER: fffffa800291da30 “Minifilter1” “321XXX.00”
> FLT_INSTANCE: fffffa8002b45bb0 “Minifilter1” “321XXX.00”
> FLT_FILTER: fffffa80028f7010 “Minifilter2” “146XXX”
> FLT_INSTANCE: fffffa8002a42010 “Minifilter2 Instance” “146XXX”
> FLT_INSTANCE: fffffa8002b45010 “Minifilter2 Instance” “146XXX”
> FLT_FILTER: fffffa800275c010 “FileInfo” “45000”
> FLT_INSTANCE: fffffa8002a3a960 “FileInfo” “45000”
> FLT_INSTANCE: fffffa8002a41bb0 “FileInfo” “45000”
> FLT_INSTANCE: fffffa8002b46bb0 “FileInfo” “45000”
> FLT_INSTANCE: fffffa8002b43bb0 “FileInfo” “45000”
>
> and so the drivers are all below legacydriver.
>
> LegacyFilter
> Minifilter1
> Minifilter2
>
> Sorry for the misinformation earlier.
>
> 3. Finally, you could change the load order of your filter to be above
> minifilter1 (or even below minifilter2). In general performance and stack
> usage improve when minifilters are all in the same frame (less converting
> between IRPs and FLT_CALLBACK_DATA and also the callback model saves some
> space).
>
> We are already above, minifilter1 and we cant be below minifilter2 because
> it is an encryption driver,
> what we have in mind is to let the first create complete and do our
> initialization once things are ‘stable’
>
> Having said that, I was curious, I have always felt that taking a global
> system wide lock and doing I/O is not a good idea(?) and can cause
> re-entrency
> issues. Do let me know what you think.
>
> Regards,
> Dhananjay
>
>
>
> On Tue, Apr 22, 2014 at 8:10 PM, Alex Carp wrote:
>
>> Don has a really good point, and if you’re writing this from scratch or
>> modifying it extensively, definitely do a minifilter.
>>
>> However, if you can’t or won’t then there are some strategies you can do:
>> 1. Why do you issue an IRP_MJ_CREATE on both threads ? Do you do that for
>> every create ? Your original post states “Now this legacy filter does
>> some IO as part of its init(it’s opening a file)” which makes me think
>> that you don’t really need to do this the second time around (on the second
>> thread) and perhaps you could just let this IRP_MJ_CREATE from Minifilter2
>> slide… I’m not familiar enough with your design…
>> 2. I don’t understand why on the second thread your IRP_MJ_CREATE ends up
>> in FltpDoFilterNotificationForNewVolume, because minifilter1 and
>> minifilter2 should be in different frames and in general frames are
>> independent filters, so frame0 (where minifilter2 is) should already be
>> initialized so your IRP_MJ_CREATE shouldn’t need frame0 to call its
>> FltpDoFilterNotificationForNewVolume function. Now, there are some cases
>> where FltMgr will look at other frames and this might be one such case (and
>> frankly I can’t tell without some serious debugging), but please verify
>> that the IRP_MJ_CREATE you issue on the second thread is targeted properly
>> and it’s not somehow getting sent to the top of the stack.
>> 3. Finally, you could change the load order of your filter to be above
>> minifilter1 (or even below minifilter2). In general performance and stack
>> usage improve when minifilters are all in the same frame (less converting
>> between IRPs and FLT_CALLBACK_DATA and also the callback model saves some
>> space).
>>
>> I don’t know enough about your particular scenario (what does your filter
>> do, what do minifilter1 and minifilter2 do and whether the load order can
>> be changed without serious problems) so I’m not sure if any of these
>> suggests actually could work for you, but hopefully something will :).
>>
>> Thanks,
>> Alex.
>>
>>
>> On Mon, Apr 21, 2014 at 9:48 AM, Don Burn wrote:
>>
>>> Why in the world are you doing a legacy filter?
>>>
>>>
>>> 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 Dhananjay Kumar
>>> Sent: Monday, April 21, 2014 12:44 PM
>>> To: Windows File Systems Devs Interest List
>>> Subject: Re: [ntfsd] [newbie question]doing I/O in instancesetupcallback
>>>
>>> Hi Alex,
>>>
>>> My filter driver is the LegacyFilter mentioned in the stack trace…
>>>
>>> Thanks
>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>> http://www.osr.com/careers 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
>>>
>>>
>>> —
>>> NTFSD is sponsored by OSR
>>>
>>> OSR is hiring!! Info at http://www.osr.com/careers
>>>
>>> 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
>>>
>>
>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>> http://www.osr.com/careers 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
>>
>
> — NTFSD is sponsored by OSR OSR is hiring!! Info at
> http://www.osr.com/careers 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
>

Alex,
Thank you for your reply

  1. I don’t know why I am getting an IRP_MJ_CREATE for a FILE_OBJECT with
    the name of \Windows\ in
    my LegacyFilter dispatch routine from Minifilter1. From what I know
    FltGetVolumeFromName does a ZwCreateFile on
    the device which is sent to the top of the stack`maybe that’s why. In my
    first post I mentioned wrong device stack
    because Minifilter1 CREATE was being seen by LegacyFilter. But after seeing
    in !fltkd.filters both
    Minifilter1 and Minifilter2 were present in Frame0 of the Filter Manager.
    This was the reason for
    the misinformation earlier.

  2. You mentioned that no IO will bypass a minifilter before it’s
    instancesetup is complete. But then again things don’t stack
    up for me. Why is the Create of the “logfile” being seen by Minifilter2
    when Minifilter1 is above it and it’s instancesetup is
    not complete yet.

  3. Yes I accept LegacyFilter is using a lot of stack 3KB. But considering
    the size of kernel stack
    on a 64-bit machine which is 24 Kb it is not much. But that is due to many
    layers of overlapping in
    our dispatch routines and it has been that way from the beginning.

Regards,
Dhananjay

On Fri, Apr 25, 2014 at 12:37 AM, Alex Carp wrote:

> I’m still a little confused about what’s going on. You say that
> LegacyFilter is on the top of the stack, above Minifilter1 and Minifilter2.
> But you also said this:
> “As part of System initialization
> IoInitSystem does a create on Pagefile.sys
> which triggers an Acquisition of Instance setup lock and invocation of
> Minifilter1.sys instancesetupcallback
> this triggers a create on C:\windows, in context of this create,
> lagacydriver will open a log file
> (this is part of initialization and happens just once). This create of our
> own log file will result in
> the create being sent to Minifilter2 and it invokes
> FltGetFilenameinformation which triggers it to be posted.”
>
> So the creation of the Pagefile should be the first operation LegacyFilter
> sees. I don’t understand why "Minifilter1.sys instancesetupcallback
> this triggers a create on C:\windows, in context of this create,
> lagacydriver will open a log file ". Why does LegacyDriver see the create
> on C:\windows that Minifilter1 issues ? If LegacyDriver is above
> Minifilter1 then it shouldn’t see the create at all, unless Minifilter1
> violates layering and sends the create to the top.
>
> “I have always felt that taking a global system wide lock and doing I/O is
> not a good idea(?) and can cause re-entrency issues.” - You’re absolutely
> right. Unfortunately it is sometimes unavoidable, and in particular with
> the InstanceSetup callbacks and serialization I feel that FltMgr decided to
> swallow the complexity (or as much as possible) and offer the semantics
> that filters want with respect to InstanceSetup (the ability to do IO from
> it and the guarantee that no IO will pass by the filter before its instance
> is set up).
>
> Since you mention that the file LegacyDriver creates is a log file,
> perhaps you could keep the log in memory and then just create the file once
> the first create on the volume completes ? I guess this is the thing you
> meant when you said “what we have in mind is to let the first create
> complete and do our initialization once things are ‘stable’” and if all you
> need is logging then this approach should work (with the caveat that your
> logging infrastructure will be a little more complex with the extra buffer;
> on the plus side it might be better for performance if you log to a buffer
> and periodically flush it from memory in a low-priority thread).
>
> Also, as an aside, your legacy filter is using a ridiculous amount of
> stack, almost 3k…
>
> Thanks,
> Alex.
>
>
>
> On Thu, Apr 24, 2014 at 8:17 AM, Dhananjay Kumar <
> xxxxx@gmail.com> wrote:
>
>> Don, Alex,
>> Thank you for your patience in working with me. The legacy aspect of
>> driver is something that is not under my control this stuff is legacy.
>>
>> 1. Why do you issue an IRP_MJ_CREATE on both threads ? Do you do that for
>> every create ?
>> There is no new create issued by the legacy driver in the second thread
>> that thread is spawned by
>> FLTMGR to get the normalized name as part of FltGetFilenameinformation
>> and we are just passing it to the next driver.
>>
>> In brief the problem is
>>
>> As part of System initialization
>> IoInitSystem does a create on Pagefile.sys
>> which triggers an Acquisition of Instance setup lock and invocation of
>> Minifilter1.sys instancesetupcallback
>> this triggers a create on C:\windows, in context of this create,
>> lagacydriver will open a log file
>> (this is part of initialization and happens just once). This create of
>> our own log file will result in
>> the create being sent to Minifilter2 and it invokes
>> FltGetFilenameinformation which triggers it to be posted.
>>
>> In thread2 we see the request has been posted to the top of the stack and
>> legacydriver simply lets the create go through.
>> No new creates by legacydriver on that thread.
>>
>>
>> 2. I don’t understand why on the second thread your IRP_MJ_CREATE ends up
>> in FltpDoFilterNotificationForNewVolume, because minifilter1 and
>> minifilter2 should be in different frames and in general frames are
>> independent filters, so frame0 (where minifilter2 is) should already be
>> initialized so your IRP_MJ_CREATE shouldn’t need frame0 to call its
>> FltpDoFilterNotificationForNewVolume function.
>> I wanted to clarify one part here,
>>
>> !fltkd.filters
>>
>> Filter List: fffffa8002758b70 “Frame 0”
>> FLT_FILTER: fffffa800291da30 “Minifilter1” “321XXX.00”
>> FLT_INSTANCE: fffffa8002b45bb0 “Minifilter1” “321XXX.00”
>> FLT_FILTER: fffffa80028f7010 “Minifilter2” “146XXX”
>> FLT_INSTANCE: fffffa8002a42010 “Minifilter2 Instance” “146XXX”
>> FLT_INSTANCE: fffffa8002b45010 “Minifilter2 Instance” “146XXX”
>> FLT_FILTER: fffffa800275c010 “FileInfo” “45000”
>> FLT_INSTANCE: fffffa8002a3a960 “FileInfo” “45000”
>> FLT_INSTANCE: fffffa8002a41bb0 “FileInfo” “45000”
>> FLT_INSTANCE: fffffa8002b46bb0 “FileInfo” “45000”
>> FLT_INSTANCE: fffffa8002b43bb0 “FileInfo” “45000”
>>
>> and so the drivers are all below legacydriver.
>>
>> LegacyFilter
>> Minifilter1
>> Minifilter2
>>
>> Sorry for the misinformation earlier.
>>
>> 3. Finally, you could change the load order of your filter to be above
>> minifilter1 (or even below minifilter2). In general performance and stack
>> usage improve when minifilters are all in the same frame (less converting
>> between IRPs and FLT_CALLBACK_DATA and also the callback model saves some
>> space).
>>
>> We are already above, minifilter1 and we cant be below minifilter2
>> because it is an encryption driver,
>> what we have in mind is to let the first create complete and do our
>> initialization once things are ‘stable’
>>
>> Having said that, I was curious, I have always felt that taking a global
>> system wide lock and doing I/O is not a good idea(?) and can cause
>> re-entrency
>> issues. Do let me know what you think.
>>
>> Regards,
>> Dhananjay
>>
>>
>>
>> On Tue, Apr 22, 2014 at 8:10 PM, Alex Carp wrote:
>>
>>> Don has a really good point, and if you’re writing this from scratch or
>>> modifying it extensively, definitely do a minifilter.
>>>
>>> However, if you can’t or won’t then there are some strategies you can do:
>>> 1. Why do you issue an IRP_MJ_CREATE on both threads ? Do you do that
>>> for every create ? Your original post states “Now this legacy filter
>>> does some IO as part of its init(it’s opening a file)” which makes me
>>> think that you don’t really need to do this the second time around (on the
>>> second thread) and perhaps you could just let this IRP_MJ_CREATE from
>>> Minifilter2 slide… I’m not familiar enough with your design…
>>> 2. I don’t understand why on the second thread your IRP_MJ_CREATE ends
>>> up in FltpDoFilterNotificationForNewVolume, because minifilter1 and
>>> minifilter2 should be in different frames and in general frames are
>>> independent filters, so frame0 (where minifilter2 is) should already be
>>> initialized so your IRP_MJ_CREATE shouldn’t need frame0 to call its
>>> FltpDoFilterNotificationForNewVolume function. Now, there are some
>>> cases where FltMgr will look at other frames and this might be one such
>>> case (and frankly I can’t tell without some serious debugging), but please
>>> verify that the IRP_MJ_CREATE you issue on the second thread is targeted
>>> properly and it’s not somehow getting sent to the top of the stack.
>>> 3. Finally, you could change the load order of your filter to be above
>>> minifilter1 (or even below minifilter2). In general performance and stack
>>> usage improve when minifilters are all in the same frame (less converting
>>> between IRPs and FLT_CALLBACK_DATA and also the callback model saves some
>>> space).
>>>
>>> I don’t know enough about your particular scenario (what does your
>>> filter do, what do minifilter1 and minifilter2 do and whether the load
>>> order can be changed without serious problems) so I’m not sure if any of
>>> these suggests actually could work for you, but hopefully something will :).
>>>
>>> Thanks,
>>> Alex.
>>>
>>>
>>> On Mon, Apr 21, 2014 at 9:48 AM, Don Burn wrote:
>>>
>>>> Why in the world are you doing a legacy filter?
>>>>
>>>>
>>>> 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 Dhananjay Kumar
>>>> Sent: Monday, April 21, 2014 12:44 PM
>>>> To: Windows File Systems Devs Interest List
>>>> Subject: Re: [ntfsd] [newbie question]doing I/O in instancesetupcallback
>>>>
>>>> Hi Alex,
>>>>
>>>> My filter driver is the LegacyFilter mentioned in the stack trace…
>>>>
>>>> Thanks
>>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>>> http://www.osr.com/careers 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
>>>>
>>>>
>>>> —
>>>> NTFSD is sponsored by OSR
>>>>
>>>> OSR is hiring!! Info at http://www.osr.com/careers
>>>>
>>>> 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
>>>>
>>>
>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>> http://www.osr.com/careers 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
>>>
>>
>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>> http://www.osr.com/careers 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
>>
>
> — NTFSD is sponsored by OSR OSR is hiring!! Info at
> http://www.osr.com/careers 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
>

Hmm… so this gives me some ideas.
Since FltGetVolumeFromName does a volume open (i missed this but you’re
right, that’s why your filter sees the create), perhaps you could ignore
volume opens in your filter (normally I’d say look at FO_VOLUME_OPEN but
since you’re a legacy filter, see this post:
http://www.osronline.com/showThread.cfm?link=77301). You could probably
quickly do this as a test and see if it changes things.

To address your second question, InstanceSetup is called in reverse order,
lowest altitude to highest. So in your example, FileInfo would be called
first, then Minifilter2 and then Minifilter1. This means that each
minifilter’s InstanceSetup can expect that all the filters below are
properly initialized, which is a requirement for being able to do IO from
InstanceSetup. So Minifilter2 is set up at this point and it’s processing
the create of the log file like it normally does. However, the point you
bring up is a good one, why isn’t your create get stuck on
FltpDoFilterNotificationForNewVolume() for Minifilter1? Do you copy the
ECPs from the original volume open create to the create you issue ?
Actually, no, I can see you’re calling NtCreateFile which doesn’t allow you
to do that…
I guess it’s because the lock used by FltpDoFilterNotificationForNewVolume()
is an ERESOURCE and it can be acquired recursively so perhaps FltMgr does
that, though I’m not sure why it wouldn’t wait for InstanceSetup() to be
complete in this case anyway.

Yeah, I agree that 3k isn’t probably the factor here and it’s most likely
to do with layering violations…

How about my suggestion from the previous mail to start the logging a
little later ? I can’t really think of anything other than your filter
ignoring some particular CREATE it shouldn’t care about (like the volume
open or the name normalization open or some such)…

Thanks,
Alex.

On Fri, Apr 25, 2014 at 3:59 AM, Dhananjay Kumar > wrote:

> Alex,
> Thank you for your reply
>
> 1. I don’t know why I am getting an IRP_MJ_CREATE for a FILE_OBJECT with
> the name of \Windows\ in
> my LegacyFilter dispatch routine from Minifilter1. From what I know
> FltGetVolumeFromName does a ZwCreateFile on
> the device which is sent to the top of the stack`maybe that’s why. In my
> first post I mentioned wrong device stack
> because Minifilter1 CREATE was being seen by LegacyFilter. But after
> seeing in !fltkd.filters both
> Minifilter1 and Minifilter2 were present in Frame0 of the Filter Manager.
> This was the reason for
> the misinformation earlier.
>
> 2. You mentioned that no IO will bypass a minifilter before it’s
> instancesetup is complete. But then again things don’t stack
> up for me. Why is the Create of the “logfile” being seen by Minifilter2
> when Minifilter1 is above it and it’s instancesetup is
> not complete yet.
>
> 3. Yes I accept LegacyFilter is using a lot of stack 3KB. But considering
> the size of kernel stack
> on a 64-bit machine which is 24 Kb it is not much. But that is due to many
> layers of overlapping in
> our dispatch routines and it has been that way from the beginning.
>
> Regards,
> Dhananjay
>
>
>
> On Fri, Apr 25, 2014 at 12:37 AM, Alex Carp wrote:
>
>> I’m still a little confused about what’s going on. You say that
>> LegacyFilter is on the top of the stack, above Minifilter1 and Minifilter2.
>> But you also said this:
>> “As part of System initialization
>> IoInitSystem does a create on Pagefile.sys
>> which triggers an Acquisition of Instance setup lock and invocation of
>> Minifilter1.sys instancesetupcallback
>> this triggers a create on C:\windows, in context of this create,
>> lagacydriver will open a log file
>> (this is part of initialization and happens just once). This create of
>> our own log file will result in
>> the create being sent to Minifilter2 and it invokes
>> FltGetFilenameinformation which triggers it to be posted.”
>>
>> So the creation of the Pagefile should be the first operation
>> LegacyFilter sees. I don’t understand why "Minifilter1.sys
>> instancesetupcallback
>> this triggers a create on C:\windows, in context of this create,
>> lagacydriver will open a log file ". Why does LegacyDriver see the create
>> on C:\windows that Minifilter1 issues ? If LegacyDriver is above
>> Minifilter1 then it shouldn’t see the create at all, unless Minifilter1
>> violates layering and sends the create to the top.
>>
>> “I have always felt that taking a global system wide lock and doing I/O
>> is not a good idea(?) and can cause re-entrency issues.” - You’re
>> absolutely right. Unfortunately it is sometimes unavoidable, and in
>> particular with the InstanceSetup callbacks and serialization I feel that
>> FltMgr decided to swallow the complexity (or as much as possible) and offer
>> the semantics that filters want with respect to InstanceSetup (the ability
>> to do IO from it and the guarantee that no IO will pass by the filter
>> before its instance is set up).
>>
>> Since you mention that the file LegacyDriver creates is a log file,
>> perhaps you could keep the log in memory and then just create the file once
>> the first create on the volume completes ? I guess this is the thing you
>> meant when you said “what we have in mind is to let the first create
>> complete and do our initialization once things are ‘stable’” and if all you
>> need is logging then this approach should work (with the caveat that your
>> logging infrastructure will be a little more complex with the extra buffer;
>> on the plus side it might be better for performance if you log to a buffer
>> and periodically flush it from memory in a low-priority thread).
>>
>> Also, as an aside, your legacy filter is using a ridiculous amount of
>> stack, almost 3k…
>>
>> Thanks,
>> Alex.
>>
>>
>>
>> On Thu, Apr 24, 2014 at 8:17 AM, Dhananjay Kumar <
>> xxxxx@gmail.com> wrote:
>>
>>> Don, Alex,
>>> Thank you for your patience in working with me. The legacy aspect of
>>> driver is something that is not under my control this stuff is legacy.
>>>
>>> 1. Why do you issue an IRP_MJ_CREATE on both threads ? Do you do that for
>>> every create ?
>>> There is no new create issued by the legacy driver in the second thread
>>> that thread is spawned by
>>> FLTMGR to get the normalized name as part of FltGetFilenameinformation
>>> and we are just passing it to the next driver.
>>>
>>> In brief the problem is
>>>
>>> As part of System initialization
>>> IoInitSystem does a create on Pagefile.sys
>>> which triggers an Acquisition of Instance setup lock and invocation of
>>> Minifilter1.sys instancesetupcallback
>>> this triggers a create on C:\windows, in context of this create,
>>> lagacydriver will open a log file
>>> (this is part of initialization and happens just once). This create of
>>> our own log file will result in
>>> the create being sent to Minifilter2 and it invokes
>>> FltGetFilenameinformation which triggers it to be posted.
>>>
>>> In thread2 we see the request has been posted to the top of the stack
>>> and legacydriver simply lets the create go through.
>>> No new creates by legacydriver on that thread.
>>>
>>>
>>> 2. I don’t understand why on the second thread your IRP_MJ_CREATE ends up
>>> in FltpDoFilterNotificationForNewVolume, because minifilter1 and
>>> minifilter2 should be in different frames and in general frames are
>>> independent filters, so frame0 (where minifilter2 is) should already be
>>> initialized so your IRP_MJ_CREATE shouldn’t need frame0 to call its
>>> FltpDoFilterNotificationForNewVolume function.
>>> I wanted to clarify one part here,
>>>
>>> !fltkd.filters
>>>
>>> Filter List: fffffa8002758b70 “Frame 0”
>>> FLT_FILTER: fffffa800291da30 “Minifilter1” “321XXX.00”
>>> FLT_INSTANCE: fffffa8002b45bb0 “Minifilter1” “321XXX.00”
>>> FLT_FILTER: fffffa80028f7010 “Minifilter2” “146XXX”
>>> FLT_INSTANCE: fffffa8002a42010 “Minifilter2 Instance” “146XXX”
>>> FLT_INSTANCE: fffffa8002b45010 “Minifilter2 Instance” “146XXX”
>>> FLT_FILTER: fffffa800275c010 “FileInfo” “45000”
>>> FLT_INSTANCE: fffffa8002a3a960 “FileInfo” “45000”
>>> FLT_INSTANCE: fffffa8002a41bb0 “FileInfo” “45000”
>>> FLT_INSTANCE: fffffa8002b46bb0 “FileInfo” “45000”
>>> FLT_INSTANCE: fffffa8002b43bb0 “FileInfo” “45000”
>>>
>>> and so the drivers are all below legacydriver.
>>>
>>> LegacyFilter
>>> Minifilter1
>>> Minifilter2
>>>
>>> Sorry for the misinformation earlier.
>>>
>>> 3. Finally, you could change the load order of your filter to be above
>>> minifilter1 (or even below minifilter2). In general performance and stack
>>> usage improve when minifilters are all in the same frame (less converting
>>> between IRPs and FLT_CALLBACK_DATA and also the callback model saves some
>>> space).
>>>
>>> We are already above, minifilter1 and we cant be below minifilter2
>>> because it is an encryption driver,
>>> what we have in mind is to let the first create complete and do our
>>> initialization once things are ‘stable’
>>>
>>> Having said that, I was curious, I have always felt that taking a global
>>> system wide lock and doing I/O is not a good idea(?) and can cause
>>> re-entrency
>>> issues. Do let me know what you think.
>>>
>>> Regards,
>>> Dhananjay
>>>
>>>
>>>
>>> On Tue, Apr 22, 2014 at 8:10 PM, Alex Carp >>> > wrote:
>>>
>>>> Don has a really good point, and if you’re writing this from scratch or
>>>> modifying it extensively, definitely do a minifilter.
>>>>
>>>> However, if you can’t or won’t then there are some strategies you can
>>>> do:
>>>> 1. Why do you issue an IRP_MJ_CREATE on both threads ? Do you do that
>>>> for every create ? Your original post states “Now this legacy filter
>>>> does some IO as part of its init(it’s opening a file)” which makes me
>>>> think that you don’t really need to do this the second time around (on the
>>>> second thread) and perhaps you could just let this IRP_MJ_CREATE from
>>>> Minifilter2 slide… I’m not familiar enough with your design…
>>>> 2. I don’t understand why on the second thread your IRP_MJ_CREATE ends
>>>> up in FltpDoFilterNotificationForNewVolume, because minifilter1 and
>>>> minifilter2 should be in different frames and in general frames are
>>>> independent filters, so frame0 (where minifilter2 is) should already be
>>>> initialized so your IRP_MJ_CREATE shouldn’t need frame0 to call its
>>>> FltpDoFilterNotificationForNewVolume function. Now, there are some
>>>> cases where FltMgr will look at other frames and this might be one such
>>>> case (and frankly I can’t tell without some serious debugging), but please
>>>> verify that the IRP_MJ_CREATE you issue on the second thread is targeted
>>>> properly and it’s not somehow getting sent to the top of the stack.
>>>> 3. Finally, you could change the load order of your filter to be above
>>>> minifilter1 (or even below minifilter2). In general performance and stack
>>>> usage improve when minifilters are all in the same frame (less converting
>>>> between IRPs and FLT_CALLBACK_DATA and also the callback model saves some
>>>> space).
>>>>
>>>> I don’t know enough about your particular scenario (what does your
>>>> filter do, what do minifilter1 and minifilter2 do and whether the load
>>>> order can be changed without serious problems) so I’m not sure if any of
>>>> these suggests actually could work for you, but hopefully something will :).
>>>>
>>>> Thanks,
>>>> Alex.
>>>>
>>>>
>>>> On Mon, Apr 21, 2014 at 9:48 AM, Don Burn wrote:
>>>>
>>>>> Why in the world are you doing a legacy filter?
>>>>>
>>>>>
>>>>> 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 Dhananjay Kumar
>>>>> Sent: Monday, April 21, 2014 12:44 PM
>>>>> To: Windows File Systems Devs Interest List
>>>>> Subject: Re: [ntfsd] [newbie question]doing I/O in
>>>>> instancesetupcallback
>>>>>
>>>>> Hi Alex,
>>>>>
>>>>> My filter driver is the LegacyFilter mentioned in the stack trace…
>>>>>
>>>>> Thanks
>>>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>>>> http://www.osr.com/careers 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
>>>>>
>>>>>
>>>>> —
>>>>> NTFSD is sponsored by OSR
>>>>>
>>>>> OSR is hiring!! Info at http://www.osr.com/careers
>>>>>
>>>>> 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
>>>>>
>>>>
>>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>>> http://www.osr.com/careers 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
>>>>
>>>
>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>> http://www.osr.com/careers 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
>>>
>>
>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>> http://www.osr.com/careers 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
>>
>
> — NTFSD is sponsored by OSR OSR is hiring!! Info at
> http://www.osr.com/careers 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
>

Hi Alex,
Thanks for your continuous help in solving the problem.

I am not seeing a volume open I mean FO_VOLUME_OPEN flag is not set in the
file_object only
FO_SYNCHRONOUS_IO is set and as I have told you it’s name is \Windows. But
in the stack we
see fltmgr!FltpGetVolumeFromName just before the Create dispatch. (not sure
why?)

You mention that InstanceSetup is called in reverse order. Is this valid in
a single frame or across
frames?. Say the driver stack is like this:

Frame1
Legacy
Frame0

Now is it guaranteed that instancesetup of all minifilters in Frame0 will
be called before miniflters in
Frame1. If it is, can you give an overview about how is this thing
implemented. I am asking this because
the first IO will reach Frame1. Now Frame1 is not aware about instancesetup
of Frame0 but it knows in
it’s frame instancesetup is not called for minifilters yet. Now, if these
minifilters don’t do an IO in
their instancesetup then won’t their instancesetup be complete before
minifilters in Frame 0 as they have
not yet received their first IO?

The design of our logging is exactly what you have mentioned where we write
to a buffer and flush that
buffer from a low-priority thread. But I am considering exactly when to
open my log file. If I open
my log file after I see the completion of first IO that my LegacyFilter
receives I can guarantee
that instancesetup of minifilters below me is called already. But what
about minifilters above me.
What if the first IO I receive is from the instancesetup of a driver above
me. I will again end up in the
same deadlock.

Thanks
Dhananjay

On Fri, Apr 25, 2014 at 8:06 PM, Alex Carp wrote:

> Hmm… so this gives me some ideas.
> Since FltGetVolumeFromName does a volume open (i missed this but you’re
> right, that’s why your filter sees the create), perhaps you could ignore
> volume opens in your filter (normally I’d say look at FO_VOLUME_OPEN but
> since you’re a legacy filter, see this post:
> http://www.osronline.com/showThread.cfm?link=77301). You could probably
> quickly do this as a test and see if it changes things.
>
> To address your second question, InstanceSetup is called in reverse order,
> lowest altitude to highest. So in your example, FileInfo would be called
> first, then Minifilter2 and then Minifilter1. This means that each
> minifilter’s InstanceSetup can expect that all the filters below are
> properly initialized, which is a requirement for being able to do IO from
> InstanceSetup. So Minifilter2 is set up at this point and it’s processing
> the create of the log file like it normally does. However, the point you
> bring up is a good one, why isn’t your create get stuck on
> FltpDoFilterNotificationForNewVolume() for Minifilter1? Do you copy the
> ECPs from the original volume open create to the create you issue ?
> Actually, no, I can see you’re calling NtCreateFile which doesn’t allow
> you to do that…
> I guess it’s because the lock used by FltpDoFilterNotificationForNewVolume()
> is an ERESOURCE and it can be acquired recursively so perhaps FltMgr does
> that, though I’m not sure why it wouldn’t wait for InstanceSetup() to be
> complete in this case anyway.
>
> Yeah, I agree that 3k isn’t probably the factor here and it’s most likely
> to do with layering violations…
>
> How about my suggestion from the previous mail to start the logging a
> little later ? I can’t really think of anything other than your filter
> ignoring some particular CREATE it shouldn’t care about (like the volume
> open or the name normalization open or some such)…
>
> Thanks,
> Alex.
>
>
>
>
>
> On Fri, Apr 25, 2014 at 3:59 AM, Dhananjay Kumar <
> xxxxx@gmail.com> wrote:
>
>> Alex,
>> Thank you for your reply
>>
>> 1. I don’t know why I am getting an IRP_MJ_CREATE for a FILE_OBJECT with
>> the name of \Windows\ in
>> my LegacyFilter dispatch routine from Minifilter1. From what I know
>> FltGetVolumeFromName does a ZwCreateFile on
>> the device which is sent to the top of the stack`maybe that’s why. In my
>> first post I mentioned wrong device stack
>> because Minifilter1 CREATE was being seen by LegacyFilter. But after
>> seeing in !fltkd.filters both
>> Minifilter1 and Minifilter2 were present in Frame0 of the Filter Manager.
>> This was the reason for
>> the misinformation earlier.
>>
>> 2. You mentioned that no IO will bypass a minifilter before it’s
>> instancesetup is complete. But then again things don’t stack
>> up for me. Why is the Create of the “logfile” being seen by Minifilter2
>> when Minifilter1 is above it and it’s instancesetup is
>> not complete yet.
>>
>> 3. Yes I accept LegacyFilter is using a lot of stack 3KB. But considering
>> the size of kernel stack
>> on a 64-bit machine which is 24 Kb it is not much. But that is due to
>> many layers of overlapping in
>> our dispatch routines and it has been that way from the beginning.
>>
>> Regards,
>> Dhananjay
>>
>>
>>
>> On Fri, Apr 25, 2014 at 12:37 AM, Alex Carp >> > wrote:
>>
>>> I’m still a little confused about what’s going on. You say that
>>> LegacyFilter is on the top of the stack, above Minifilter1 and Minifilter2.
>>> But you also said this:
>>> “As part of System initialization
>>> IoInitSystem does a create on Pagefile.sys
>>> which triggers an Acquisition of Instance setup lock and invocation of
>>> Minifilter1.sys instancesetupcallback
>>> this triggers a create on C:\windows, in context of this create,
>>> lagacydriver will open a log file
>>> (this is part of initialization and happens just once). This create of
>>> our own log file will result in
>>> the create being sent to Minifilter2 and it invokes
>>> FltGetFilenameinformation which triggers it to be posted.”
>>>
>>> So the creation of the Pagefile should be the first operation
>>> LegacyFilter sees. I don’t understand why "Minifilter1.sys
>>> instancesetupcallback
>>> this triggers a create on C:\windows, in context of this create,
>>> lagacydriver will open a log file ". Why does LegacyDriver see the create
>>> on C:\windows that Minifilter1 issues ? If LegacyDriver is above
>>> Minifilter1 then it shouldn’t see the create at all, unless Minifilter1
>>> violates layering and sends the create to the top.
>>>
>>> “I have always felt that taking a global system wide lock and doing I/O
>>> is not a good idea(?) and can cause re-entrency issues.” - You’re
>>> absolutely right. Unfortunately it is sometimes unavoidable, and in
>>> particular with the InstanceSetup callbacks and serialization I feel that
>>> FltMgr decided to swallow the complexity (or as much as possible) and offer
>>> the semantics that filters want with respect to InstanceSetup (the ability
>>> to do IO from it and the guarantee that no IO will pass by the filter
>>> before its instance is set up).
>>>
>>> Since you mention that the file LegacyDriver creates is a log file,
>>> perhaps you could keep the log in memory and then just create the file once
>>> the first create on the volume completes ? I guess this is the thing you
>>> meant when you said “what we have in mind is to let the first create
>>> complete and do our initialization once things are ‘stable’” and if all you
>>> need is logging then this approach should work (with the caveat that your
>>> logging infrastructure will be a little more complex with the extra buffer;
>>> on the plus side it might be better for performance if you log to a buffer
>>> and periodically flush it from memory in a low-priority thread).
>>>
>>> Also, as an aside, your legacy filter is using a ridiculous amount of
>>> stack, almost 3k…
>>>
>>> Thanks,
>>> Alex.
>>>
>>>
>>>
>>> On Thu, Apr 24, 2014 at 8:17 AM, Dhananjay Kumar <
>>> xxxxx@gmail.com> wrote:
>>>
>>>> Don, Alex,
>>>> Thank you for your patience in working with me. The legacy aspect of
>>>> driver is something that is not under my control this stuff is legacy.
>>>>
>>>> 1. Why do you issue an IRP_MJ_CREATE on both threads ? Do you do that
>>>> for
>>>> every create ?
>>>> There is no new create issued by the legacy driver in the second thread
>>>> that thread is spawned by
>>>> FLTMGR to get the normalized name as part of FltGetFilenameinformation
>>>> and we are just passing it to the next driver.
>>>>
>>>> In brief the problem is
>>>>
>>>> As part of System initialization
>>>> IoInitSystem does a create on Pagefile.sys
>>>> which triggers an Acquisition of Instance setup lock and invocation of
>>>> Minifilter1.sys instancesetupcallback
>>>> this triggers a create on C:\windows, in context of this create,
>>>> lagacydriver will open a log file
>>>> (this is part of initialization and happens just once). This create of
>>>> our own log file will result in
>>>> the create being sent to Minifilter2 and it invokes
>>>> FltGetFilenameinformation which triggers it to be posted.
>>>>
>>>> In thread2 we see the request has been posted to the top of the stack
>>>> and legacydriver simply lets the create go through.
>>>> No new creates by legacydriver on that thread.
>>>>
>>>>
>>>> 2. I don’t understand why on the second thread your IRP_MJ_CREATE ends
>>>> up
>>>> in FltpDoFilterNotificationForNewVolume, because minifilter1 and
>>>> minifilter2 should be in different frames and in general frames are
>>>> independent filters, so frame0 (where minifilter2 is) should already be
>>>> initialized so your IRP_MJ_CREATE shouldn’t need frame0 to call its
>>>> FltpDoFilterNotificationForNewVolume function.
>>>> I wanted to clarify one part here,
>>>>
>>>> !fltkd.filters
>>>>
>>>> Filter List: fffffa8002758b70 “Frame 0”
>>>> FLT_FILTER: fffffa800291da30 “Minifilter1” “321XXX.00”
>>>> FLT_INSTANCE: fffffa8002b45bb0 “Minifilter1” “321XXX.00”
>>>> FLT_FILTER: fffffa80028f7010 “Minifilter2” “146XXX”
>>>> FLT_INSTANCE: fffffa8002a42010 “Minifilter2 Instance” “146XXX”
>>>> FLT_INSTANCE: fffffa8002b45010 “Minifilter2 Instance” “146XXX”
>>>> FLT_FILTER: fffffa800275c010 “FileInfo” “45000”
>>>> FLT_INSTANCE: fffffa8002a3a960 “FileInfo” “45000”
>>>> FLT_INSTANCE: fffffa8002a41bb0 “FileInfo” “45000”
>>>> FLT_INSTANCE: fffffa8002b46bb0 “FileInfo” “45000”
>>>> FLT_INSTANCE: fffffa8002b43bb0 “FileInfo” “45000”
>>>>
>>>> and so the drivers are all below legacydriver.
>>>>
>>>> LegacyFilter
>>>> Minifilter1
>>>> Minifilter2
>>>>
>>>> Sorry for the misinformation earlier.
>>>>
>>>> 3. Finally, you could change the load order of your filter to be above
>>>> minifilter1 (or even below minifilter2). In general performance and
>>>> stack
>>>> usage improve when minifilters are all in the same frame (less
>>>> converting
>>>> between IRPs and FLT_CALLBACK_DATA and also the callback model saves
>>>> some
>>>> space).
>>>>
>>>> We are already above, minifilter1 and we cant be below minifilter2
>>>> because it is an encryption driver,
>>>> what we have in mind is to let the first create complete and do our
>>>> initialization once things are ‘stable’
>>>>
>>>> Having said that, I was curious, I have always felt that taking a
>>>> global system wide lock and doing I/O is not a good idea(?) and can cause
>>>> re-entrency
>>>> issues. Do let me know what you think.
>>>>
>>>> Regards,
>>>> Dhananjay
>>>>
>>>>
>>>>
>>>> On Tue, Apr 22, 2014 at 8:10 PM, Alex Carp <
>>>> xxxxx@gmail.com> wrote:
>>>>
>>>>> Don has a really good point, and if you’re writing this from scratch
>>>>> or modifying it extensively, definitely do a minifilter.
>>>>>
>>>>> However, if you can’t or won’t then there are some strategies you can
>>>>> do:
>>>>> 1. Why do you issue an IRP_MJ_CREATE on both threads ? Do you do that
>>>>> for every create ? Your original post states “Now this legacy filter
>>>>> does some IO as part of its init(it’s opening a file)” which makes me
>>>>> think that you don’t really need to do this the second time around (on the
>>>>> second thread) and perhaps you could just let this IRP_MJ_CREATE from
>>>>> Minifilter2 slide… I’m not familiar enough with your design…
>>>>> 2. I don’t understand why on the second thread your IRP_MJ_CREATE ends
>>>>> up in FltpDoFilterNotificationForNewVolume, because minifilter1 and
>>>>> minifilter2 should be in different frames and in general frames are
>>>>> independent filters, so frame0 (where minifilter2 is) should already be
>>>>> initialized so your IRP_MJ_CREATE shouldn’t need frame0 to call its
>>>>> FltpDoFilterNotificationForNewVolume function. Now, there are some
>>>>> cases where FltMgr will look at other frames and this might be one such
>>>>> case (and frankly I can’t tell without some serious debugging), but please
>>>>> verify that the IRP_MJ_CREATE you issue on the second thread is targeted
>>>>> properly and it’s not somehow getting sent to the top of the stack.
>>>>> 3. Finally, you could change the load order of your filter to be above
>>>>> minifilter1 (or even below minifilter2). In general performance and stack
>>>>> usage improve when minifilters are all in the same frame (less converting
>>>>> between IRPs and FLT_CALLBACK_DATA and also the callback model saves some
>>>>> space).
>>>>>
>>>>> I don’t know enough about your particular scenario (what does your
>>>>> filter do, what do minifilter1 and minifilter2 do and whether the load
>>>>> order can be changed without serious problems) so I’m not sure if any of
>>>>> these suggests actually could work for you, but hopefully something will :).
>>>>>
>>>>> Thanks,
>>>>> Alex.
>>>>>
>>>>>
>>>>> On Mon, Apr 21, 2014 at 9:48 AM, Don Burn wrote:
>>>>>
>>>>>> Why in the world are you doing a legacy filter?
>>>>>>
>>>>>>
>>>>>> 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 Dhananjay Kumar
>>>>>> Sent: Monday, April 21, 2014 12:44 PM
>>>>>> To: Windows File Systems Devs Interest List
>>>>>> Subject: Re: [ntfsd] [newbie question]doing I/O in
>>>>>> instancesetupcallback
>>>>>>
>>>>>> Hi Alex,
>>>>>>
>>>>>> My filter driver is the LegacyFilter mentioned in the stack trace…
>>>>>>
>>>>>> Thanks
>>>>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>>>>> http://www.osr.com/careers 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
>>>>>>
>>>>>>
>>>>>> —
>>>>>> NTFSD is sponsored by OSR
>>>>>>
>>>>>> OSR is hiring!! Info at http://www.osr.com/careers
>>>>>>
>>>>>> 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
>>>>>>
>>>>>
>>>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>>>> http://www.osr.com/careers 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
>>>>>
>>>>
>>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>>> http://www.osr.com/careers 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
>>>>
>>>
>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>> http://www.osr.com/careers 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
>>>
>>
>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>> http://www.osr.com/careers 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
>>
>
> — NTFSD is sponsored by OSR OSR is hiring!! Info at
> http://www.osr.com/careers 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
>

Hi Dhananjay,

You’re welcome, though I’m afraid I’ve not been that much help :).

I don’t know about the \Windows\ name, it’s interesting but I can’t tell
from the stack.

So InstanceSetup isn’t called in response to IO on the volume, it is called
when a filter is attached to a volume or when a volume is mounted, not on
the first IO (well, mounting actually happens on the first IO but let’s
leave that aside for now). It appears like the first IO matters in this
case because a minifilter is doing IO from its InstanceSetup, but if there
was no InstanceSetup IO then all minifilters would have their InstanceSetup
complete before seeing any IO at all… The problem is I don’t really
remember how instance setup works across multiple frames so maybe I have it
wrong, but it shouldn’t be too hard to figure out with a couple of
minifilters that print the various callbacks.

Yeah, it’s a pretty tricky problem. IMO this is all due to layering
violation in the name resolution path… I’m afraid I don’t have a better
answer… Maybe just open the log file in a separate thread ?So that you
just keep logging but never blocking IO and whenever the worker thread
manages to open the file it can flush it. In this way you will never end up
blocking the InstanceSetup path…

Thanks,
Alex.

On Tue, Apr 29, 2014 at 4:04 AM, Dhananjay Kumar > wrote:

> Hi Alex,
> Thanks for your continuous help in solving the problem.
>
> I am not seeing a volume open I mean FO_VOLUME_OPEN flag is not set in the
> file_object only
> FO_SYNCHRONOUS_IO is set and as I have told you it’s name is \Windows.
> But in the stack we
> see fltmgr!FltpGetVolumeFromName just before the Create dispatch. (not
> sure why?)
>
> You mention that InstanceSetup is called in reverse order. Is this valid
> in a single frame or across
> frames?. Say the driver stack is like this:
>
> Frame1
> Legacy
> Frame0
>
> Now is it guaranteed that instancesetup of all minifilters in Frame0 will
> be called before miniflters in
> Frame1. If it is, can you give an overview about how is this thing
> implemented. I am asking this because
> the first IO will reach Frame1. Now Frame1 is not aware about
> instancesetup of Frame0 but it knows in
> it’s frame instancesetup is not called for minifilters yet. Now, if these
> minifilters don’t do an IO in
> their instancesetup then won’t their instancesetup be complete before
> minifilters in Frame 0 as they have
> not yet received their first IO?
>
>
> The design of our logging is exactly what you have mentioned where we
> write to a buffer and flush that
> buffer from a low-priority thread. But I am considering exactly when to
> open my log file. If I open
> my log file after I see the completion of first IO that my LegacyFilter
> receives I can guarantee
> that instancesetup of minifilters below me is called already. But what
> about minifilters above me.
> What if the first IO I receive is from the instancesetup of a driver above
> me. I will again end up in the
> same deadlock.
>
> Thanks
> Dhananjay
>
>
> On Fri, Apr 25, 2014 at 8:06 PM, Alex Carp wrote:
>
>> Hmm… so this gives me some ideas.
>> Since FltGetVolumeFromName does a volume open (i missed this but you’re
>> right, that’s why your filter sees the create), perhaps you could ignore
>> volume opens in your filter (normally I’d say look at FO_VOLUME_OPEN but
>> since you’re a legacy filter, see this post:
>> http://www.osronline.com/showThread.cfm?link=77301). You could probably
>> quickly do this as a test and see if it changes things.
>>
>> To address your second question, InstanceSetup is called in reverse
>> order, lowest altitude to highest. So in your example, FileInfo would be
>> called first, then Minifilter2 and then Minifilter1. This means that
>> each minifilter’s InstanceSetup can expect that all the filters below are
>> properly initialized, which is a requirement for being able to do IO from
>> InstanceSetup. So Minifilter2 is set up at this point and it’s processing
>> the create of the log file like it normally does. However, the point you
>> bring up is a good one, why isn’t your create get stuck on
>> FltpDoFilterNotificationForNewVolume() for Minifilter1? Do you copy the
>> ECPs from the original volume open create to the create you issue ?
>> Actually, no, I can see you’re calling NtCreateFile which doesn’t allow
>> you to do that…
>> I guess it’s because the lock used by FltpDoFilterNotificationForNewVolume()
>> is an ERESOURCE and it can be acquired recursively so perhaps FltMgr does
>> that, though I’m not sure why it wouldn’t wait for InstanceSetup() to be
>> complete in this case anyway.
>>
>> Yeah, I agree that 3k isn’t probably the factor here and it’s most likely
>> to do with layering violations…
>>
>> How about my suggestion from the previous mail to start the logging a
>> little later ? I can’t really think of anything other than your filter
>> ignoring some particular CREATE it shouldn’t care about (like the volume
>> open or the name normalization open or some such)…
>>
>> Thanks,
>> Alex.
>>
>>
>>
>>
>>
>> On Fri, Apr 25, 2014 at 3:59 AM, Dhananjay Kumar <
>> xxxxx@gmail.com> wrote:
>>
>>> Alex,
>>> Thank you for your reply
>>>
>>> 1. I don’t know why I am getting an IRP_MJ_CREATE for a FILE_OBJECT with
>>> the name of \Windows\ in
>>> my LegacyFilter dispatch routine from Minifilter1. From what I know
>>> FltGetVolumeFromName does a ZwCreateFile on
>>> the device which is sent to the top of the stack`maybe that’s why. In my
>>> first post I mentioned wrong device stack
>>> because Minifilter1 CREATE was being seen by LegacyFilter. But after
>>> seeing in !fltkd.filters both
>>> Minifilter1 and Minifilter2 were present in Frame0 of the Filter
>>> Manager. This was the reason for
>>> the misinformation earlier.
>>>
>>> 2. You mentioned that no IO will bypass a minifilter before it’s
>>> instancesetup is complete. But then again things don’t stack
>>> up for me. Why is the Create of the “logfile” being seen by Minifilter2
>>> when Minifilter1 is above it and it’s instancesetup is
>>> not complete yet.
>>>
>>> 3. Yes I accept LegacyFilter is using a lot of stack 3KB. But
>>> considering the size of kernel stack
>>> on a 64-bit machine which is 24 Kb it is not much. But that is due to
>>> many layers of overlapping in
>>> our dispatch routines and it has been that way from the beginning.
>>>
>>> Regards,
>>> Dhananjay
>>>
>>>
>>>
>>> On Fri, Apr 25, 2014 at 12:37 AM, Alex Carp <
>>> xxxxx@gmail.com> wrote:
>>>
>>>> I’m still a little confused about what’s going on. You say that
>>>> LegacyFilter is on the top of the stack, above Minifilter1 and Minifilter2.
>>>> But you also said this:
>>>> “As part of System initialization
>>>> IoInitSystem does a create on Pagefile.sys
>>>> which triggers an Acquisition of Instance setup lock and invocation of
>>>> Minifilter1.sys instancesetupcallback
>>>> this triggers a create on C:\windows, in context of this create,
>>>> lagacydriver will open a log file
>>>> (this is part of initialization and happens just once). This create of
>>>> our own log file will result in
>>>> the create being sent to Minifilter2 and it invokes
>>>> FltGetFilenameinformation which triggers it to be posted.”
>>>>
>>>> So the creation of the Pagefile should be the first operation
>>>> LegacyFilter sees. I don’t understand why "Minifilter1.sys
>>>> instancesetupcallback
>>>> this triggers a create on C:\windows, in context of this create,
>>>> lagacydriver will open a log file ". Why does LegacyDriver see the create
>>>> on C:\windows that Minifilter1 issues ? If LegacyDriver is above
>>>> Minifilter1 then it shouldn’t see the create at all, unless Minifilter1
>>>> violates layering and sends the create to the top.
>>>>
>>>> “I have always felt that taking a global system wide lock and doing I/O
>>>> is not a good idea(?) and can cause re-entrency issues.” - You’re
>>>> absolutely right. Unfortunately it is sometimes unavoidable, and in
>>>> particular with the InstanceSetup callbacks and serialization I feel that
>>>> FltMgr decided to swallow the complexity (or as much as possible) and offer
>>>> the semantics that filters want with respect to InstanceSetup (the ability
>>>> to do IO from it and the guarantee that no IO will pass by the filter
>>>> before its instance is set up).
>>>>
>>>> Since you mention that the file LegacyDriver creates is a log file,
>>>> perhaps you could keep the log in memory and then just create the file once
>>>> the first create on the volume completes ? I guess this is the thing you
>>>> meant when you said “what we have in mind is to let the first create
>>>> complete and do our initialization once things are ‘stable’” and if all you
>>>> need is logging then this approach should work (with the caveat that your
>>>> logging infrastructure will be a little more complex with the extra buffer;
>>>> on the plus side it might be better for performance if you log to a buffer
>>>> and periodically flush it from memory in a low-priority thread).
>>>>
>>>> Also, as an aside, your legacy filter is using a ridiculous amount of
>>>> stack, almost 3k…
>>>>
>>>> Thanks,
>>>> Alex.
>>>>
>>>>
>>>>
>>>> On Thu, Apr 24, 2014 at 8:17 AM, Dhananjay Kumar <
>>>> xxxxx@gmail.com> wrote:
>>>>
>>>>> Don, Alex,
>>>>> Thank you for your patience in working with me. The legacy aspect of
>>>>> driver is something that is not under my control this stuff is legacy.
>>>>>
>>>>> 1. Why do you issue an IRP_MJ_CREATE on both threads ? Do you do that
>>>>> for
>>>>> every create ?
>>>>> There is no new create issued by the legacy driver in the second
>>>>> thread that thread is spawned by
>>>>> FLTMGR to get the normalized name as part of FltGetFilenameinformation
>>>>> and we are just passing it to the next driver.
>>>>>
>>>>> In brief the problem is
>>>>>
>>>>> As part of System initialization
>>>>> IoInitSystem does a create on Pagefile.sys
>>>>> which triggers an Acquisition of Instance setup lock and invocation of
>>>>> Minifilter1.sys instancesetupcallback
>>>>> this triggers a create on C:\windows, in context of this create,
>>>>> lagacydriver will open a log file
>>>>> (this is part of initialization and happens just once). This create of
>>>>> our own log file will result in
>>>>> the create being sent to Minifilter2 and it invokes
>>>>> FltGetFilenameinformation which triggers it to be posted.
>>>>>
>>>>> In thread2 we see the request has been posted to the top of the stack
>>>>> and legacydriver simply lets the create go through.
>>>>> No new creates by legacydriver on that thread.
>>>>>
>>>>>
>>>>> 2. I don’t understand why on the second thread your IRP_MJ_CREATE ends
>>>>> up
>>>>> in FltpDoFilterNotificationForNewVolume, because minifilter1 and
>>>>> minifilter2 should be in different frames and in general frames are
>>>>> independent filters, so frame0 (where minifilter2 is) should already be
>>>>> initialized so your IRP_MJ_CREATE shouldn’t need frame0 to call its
>>>>> FltpDoFilterNotificationForNewVolume function.
>>>>> I wanted to clarify one part here,
>>>>>
>>>>> !fltkd.filters
>>>>>
>>>>> Filter List: fffffa8002758b70 “Frame 0”
>>>>> FLT_FILTER: fffffa800291da30 “Minifilter1” “321XXX.00”
>>>>> FLT_INSTANCE: fffffa8002b45bb0 “Minifilter1” “321XXX.00”
>>>>> FLT_FILTER: fffffa80028f7010 “Minifilter2” “146XXX”
>>>>> FLT_INSTANCE: fffffa8002a42010 “Minifilter2 Instance” “146XXX”
>>>>> FLT_INSTANCE: fffffa8002b45010 “Minifilter2 Instance” “146XXX”
>>>>> FLT_FILTER: fffffa800275c010 “FileInfo” “45000”
>>>>> FLT_INSTANCE: fffffa8002a3a960 “FileInfo” “45000”
>>>>> FLT_INSTANCE: fffffa8002a41bb0 “FileInfo” “45000”
>>>>> FLT_INSTANCE: fffffa8002b46bb0 “FileInfo” “45000”
>>>>> FLT_INSTANCE: fffffa8002b43bb0 “FileInfo” “45000”
>>>>>
>>>>> and so the drivers are all below legacydriver.
>>>>>
>>>>> LegacyFilter
>>>>> Minifilter1
>>>>> Minifilter2
>>>>>
>>>>> Sorry for the misinformation earlier.
>>>>>
>>>>> 3. Finally, you could change the load order of your filter to be above
>>>>> minifilter1 (or even below minifilter2). In general performance and
>>>>> stack
>>>>> usage improve when minifilters are all in the same frame (less
>>>>> converting
>>>>> between IRPs and FLT_CALLBACK_DATA and also the callback model saves
>>>>> some
>>>>> space).
>>>>>
>>>>> We are already above, minifilter1 and we cant be below minifilter2
>>>>> because it is an encryption driver,
>>>>> what we have in mind is to let the first create complete and do our
>>>>> initialization once things are ‘stable’
>>>>>
>>>>> Having said that, I was curious, I have always felt that taking a
>>>>> global system wide lock and doing I/O is not a good idea(?) and can cause
>>>>> re-entrency
>>>>> issues. Do let me know what you think.
>>>>>
>>>>> Regards,
>>>>> Dhananjay
>>>>>
>>>>>
>>>>>
>>>>> On Tue, Apr 22, 2014 at 8:10 PM, Alex Carp <
>>>>> xxxxx@gmail.com> wrote:
>>>>>
>>>>>> Don has a really good point, and if you’re writing this from scratch
>>>>>> or modifying it extensively, definitely do a minifilter.
>>>>>>
>>>>>> However, if you can’t or won’t then there are some strategies you can
>>>>>> do:
>>>>>> 1. Why do you issue an IRP_MJ_CREATE on both threads ? Do you do that
>>>>>> for every create ? Your original post states “Now this legacy filter
>>>>>> does some IO as part of its init(it’s opening a file)” which makes
>>>>>> me think that you don’t really need to do this the second time around (on
>>>>>> the second thread) and perhaps you could just let this IRP_MJ_CREATE from
>>>>>> Minifilter2 slide… I’m not familiar enough with your design…
>>>>>> 2. I don’t understand why on the second thread your IRP_MJ_CREATE
>>>>>> ends up in FltpDoFilterNotificationForNewVolume, because minifilter1
>>>>>> and minifilter2 should be in different frames and in general frames are
>>>>>> independent filters, so frame0 (where minifilter2 is) should already be
>>>>>> initialized so your IRP_MJ_CREATE shouldn’t need frame0 to call its
>>>>>> FltpDoFilterNotificationForNewVolume function. Now, there are some
>>>>>> cases where FltMgr will look at other frames and this might be one such
>>>>>> case (and frankly I can’t tell without some serious debugging), but please
>>>>>> verify that the IRP_MJ_CREATE you issue on the second thread is targeted
>>>>>> properly and it’s not somehow getting sent to the top of the stack.
>>>>>> 3. Finally, you could change the load order of your filter to be
>>>>>> above minifilter1 (or even below minifilter2). In general performance and
>>>>>> stack usage improve when minifilters are all in the same frame (less
>>>>>> converting between IRPs and FLT_CALLBACK_DATA and also the callback model
>>>>>> saves some space).
>>>>>>
>>>>>> I don’t know enough about your particular scenario (what does your
>>>>>> filter do, what do minifilter1 and minifilter2 do and whether the load
>>>>>> order can be changed without serious problems) so I’m not sure if any of
>>>>>> these suggests actually could work for you, but hopefully something will :).
>>>>>>
>>>>>> Thanks,
>>>>>> Alex.
>>>>>>
>>>>>>
>>>>>> On Mon, Apr 21, 2014 at 9:48 AM, Don Burn wrote:
>>>>>>
>>>>>>> Why in the world are you doing a legacy filter?
>>>>>>>
>>>>>>>
>>>>>>> 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 Dhananjay Kumar
>>>>>>> Sent: Monday, April 21, 2014 12:44 PM
>>>>>>> To: Windows File Systems Devs Interest List
>>>>>>> Subject: Re: [ntfsd] [newbie question]doing I/O in
>>>>>>> instancesetupcallback
>>>>>>>
>>>>>>> Hi Alex,
>>>>>>>
>>>>>>> My filter driver is the LegacyFilter mentioned in the stack trace…
>>>>>>>
>>>>>>> Thanks
>>>>>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>>>>>> http://www.osr.com/careers 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
>>>>>>>
>>>>>>>
>>>>>>> —
>>>>>>> NTFSD is sponsored by OSR
>>>>>>>
>>>>>>> OSR is hiring!! Info at http://www.osr.com/careers
>>>>>>>
>>>>>>> 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
>>>>>>>
>>>>>>
>>>>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>>>>> http://www.osr.com/careers 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
>>>>>>
>>>>>
>>>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>>>> http://www.osr.com/careers 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
>>>>>
>>>>
>>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>>> http://www.osr.com/careers 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
>>>>
>>>
>>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>>> http://www.osr.com/careers 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
>>>
>>
>> — NTFSD is sponsored by OSR OSR is hiring!! Info at
>> http://www.osr.com/careers 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
>>
>
> — NTFSD is sponsored by OSR OSR is hiring!! Info at
> http://www.osr.com/careers 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
>