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
>