Uncover the mystery of a bugcheck 0x24 (NTFS_FILE_SYSTEM)
My name is Nan, I am an Escalation Engineer in Platforms Global Escalation Services in GCR. Today I’d like to share an interesting sample case with respect to filter manager to showcase the powerful debugging extension fltkd.dll (it is included in the public debugging tools) and talk about Filter Manager/Minifilter architecture briefly through the investigation.
Recently I worked on an interesting server bugcheck case where Windows Server 2012 R2 would crash with bugcheck code 0x24 (NTFS_FILE_SYSTEM) after mounting a ReFS volume.
3: kd> .bugcheck
Bugcheck code 00000024
Arguments 000000b5`00190637 ffffd000`23f17e58 ffffd000`23f17660 fffff800`00cf95c7
The 2nd and 3rd parameters are the exception record and context record. Do a .cxr on the 3rd parameter and we obtain a more informative stack.
3: kd> .cxr ffffd00023f17660
rax=ffffe0003c8dae20 rbx=ffffc00003dba2c0 rcx=0000000000000018
rdx=ffffe0003c84bc60 rsi=ffffd00023f18210 rdi=ffffc00003dba120
rip=fffff80000cf95c7 rsp=ffffd00023f18090 rbp=0000000000000000
r8=0000000100000000 r9=0000000000000001 r10=0000000000000004
r11=ffffd00023f18168 r12=0000000000000000 r13=ffffe0003c84bf70
r14=0000000000000005 r15=0000000000000000
iopl=0 nv up ei ng nz na pe nc
cs=0010 ss=0018 ds=002b es=002b fs=0053 gs=002b efl=00010282
Ntfs!NtfsCommonQueryInformation+0xa7:
fffff800`00cf95c7 418b4104 mov eax,dword ptr [r9+4] ds:002b:00000000`00000005=???????? <<<< R9 has invalid data.
3: kd> knL
*** Stack trace for last set context - .thread/.cxr resets it
# Child-SP RetAddr Call Site
00 ffffd000`23f18090 fffff800`00d00813 Ntfs!NtfsCommonQueryInformation+0xa7
01 ffffd000`23f18170 fffff800`00d01156 Ntfs!NtfsFsdDispatchSwitch+0xd3
02 ffffd000`23f181f0 fffff800`00402f3e Ntfs!NtfsFsdDispatchWait+0x47
03 ffffd000`23f18440 fffff800`00406986 FLTMGR!FltpLegacyProcessingAfterPreCallbacksCompleted+0x25e
04 ffffd000`23f184c0 fffff800`0042ef2a FLTMGR!FltPerformSynchronousIo+0x2b6
05 ffffd000`23f18570 fffff800`01041843 FLTMGR!FltQueryInformationFile+0x52
06 ffffd000`23f185b0 fffff800`010417bb av+0x3843
07 ffffd000`23f18600 fffff800`00f1c06d av+0x37bb
08 ffffd000`23f18630 fffff800`00401eea fltdrv1+0xc06d
09 ffffd000`23f18720 fffff800`00405c13 FLTMGR!FltpPerformPreCallbacks+0x31a
0a ffffd000`23f18830 fffff800`0042bcf2 FLTMGR!FltpPassThroughFastIo+0x73
0b ffffd000`23f18890 fffff801`6c9b62b1 FLTMGR!FltpFastIoQueryStandardInfo+0x132
0c ffffd000`23f18920 fffff801`6c7684b3 nt!NtQueryInformationFile+0x3e1
0d ffffd000`23f18a90 00007ff9`e632668a nt!KiSystemServiceCopyEnd+0x13
0e 00000000`09bcd828 00000000`00000000 0x00007ff9`e632668a
An exception happens in Ntfs.sys because Ntfs!NtfsCommonQueryInformation attempts to access an invalid memory address in kernel mode. We look back a few instructions to figure how R9 obtains the bogus value.
3: kd> ub fffff80000cf95c7
Ntfs!NtfsCommonQueryInformation+0x81:
fffff800`00cf95a1 4c8b8fa8000000 mov r9,qword ptr [rdi+0A8h] <<<< where R9 value is obtained.
fffff800`00cf95a8 4d894bb0 mov qword ptr [r11-50h],r9
fffff800`00cf95ac 4d894ba0 mov qword ptr [r11-60h],r9
fffff800`00cf95b0 488b5820 mov rbx,qword ptr [rax+20h]
fffff800`00cf95b4 49895ba8 mov qword ptr [r11-58h],rbx
fffff800`00cf95b8 4c8b87a0000000 mov r8,qword ptr [rdi+0A0h]
fffff800`00cf95bf 4d894388 mov qword ptr [r11-78h],r8
fffff800`00cf95c3 4d894398 mov qword ptr [r11-68h],r8
3: kd> r rdi
Last set context:
rdi=ffffc00003dba120
Data in R9 is obtained from memory being referenced by RDI+0A8h. Typically it is supposed to be an opaque structure pertaining to NTFS. Before giving up and engaging Microsoft support, we can give another shot by our old friend !pool extension.
3: kd> !pool ffffc00003dba120 2
Pool page ffffc00003dba120 region is Paged pool
*ffffc00003dba000 size: 450 previous size: 0 (Allocated) *Reff
Pooltag Reff : FCB_DATA, Binary : refs.sys
To my surprise, the pool tag points to ReFS. Let’s revisit the call stack above, it crashes in Ntfs path clearly. How the query operation against Ntfs end up referencing something in ReFS?
Instead of doing the bottom-up analysis, we can take the top-down approach in effort to figure out more information. Let’s revisit the call stack again. The top entry on the stack is nt!NtQueryInformationFile that enters Filter Manager and winds up calling FltpPerformPreCallbacks function, which calls into 3rd party driver fltdrv1.sys.
3: kd> knL
*** Stack trace for last set context - .thread/.cxr resets it
# Child-SP RetAddr Call Site
00 ffffd000`23f18090 fffff800`00d00813 Ntfs!NtfsCommonQueryInformation+0xa7
01 ffffd000`23f18170 fffff800`00d01156 Ntfs!NtfsFsdDispatchSwitch+0xd3
02 ffffd000`23f181f0 fffff800`00402f3e Ntfs!NtfsFsdDispatchWait+0x47
03 ffffd000`23f18440 fffff800`00406986 FLTMGR!FltpLegacyProcessingAfterPreCallbacksCompleted+0x25e
04 ffffd000`23f184c0 fffff800`0042ef2a FLTMGR!FltPerformSynchronousIo+0x2b6
05 ffffd000`23f18570 fffff800`01041843 FLTMGR!FltQueryInformationFile+0x52
06 ffffd000`23f185b0 fffff800`010417bb av+0x3843
07 ffffd000`23f18600 fffff800`00f1c06d av+0x37bb
08 ffffd000`23f18630 fffff800`00401eea fltdrv1+0xc06d
09 ffffd000`23f18720 fffff800`00405c13 FLTMGR!FltpPerformPreCallbacks+0x31a
0a ffffd000`23f18830 fffff800`0042bcf2 FLTMGR!FltpPassThroughFastIo+0x73
0b ffffd000`23f18890 fffff801`6c9b62b1 FLTMGR!FltpFastIoQueryStandardInfo+0x132
0c ffffd000`23f18920 fffff801`6c7684b3 nt!NtQueryInformationFile+0x3e1
0d ffffd000`23f18a90 00007ff9`e632668a nt!KiSystemServiceCopyEnd+0x13
0e 00000000`09bcd828 00000000`00000000 0x00007ff9`e632668a
As implied by the function name FLTMGR!FltpPerformPreCallbacks, we can suppose it is calling some call back routine in 3rd party driver fltdrv1.sys which is a minifilter registered in Filter Manager.
In the Filter Manager architecture a minifilter driver can filter IRP-based I/O operations as well as fast I/O and file system filter (FSFilter) callback operations. For each of the I/O operations it chooses to filter, a minifilter driver can register a preoperation callback routine, a postoperation callback routine, or both. When handling an I/O operation, the filter manager calls the appropriate callback routine for each minifilter driver that registered for that operation. When that callback routine returns, the filter manager calls the appropriate callback routine for the next minifilter driver that registered for the operation.
So FLTMGR!FltpPerformPreCallbacks is supposed to invoke the preoperation call back inside fltdrv1.sys, Here is how preoperation call back is declared.
typedef FLT_PREOP_CALLBACK_STATUS ( *PFLT_PRE_OPERATION_CALLBACK)(
_Inout_ PFLT_CALLBACK_DATA Data,
_In_ PCFLT_RELATED_OBJECTS FltObjects,
_Out_ PVOID *CompletionContext
);
The FLT_CALLBACK_DATA structure represents an I/O operation. The Filter Manager and minifilters use this structure to initiate and process I/O operations. In this structure Iopb pointers to an FLT_IO_PARAMETER_BLOCK structure that contains the parameters for the I/O operation.
So let’s decode the assembly code FLTMGR!FltpPerformPreCallbacks and figure out the parameters it passes into the 3rd party callback first.
3: kd> ub fffff800`00401eea
FLTMGR!FltpPerformPreCallbacks+0x2ff:
fffff800`00401ecf 7810 js FLTMGR!FltpPerformPreCallbacks+0x311 (fffff800`00401ee1)
fffff800`00401ed1 000f add byte ptr [rdi],cl
fffff800`00401ed3 85d2 test edx,edx
fffff800`00401ed5 c00000 rol byte ptr [rax],0
fffff800`00401ed8 4c8d45bf lea r8,[rbp-41h]
fffff800`00401edc 488d55d7 lea rdx,[rbp-29h]
fffff800`00401ee0 488d8bd8000000 lea rcx,[rbx+0D8h] <<<< this has the first parameter Data
fffff800`00401ee7 ff5618 call qword ptr [rsi+18h]
3: kd> .frame /r 09
09 ffffd000`23f18720 fffff800`00405c13 FLTMGR!FltpPerformPreCallbacks+0x31a
rax=ffffe0003c8dae20 rbx=ffffe0003c8d2c80 rcx=0000000000000018
rdx=ffffe0003c84bc60 rsi=ffffe0000165b560 rdi=ffffe0003c884890
rip=fffff80000401eea rsp=ffffd00023f18720 rbp=ffffd00023f187c9
r8=0000000100000000 r9=0000000000000001 r10=0000000000000004
r11=ffffd00023f18168 r12=ffffe0003c8d2d00 r13=ffffe0000165b010
r14=ffffe0003c8d2df8 r15=0000000000000004
iopl=0 nv up ei ng nz na pe nc
cs=0010 ss=0018 ds=002b es=002b fs=0053 gs=002b efl=00010282
FLTMGR!FltpPerformPreCallbacks+0x31a:
fffff800`00401eea 8bf8 mov edi,eax
3: kd> dt ffffe0003c8d2c80+d8 _FLT_CALLBACK_DATA
FLTMGR!_FLT_CALLBACK_DATA
+0x000 Flags : 2
+0x008 Thread : 0xffffe000`0375c880 _KTHREAD
+0x010 Iopb : 0xffffe000`3c8d2db0 _FLT_IO_PARAMETER_BLOCK
…
3: kd> dt 0xffffe000`3c8d2db0 _FLT_IO_PARAMETER_BLOCK
FLTMGR!_FLT_IO_PARAMETER_BLOCK
+0x000 IrpFlags : 0
+0x004 MajorFunction : 0x5 ''
+0x005 MinorFunction : 0 ''
+0x006 OperationFlags : 0 ''
+0x007 Reserved : 0 ''
+0x008 TargetFileObject : 0xffffe000`3c884890 _FILE_OBJECT
+0x010 TargetInstance : 0xffffe000`0165b010 _FLT_INSTANCE
What we are concerned about are parameters TargetFileObject and TargetInstance.
- TargetFileObject - A file object pointer for the file or directory that is the target for this I/O operation.
- TargetInstance - An opaque instance pointer for the minifilter that is the target for this I/O operation.
Let’s dump the TargetFileObject first, it is a file open on HarddiskVolume4.
3: kd> !fileobj 0xffffe000`3c884890
\AV-REDIRECT-F3392236-BA8C-4AD9-8AEA-48F099A8EE9C\ffffe0003c8dae20.ini
Device Object: 0xffffe000011009b0 \Driver\volmgr
Vpb is NULL
Event signalled
Flags: 0x40002
Synchronous IO
Handle Created
File Object is currently busy and has 0 waiters.
FsContext: 0x00000000 FsContext2: 0x46527641
CurrentByteOffset: 0
3: kd> !devstack 0xffffe000011009b0
!DevObj !DrvObj !DevExt ObjectName
ffffe00001143040 \Driver\volsnap ffffe00001143190
> ffffe000011009b0 \Driver\volmgr ffffe00001100b00 HarddiskVolume4
!DevNode ffffe00001148a50 :
DeviceInst is "STORAGE\Volume\{19df1540-2f74-11e4-80bb-0050568127c8}#0000000000100000"
ServiceName is "volsnap"
The target File open is \AV-REDIRECT-F3392236-BA8C-4AD9-8AEA-48F099A8EE9C\ffffe0003c8dae20.ini on HarddiskVolume4. Next, what is the target filter instance?
In short, a minifilter driver attaches to the file system stack indirectly, by registering with the filter manager for the I/O operations the minifilter driver chooses to filter. An instance represents an attachment of a filter on a volume.Here is an excellent article to elaborate how filter attach/altitudes works.
Public symbols for fltmgr.sys does include the definitions of various key filter manager structures. We don’t bother to browse the structure manually. There is a public debug extension fltkd.dll and we can use it to view the instance in a very neat way. Here is how we print out the filter instance in question.
3: kd> !fltkd.instance 0xffffe000`0165b010
FLT_INSTANCE: ffffe0000165b010 "FLTDRV1" "388920" <<<< instance name and altitude #
FLT_OBJECT: ffffe0000165b010 [01000000] Instance
RundownRef : 0x0000000000000002 (1)
PointerCount : 0x00000001
PrimaryLink : [ffffe0000165dab0-ffffe00002501108]
OperationRundownRef : ffffe000025035b0
Could not read field "Number" of fltmgr!_EX_RUNDOWN_REF_CACHE_AWARE from address: ffffe000025035b0
Flags : [00000000]
Volume : ffffe00002501010 "\Device\HarddiskVolume4" <<<< the underlying volume filter instance attaches to.
Filter : ffffe000011f1010 "fltdrv1" <<<< filter name
TrackCompletionNodes : ffffe0000165bda0
ContextLock : (ffffe0000165b080)
Context : 0000000000000000
CallbackNodes : (ffffe0000165b0a0)
VolumeLink : [ffffe0000165dab0-ffffe00002501108]
FilterLink : [ffffe00001650070-ffffe0000164c340]
In !fltkd.instance output, we can see the instance passed into 3rd party pre-operation call back is attached to the volume "\Device\HarddiskVolume4”. Filter in the output describes a minifilter. We can run !fltkd.filter to print out the details of filter.
3: kd> !fltkd.filter ffffe000011f1010
FLT_FILTER: ffffe000011f1010 "fltdrv1" "388920"
FLT_OBJECT: ffffe000011f1010 [02000000] Filter
RundownRef : 0x0000000000000026 (19)
PointerCount : 0x00000002
PrimaryLink : [ffffe00000a9ac60-ffffe00000ab50c0]
Frame : ffffe00000ab5010 "Frame 0"
Flags : [00000002] FilteringInitiated
DriverObject : ffffe0000119f9c0
FilterLink : [ffffe00000a9ac60-ffffe00000ab50c0] *** ERROR: Module load completed but symbols could not be loaded for fltdrv1.sys
PreVolumeMount : fffff80000f1bd78 fltdrv1+0xbd78
PostVolumeMount : fffff80000f1c354 fltdrv1+0xc354
FilterUnload : 0000000000000000 (null)
InstanceSetup : fffff80000f1c528 fltdrv1+0xc528
…
InstanceList : (ffffe000011f1068) <<<< all filter instances this filter creates.
FLT_INSTANCE: ffffe000011e6640 "FLTDRV1" "388920"
…
FLT_INSTANCE: ffffe0000173d010 "FLTDRV1" "388920"
FLT_INSTANCE: ffffe00001793010 "FLTDRV1" "388920"
FLT_INSTANCE: ffffe00001787010 "FLTDRV1" "388920"
A side note about Filter Frame, for interoperability with legacy filter drivers the filter manager can attach filter device objects to a file system I/O stack in more than one location. Each of the filter manager's filter device objects is called a frame. From the perspective of a legacy filter driver, each filter manager frame is just another legacy filter driver. If there are no legacy filters present, there is only one frame, "Frame 0". If there are some legacy filters present on the system (attached on top of Frame 0), FltMgr might create more frames. We can view all frames Filter Manager manages by running !fltkd.frames
In !fltkd.instance output, it also displays the volume object filter instance is attached to. We can also dump out the Filter Volume and see all filter instances attached to it. All filter instances are displayed in order of altitude (number next to the filter instance name). Filter manager will process the I/O from filter with higher altitude to one with lower altitude. The filter I figured out just now is the top one and its filter instance altitude implies FLTDRV1 is a sort of FSFilter Activity Monitor.
3: kd> !fltkd.volume ffffe00002501010
FLT_VOLUME: ffffe00002501010 "\Device\HarddiskVolume4"
FLT_OBJECT: ffffe00002501010 [04000000] Volume
RundownRef : 0x000000000000000a (5)
PointerCount : 0x00000001
PrimaryLink : [ffffe0000165a020-ffffe0000254f020]
Frame : ffffe00000ab5010 "Frame 0"
Flags : [00000064] SetupNotifyCalled EnableNameCaching FilterAttached
FileSystemType : [00000002] FLT_FSTYPE_NTFS
VolumeLink : [ffffe0000165a020-ffffe0000254f020]
DeviceObject : ffffe00002501df0
DiskDeviceObject : ffffe000011009b0
FrameZeroVolume : ffffe00002501010
VolumeInNextFrame : 0000000000000000
Guid : "\??\Volume{19df169b-2f74-11e4-80bb-0050568127c8}"
CDODeviceName : "\Ntfs"
CDODriverName : "\FileSystem\Ntfs"
TargetedOpenCount : 0
Callbacks : (ffffe00002501120)
ContextLock : (ffffe00002501508)
VolumeContexts : (ffffe00002501510) Count=0
StreamListCtrls : (ffffe00002501518) rCount=4
FileListCtrls : (ffffe00002501598) rCount=0
NameCacheCtrl : (ffffe00002501618)
InstanceList : (ffffe000025010a0) <<<< all filter instances attached to particular volume.
FLT_INSTANCE: ffffe0000165b010 "FLTDRV1" "388920"
FLT_INSTANCE: ffffe0000165daa0 "Fltdrv2 Instance" "366992"
FLT_INSTANCE: ffffe00001661600 "V-locity cache Instance" "366789"
FLT_INSTANCE: ffffe0000343c010 "DKRtWrt Instance" "137100"
3: kd> !devstack ffffe00002501df0
!DevObj !DrvObj !DevExt ObjectName
> ffffe00002501df0 \FileSystem\FltMgr ffffe00002501f40
ffffe00000244030 \FileSystem\Ntfs ffffe00000244180 <<<< this volume is a NTFS volume.
Let’s recap a bit before proceeding, we know the original query is all about a file open against \AV-REDIRECT-F3392236-BA8C-4AD9-8AEA-48F099A8EE9C\ffffe0003c8dae20.ini on HarddiskVolume4 which happens to be NTFS volume.
It appears to be a normal query from I/O manager and nothing stands out yet. Let’s carry on the investigation.
On the call stack, 3rd party functions are black box, but the third party driver calls filter manager API FLTMGR!FltQueryInformationFile to retrieve some file information. So we pick up the analysis from that call.
3: kd> knL
*** Stack trace for last set context - .thread/.cxr resets it
# Child-SP RetAddr Call Site
00 ffffd000`23f18090 fffff800`00d00813 Ntfs!NtfsCommonQueryInformation+0xa7
01 ffffd000`23f18170 fffff800`00d01156 Ntfs!NtfsFsdDispatchSwitch+0xd3
02 ffffd000`23f181f0 fffff800`00402f3e Ntfs!NtfsFsdDispatchWait+0x47
03 ffffd000`23f18440 fffff800`00406986 FLTMGR!FltpLegacyProcessingAfterPreCallbacksCompleted+0x25e
04 ffffd000`23f184c0 fffff800`0042ef2a FLTMGR!FltPerformSynchronousIo+0x2b6
05 ffffd000`23f18570 fffff800`01041843 FLTMGR!FltQueryInformationFile+0x52
06 ffffd000`23f185b0 fffff800`010417bb av+0x3843
07 ffffd000`23f18600 fffff800`00f1c06d av+0x37bb
08 ffffd000`23f18630 fffff800`00401eea fltdrv1+0xc06d
09 ffffd000`23f18720 fffff800`00405c13 FLTMGR!FltpPerformPreCallbacks+0x31a
Here is how function FltQueryInformationFile is defined.
NTSTATUS FltQueryInformationFile(
_In_ PFLT_INSTANCE Instance,
_In_ PFILE_OBJECT FileObject,
_Out_ PVOID FileInformation,
_In_ ULONG Length,
_In_ FILE_INFORMATION_CLASS FileInformationClass,
_Out_opt_ PULONG LengthReturned
);
First parameter represents an attachment to specific volume and second parameter FileObject is the target file to be queried. We need to figure out what instance and file object 3rd party driver were passed into FltQueryInformationFile. As there is no public symbol information for FltQueryInformationFile, we can decode the assembly code directly.
3: kd> u FltQueryInformationFile
FLTMGR!FltQueryInformationFile:
fffff800`0042eed8 48895c2408 mov qword ptr [rsp+8],rbx
fffff800`0042eedd 4889742410 mov qword ptr [rsp+10h],rsi
fffff800`0042eee2 57 push rdi
fffff800`0042eee3 4883ec30 sub rsp,30h
fffff800`0042eee7 498bf0 mov rsi,r8
fffff800`0042eeea 4c8d442420 lea r8,[rsp+20h]
fffff800`0042eeef 418bf9 mov edi,r9d
fffff800`0042eef2 e8b970fdff call FLTMGR!FltAllocateCallbackData (fffff800`00405fb0)
Because FltQueryInformationFile does not populate the rcx and rdx registers (used for the first to parameters), we can assume that it passes its first two parameters through to FltAllocateCallbackData. Let’s see what FltAllocateCallbackData does and what we may obtain from this hint.
NTSTATUS FltAllocateCallbackData(
_In_ PFLT_INSTANCE Instance,
_In_opt_ PFILE_OBJECT FileObject,
_Out_ PFLT_CALLBACK_DATA *RetNewCallbackData
);
It takes Instance and FileObject as the first two parameters and an instance of PFLT_CALLBACK_DATA as the third parameter. Keep in mind the FLT_CALLBACK_DATA structure represents an I/O operation. The Filter Manager and minifilters use this structure to initiate and process I/O operations, so it should contain the information pertaining to the query a 3rd party driver issues.
Looking back the assembly code before calling FltAllocateCallbackData, 3rd output parameter RetNewCallbackData is obtained by this instruction:
fffff800`0042eeea 4c8d442420 lea r8,[rsp+20h]
So let’s dump out the PFLT_CALLBACK_DATA from the stack pointer.
3: kd> .frame /r 5
05 ffffd000`23f18570 fffff800`01041843 FLTMGR!FltQueryInformationFile+0x52
rax=ffffe0003c8dae20 rbx=ffffe0003c8d20e8 rcx=0000000000000018
rdx=ffffe0003c84bc60 rsi=0000000009bcd870 rdi=0000000000000018
rip=fffff8000042ef2a rsp=ffffd00023f18570 rbp=ffffd00023f18690
r8=0000000100000000 r9=0000000000000001 r10=0000000000000004
r11=ffffd00023f18168 r12=0000000000000000 r13=0000000000000000
r14=0000000003000000 r15=0000000000000000
iopl=0 nv up ei ng nz na pe nc
cs=0010 ss=0018 ds=002b es=002b fs=0053 gs=002b efl=00010282
FLTMGR!FltQueryInformationFile+0x52:
fffff800`0042ef2a 488b4c2468 mov rcx,qword ptr [rsp+68h] ss:0018:ffffd000`23f185d8=ffffd00023f18618
3: kd> dt poi(ffffd00023f18570+20) _FLT_CALLBACK_DATA
FLTMGR!_FLT_CALLBACK_DATA
+0x000 Flags : 0x10009
+0x008 Thread : 0xffffe000`0375c880 _KTHREAD
+0x010 Iopb : 0xffffe000`3c8d2140 _FLT_IO_PARAMETER_BLOCK
3: kd> dt 0xffffe000`3c8d2140 _FLT_IO_PARAMETER_BLOCK
FLTMGR!_FLT_IO_PARAMETER_BLOCK
+0x000 IrpFlags : 0
+0x004 MajorFunction : 0x5 ''
+0x005 MinorFunction : 0 ''
+0x006 OperationFlags : 0 ''
+0x007 Reserved : 0 ''
+0x008 TargetFileObject : 0xffffe000`3c8dae20 _FILE_OBJECT
+0x010 TargetInstance : 0xffffe000`0165daa0 _FLT_INSTANCE
Now we’ve got the target instance and file object the 3rd party driver hopes is querying. Let’s look at the target file object first.
3: kd> !fileobj 0xffffe000`3c8dae20
\$RECYCLE.BIN\S-1-5-21-589703330-573742762-725482543-110873\desktop.ini
Device Object: 0xffffe000010f1ca0 \Driver\volmgr
Vpb: 0xffffe000010cc9a0
Access: Read SharedRead SharedWrite SharedDelete
Flags: 0x62
Synchronous IO
Sequential Only
Cache Supported
FsContext: 0xffffc00003dba120 FsContext2: 0xffffc00003dba2c0
CurrentByteOffset: 0
Cache Data:
Section Object Pointers: ffffe0003c887380
Shared Cache Map: 00000000
3: kd> !devstack 0xffffe000010f1ca0
!DevObj !DrvObj !DevExt ObjectName
ffffe00001142040 \Driver\volsnap ffffe00001142190
> ffffe000010f1ca0 \Driver\volmgr ffffe000010f1df0 HarddiskVolume5 <<<< volume changes.
!DevNode ffffe00001148770 :
DeviceInst is "STORAGE\Volume\{19df16e3-2f74-11e4-80bb-0050568127c8}#0000000000100000"
ServiceName is "volsnap"
The biggest difference between the original query and current query is not only the file name but also the target volume, now it is against the file \$RECYCLE.BIN\S-1-5-21-589703330-573742762-725482543-110873\desktop.ini on HarddiskVolume5.
Another note, is about the FsContext 0xffffc00003dba120 in the file object, that is the address I ran !pool with and it is from ReFS. It seems we’ve nailed down where the ReFS things come from.
Let’s continue to dump all of the volumes managed by Filter Manager. Apparently hardiskvolume5 is an ReFS volume instead of NTFS.
3: kd> !fltkd.volumes
Volume List: ffffe00000ab5140 "Frame 0"
FLT_VOLUME: ffffe000010e5010 "\Device\Mup"
FLT_INSTANCE: ffffe000011e6640 "FLTDRV1" "388920"
..
FLT_VOLUME: ffffe00002501010 "\Device\HarddiskVolume4"
FLT_INSTANCE: ffffe0000165b010 "FLTDRV1" "388920"
FLT_INSTANCE: ffffe0000165daa0 "Fltdrv2 Instance" "366992"
FLT_INSTANCE: ffffe00001661600 "V-locity cache Instance" "366789"
FLT_INSTANCE: ffffe0000343c010 "DKRtWrt Instance" "137100"
…
FLT_VOLUME: ffffe0000169e010 "\Device\HarddiskVolume5"
FLT_INSTANCE: ffffe00001694190 "FLTDRV1" "388920"
…
3: kd> !fltkd.volume ffffe0000169e010
FLT_VOLUME: ffffe0000169e010 "\Device\HarddiskVolume5"
FLT_OBJECT: ffffe0000169e010 [04000000] Volume
RundownRef : 0x0000000000000004 (2)
PointerCount : 0x00000001
PrimaryLink : [ffffe00001693020-ffffe000016aa020]
Frame : ffffe00000ab5010 "Frame 0"
Flags : [00000064] SetupNotifyCalled EnableNameCaching FilterAttached
FileSystemType : [0000001c]
VolumeLink : [ffffe00001693020-ffffe000016aa020]
DeviceObject : ffffe000016a1df0
DiskDeviceObject : ffffe000010f1ca0
FrameZeroVolume : ffffe0000169e010
VolumeInNextFrame : 0000000000000000
Guid : "\??\Volume{19df173a-2f74-11e4-80bb-0050568127c8}"
CDODeviceName : "\Refs"
CDODriverName : "\FileSystem\ReFS"
TargetedOpenCount : 0
Callbacks : (ffffe0000169e120)
ContextLock : (ffffe0000169e508)
VolumeContexts : (ffffe0000169e510) Count=0
StreamListCtrls : (ffffe0000169e518) rCount=2
FileListCtrls : (ffffe0000169e598) rCount=0
NameCacheCtrl : (ffffe0000169e618)
InstanceList : (ffffe0000169e0a0)
FLT_INSTANCE: ffffe00001694190 "FLTDRV1" "388920"
3: kd> !devstack ffffe000016a1df0
!DevObj !DrvObj !DevExt ObjectName
> ffffe000016a1df0 \FileSystem\FltMgr ffffe000016a1f40
ffffe00002259030 \FileSystem\ReFS ffffe00002259180
So the target file object that 3rd party driver would like to query is on a ReFS volume. Let’s dump out the target instance now.
3: kd> !fltkd.instance 0xffffe000`0165daa0
FLT_INSTANCE: ffffe0000165daa0 "Fltdrv2 Instance" "366992" <<<< instance changes.
FLT_OBJECT: ffffe0000165daa0 [01000000] Instance
RundownRef : 0x0000000000000000 (0)
PointerCount : 0x00000002
PrimaryLink : [ffffe00001661610-ffffe0000165b020]
OperationRundownRef : ffffe0000165f140
Could not read field "Number" of fltmgr!_EX_RUNDOWN_REF_CACHE_AWARE from address: ffffe0000165f140
Flags : [00000000]
Volume : ffffe00002501010 "\Device\HarddiskVolume4" <<<< volume remains the same
Filter : ffffe00000a9ac50 "DKTLFSMF" <<<< another filter.
TrackCompletionNodes : ffffe0000165ceb0
ContextLock : (ffffe0000165db10)
Context : ffffe00000d096d0
CallbackNodes : (ffffe0000165db30)
VolumeLink : [ffffe00001661610-ffffe0000165b020]
FilterLink : [ffffe00000a9ad10-ffffe00002553cc0]
We can notice that instance changes from original FLT_INSTANCE: ffffe0000165b010 "FLTDRV1" "388920" to FLT_INSTANCE: 0xffffe000`0165daa0 "Fltdrv2 Instance" "366992". However, the instance is attached to HarddiskVolume4 which is bound to NTFS. After initializing the parameters of the callback data structure returned by FltAllocateCallbackData, FltQueryInformationFile initiates the I/O operation by passing the structure to FltPerformSynchronousIo or FltPerformAsynchronousIo. These routines send the I/O operation only to the minifilter driver instances attached below the initiating instance (specified in the Instance parameter) and to the file system i.e. NTFS.
So the whole story is, the original query is all about a file open against \AV-REDIRECT-F3392236-BA8C-4AD9-8AEA-48F099A8EE9C\ffffe0003c8dae20.ini on HarddiskVolume4 which happens to be NTFS volume. The query is passed to 3rd party preoperation call back routine. The 3rd party driver continues the query by calling FltQueryInformationFile for a different file open that is on a ReFS volume but the filter instance attached to original NTFS volume.
It is not hard to image the potential corruption if NTFS is instructed to operate on something pertaining to ReFS system. Bugcheck is one of the payoffs.
Actually the 3rd party drivers’ behavior breaks the minifilter callback rule. Here is except from MSDN:
A minifilter driver can modify the parameters for an I/O operation. For example, a minifilter driver's preoperation callback routine can redirect an I/O operation to a different volume by changing the target instance for the operation. The new target instance must be an instance of the same minifilter driver at the same altitude on another volume.
Conclusion:
The fltdrv1.sys driver is violating the minifilter callback rule by redirecting I/O to an instance of a different minifilter driver.
In this post, we go through the dump analysis to look for the useful information about filter manager and minifilter, and solve a case with public debugging extension fltkd.dll and public filter manger symbol. Hope you enjoyed it!
Comments
- Anonymous
June 03, 2015
what can we do to avoid this..? solution for it? [If you are a system administrator, remove the minifilter that is causing the problem. If you are a driver developer you can recode your driver to avoid breaking the minifilter callback rule.]