FltSendMessage in Paging I/O path and IRQL greater than APC_LEVEL

Hello Everyone,

I am developing a minifilter driver to monitor Create/Read/Write/Close operations on system and need to send these operations data of interested processes to user mode application for processing. Based on processing of user mode application, i am completing those respective callbacks. In this i am facing one issue that some Post-Read callbacks are coming as paging I/O along with IRQL of those callbacks is greater than APC_LEVEL. So in such scenario, i could not send data to user mode as FltSendMessage needs to be called below or at APC_LEVEL. Also FltDoCompletionProcessingWhenSafe function fails for Paging I/O which is mentioned in its MSDN documentation.

I would like to understand whether this is indeed not possible to send notification from Paging I/O + IRQL greater than APC_LEVEL to user mode or is there any way to do this? I have tried returning FLT_PREOP_SYNCHRONIZE from PreRead callback but that callback comes as asynchronous callback so i could not return FLT_PREOP_SYNCHRONIZE.

I also looked into FltQueueDeferredIoWorkItem API but documentation says that this function also fails with STATUS_FLT_NOT_SAFE_TO_POST_OPERATION for paging I/O. So as per my understanding till now, is it like we can not defer processing of Paging I/O to any worker thread and we have to process it in the same context in which it got called?

Please help me to understand this.

Thank you in advance.

You are correct that FltDoCompletionProcessingWhenSafe and FltQueueDeferredIoWorkItem fail for paging I/O. As a general rule filters should avoid posting paging I/O due to locking of the underlying file system. For example, the file system might have recursively acquireable locks held for the current thread when you receive a paging request in your PreOp. If you then post the request to another thread and send it down to the file system you’ll deadlock.

I’d argue that posting the PostOp is inherently safer because the file system is done with the request at this point, but there’s some hairy O/S edges you can bump into if you try to asynchronously process a synchronous request. It can work given some designs, but not with these APIs and it’s best to avoid as a general rule unless you really understand paging I/O and why it’s OK for your filter.

So, the FltMgr solution to this problem would be to synchronize the paging I/Os and therefore guarantee the IRQL of your PostOp callbacks. Depending on what you’re trying to do this may or may not impact performance.

So, let me back this up and ask two questions:

  1. Do you really need to intercept paging I/Os?
  2. If the answer to #1 is yes, do you really need to be in the PostOp callbacks for the paging I/Os?

Thank you Scott for your reply.

  1. Do you really need to intercept paging I/Os?

Yes, I need to intercept paging I/Os in my minifilter.

  1. If the answer to #1 is yes, do you really need to be in the PostOp callbacks for the paging I/Os?

Yes, In the case of read operations i need to be in PostOp callback as .

As FltDoCompletionProcessingWhenSafe and FltQueueDeferredIoWorkItem does not work for Paging I/O, I have created a worker thread using PsCreateSystemThread() in DriverEntry and i handled all paging I/O requests which has IRQL higher than APC_LEVEL in worker thread by returning FLT_POSTOP_MORE_PROCESSING_REQUIRED from PostRead callback. Once i am done with processing of I/O in worker thread i call FltCompletePendedPostOperation() to complete pended operation.

It seems to work sometimes but crash occurs often. The crash occurs at the entry point address of the PostRead operation callback function itself saying DRIVER_IRQL_NOT_LESS_OR_EQUAL (d1). So is this the side effect of pending Paging I/O in post-op and completing it later in worker thread?

Below is output of !analyze -v:

2: kd> !analyze -v


  •                                                                         *
    
  •                    Bugcheck Analysis                    *
    
  •                                                                         *
    

DRIVER_IRQL_NOT_LESS_OR_EQUAL (d1)
An attempt was made to access a pageable (or completely invalid) address at an
interrupt request level (IRQL) that is too high. This is usually
caused by drivers using improper addresses.
If kernel debugger is available get stack backtrace.
Arguments:
Arg1: 88349970, memory referenced
Arg2: 00000002, IRQL
Arg3: 00000000, value 0 = read operation, 1 = write operation
Arg4: 88349970, address which referenced memory

Debugging Details:

KEY_VALUES_STRING: 1

STACKHASH_ANALYSIS: 1

TIMELINE_ANALYSIS: 1

DUMP_CLASS: 1

DUMP_QUALIFIER: 0

BUILD_VERSION_STRING: 7601.24384.x86fre.win7sp1_ldr_escrow.190220-1800

DUMP_TYPE: 0

BUGCHECK_P1: ffffffff88349970

BUGCHECK_P2: 2

BUGCHECK_P3: 0

BUGCHECK_P4: ffffffff88349970

READ_ADDRESS: 88349970

CURRENT_IRQL: 2

FAULTING_IP:
MyFilter!MyFilterPostRead+0 [d:\work\repos\temp\My\My\Myfilter\opcallbacks.c @ 593]
88349970 55 push ebp

IP_IN_PAGED_CODE:
MyFilter!MyFilterPostRead+0 [d:\work\repos\temp\My\My\Myfilter\opcallbacks.c @ 593]
88349970 55 push ebp

CPU_COUNT: 3

CPU_MHZ: a20

CPU_VENDOR: GenuineIntel

CPU_FAMILY: 6

CPU_MODEL: 9e

CPU_STEPPING: a

CPU_MICROCODE: 6,9e,a,0 (F,M,S,R) SIG: 0’00000000 (cache) 0’00000000 (init)

DEFAULT_BUCKET_ID: INTEL_CPU_MICROCODE_ZERO

BUGCHECK_STR: 0xD1

PROCESS_NAME: System

ANALYSIS_SESSION_HOST: LAPTOP-N67OVL4H

ANALYSIS_SESSION_TIME: 10-14-2019 18:26:44.0135

ANALYSIS_VERSION: 10.0.17763.1 amd64fre

TRAP_FRAME: 89040748 – (.trap 0xffffffff89040748)
ErrCode = 00000000
eax=00000019 ebx=8904080c ecx=00000001 edx=00000018 esi=82806e74 edi=9162e62c
eip=88349970 esp=890407bc ebp=890407e8 iopl=0 nv up ei pl nz na po nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010202
MyFilter!MyFilterPostRead:
88349970 55 push ebp
Resetting default scope

LAST_CONTROL_TRANSFER: from 8290d30d to 828946cc

FAILED_INSTRUCTION_ADDRESS:
MyFilter!MyFilterPostRead+0 [d:\work\repos\temp\My\My\Myfilter\opcallbacks.c @ 593]
88349970 55 push ebp

STACK_TEXT:
89040314 8290d30d 00000003 e2d8ffad 00000065 nt!RtlpBreakWithStatusInstruction
89040364 8290de09 00000003 88349970 88349970 nt!KiBugCheckDebugBreak+0x1c
89040728 828730db 0000000a 88349970 00000002 nt!KeBugCheck2+0x68b
89040728 88349970 0000000a 88349970 00000002 nt!KiTrap0E+0x367
890407b8 85f787d1 9228a628 8904080c a7bfcff0 MyFilter!MyFilterPostRead [d:\work\repos\temp\My\My\Myfilter\opcallbacks.c @ 593]
890407e8 85f53324 9228a628 0204080c a7bfcff0 fltmgr!FltvPostOperation+0x71
89040850 85f56512 0028a5c8 9228a5c8 10000000 fltmgr!FltpPerformPostCallbacks+0x24a
89040864 85f56b46 9228a5c8 89040918 890408a4 fltmgr!FltpProcessIoCompletion+0x10
89040874 82b68cd4 9175fba8 a79bae48 9228a5c8 fltmgr!FltpPassThroughCompletion+0x98
890408a4 82891860 9175fba8 a79bae48 89040918 nt!IovpLocalCompletionRoutine+0x14b
890408e8 82b68b64 00000001 91775ab0 8ca28008 nt!IopfCompleteRequest+0x115
89040950 86692498 89040984 86692abd 8ca247b8 nt!IovCompleteRequest+0x133
89040958 86692abd 8ca247b8 a79bae48 00000001 CLASSPNP!ClassCompleteRequest+0x11
89040984 82b68cd4 00000000 8bb2cf48 00775ab0 CLASSPNP!TransferPktComplete+0x2e4
890409b4 82891860 00000000 8bb2cf48 89040a28 nt!IovpLocalCompletionRoutine+0x14b
890409f8 82b68b64 00000000 8bb2cf48 8bb2cf48 nt!IopfCompleteRequest+0x115
89040a60 85f13da3 91775b5c 91775500 89040a90 nt!IovCompleteRequest+0x133
89040a70 85f14654 8c9220e8 8bb2cf48 91775b5c ataport!IdeCompleteScsiIrp+0x31
89040a90 85f114bd 8c9220e8 91775500 8c7f80e0 ataport!IdeCommonCrbCompletion+0x44
89040aac 85f17486 8c7f80e0 91775500 91775500 ataport!IdeTranslateCompletedRequest+0x161
89040b24 85f17689 8c7f80e0 91775500 89023a00 ataport!IdeProcessCompletedRequests+0x2a0
89040b78 82890f76 8c7f809c 8c7f8028 00000000 ataport!IdePortCompletionDpc+0xab
89040bd4 82890dd8 89022120 89027000 00000000 nt!KiExecuteAllDpcs+0xfa
89040c20 82890bf8 00000000 0000000e 00000000 nt!KiRetireDpcList+0xd5
89040c24 00000000 0000000e 00000000 00000000 nt!KiIdleLoop+0x38

THREAD_SHA1_HASH_MOD_FUNC: e81795dbd4e18b406e932ea7bd2b1b921bb1e448

THREAD_SHA1_HASH_MOD_FUNC_OFFSET: 66775c8f49eb976387274dc48d9d67caba858932

THREAD_SHA1_HASH_MOD: 86cb5c408da196a1818427ca57bc5f3d450d8f42

FOLLOWUP_IP:
MyFilter!MyFilterPostRead+0 [d:\work\repos\temp\My\My\Myfilter\opcallbacks.c @ 593]
88349970 55 push ebp

FAULT_INSTR_CODE: 83ec8b55

FAULTING_SOURCE_LINE: d:\work\repos\temp\My\My\Myfilter\opcallbacks.c

FAULTING_SOURCE_FILE: d:\work\repos\temp\My\My\Myfilter\opcallbacks.c

FAULTING_SOURCE_LINE_NUMBER: 593

FAULTING_SOURCE_CODE:
589: In PCFLT_RELATED_OBJECTS pFltObjects,
590: In_opt PVOID pCompletionContext,
591: In FLT_POST_OPERATION_FLAGS Flags
592: )

593: {
594: NTSTATUS ntStatus;
595: // BOOLEAN bRet = FALSE;
596: LONGLONG llReadOffset = 0;
597: PVOID pvOrigReadBuff = NULL;
598: ULONG ulOrigReadBuffLen = 0;

SYMBOL_STACK_INDEX: 4

SYMBOL_NAME: MyFilter!MyFilterPostRead+0

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: MyFilter

IMAGE_NAME: MyFilter.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 5da45f61

STACK_COMMAND: .thread ; .cxr ; kb

FAILURE_BUCKET_ID: 0xD1_VRF_CODE_AV_PAGED_IP_MyFilter!MyFilterPostRead+0

BUCKET_ID: 0xD1_VRF_CODE_AV_PAGED_IP_MyFilter!MyFilterPostRead+0

PRIMARY_PROBLEM_CLASS: 0xD1_VRF_CODE_AV_PAGED_IP_MyFilter!MyFilterPostRead+0

TARGET_TIME: 2019-10-14T12:56:07.000Z

OSBUILD: 7601

OSSERVICEPACK: 1000

SERVICEPACK_NUMBER: 0

OS_REVISION: 0

SUITE_MASK: 272

PRODUCT_TYPE: 1

OSPLATFORM_TYPE: x86

OSNAME: Windows 7

OSEDITION: Windows 7 WinNt (Service Pack 1) TerminalServer SingleUserTS

OS_LOCALE:

USER_LCID: 0

OSBUILD_TIMESTAMP: 2019-02-21 09:05:30

BUILDDATESTAMP_STR: 190220-1800

BUILDLAB_STR: win7sp1_ldr_escrow

BUILDOSVER_STR: 6.1.7601.24384.x86fre.win7sp1_ldr_escrow.190220-1800

ANALYSIS_SESSION_ELAPSED_TIME: b36

ANALYSIS_SOURCE: KM

FAILURE_ID_HASH_STRING: km:0xd1_vrf_code_av_paged_ip_Myfilter!Myfilterpostread+0

FAILURE_ID_HASH: {7cf7e16a-1dc8-96be-1d16-189e48272ff1}

Followup: MachineOwner

Looks like your post read handler is in a pageable code section. Can’t use pageable code here because it can run at DISPATCH_LEVEL.

Good luck!