'The IRQL at which the lock was acquired.' Error on FltSendMessage

I’m a student in Korea, and sorry for my bad English :confused:

i’m studying minifilter, referencing Microsoft’s scanner example.
I simply programmed a driver to send some callback information to user-mode application.
this works pretty well for a second. after few seconds, i can see BSOD with this message, KERNEL_AUTO_BOOST_LOCK_ACQUISITION_WITH_RAISED_IRQL.

what is this means? i tried SpinLock but situation worse.

my code is this.

notification = ExAllocatePool(
NonPagedPool,
sizeof(KPSMON_NOTIFICATION));

if (!NT_SUCCESS(status))
{
leave;
}

notification->fltobject = (__int64)FltObjects;

notification->pId = FltGetRequestorProcessId(Data);

notification->isWriteAccess = FltObjects->FileObject->WriteAccess;

notification->PrePost = PreOrPost;

RtlCopyMemory(
&notification->MJCode,
“Abcd”,
sizeof(“abcd”)); //test string

rLength = KPSMON_REPLY_BUFFER_SIZE;

status = FltSendMessage(
kpsmonData.Filter,
&kpsmonData.ClientPort,
notification,
sizeof(KPSMON_NOTIFICATION),
notification,
&rLength,
&timeout);

if (!NT_SUCCESS(status))
{
leave;
}

Hi,
You forgot to mention where does the BSOD occur, and post the !analyze -v
output.
You could also post the structure KPSMON_NOTIFICATION so we can see what it
looks like.
The BSOD could be occurring even in the RtlCopyMemory or the Flt call, who
knows.
Also you should mention where in the minifilter is this code called ( in
what pre/post operation ) and if you raise the irql yourself,
or just check the irql in the debugger yourself before running the code.


Regards,
Gabriel Bercea
Windows Kernel Driver Consulting
www.kasardia.com

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of xxxxx@gmail.com
Sent: Saturday, 7 May, 2016 16:29
To: Windows File Systems Devs Interest List
Subject: [ntfsd] ‘The IRQL at which the lock was acquired.’ Error on
FltSendMessage

I’m a student in Korea, and sorry for my bad English :confused:

i’m studying minifilter, referencing Microsoft’s scanner example.
I simply programmed a driver to send some callback information to user-mode
application.
this works pretty well for a second. after few seconds, i can see BSOD with
this message, KERNEL_AUTO_BOOST_LOCK_ACQUISITION_WITH_RAISED_IRQL.

what is this means? i tried SpinLock but situation worse.

my code is this.

notification = ExAllocatePool(
NonPagedPool,
sizeof(KPSMON_NOTIFICATION));

if (!NT_SUCCESS(status))
{
leave;
}

notification->fltobject = (__int64)FltObjects;

notification->pId = FltGetRequestorProcessId(Data);

notification->isWriteAccess =
FltObjects->FileObject->WriteAccess;

notification->PrePost = PreOrPost;

RtlCopyMemory(
&notification->MJCode,
“Abcd”,
sizeof(“abcd”)); //test string

rLength = KPSMON_REPLY_BUFFER_SIZE;

status = FltSendMessage(
kpsmonData.Filter,
&kpsmonData.ClientPort,
notification,
sizeof(KPSMON_NOTIFICATION),
notification,
&rLength,
&timeout);

if (!NT_SUCCESS(status))
{
leave;
}


NTFSD is sponsored by OSR

MONTHLY seminars on crash dump analysis, WDF, Windows internals and software
drivers!
Details at http:

To unsubscribe, visit the List Server section of OSR Online at
http:</http:></http:>

Ok. i understood.

WinDbg is pointing this

527: sizeof(“abcd”));
528:
529: rLength = KPSMON_REPLY_BUFFER_SIZE;
530:

531:
532: status = FltSendMessage(
533: kpsmonData.Filter,
534: &kpsmonData.ClientPort,
535: notification,
536: sizeof(KPSMON_NOTIFICATION),

Bug message is :
KERNEL_AUTO_BOOST_LOCK_ACQUISITION_WITH_RAISED_IRQL (192)
A lock tracked by AutoBoost was acquired while executing at DISPATCH_LEVEL or
above.
Arguments:
Arg1: ffffe001cedb1080, The address of the thread.
Arg2: ffffe001ce4dd7d8, The lock address.
Arg3: 0000000000000002, The IRQL at which the lock was acquired.
Arg4: 0000000000000000, Reserved.

here is my full code

structures :
typedef struct KPSMON_DATA {

//
// The filter handle that results from a call to
// FltRegisterFilter.
//
PDRIVER_OBJECT DriverObject;

PFLT_FILTER Filter;

PFLT_PORT ServerPort;

PFLT_PORT ClientPort;

PEPROCESS UserProcess;

} KPSMON_DATA, *PKPSMON_DATA;

typedef struct _KPSMON_NOTIFICATION
{
ULONG pId;
UCHAR MJCode[20];
BOOLEAN isWriteAccess;
INT PrePost;
__int64 fltobject;

}KPSMON_NOTIFICATION, *PKPSMON_NOTIFICATION;

typedef struct _KPSMON_REPLY
{
BOOLEAN rcvd;

}KPSMON_REPLY, *PKPSMON_REPLY;

typedef struct _KPSMON_STREAM_HANDLE_CONTEXT
{
BOOLEAN allowed;

}KPSMON_STREAM_HANDLE_CONTEXT, *PKPSMON_STREAM_HANDLE_CONTEXT;

#define KPSMON_REPLY_BUFFER_SIZE sizeof(FILTER_REPLY_HEADER) + sizeof(KPSMON_REPLY)

driver code :

FLT_PREOP_CALLBACK_STATUS
kpsmonPreOperation(
Inout PFLT_CALLBACK_DATA Data,
In PCFLT_RELATED_OBJECTS FltObjects,
Flt_CompletionContext_Outptr PVOID *CompletionContext
)
{
UNREFERENCED_PARAMETER(CompletionContext);

kpsmonSendInformation(FltObjects, Data, PRE);

return FLT_PREOP_SUCCESS_WITH_CALLBACK;
}

FLT_POSTOP_CALLBACK_STATUS
kpsmonPostOperation(
Inout PFLT_CALLBACK_DATA Data,
In PCFLT_RELATED_OBJECTS FltObjects,
In_opt PVOID CompletionContext,
In FLT_POST_OPERATION_FLAGS Flags
)
{
UNREFERENCED_PARAMETER(CompletionContext);
UNREFERENCED_PARAMETER(Flags);

kpsmonSendInformation(FltObjects, Data, POST);

return FLT_POSTOP_FINISHED_PROCESSING;
}

NTSTATUS
kpsmonSendInformation(
In PCFLT_RELATED_OBJECTS FltObjects,
In PFLT_CALLBACK_DATA Data,
In INT PreOrPost
)
{
PKPSMON_NOTIFICATION notification = NULL;
NTSTATUS status = STATUS_SUCCESS;
ULONG rLength;
LARGE_INTEGER timeout;
timeout.QuadPart = -(LONGLONG)10000000;

try
{
DbgPrint(“pID = %u, isWriteAccess = %s, PreOrPost = %s”, FltGetRequestorProcessId(Data), FltObjects->FileObject->WriteAccess ? “true” : “false”, (PreOrPost == 0) ? “PRE” : “POST”);

if (isConnected)
{
notification = ExAllocatePool(
NonPagedPool,
sizeof(KPSMON_NOTIFICATION));

if (!NT_SUCCESS(status))
{
leave;
}

notification->fltobject = (__int64)FltObjects;

notification->pId = FltGetRequestorProcessId(Data);

notification->isWriteAccess = FltObjects->FileObject->WriteAccess;

notification->PrePost = PreOrPost;

RtlCopyMemory(
&notification->MJCode,
“Abcd”,
sizeof(“abcd”));

rLength = KPSMON_REPLY_BUFFER_SIZE;

status = FltSendMessage(
kpsmonData.Filter,
&kpsmonData.ClientPort,
notification,
sizeof(KPSMON_NOTIFICATION),
notification,
&rLength,
&timeout);

if (!NT_SUCCESS(status))
{
leave;
}

}
else
{
DbgPrint(“kpsmon: Not Connected!”);
}
}
finally
{
if (!NT_SUCCESS(status))
{
DbgPrint(“kpsmon: Send Message Failed, status 0x%X”, status);
}
}

return status;
}

user-mode code is exactly same as Microsoft’s scanner example code
this is github link : https://goo.gl/T11Ptr

Your code clearly does not match what’s running on the target, note that the
debugger is pointing a blank line in your source (531).

Rebuild your code, copy over the new version, and turn on Driver Verifier.

-scott
OSR
@OSRDrivers

wrote in message news:xxxxx@ntfsd…

Ok. i understood.

WinDbg is pointing this

527: sizeof(“abcd”));
528:
529: rLength = KPSMON_REPLY_BUFFER_SIZE;
530:

531:
532: status = FltSendMessage(
533: kpsmonData.Filter,
534: &kpsmonData.ClientPort,
535: notification,
536: sizeof(KPSMON_NOTIFICATION),

Bug message is :
KERNEL_AUTO_BOOST_LOCK_ACQUISITION_WITH_RAISED_IRQL (192)
A lock tracked by AutoBoost was acquired while executing at DISPATCH_LEVEL
or
above.
Arguments:
Arg1: ffffe001cedb1080, The address of the thread.
Arg2: ffffe001ce4dd7d8, The lock address.
Arg3: 0000000000000002, The IRQL at which the lock was acquired.
Arg4: 0000000000000000, Reserved.

here is my full code

structures :
typedef struct KPSMON_DATA {

//
// The filter handle that results from a call to
// FltRegisterFilter.
//
PDRIVER_OBJECT DriverObject;

PFLT_FILTER Filter;

PFLT_PORT ServerPort;

PFLT_PORT ClientPort;

PEPROCESS UserProcess;

} KPSMON_DATA, *PKPSMON_DATA;

typedef struct _KPSMON_NOTIFICATION
{
ULONG pId;
UCHAR MJCode[20];
BOOLEAN isWriteAccess;
INT PrePost;
__int64 fltobject;

}KPSMON_NOTIFICATION, *PKPSMON_NOTIFICATION;

typedef struct _KPSMON_REPLY
{
BOOLEAN rcvd;

}KPSMON_REPLY, *PKPSMON_REPLY;

typedef struct _KPSMON_STREAM_HANDLE_CONTEXT
{
BOOLEAN allowed;

}KPSMON_STREAM_HANDLE_CONTEXT, *PKPSMON_STREAM_HANDLE_CONTEXT;

#define KPSMON_REPLY_BUFFER_SIZE sizeof(FILTER_REPLY_HEADER) +
sizeof(KPSMON_REPLY)

driver code :

FLT_PREOP_CALLBACK_STATUS
kpsmonPreOperation(
Inout PFLT_CALLBACK_DATA Data,
In PCFLT_RELATED_OBJECTS FltObjects,
Flt_CompletionContext_Outptr PVOID *CompletionContext
)
{
UNREFERENCED_PARAMETER(CompletionContext);

kpsmonSendInformation(FltObjects, Data, PRE);

return FLT_PREOP_SUCCESS_WITH_CALLBACK;
}

FLT_POSTOP_CALLBACK_STATUS
kpsmonPostOperation(
Inout PFLT_CALLBACK_DATA Data,
In PCFLT_RELATED_OBJECTS FltObjects,
In_opt PVOID CompletionContext,
In FLT_POST_OPERATION_FLAGS Flags
)
{
UNREFERENCED_PARAMETER(CompletionContext);
UNREFERENCED_PARAMETER(Flags);

kpsmonSendInformation(FltObjects, Data, POST);

return FLT_POSTOP_FINISHED_PROCESSING;
}

NTSTATUS
kpsmonSendInformation(
In PCFLT_RELATED_OBJECTS FltObjects,
In PFLT_CALLBACK_DATA Data,
In INT PreOrPost
)
{
PKPSMON_NOTIFICATION notification = NULL;
NTSTATUS status = STATUS_SUCCESS;
ULONG rLength;
LARGE_INTEGER timeout;
timeout.QuadPart = -(LONGLONG)10000000;

try
{
DbgPrint(“pID = %u, isWriteAccess = %s, PreOrPost = %s”,
FltGetRequestorProcessId(Data), FltObjects->FileObject->WriteAccess ? “true”
: “false”, (PreOrPost == 0) ? “PRE” : “POST”);

if (isConnected)
{
notification = ExAllocatePool(
NonPagedPool,
sizeof(KPSMON_NOTIFICATION));

if (!NT_SUCCESS(status))
{
leave;
}

notification->fltobject = (__int64)FltObjects;

notification->pId = FltGetRequestorProcessId(Data);

notification->isWriteAccess = FltObjects->FileObject->WriteAccess;

notification->PrePost = PreOrPost;

RtlCopyMemory(
&notification->MJCode,
“Abcd”,
sizeof(“abcd”));

rLength = KPSMON_REPLY_BUFFER_SIZE;

status = FltSendMessage(
kpsmonData.Filter,
&kpsmonData.ClientPort,
notification,
sizeof(KPSMON_NOTIFICATION),
notification,
&rLength,
&timeout);

if (!NT_SUCCESS(status))
{
leave;
}

}
else
{
DbgPrint(“kpsmon: Not Connected!”);
}
}
finally
{
if (!NT_SUCCESS(status))
{
DbgPrint(“kpsmon: Send Message Failed, status 0x%X”, status);
}
}

return status;
}

user-mode code is exactly same as Microsoft’s scanner example code
this is github link : https://goo.gl/T11Ptr

I rebuilded the code

STACK_TEXT:
fffff8000c679e38 fffff8000aa1d981 : 0000000000000192 fffff8000ada2740 ffffe0014ef7c2b8 0000000000000002 : nt!KeBugCheckEx
fffff8000c679e40 fffff800350811a8 : 0000000000000000 0000000000000080 ffffe0014fac0f02 ffffe0014ef7c010 : nt!ExAcquirePushLockSharedEx+0x1a1
fffff8000c679e80 fffff8003762643d : ffffe0014eedc648 fffff80037626535 ffffe0014ee14610 fffff80000000028 : FLTMGR!FltSendMessage+0x78
fffff8000c679fc0 fffff800376260c2 : fffff8000c67a0d0 ffffe0014eedc648 ffffe00100000001 ffffe0014f64c030 : kpsmon!kpsmonSendInformation+0x17d [e:\projects\antivirusengine\kpsmon\kpsmon.c @ 544]
fffff8000c67a050 fffff800350862db : ffffe0014eedc648 fffff8000c67a0d0 0000000000000000 ffffd00100000000 : kpsmon!kpsmonPostOperation+0x42 [e:\projects\antivirusengine\kpsmon\kpsmon.c @ 493]
fffff8000c67a080 fffff80035085cb6 : 0000000000000000 0000000000000000 0000000000000001 ffffe0014e48d010 : FLTMGR!FltpPerformPostCallbacks+0x2ab
fffff8000c67a150 fffff8000aa90f56 : fffff8000c67a249 ffffe00150e1f4f0 ffffe0014f6498a0 ffffe00150e1f803 : FLTMGR!FltpPassThroughCompletionWorker+0x76
fffff8000c67a190 fffff80035ed6011 : ffffe00150b48708 00000000003bb901 0000000000000027 ffffe00150e1f4f0 : nt!IopfCompleteRequest+0x216
fffff8000c67a2b0 fffff8000aa90f56 : ffffe001501982b0 ffffe0014f5f45e0 fffff8000c67a510 ffffe0014f5f47d8 : CLASSPNP!TransferPktComplete+0x1521
fffff8000c67a4b0 fffff80035482b0e : ffffe0014eecd280 fffff8000aadd201 ffffd0013fde5010 0000000000000000 : nt!IopfCompleteRequest+0x216
fffff8000c67a5d0 fffff80035482114 : ffffd0013fde5010 00000000003bb954 fffff8000c67a7a0 ffffd0013fde5bc0 : storport!RaidCompleteRequestEx+0x8e
fffff8000c67a6a0 fffff8003549552c : 0000000000000000 ffffd0013fde5010 0000000000000000 ffffe0014f1bc1a0 : storport!RaidUnitCompleteRequest+0xa74
fffff8000c67a820 fffff8000aa5db60 : fffff8000ad2ef00 fffff8000ad2c180 0000000000000000 fffff8000c67ab20 : storport!RaidpAdapterRedirectDpcRoutine+0xbc
fffff8000c67a8c0 fffff8000aa5d279 : 0000000000000000 0000000000000000 0000000000000000 0000000000000000 : nt!KiExecuteAllDpcs+0x270
fffff8000c67aa10 fffff8000ab5453a : 0000000000026f46 fffff8000ad2c180 fffff8000ada2740 ffffe0014e4f9040 : nt!KiRetireDpcList+0xe9
fffff8000c67ac60 0000000000000000 : fffff8000c67b000 fffff8000c675000 0000000000000000 0000000000000000 : nt!KiIdleLoop+0x5a

STACK_COMMAND: kb

THREAD_SHA1_HASH_MOD_FUNC: 30f2d98e28e7bcea3798a99cc968912178e775af

THREAD_SHA1_HASH_MOD_FUNC_OFFSET: dfe8ee46c5944f44c532aba6d145a9a197ff1b7b

THREAD_SHA1_HASH_MOD: d19efae6bdb25d189b2db5a7d4ba46fb64108eb0

FOLLOWUP_IP:
kpsmon!kpsmonSendInformation+17d [e:\projects\antivirusengine\kpsmon\kpsmon.c @ 544]
fffff800`3762643d 89442440 mov dword ptr [rsp+40h],eax

FAULT_INSTR_CODE: 40244489

FAULTING_SOURCE_LINE: e:\projects\antivirusengine\kpsmon\kpsmon.c

FAULTING_SOURCE_FILE: e:\projects\antivirusengine\kpsmon\kpsmon.c

FAULTING_SOURCE_LINE_NUMBER: 544

FAULTING_SOURCE_CODE:
540: sizeof(“abcd”));
541:
542: rLength = KPSMON_REPLY_BUFFER_SIZE;
543:

544: status = FltSendMessage(
545: kpsmonData.Filter,
546: &kpsmonData.ClientPort,
547: notification,
548: sizeof(KPSMON_NOTIFICATION),
549: notification,

SYMBOL_STACK_INDEX: 3

SYMBOL_NAME: kpsmon!kpsmonSendInformation+17d

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: kpsmon

IMAGE_NAME: kpsmon.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 5736ed32

BUCKET_ID_FUNC_OFFSET: 17d

FAILURE_BUCKET_ID: 0x192_kpsmon!kpsmonSendInformation

BUCKET_ID: 0x192_kpsmon!kpsmonSendInformation

PRIMARY_PROBLEM_CLASS: 0x192_kpsmon!kpsmonSendInformation

TARGET_TIME: 2016-05-14T09:19:03.000Z

OSBUILD: 10586

OSSERVICEPACK: 0

SERVICEPACK_NUMBER: 0

OS_REVISION: 0

SUITE_MASK: 272

PRODUCT_TYPE: 1

OSPLATFORM_TYPE: x64

OSNAME: Windows 10

OSEDITION: Windows 10 WinNt TerminalServer SingleUserTS

OS_LOCALE:

USER_LCID: 0

OSBUILD_TIMESTAMP: 2016-04-23 13:04:21

BUILDDATESTAMP_STR: 160422-1850

BUILDLAB_STR: th2_release_sec

BUILDOSVER_STR: 10.0.10586.306.amd64fre.th2_release_sec.160422-1850

ANALYSIS_SESSION_ELAPSED_TIME: 282e

ANALYSIS_SOURCE: KM

FAILURE_ID_HASH_STRING: km:0x192_kpsmon!kpsmonsendinformation

FAILURE_ID_HASH: {2776e8b1-04fd-84cb-bb5f-313b917d09e6}

Followup: MachineOwner

That explains it…

FltSendMessage requires <= APC_LEVEL but you are in your post operation callback running at DISPATCH_LEVEL. You need to call FltDoCompletionProcessingWhenSafe and do the work in the callback. See the remarks section here:

https://msdn.microsoft.com/en-us/library/windows/hardware/ff551107(v=vs.85).aspx

-scott
OSR
@OSRDrivers

To Scott.
Thanks for your advice!
I just fixed the problem. thanks to you.
but if i use FltDoCompletionProcessingWhenSafe function, is that means i can’t send DPC_LEVEL datas?

Correct, you can’t call FltSendMessage at DISPATCH_LEVEL. If you’re at
DISPATCH_LEVEL and you want to send a message you need to post the work to a
work item.

-scott
OSR
@OSRDrivers

wrote in message news:xxxxx@ntfsd…

To Scott.
Thanks for your advice!
I just fixed the problem. thanks to you.
but if i use FltDoCompletionProcessingWhenSafe function, is that means i
can’t send DPC_LEVEL datas?