Multiple PostCreate and PreCleanup in minifilter

All,
I have written minifilter that tracks each open/read/write/close operation
of the file. This is for XP SP3, DDK 6.1.

*** Problem ***
I am seeing multiple OPEN/CLOSE for the same file and same process.

*** Detail ***
I have implemented PostCreate/PreRead/PreWrite/PreClose/PreCleanup. I am
ignoring PAGING_IO request in all of the callbacks. I am using
FltgetRequestorProcessID to get the PID. For the process name I am using
technique described on the OSR article.
I am creating a new context or use existing context in the PostCreate call
back. I also have counter associated with each operation to track when to
free the context. In PreCleanup I check the statistics and take appropriate
actions.
What I am seeing in my logs is that PostCreate followed by PreCleanup
followed by PostCreate. This goes on and on. In many cases
PreWrite->PreCleanup->PreWrite->PreCleanup.

Can someone please explain why I am getting multiple callback for same file
and process. Do I need to exclude any other requests?
Thank you,
-AR

>>Can someone please explain why I am getting multiple callback for same file
and process.

Isn’t that obvious, For example a flash installer calls GetTempFileName (you’ll see create, clean up, close), than it calls delete file on that, (you’ll see create, cleanup, close), it than checks for the file existence using CreateFile/or getfileattribute. After all this it proceed with the actual task of reading and writing.

So it is application behavior, you can write your custom app and verify it, having an AV or other filter before you may change this as they will open the file as well.(in this case you may see same process name or the AV process name, which depends upon AV implementation ).

Aditya

I’ll add to this that the driver stack itself can send two creates per
create. So if you fire up filetest and send a single create on an otherwise
quiescent volume, you are likely to see the create, and then another one
which seems to start as a FltCreate in FileInfo (ISTR that it is in the name
provider space).

Rod

wrote in message news:xxxxx@ntfsd…
>>>Can someone please explain why I am getting multiple callback for same
>>>file
> and process.
>
> Isn’t that obvious, For example a flash installer calls GetTempFileName
> (you’ll see create, clean up, close), than it calls delete file on that,
> (you’ll see create, cleanup, close), it than checks for the file existence
> using CreateFile/or getfileattribute. After all this it proceed with the
> actual task of reading and writing.
>
> So it is application behavior, you can write your custom app and verify
> it, having an AV or other filter before you may change this as they will
> open the file as well.(in this case you may see same process name or the
> AV process name, which depends upon AV implementation ).
>
> Aditya
>

Thank you Aditya and Rod for quick response.

Aditya, what you describing is obvious, what I am asking is not, at-least
not to me. My problem is I am seeing multiple subsequent Create and Cleanup
of same process and same file. What you describing is
create/close/create/close. My problem is create/create/create… And
cleanup/cleanup/cleanup…And Write/cleanup/write/cleanup…for every
single file access.

Also, if it was only one application, I would conclude that the application
is opening multiple handles to same file and then closing them. But the
above behavior is true for every single access of the file.

My test system has no AV or any other filter driver installed. It is a XP
SP3 install and that is it.

Rod, I don’ understand what you mean by “then another one which seems to
start as a FltCreate in FileInfo (ISTR that it is in the name provider
space)”. Can you please elaborate on that one.

Any other suggestions.
-AR

On Sat, Aug 14, 2010 at 5:50 AM, Rod Widdowson wrote:

> I’ll add to this that the driver stack itself can send two creates per
> create. So if you fire up filetest and send a single create on an otherwise
> quiescent volume, you are likely to see the create, and then another one
> which seems to start as a FltCreate in FileInfo (ISTR that it is in the name
> provider space).
>
> Rod
>
> wrote in message news:xxxxx@ntfsd…
>
> Can someone please explain why I am getting multiple callback for same
>>>> file
>>>>
>>> and process.
>>
>> Isn’t that obvious, For example a flash installer calls GetTempFileName
>> (you’ll see create, clean up, close), than it calls delete file on that,
>> (you’ll see create, cleanup, close), it than checks for the file existence
>> using CreateFile/or getfileattribute. After all this it proceed with the
>> actual task of reading and writing.
>>
>> So it is application behavior, you can write your custom app and verify
>> it, having an AV or other filter before you may change this as they will
>> open the file as well.(in this case you may see same process name or the AV
>> process name, which depends upon AV implementation ).
>>
>> Aditya
>>
>>
>
> —
> NTFSD is sponsored by OSR
>
> For our schedule of debugging and file system seminars
> (including our new fs mini-filter seminar) 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
>

> My test system has no AV or any other filter driver installed. It is a XP

SP3 install and that is it.

In that case you should be OK.

Rod, I don’ understand what you mean by “then another one which seems to
start as a FltCreate
in FileInfo (ISTR that it is in the name provider space)”. Can you please
elaborate on that one.

I was referring to the habit of the FileInfo minifilter (in Win7) to do
thing when you least expect it. For example, from one create from Filetest
I see this

MyDrv!PreCreate+0x65 [create.cpp @ 66]
fltmgr!FltvPreOperation+0x81
[d:\w7rtm\minkernel\fs\filtermgr\filter\verifiersup.c @ 2983]
fltmgr!FltpPerformPreCallbacks+0x34d
[d:\w7rtm\minkernel\fs\filtermgr\filter\callbacksup.c @ 1296]
fltmgr!FltpPassThroughInternal+0x40
[d:\w7rtm\minkernel\fs\filtermgr\filter\fltmgr.c @ 2574]
fltmgr!FltpCreateInternal+0x24
[d:\w7rtm\minkernel\fs\filtermgr\filter\fltmgr.c @ 5199]
fltmgr!FltpCreate+0x2c9 [d:\w7rtm\minkernel\fs\filtermgr\filter\fltmgr.c @
5136]
nt!IovCallDriver+0x258
nt!IofCallDriver+0x1b
nt!IopParseDevice+0xed7
nt!ObpLookupObjectName+0x4fa
nt!ObOpenObjectByName+0x165
nt!IopCreateFile+0x673
nt!NtCreateFile+0x34
nt!KiFastCallEntry+0x12a

and then:

MyDrv!PreCreate+0x65 [create.cpp @ 66]
fltmgr!FltvPreOperation+0x81
[d:\w7rtm\minkernel\fs\filtermgr\filter\verifiersup.c @ 2983]
fltmgr!FltpPerformPreCallbacks+0x34d
[d:\w7rtm\minkernel\fs\filtermgr\filter\callbacksup.c @ 1296]
fltmgr!FltpPassThroughInternal+0x40
[d:\w7rtm\minkernel\fs\filtermgr\filter\fltmgr.c @ 2574]
fltmgr!FltpCreateInternal+0x24
[d:\w7rtm\minkernel\fs\filtermgr\filter\fltmgr.c @ 5199]
fltmgr!FltReissueSynchronousIo+0x134
[d:\w7rtm\minkernel\fs\filtermgr\filter\iosup.c @ 5179]
fileinfo!FIPfFileFSOpPostCreate+0x328
fileinfo!FIPostCreateCallback+0x20c
fltmgr!FltpPerformPostCallbacks+0x24a
[d:\w7rtm\minkernel\fs\filtermgr\filter\callbacksup.c @ 2769]
fltmgr!FltpProcessIoCompletion+0x10
[d:\w7rtm\minkernel\fs\filtermgr\filter\fltmgr.c @ 3630]
fltmgr!FltpPassThroughCompletion+0x98
[d:\w7rtm\minkernel\fs\filtermgr\filter\fltmgr.c @ 3932]
fltmgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x121
[d:\w7rtm\minkernel\fs\filtermgr\filter\fltmgr.c @ 2878]
fltmgr!FltpCreate+0x2db [d:\w7rtm\minkernel\fs\filtermgr\filter\fltmgr.c @
5140]
nt!IovCallDriver+0x258
nt!IofCallDriver+0x1b
nt!IopParseDevice+0xed7
nt!ObpLookupObjectName+0x4fa
nt!ObOpenObjectByName+0x165
nt!IopCreateFile+0x673

In this case fileinfo is sending another create down. It could be any other
minifilter, but the key point is that fileinfo is one of several minifilters
which you get on a bare Win7 machine.

In Win7, you also get prefetcher creates:

MyDrv!PreCreate
fltmgr!FltvPreOperation
fltmgr!FltpPerformPreCallbacks
fltmgr!FltpPassThroughInternal
fltmgr!FltpCreateInternal
fltmgr!FltpCreate
nt!IovCallDriver
nt!IofCallDriver
nt!IopParseDevice
nt!IopParseFile
nt!ObpLookupObjectName
nt!ObOpenObjectByName
nt!IopCreateFile
nt!IoCreateFileEx
fltmgr!FltCreateFileEx2
fileinfo!FIPfInterfaceOpen
nt!PfpOpenHandleCreate
nt!PfpPrefetchDirectoryStream
nt!PfpVolumePrefetchMetadata

and ISTR that XP had some sort of prefetcher as well (its been too long
since I looked), so that might be what’s hurting…

> fltmgr!FltCreateFileEx2

fileinfo!FIPfInterfaceOpen
nt!PfpOpenHandleCreate

So, NT kernel’s prefetcher is aware of the existence of fileinfo.sys and call into it directly?


Maxim S. Shatskih
Windows DDK MVP
xxxxx@storagecraft.com
http://www.storagecraft.com

>> My problem is create/create/create

Wonder what could be that(especially as you mentioned NO AV is installed), you can probably verify it using fileTest.

I test on my XP SP3 VM, and when I said createfile test.dat at c:\test, I saw just *one* create request, when I say CloseHandle, I saw Cleanup/close. Nothing else.

Could be related to your test setup.

All,
Thank you for all the help. Please consider this thread closed.

My minifilter did not have any issues. Turns out that other driver in the
system was culprit. I was able to verify minifilter by removing all the
additional code that was doing something with the tracked record and at some
point getting confused with its tracking reporting duplicate records.

Once again, thank you everyone for the info. I was not using FileTest prior
to this thread and what a change. I actually had something similar written
for the minifilter to test out the functionality. Wish I had known this
before, it would have saved me lot of time.

Thanks,
-AR

On Sun, Aug 15, 2010 at 11:38 PM, wrote:

> >> My problem is create/create/create
>
> Wonder what could be that(especially as you mentioned NO AV is installed),
> you can probably verify it using fileTest.
>
> I test on my XP SP3 VM, and when I said createfile test.dat at c:\test, I
> saw just one create request, when I say CloseHandle, I saw Cleanup/close.
> Nothing else.
>
> Could be related to your test setup.
>
> —
> NTFSD is sponsored by OSR
>
> For our schedule of debugging and file system seminars
> (including our new fs mini-filter seminar) 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
>