minispy hangs on unload when using FltQueryInformationFile()

Hello,

In Windows Vista, I’m trying to get the fileID by FltQueryInformationFile() in Pre-Operation-Call of three IRP_MJ codes, i.e., READ,WRITE, and SET_INFORMATION.

I do this by reusing the minspy sample code (a minifilter driver).
The calls to FltQueryInformationFile are always successful.
However, when I unload the minispy by FltMc. The driver halts infinitely.

The Windbg shows the driver halt when calling the FltUnregisterFilter() in the SpyFilterUnload callback.

Does anyone know why this happens?

I’m struggling for quite a few days. Thanks for help in advance!

P.S. I’m having troubles in using driver verifier due to lack of symbol file.

To help understand what revsion I have made in the SpyLogPreOperationData, here is the code.

PRECORD_DATA recordData = &RecordList->LogRecord.Data;
PDEVICE_OBJECT devObj;
NTSTATUS status;
FILE_INTERNAL_INFORMATION FileInfo;
FILE_FS_VOLUME_INFORMATION VolInfo;

recordData->fileId.QuadPart = -1;
if (FltObjects->FileObject != NULL && FltObjects->Instance != NULL){
status = FltQueryInformationFile(FltObjects->Instance, FltObjects->FileObject, (PVOID) &FileInfo, sizeof(FileInfo), FileInternalInformation, NULL);
if (NT_SUCCESS(status))
recordData->fileId = FileInfo.IndexNumber;

}

status = FltGetDeviceObject(FltObjects->Volume,&devObj);
if (NT_SUCCESS(status)) {

ObDereferenceObject(devObj);

} else {

devObj = NULL;
}

//
// Save the information we want
//

recordData->CallbackMajorId = Data->Iopb->MajorFunction;
recordData->CallbackMinorId = Data->Iopb->MinorFunction;
recordData->IrpFlags = Data->Iopb->IrpFlags;
recordData->Flags = Data->Flags;

// recordData->DeviceObject = (FILE_ID)devObj;
// recordData->FileObject = (FILE_ID)FltObjects->FileObject;
// recordData->Transaction = (FILE_ID)FltObjects->Transaction;
recordData->ProcessId = (FILE_ID)PsGetCurrentProcessId();
recordData->ThreadId = (FILE_ID)PsGetCurrentThreadId();

KeQuerySystemTime( &recordData->OriginatingTime );

Have tried running with verifier enabled for your minifilter ? Filter Manager verifier keeps track of all sorts of things and can tell you if you’re leaking references or doing something that might make your minifilter to appear to hang when unloading.

When you try to unload your minifilter filter manager will wait for the reference count on your objects to get to 0 (among other things) and so if something is leaking references then it will wait forever.

Regards,
Alex.
This posting is provided “AS IS” with no warranties, and confers no rights.

Hi Alex,

Thanks for the suggestion.

I’ve tried to look at the problem through verifier but getting no hint. It seems all the object usage/reference number is 0.

Note that the halting also happens when the only instance (attached to volume 0) is trying to detach.

here is the output when the driver halts on unload.

kd> !filter ace12e40 8

*** Extension DLL(6721 Free) does not match target system(6001 Free)

FLT_FILTER: ace12e40 “Minispy” “385100”
InstanceList : (ace12e70)
FLT_INSTANCE: b06d6e68 “Minispy - Top Instance” “385100”
Object usage/reference information:
References to FLT_CONTEXT : 0
Allocations of FLT_CALLBACK_DATA : 0
Allocations of FLT_DEFERRED_IO_WORKITEM : 0
Allocations of FLT_GENERIC_WORKITEM : 0
References to FLT_FILE_NAME_INFORMATION : 0
Open files : 0
References to FLT_OBJECT : 0

The filter’s verification information is:

kd> !filter ace12e40 10

*** Extension DLL(6721 Free) does not match target system(6001 Free)

FLT_FILTER: ace12e40 “Minispy” “385100”
InstanceList : (ace12e70)
FLT_INSTANCE: b06d6e68 “Minispy - Top Instance” “385100”
VerifierExtension : b3da2dc8
FilterUnload : 00000000 (null)
InstanceSetup : 00000000 (null)
InstanceQueryTeardown : a4dd2150 minispy!SpyQueryTeardown
InstanceTeardownStart : 00000000 (null)
InstanceTeardownComplete : 00000000 (null)
READ (3)
PreOperation : a4dce050 minispy!SpyPreOperationCallback
PostOperation : a4dce2f0 minispy!SpyPostOperationCallback
WRITE (4)
PreOperation : a4dce050 minispy!SpyPreOperationCallback
PostOperation : a4dce2f0 minispy!SpyPostOperationCallback
SET_INFORMATION (6)
PreOperation : a4dce050 minispy!SpyPreOperationCallback
PostOperation : a4dce2f0 minispy!SpyPostOperationCallback

I don’t see anything wrong.

My guess is the halting actually happens within fltmgr but I don’t know how to look into that.

Any suggestion?

When I detach the only instance, the user mode application never return.

The windbg call stack indicates the kernel stuck on a call at fltmgr!FltpCommonDetachVolume.

The Object usage/reference count are all 0.

The filter’s context usage information is:

kd> !filter ad8b0e40 2

*** Extension DLL(6721 Free) does not match target system(6001 Free)

FLT_FILTER: ad8b0e40 “Minispy” “385100”
FLT_OBJECT: ad8b0e40 [02000000] Filter
RundownRef : 0x00000008 (4)
PointerCount : 0x00000002
PrimaryLink : [9bcfaacc-86202d1c]
Frame : 86202cc0 “Frame 0”
Flags : [00000002] FilteringInitiated
DriverObject : 86b3b040
FilterLink : [9bcfaacc-86202d1c]
PreVolumeMount : 00000000 (null)
PostVolumeMount : 00000000 (null)
FilterUnload : a420e0e0 minispy!SpyFilterUnload
InstanceSetup : 00000000 (null)
InstanceQueryTeardown : 83388d14 fltmgr!FltvInstanceQueryTeardown
InstanceTeardownStart : 00000000 (null)
InstanceTeardownComplete : 00000000 (null)
ActiveOpens : (ad8b0f14) mCount=0
Communication Port List : (ad8b0f40) mCount=1
Client Port List : (ad8b0f6c) mCount=1
VerifierExtension : adb3adc8
Operations : ad8b0f9c
OldDriverUnload : 00000000 (null)
SupportedContexts : (ad8b0ed8)
VolumeContexts : (ad8b0ed8)
InstanceContexts : (ad8b0edc)
FileContexts : (ad8b0ee0)
StreamContexts : (ad8b0ee4)
StreamHandleContexts : (ad8b0ee8)
TransactionContext : (ad8b0eec)
ALLOCATE_CONTEXT_NODE: adb3cf38 [01] LookasideList
Filter : ad8b0e40 “Minispy”
ContextCleanupCallback : a420a6a0 minispy!SpyDeleteTxfContext
Next : 00000000
ContextType : [0020] TransactionContext
Flags : [01] LookAsideListInited
Could not read field “NonPaged.L.Size” of FltMgr!_ALLOCATE_CONTEXT_LOOKASIDE from address: adb3cf38
InstanceList : (ad8b0e70)
FLT_INSTANCE: af096e68 “Minispy - Top Instance” “385100”

Anything wrong here? I can’t figure out it.

Query it in PostCreate and save to your context instead.


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

wrote in message news:xxxxx@ntfsd…
> Hello,
>
> In Windows Vista, I’m trying to get the fileID by FltQueryInformationFile() in Pre-Operation-Call of three IRP_MJ codes, i.e., READ,WRITE, and SET_INFORMATION.
>
> I do this by reusing the minspy sample code (a minifilter driver).
> The calls to FltQueryInformationFile are always successful.
> However, when I unload the minispy by FltMc. The driver halts infinitely.
>
> The Windbg shows the driver halt when calling the FltUnregisterFilter() in the SpyFilterUnload callback.
>
> Does anyone know why this happens?
>
> I’m struggling for quite a few days. Thanks for help in advance!
>
> P.S. I’m having troubles in using driver verifier due to lack of symbol file.
>

Hi Maxim,

Thanks for the hint.

I need to intercept every read/write/move/delete IRP to see what file this IRP is doing with. Therefore, querying it in PostCreate cannot meet our requirement.

I’m not sure how to save the context. Do you mean I should keep the four values in FilterContext array in the FLT_CALLBACK_DATA before calling FltQueryInformationFile() and set them back when the call returns?

Any sample code is appreciated.

In addition, it would be great if you can provide a little more detail about how this driver halting could happen.

Thank you very much!

Frank

> I need to intercept every read/write/move/delete IRP to see what file this IRP is doing with. Therefore,

querying it in PostCreate cannot meet our requirement.

Why? it can.

Create a stream context. In PostCreate, put the file ID there, in all other paths, just query it there.


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

Ah, I get your point.

Seems to be a very good way.

I find a related MSDN information about how to create/associate a per-stream context with a file stream. http://msdn.microsoft.com/en-us/library/ms790772.aspx

Is it a correct entry point for me to dig into?

Other than that, I’m still confused about why my code causes this halting issue.

Could you explain it in more details? I don’t find any hint by crawling the entire Internet and this website. :frowning:

> Other than that, I’m still confused about why my code causes this halting issue.

Try using the FltMgr’s WinDbg/KD extension to investigate. I think it is called !fltkd


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

I did use the !fltkd.

The previous threads (4 and 5) list the results. However, everything looks fine (at least to me).

I think I need to see some stacks, especially the one with FltpCommonDetachVolume, but all the stacks with your minifilter or fltmgr would be better.

Regards,
Alex.
This posting is provided “AS IS” with no warranties, and confers no rights.

Hi Alex,

I found the real place causing driver halt is a KeWaitForSingleObject Call in
nt!ExWaitForRundownProtectionReleaseCacheAware+0xac:

The callstack looks like this:
kd> kp
ChildEBP RetAddr
WARNING: Stack unwind information not available. Following frames may be wrong.
87b44ae4 8337deea nt!ExWaitForRundownProtectionReleaseCacheAware+0xac
87b44af0 83384d84 fltmgr!FltpDrainPendingCallbacksForInstance+0x18
87b44b20 8337d92f fltmgr!FltpFreeInstance+0x74
87b44b34 8338d345 fltmgr!FltpCommonDetachVolume+0x7d
87b44b8c 8338d9c1 fltmgr!FltpDetachVolume+0x11d
87b44ba0 8337019d fltmgr!FltpCommonDeviceControl+0x13b
87b44be0 83370cbf fltmgr!FltpControlDispatch+0x81
87b44c0c 81f0a6be fltmgr!FltpDispatch+0x1d
87b44c30 81c7b184 nt!PoSetHiberRange+0xbe7b
87b44c44 81e28064 nt!IofCallDriver+0x1b
87b44c64 81e32a4c nt!CcUnpinData+0x237
87b44d00 81e64794 nt!NtWriteFile+0x102a
87b44d34 81c8c97a nt!NtDeviceIoControlFile+0x2a
87b44d64 77199a93 nt!ZwQueryLicenseValue+0xbf2
87b44d68 badb0d00 ntdll!KiFastSystemCall+0x3
87b44d6c 0012f618 0xbadb0d00
87b44d70 00000000 0x12f618

Note that this is stack state right before the FltMgr is about to call KeWaitForSingleObject listed below.
81c4ae70 e804e90300 call nt!KeWaitForSingleObject (81c89779)

From the call stack, it seems fltmgr is waiting for some pending IRP callbacks to complete. But I double check the object/context usage of minispy and find it all 0.

So I have no clue how to find out the pending IRPs.
Any suggestions?

Thanks,
Frank

This means filter manager is waiting for all operations to drain. Look here for more information on unloading and draining:

http://download.microsoft.com/download/f/0/5/f05a42ce-575b-4c60-82d6-208d3754b2d6/LoadUnload.ppt

Regards,
Alex.
This posting is provided “AS IS” with no warranties, and confers no rights.

Hi Alex,

Your hint is of great value to me.

Ok. Here is what I guess.

The FltQueryInformationFile() in my Pre-Operation-Callback actually issues a new I/O request packet (IRP_MJ_SET_INFORMATION) to the lower layer driver. And this I/O operation is “asynchronous” in nature.

Therefore, when driver unload/instance teardown happens, it is possible that FltMgr removes all resource (FltObject, Context, callback data, etc) before the minispy-initiated IO return. And specifically in my case, the IRP_MJ_SET_INFORMATION IO processed by the lower layer driver will be pending outside somewhere nobody would be able to handle. And that is also why I cannot see any pending IRPs from minispy itself.

If this is the case, there are two ways to solve this issue.
First, issue a synchronized I/O, i.e., instead of calling FltQueryInformationFile by using FltPerformSynchronousIo with IRJ_MJ_SET_INFORMATION. But this could incur significant performance overhead.

Second, in SpyFilterUnload and SpyQueryTeardown callback function, canceling any filter initiated IO.

I prefer the second way. However, I’m not sure how to do this.
A possible solution in my mind is: use FltPerformAsynchronousIo instead of FltQueryInformationFile in Pre-Operation-Callback and do a FltCancelIo when driver unload/instance teardown.

Do you think this is feasible?

Thanks,
Frank

Alex,

The ppt file you gave me suggests we cancel filter initiated IOs in InstanceTeardownStart callback.

Therefore my second way sounds feasible.

However, I don’t know how to query the filter intiated IOs and cancel it.

Do you know the related APIs for me to dig into?

Thank you very much for your continous help.

Fan

I think you should add your CALLBACK_DATA to some tracking structure before you call FltPerformAsynchronousIo, remove it on completion and when you need to unload walk the structure and cancel everything that’s left there (i.e. that hasn’t completed yet).

Regards,
Alex.
This posting is provided “AS IS” with no warranties, and confers no rights.

Alex,

Thanks for your suggestion.

The problem here is I 'm not sure where the right place to keep the Callback_data should be.

Is it as Maxim suggested, create a stream context and save it somewhere (again, where is the right place here?)

Regards,
Frank

I would go with an instance context or a filter context, depending on your architecture.

Thanks,
Alex.

Thanks a lot for the suggestion.