Investigating an SR.sys Issue

This week I've looked at an interop issue with SR.sys and I want to share the results and the investigation. The filter I was looking at (MyFilter) is an SFO type filter which completes certain IRP_MJ_CREATEs for specific FILE_OBJECTs and then implements all the requests for them. As usual great care must be taken that none of the FILE_OBJECTs that MyFilter owns (SFOs) are ever seen below my filter (in other filters or in the file system) or those filters or the file system might think they own the FILE_OBJECTs and start walking their private structures (like the FCB or CCB) and get very confused about things and then either end with a bugcheck in the good case or data corruption in the bad case.
The problem I was investigating was exactly one of these, where somehow one of my FILE_OBJECTs ended up on the lower file system, NTFS. This is what the stack looked like:

f511ee9c f840cedc f511ef88 82035578 f511eed8 Ntfs!NtfsDecodeFileObject+0x37
f511ef10 f840b49c f511ef88 81fd5900 81cfb770 Ntfs!NtfsCommonQueryInformation+0x56
f511ef74 f840b4d5 f511ef88 81fd5900 00000001 Ntfs!NtfsFsdDispatchSwitch+0x12a
f511f098 804ef18f 81cfb770 81fd5900 81fd5900 Ntfs!NtfsFsdDispatchWait+0x1c
f511f0a8 f849852d 81d1fc10 f511f16e f511f15c nt!IopfCallDriver+0x31
f511f0d4 f849282c 81cfb770 82035578 f511f16e sr!SrQueryInformationFile+0x99
f511f100 f8492f33 00000034 82035578 f511f15c sr!SrpGetFileName+0x32
f511f270 f84936d1 81d1fc10 f511f2e0 f511f2d7 sr!SrpExpandPathOfFileName+0x19f
f511f290 f8493873 81d1fc10 823896a0 f511f2e0 sr!SrpGetFileNameFromFileObject+0xe7
f511f3f4 f848e8c2 81d1fc10 823896a0 00000000 sr!SrFileAlreadyExists+0x5f
f511f44c 804ef18f 81d1fc10 00000002 82130c98 sr!SrCreate+0x19c
f511f45c f84ab6c3 823896a0 82130ca8 823ca2e0 nt!IopfCallDriver+0x31
f511f48c 804ef18f 81e32020 82130c98 82130c98 fltMgr!FltpCreate+0x1d9
f511f49c 805831fa 81ccdb68 81fddfd4 f511f634 nt!IopfCallDriver+0x31
f511f57c 805bf444 81ccdb80 00000000 81fddf30 nt!IopParseDevice+0xa12
f511f5f4 805bb9d0 00000000 f511f634 00000640 nt!ObpLookupObjectName+0x53c
f511f648 80576033 00000000 00000000 36039c00 nt!ObOpenObjectByName+0xea
f511f6c4 80576a20 f511f848 00100002 f511f850 nt!IopCreateFile+0x407
f511f70c f84ad5b9 f511f848 00100002 f511f850 nt!IoCreateFileSpecifyDeviceObjectHint+0x52
f511f7b8 f84ada28 81d2d2d0 81d31008 f511f848 fltMgr!FltCreateFileEx+0x113
f511f7fc f500ea00 81d2d2d0 81d31008 f511f848 fltMgr!FltCreateFile+0x36
f511f868 f500ec87 81fc0994 81d31008 00000000 myfilter!MyCreateFile+0x100

Looking at the stack one thing looks really strange: FltMgr is calling into SR which is calling into NTFS. This indicates that SR is somehow loaded between FltMgr and NTFS. So I decided to see that the file system stack looks like:

1: kd> !fltkd.volumes

Volume List: 820210a0 "Frame 0" 
   FLT_VOLUME: 820ad668 "\Device\WebDavRedirector"
   FLT_VOLUME: 81d01168 "\Device\LanmanRedirector"
   FLT_VOLUME: 82005b48 "\Device\HGFS"
   FLT_VOLUME: 81ccbc18 "\Device\VhdDisk00000003"
      FLT_INSTANCE: 81d31008 "MyFilter Default Instance" "137000"
   FLT_VOLUME: 81d01c18 "\Device\VhdDisk00000002"
   FLT_VOLUME: 81cc8c18 "\Device\VhdDisk00000001"
   FLT_VOLUME: 8207fbd8 "\Device\HarddiskDmVolumes\PhysicalDmVolumes\BlockVolume1"
   FLT_VOLUME: 81e9a8a0 "\Device\HarddiskVolume2"
   FLT_VOLUME: 81d2e008 "\Device\HarddiskVolume1"
1: kd> !fltkd.volume 81ccbc18 

FLT_VOLUME: 81ccbc18 "\Device\VhdDisk00000003"
   FLT_OBJECT: 81ccbc18  [04000000] Volume
      RundownRef               : 0x00000004 (2)
      PointerCount             : 0x00000001 
      PrimaryLink              : [81d01c24-82005b54] 
   Frame                    : 82021000 "Frame 0" 
   Flags                    : [00000004] SetupNotifyCalled
   FileSystemType           : [00000002] FLT_FSTYPE_NTFS
   VolumeLink               : [81d01c24-82005b54] 
   DeviceObject             : 81e32020 
   DiskDeviceObject         : 81ccdb80 
   VolumeInNextFrame        : 00000000 
   Guid                     : "" 
   CDODeviceName            : "\Ntfs" 
   CDODriverName            : "\FileSystem\Ntfs" 
   Callbacks                : (81ccbca8)
   ContextLock              : (81ccbe38)
   VolumeContexts           : (81ccbe70)  Count=0
   StreamListCtrls          : (81ccbe74)  rCount=56 
   NameCacheCtrl            : (81ccbeb8)
   InstanceList             : (81ccbc64)
      FLT_INSTANCE: 81d31008 "MyFilter Default Instance" "137000"
1: kd> !devstack 81e32020 
  !DevObj   !DrvObj            !DevExt   ObjectName
> 81e32020  \FileSystem\FltMgr 81e320d8  
  81d1fb58  \FileSystem\sr     81d1fc10  
  81cfb770  \FileSystem\Ntfs   81cfb828 

So as you can see SR is indeed loaded between NTFS and FltMgr's frame0. As I mentioned in my post on how the file system stack is layered, in XP FltMgr doesn't create frame0 immediately and instead it waits for the first minifilter to register before it creates it. Since on my system there is no other minifilter FltMgr never created frame0 until I manually loaded my filter. However, since SR is a boot start driver by the time FltMgr initialized frame0 SR was already attached and FltMgr had no option but to attach on top of it.
Now, the FILE_OBJECT that NTFS chokes on is 82035578 and it is indeed an SFO. Looking on the stack we can see that it first appears when SR calls SrpGetFileName. There were two possibilities. Either I had leaked my SFO below my filter (either in this operation or at some point in the past) and SR got it and was using it or SR got their own FILE_OBJECT from my filter by issuing a request above my filter (most likely to the top of the stack). So I decided to see what the function that calls SrpGetFileName does (the function is rather long so I trimmed it a bit but it's still quite long so i tried to highlight things):

1: kd> uf sr!SrpExpandPathOfFileName
sr!SrpExpandPathOfFileName:
f8492d94 8bff            mov     edi,edi
f8492d96 55              push    ebp
…
f8492e3a 56              push    esi
f8492e3b 6800080000      push    800h
f8492e40 56              push    esi
f8492e41 56              push    esi
f8492e42 8385d4feffff02  add     dword ptr [ebp-12Ch],2
f8492e49 56              push    esi
f8492e4a 56              push    esi
f8492e4b 6821400000      push    4021h
f8492e50 6a01            push    1
f8492e52 6a03            push    3
f8492e54 6880000000      push    80h
f8492e59 56              push    esi
f8492e5a 8d85b0feffff    lea     eax,[ebp-150h]
f8492e60 50              push    eax
f8492e61 8d85b8feffff    lea     eax,[ebp-148h]
f8492e67 50              push    eax
f8492e68 6800001000      push    100000h
f8492e6d 8d85d8feffff    lea     eax,[ebp-128h]
f8492e73 50              push    eax
f8492e74 c785b8feffff18000000 mov dword ptr [ebp-148h],18h
f8492e7e 89b5bcfeffff    mov     dword ptr [ebp-144h],esi
f8492e84 c785c4feffff00020000 mov dword ptr [ebp-13Ch],200h
f8492e8e 899dc0feffff    mov     dword ptr [ebp-140h],ebx
f8492e94 89b5c8feffff    mov     dword ptr [ebp-138h],esi
f8492e9a 89b5ccfeffff    mov     dword ptr [ebp-134h],esi
f8492ea0 e8296bffff      call    sr!IoCreateFileSpecifyDeviceObjectHint (f84899ce)
f8492ea5 3bc6            cmp     eax,esi
f8492ea7 8985e8feffff    mov     dword ptr [ebp-118h],eax
f8492ead 7d08            jge     sr!SrpExpandPathOfFileName+0x123 (f8492eb7)

sr!SrpExpandPathOfFileName+0x11b:
f8492eaf c60701          mov     byte ptr [edi],1
f8492eb2 e9c0010000      jmp     sr!SrpExpandPathOfFileName+0x2e3 (f8493077)

sr!SrpExpandPathOfFileName+0x123:
f8492eb7 56              push    esi
f8492eb8 8d85dcfeffff    lea     eax,[ebp-124h]
f8492ebe 50              push    eax
f8492ebf a1389b48f8      mov     eax,dword ptr [sr!_imp__IoFileObjectType (f8489b38)]
f8492ec4 56              push    esi
f8492ec5 ff30            push    dword ptr [eax]
f8492ec7 56              push    esi
f8492ec8 ffb5d8feffff    push    dword ptr [ebp-128h]
f8492ece ff15349b48f8    call    dword ptr [sr!_imp__ObReferenceObjectByHandle (f8489b34)]
f8492ed4 3bc6            cmp     eax,esi
f8492ed6 8985e8feffff    mov     dword ptr [ebp-118h],eax
f8492edc 0f8c95010000    jl      sr!SrpExpandPathOfFileName+0x2e3 (f8493077)

sr!SrpExpandPathOfFileName+0x14e:
f8492ee2 8b85e0feffff    mov     eax,dword ptr [ebp-120h]
f8492ee8 ff7048          push    dword ptr [eax+48h]
f8492eeb ff15149c48f8    call    dword ptr [sr!_imp__IoGetAttachedDevice (f8489c14)]
f8492ef1 ffb5dcfeffff    push    dword ptr [ebp-124h]
f8492ef7 8bf8            mov     edi,eax
f8492ef9 ff15309b48f8    call    dword ptr [sr!_imp__IoGetRelatedDeviceObject (f8489b30)]
f8492eff 3bc7            cmp     eax,edi
f8492f01 7418            je      sr!SrpExpandPathOfFileName+0x187 (f8492f1b)

sr!SrpExpandPathOfFileName+0x16f:
f8492f03 8b85d0feffff    mov     eax,dword ptr [ebp-130h]
f8492f09 c785e8feffffd40000c0 mov dword ptr [ebp-118h],0C00000D4h
f8492f13 c60001          mov     byte ptr [eax],1
f8492f16 e95c010000      jmp     sr!SrpExpandPathOfFileName+0x2e3 (f8493077)

sr!SrpExpandPathOfFileName+0x187:
f8492f1b 8d85ecfeffff    lea     eax,[ebp-114h]
f8492f21 50              push    eax
f8492f22 ffb5dcfeffff    push    dword ptr [ebp-124h]
f8492f28 ffb5e0feffff    push    dword ptr [ebp-120h]
f8492f2e e8c7f8ffff      call    sr!SrpGetFileName (f84927fa)
…

So looking at the function we can see that SR is calling IoCreateFileSpecifyDeviceObjectHint and then gets the FILE_OBJECT associated with the handle it has (by calling ObReferenceObjectByHandle). From this call we can infer that the handle is stored in the local variable @ebp-128h and that the FILE_OBJECT is stored in the variable @ebp-124h. Then SR compares the device of the FILE_OBJECT with the device it is attached to and if they don't match it fails with status 0C00000D4h (STATUS_NOT_SAME_DEVICE; also please note that the status gets put into @ebp-118h). Then the function calls SrpGetFileName with the FILE_OBJECT it got from the call to IoCreateFileSpecifyDeviceObjectHint. Since all these are stored in local variables we can get the value of EBP for that function from the ChildEBP column (0xf511f270) and see which FILE_OBJECT they got:

1: kd> !error 0C00000D4h
Error code: (NTSTATUS) 0xc00000d4 (3221225684) - {Incorrect Volume}  The target file of a rename request is located on a different device than the source of the rename request.
1: kd> dp f511f270-0x128
f511f148  800005f4 82035578 81d1fc10 0000001e
f511f158  00000000 00fe0000 f511f16e 000000fe
f511f168  00000000 01000000 f511f0a8 f511f858
f511f178  f511f32c f83ea75b e113f858 ffffffff
f511f188  f83e5b5c e1cbada0 f511f858 81de4290
f511f198  00000000 00000000 f511f118 f511f1bc
f511f1a8  f511f32c f83ea75b f511f1c8 f511f2dc
f511f1b8  804e1ec4 f511f1fc f511f1d8 81cfb850
1: kd> !handle 800005f4 

PROCESS 81f43020  SessionId: 0  Cid: 0714    Peb: 7ffde000  ParentCid: 03ec
    DirBase: 02b40320  ObjectTable: e1518008  HandleCount:  32.
    Image: ifstest.exe

Kernel handle table at e1004000 with 345 entries in use

800005f4: Object: 82035578  GrantedAccess: 00100000 Entry: e1004be8
Object: 82035578  Type: (823aead0) File
    ObjectHeader: 82035560 (old version)
        HandleCount: 1  PointerCount: 2
        Directory Object: 00000000  Name: \opcreatg\ {VhdDisk00000003}

So as we can see SR actually got one my SFOs by sending a create to the top of the stack and then sent it directly to NTFS in a query. This was puzzling because SR is actually using IoCreateFileSpecifyDeviceObjectHint which is exactly what I expected it would use to target the IRP_MJ_CREATE appropriately. However, when looking at the call we can see that the DeviceObject member is passed in as "push esi" and it's hard to track exactly what a given register's value was at the time of the call without carefully analyzing the code. In this case however it seems we got lucky because a lot of other parameters are set up using the "push esi" instruction which means that either SR called IoCreateFileSpecifyDeviceObjectHint with a lot of the parameters set to the DEVICE_OBJECT or that it passed in NULL for the DEVICE_OBJECT. Looking at where ESI is initialized (which is not in the chunk of code I pasted here) we can see that indeed ESI is set to 0 and so now we know what is going on:

1. SR calls IoCreateFileSpecifyDeviceObjectHint and sends a request to the top of the stack.
2. SR takes the handle and resolves it to a FILE_OBJECT
3. SR compares the DEVICE_OBJECT for the FILE_OBJECT it just got with the DEVICE_OBJECT it is attached to and if they are different it fails with STATUS_NOT_SAME_DEVICE.
4. Finally SR uses the FILE_OBJECT in a call that is targeted below itself and thus my SFO reaches NTFS.

I'm not exactly sure why SR does this. It looks like the code was written so that it used IoCreateFileSpecifyDeviceObjectHint but then the DeviceObject was passed in as NULL which effectively changes it to IoCreateFile. But then the code itself checks whether the device for the FILE_OBJECT it gets is the same as the one it's attached on, which is something IoCreateFileSpecifyDeviceObjectHint would have done if used with a DeviceObject parameter. Anyway the problem is that SR sent requests to two different points on the stack, the IRP_MJ_CREATE to the top of the stack and then subsequent requests below itself on the stack and thus it runs into trouble when things change between the top of the stack and the altitude where SR is located. Had SR sent the IRP_MJ_CREATE below itself (which is the right behavior from a layering perspective) or the subsequent requests to the top of the stack (which is actually still wrong because it could lead to infinite loops and such) then it would have avoided this problem.