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:
- SR calls IoCreateFileSpecifyDeviceObjectHint and sends a request to the top of the stack.
- SR takes the handle and resolves it to a FILE_OBJECT
- 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.
- 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.