Thursday, August 30, 2012

Mount Point Resolution with FltGetFileNameInformation - Part II

In the previous post I showed a couple of examples of how FltMgr handles mount point resolution. I also ran into a problem where querying for the normalized name during preCreate for a path that would traverse a mountpoint failed, and I promised I would investigate and post my findings. In this post I will explain what I found and how I went about it (which might be interesting for someone that doesn't have a lot of experience debugging the workings of fltmgr or other kernel components).
So first, let me explain my findings. As a quick refresher, FltMgr performs name normalization by taking an opened name for a file (like C:\foo~1\bar~2.txt) and opening the parent directory (C:\foo~1) and then querying the directory (via the directory enumeration call) for the file name (bar~2.txt). FltMgr uses one of the directory structures that returns the long name for the file (like FILE_BOTH_DIR_INFORMATION or FILE_NAMES_INFORMATION) and then copies the long name for the file (let's say it is BarBarBar.txt). It then does the same for current directory name (for C:\foo~1 it would open C:\ and query for foo~1 and get back FooFooFoo) and then assembles everything back together into C:\FooFooFoo\BarBarBar.txt. Now, this process will fail with STATUS_NOT_SAME_DEVICE if when trying to open a parent directory (C:\foo~1) FltMgr encounters a reparse point that reparses to a different volume. The relevant code is this:
0: kd> u fltmgr!FltpExpandFilePathWorker+0x29e
fltmgr!FltpExpandFilePathWorker+0x29e:
96034a1c ff154c030296    call    dword ptr [fltmgr!_imp__IoGetAttachedDevice (9602034c)]
96034a22 ff765c          push    dword ptr [esi+5Ch]
96034a25 8bf8            mov     edi,eax
96034a27 ff1548010296    call    dword ptr [fltmgr!_imp__IoGetRelatedDeviceObject (96020148)]
96034a2d 3bc7            cmp     eax,edi
96034a2f 740c            je      fltmgr!FltpExpandFilePathWorker+0x2bf (96034a3d)
96034a31 c74508d40000c0  mov     dword ptr [ebp+8],0C00000D4h
96034a38 e9e8feffff      jmp     fltmgr!FltpExpandFilePathWorker+0x1a7 (96034925)
As you can see, FltMgr compares two devices, the one on which the IRP_MJ_CREATE to open the parent directory was issued and the one where it was actually opened on, and if they don't match it will fail with STATUS_NOT_SAME_DEVICE (which is an interesting and confusing choice since the actual error message (from ntstatus.h) is "The target file of a rename request is located on a different device than the source of the rename request." and there is no rename involved). There are a couple of interesting points to make:
  • This should only impact preCreate queries since after the IRP_MJ_CREATE completes successfully we are on the final volume and so the opened file name can't traverse any reparse points (as discussed in my previous post on this subject). So in postCreate (and this implies a successful create) there will be no reparse points to traverse.
  • The other interesting thing to note is that FltMgr actually issues its IRP_MJ_CREATE violating the file system filter layering rules, in that it sends the request to the top of the IO stack. It does this with the explicit goal of being able to survive reparses to other volumes (like I've discussed elsewhere on this blog). However, it then checks to figure out if it actually ended up on a different volume and fails the operation, which would have happened anyway if they targeted the IRP_MJ_CREATE properly. The only case where this might actually work and the proper layering of the IRP_MJ_CREATE would have failed is where there multiple reparses that eventually end up on the original volume where the IRP_MJ_CREATE was issued on (so you'd have C:\foo~1 reparse to D:\bar~1 which would in turn reparse back to C:\baz~1). This would fail with proper layering of the IRP_MJ_CREATE because the first reparse (from C:\ to D:\) would fail, but it would work with the current implementation because the request is targeted at C:\ and the directory that is opened eventually is on C:\ as well). However, I doubt that this behavior is what FltMgr's designers had in mind and instead I tend to believe that violating the layering in this case was unnecessary.  
Anyway, let me quickly show how I've debugged this issue to find where the error comes from in a couple of minutes. I'll first show you the code that I added to the passthrough sample to detect when this case happens:
    if (PtDoRequestOperationStatus( Data )) {

        status = FltRequestOperationStatusCallback( Data,
                                                    PtOperationStatusCallback,
                                                    (PVOID)(++OperationStatusCtx) );
        if (!NT_SUCCESS(status)) {

            PT_DBG_PRINT( PTDBG_TRACE_OPERATION_STATUS,
                          ("PassThrough!PtPreOperationPassThrough: FltRequestOperationStatusCallback Failed, status=%08x\n",
                           status) );
        }
    }

    if (Data->Iopb->MajorFunction == IRP_MJ_CREATE) {

        status = FltGetFileNameInformation( Data, 
                                            FLT_FILE_NAME_NORMALIZED,
                                            &fileName );

        if (NT_SUCCESS(status)) {

            DbgPrint("preCreate|normalized -> \"%wZ\"\n", &fileName->Name); 

            FltReleaseFileNameInformation( fileName );

        } else {

            DbgBreakPoint();

            status = FltGetFileNameInformation( Data, 
                                                FLT_FILE_NAME_NORMALIZED,
                                                &fileName );

        
        }
As you can see, when the call to FltGetFileNameInformation fails I've added a breakpoint and then I retry the operation with the exact same parameters, which allows me to investigate the call. After that, when the breakpoint triggers, I do this:
Break instruction exception - code 80000003 (first chance)    <- here I've hit the breakpoint
PassThrough!PtPreOperationPassThrough+0xd2:
a414c0f2 cc              int     3
0: kd> p <- step over the breakpoint
PassThrough!PtPreOperationPassThrough+0xd3:
a414c0f3 8d45f8          lea     eax,[ebp-8]
0: kd> t <- trace into the function
fltmgr!FltGetFileNameInformation:
9601ce78 8bff            mov     edi,edi
0: kd> pc <- find the next call
fltmgr!FltGetFileNameInformation+0x118:
9601cf90 e833010000      call    fltmgr!FltpAllocateInitializeNameGenerationContext (9601d0c8)
0: kd> p <- and step over it
fltmgr!FltGetFileNameInformation+0x11d:
9601cf95 8bf0            mov     esi,eax
0: kd> r <- and now inspect the registers. In this calling convention eax will be the NTSTATUS , so eax = 00000000 means STATUS_SUCCESS
eax=00000000 ebx=92639008 ecx=944f6ae0 edx=944f6ae0 esi=92639068 edi=00000000
eip=9601cf95 esp=a194d96c ebp=a194d988 iopl=0         nv up ei pl zr na pe nc
cs=0008  ss=0010  ds=0023  es=0023  fs=0030  gs=0000             efl=00000246
fltmgr!FltGetFileNameInformation+0x11d:
9601cf95 8bf0            mov     esi,eax
0: kd> pc <- ok, find the next call
fltmgr!FltGetFileNameInformation+0x126:
9601cf9e e85df8ffff      call    fltmgr!FltpGetFileNameInformation (9601c800)
0: kd> p <- step over it 
fltmgr!FltGetFileNameInformation+0x12b:
9601cfa3 8bf0            mov     esi,eax
0: kd> r <- inspect the result again and note that eax=c00000d4, which happens to be STATUS_NOT_SAME_DEVICE .
eax=c00000d4 ebx=92639008 ecx=00000000 edx=00000003 esi=00000000 edi=00000000
eip=9601cfa3 esp=a194d96c ebp=a194d988 iopl=0         nv up ei pl zr na pe nc
cs=0008  ss=0010  ds=0023  es=0023  fs=0030  gs=0000             efl=00000246
fltmgr!FltGetFileNameInformation+0x12b:
9601cfa3 8bf0            mov     esi,eax
So now I know that the STATUS_NOT_SAME_DEVICE error came from the call to fltmgr!FltpGetFileNameInformation. Time to continue this investigation, but this time looking into that function:
0: kd> g <- hit go and trigger the condition (which in my case was trying to traverse a mountpoint so I just did a notepad C:\mnt\foo.txt, where C:\mnt was a mount point)
Break instruction exception - code 80000003 (first chance)
PassThrough!PtPreOperationPassThrough+0xd2:
a414c0f2 cc              int     3 <- so I hit the breakpoint again, as expected. 
0: kd> bp /t @$thread fltmgr!FltpGetFileNameInformation  <- set a threaded breakpoint on the function where I know the failure should happen. The thread is useful when a function is called from multiple threads and I don't want the breakpoint to trigger for those.
0: kd> g <- hit go and we should hit the breakpoint when the current thread enters that function
Breakpoint 0 hit  <- and so it is...
fltmgr!FltpGetFileNameInformation:
9601c800 8bff            mov     edi,edi
0: kd> bc * <- clear the breakpoint . This is sometimes necessary because if there is recursion it will hit again on the same thread and might confuse things
0: kd> pc <- find the first call
fltmgr!FltpGetFileNameInformation+0x48:
9601c848 e8db9bffff      call    fltmgr!FltpGetNextCallbackNodeForInstance (96016428)
0: kd> p <- and step over to see the status
fltmgr!FltpGetFileNameInformation+0x4d:
9601c84d 894614          mov     dword ptr [esi+14h],eax
0: kd> r <- check the status, which is STATUS_SUCCESS
eax=00000000 ebx=92639008 ecx=9444cd48 edx=00000000 esi=94501858 edi=00000000
eip=9601c84d esp=a194d864 ebp=a194d888 iopl=0         nv up ei pl zr na pe nc
cs=0008  ss=0010  ds=0023  es=0023  fs=0030  gs=0000             efl=00000246
fltmgr!FltpGetFileNameInformation+0x4d:
9601c84d 894614          mov     dword ptr [esi+14h],eax ds:0023:9450186c=00000000
0: kd> pc <- find the next call
fltmgr!FltpGetFileNameInformation+0x5a:
9601c85a e8c99bffff      call    fltmgr!FltpGetNextCallbackNodeForInstance (96016428)
0: kd> p <- step again
fltmgr!FltpGetFileNameInformation+0x5f:
9601c85f 894618          mov     dword ptr [esi+18h],eax
0: kd> r <- STATUS_SUCCESS again
eax=00000000 ebx=92639008 ecx=9444cd48 edx=00000000 esi=94501858 edi=00000000
eip=9601c85f esp=a194d864 ebp=a194d888 iopl=0         nv up ei pl zr na pe nc
cs=0008  ss=0010  ds=0023  es=0023  fs=0030  gs=0000             efl=00000246
fltmgr!FltpGetFileNameInformation+0x5f:
9601c85f 894618          mov     dword ptr [esi+18h],eax ds:0023:94501870=00000000
0: kd> pc <- and then the next call
fltmgr!FltpGetFileNameInformation+0xb2:
9601c8b2 e829160000      call    fltmgr!FltpGetStreamListCtrl (9601dee0)
0: kd> p 
fltmgr!FltpGetFileNameInformation+0xb7:
9601c8b7 894508          mov     dword ptr [ebp+8],eax
0: kd> r <- this fails with STATUS_NOT_SUPPORTED. This might be a failure that gets converted into the one we're looking for. I investigated it (not shown here) but it doesn't result in a failure, it just changes the code path through the function
eax=c00000bb ebx=92639008 ecx=9601e0a8 edx=00000000 esi=94501858 edi=00000000
eip=9601c8b7 esp=a194d864 ebp=a194d888 iopl=0         nv up ei pl zr na pe nc
cs=0008  ss=0010  ds=0023  es=0023  fs=0030  gs=0000             efl=00000246
fltmgr!FltpGetFileNameInformation+0xb7:
9601c8b7 894508          mov     dword ptr [ebp+8],eax ss:0010:a194d890=94501858
0: kd> pc <-find the next call
fltmgr!FltpGetFileNameInformation+0xc2:
9601c8c2 e887fdffff      call    fltmgr!HandleStreamListNotSupported (9601c64e)
0: kd> p <- step over
fltmgr!FltpGetFileNameInformation+0xc7:
9601c8c7 894508          mov     dword ptr [ebp+8],eax
0: kd> r <- and we can see that we've hit the status we wanted, eax=c00000d4. so now we know the failure comes from fltmgr!HandleStreamListNotSupported, so set a breakpoint on it.
eax=c00000d4 ebx=92639008 ecx=00000000 edx=00000003 esi=94501858 edi=00000000
eip=9601c8c7 esp=a194d864 ebp=a194d888 iopl=0         nv up ei pl nz na po nc
cs=0008  ss=0010  ds=0023  es=0023  fs=0030  gs=0000             efl=00000202
fltmgr!FltpGetFileNameInformation+0xc7:
9601c8c7 894508          mov     dword ptr [ebp+8],eax ss:0010:a194d890=c00000bb
0: kd> g <- so now we need to go back to trigger the breakpoint
Break instruction exception - code 80000003 (first chance)
PassThrough!PtPreOperationPassThrough+0xd2:
a414c0f2 cc              int     3
0: kd> bp /t@$thread fltmgr!HandleStreamListNotSupported  <- set our threaded breakpoint on that function
0: kd> g <- and run
Breakpoint 0 hit
fltmgr!HandleStreamListNotSupported:
9601c64e 8bff            mov     edi,edi
After a couple of iterations (in about 5 minutes of debugging) we end up with this stack, where the status is actually generated.:
0: kd> k
ChildEBP RetAddr  
a194d8ac 96034c59 fltmgr!FltpExpandFilePathWorker+0x2b3
a194d8c4 96034dc3 fltmgr!FltpExpandFilePath+0x19
a194d8e0 96035505 fltmgr!FltpGetNormalizedFileNameWorker+0x7d
a194d8f8 96032765 fltmgr!FltpGetNormalizedFileName+0x19
a194d910 9601c773 fltmgr!FltpCreateFileNameInformation+0x81
a194d930 9601c8c7 fltmgr!HandleStreamListNotSupported+0x125
a194d960 9601cfa3 fltmgr!FltpGetFileNameInformation+0xc7
a194d988 a414c102 fltmgr!FltGetFileNameInformation+0x12b
a194d9ac 96016aeb PassThrough!PtPreOperationPassThrough+0xe2 [c:\temp11\passthrough\passthrough.c @ 705]
a194da18 960199f0 fltmgr!FltpPerformPreCallbacks+0x34d
a194da30 9602d1fe fltmgr!FltpPassThroughInternal+0x40
a194da44 9602d8b7 fltmgr!FltpCreateInternal+0x24
a194da88 828884bc fltmgr!FltpCreate+0x2c9
a194daa0 82a8c6ad nt!IofCallDriver+0x63
a194db78 82a6d26b nt!IopParseDevice+0xed7
a194dbf4 82a932d9 nt!ObpLookupObjectName+0x4fa
a194dc50 82a8b62b nt!ObOpenObjectByName+0x165
a194dccc 82ac667e nt!IopCreateFile+0x673
a194dd14 8288f44a nt!NtOpenFile+0x2a
a194dd14 776064f4 nt!KiFastCallEntry+0x12a
WARNING: Stack unwind information not available. Following frames may be wrong.