Crash while using microsoft's serial line driver

milan_durovic · September 5, 2024, 12:12am

I wrote a driver that filters raw data received from the serial line. It's not implemented as a filter driver because which physical serial line will be used is known only at run time. So the driver has an IOCTL command that identifies which serial port to attach the filter to.

The basic operation of the driver goes like this:

set up a WDFIOTARGET that points to the serial line device to be used
set up a WDFREQUEST to be used repeatedly to send read requests to the serial line.
format the request for reading
set the read completion routine
send the request to the target
in the read completion routine:
- read and process data
- complete the I/O request
- call WdfRequestReuse on the read request
- go the the 3rd step (format the request for reading) to complete the loop

The system crashes somewhere outside of my driver and it appears it's some kind of a lifecycle problem, possibly reference counting problem, but I don't know which object is problematic. WDFMEMORY object required for each read operation is created around my fixed read buffer and I create WDFMEMORY object using WdfMemoryCreatePreallocated call, each time when I'm preparing to re-issue a read request.

analyze -v in WinDbg gives me the following information:

WDF_VIOLATION (10d)
The Kernel-Mode Driver Framework was notified that Windows detected an error
in a framework-based driver. In general, the dump file will yield additional
information about the driver that caused this bug check.
Arguments:
Arg1: 0000000000000007, A driver attempted to delete a framework object incorrectly
	by calling WdfObjectDereference to delete a handle instead
	of calling WdfObjectDelete.
Arg2: 00003ef2df858d98, Reserved.
Arg3: ffffc10d207a7260, Reserved.
Arg4: ffffc10d1f646de0, Reserved.

and the call stack looks like:

BUGCHECK_CODE:  10d

BUGCHECK_P1: 7

BUGCHECK_P2: 3ef2df858d98

BUGCHECK_P3: ffffc10d207a7260

BUGCHECK_P4: ffffc10d1f646de0

PROCESS_NAME:  System

STACK_TEXT:  
fffffb89`ee84eb58 fffff805`5bb18f82     : fffffb89`ee84ecc0 fffff805`5b97f570 00000000`00000100 00000000`00000000 : nt!DbgBreakPointWithStatus
fffffb89`ee84eb60 fffff805`5bb18566     : 00000000`00000003 fffffb89`ee84ecc0 fffff805`5ba15ce0 00000000`0000010d : nt!KiBugCheckDebugBreak+0x12
fffffb89`ee84ebc0 fffff805`5b9fdee7     : 00000000`00000000 00000000`ffffffff ffffc10d`207a7260 00000000`00000000 : nt!KeBugCheck2+0x946
fffffb89`ee84f2d0 fffff805`5f758a44     : 00000000`0000010d 00000000`00000007 00003ef2`df858d98 ffffc10d`207a7260 : nt!KeBugCheckEx+0x107
fffffb89`ee84f310 fffff805`5f72517c     : ffffc10d`207a7260 00000000`00000000 00003ef2`df858d98 fffff805`5f70274b : Wdf01000!FxVerifierBugCheckWorker+0x24 [minkernel\wdf\framework\shared\object\fxverifierbugcheck.cpp @ 68] 
fffffb89`ee84f350 fffff805`5f705a10     : 00000000`00000000 ffffc10d`219db570 00000000`00000000 ffffc10d`219db570 : Wdf01000!FxObject::~FxObject+0x1d73c [minkernel\wdf\framework\shared\object\fxobject.cpp @ 146] 
fffffb89`ee84f3b0 fffff805`5f705744     : 00000000`00000001 00003ef2`f3ae7118 00000000`00000000 00000000`00000010 : Wdf01000!FxRequestBase::~FxRequestBase+0x8c [minkernel\wdf\framework\shared\core\fxrequestbase.cpp @ 180] 
fffffb89`ee84f3e0 fffff805`5f7040cb     : ffffc10d`207a7260 fffff805`74a343f1 ffffc10d`1f4e0310 fffffb89`00000010 : Wdf01000!FxRequestFromLookaside::`scalar deleting destructor'+0x14
fffffb89`ee84f410 fffff805`5f702328     : fffff805`74a38248 00003ef2`00000004 ffffc10d`00000000 00000000`00000004 : Wdf01000!FxObject::SelfDestruct+0x1b [minkernel\wdf\framework\shared\inc\private\common\fxobject.hpp @ 453] 
fffffb89`ee84f440 fffff805`5f709309     : 00003ef2`df858d98 00000000`00000000 00000000`00000002 00000000`00000000 : Wdf01000!FxRequest::Release+0x158 [minkernel\wdf\framework\shared\core\fxrequest.cpp @ 3127] 
fffffb89`ee84f4b0 fffff805`5f70c8f4     : 00003ef2`df858d98 ffffc10d`207a7260 ffffc10d`207a7260 ffff9201`75279180 : Wdf01000!FxRequestBase::CompleteSubmitted+0x109 [minkernel\wdf\framework\shared\core\fxrequestbase.cpp @ 530] 
fffffb89`ee84f540 fffff805`5b948906     : ffffc10d`1f1a28f0 ffffc10d`219db502 ffffc10d`219db570 ffffffff`ffffffff : Wdf01000!FxIoTarget::_RequestCompletionRoutine+0xe4 [minkernel\wdf\framework\shared\targets\general\fxiotarget.cpp @ 2448] 
fffffb89`ee84f5b0 fffff805`5b854975     : ffffc10d`219db6d3 fffffb89`ee84f659 ffffc10d`219db570 00000000`00000000 : nt!IopUnloadSafeCompletion+0x56
fffffb89`ee84f5e0 fffff805`5b8547b7     : ffffc10d`219db570 00000000`3283c902 ffffc10d`05add350 ffff0934`45a5ea8b : nt!IopfCompleteRequest+0x1a5
fffffb89`ee84f6c0 fffff805`644147d9     : ffffc10d`219db570 ffffc10d`08115380 ffffc10d`219db570 00000000`00000001 : nt!IofCompleteRequest+0x17
fffffb89`ee84f6f0 fffff805`64414727     : fffff805`64414601 ffffc10d`08115380 fffffb89`ee84f7d0 fffff805`64404c7d : serial!SerialGetNextIrpLocked+0x95
fffffb89`ee84f720 fffff805`6441491f     : fffff805`644146d0 fffffb89`ee84f902 ffffc10d`08115280 fffffb89`ee84f920 : serial!SerialGetNextIrp+0x57
fffffb89`ee84f770 fffff805`6440436f     : ffffc10d`08115280 fffffb89`ee84f920 fffffb89`ee84fae0 00000000`00000000 : serial!SerialTryToCompleteCurrent+0x127
fffffb89`ee84f7b0 fffff805`5b8c607e     : ffff9201`7527c240 fffffb89`ee84f902 00000000`00000000 ffff9201`00000002 : serial!SerialCompleteRead+0x9f
fffffb89`ee84f820 fffff805`5b8c5364     : 00000000`00000000 00000000`00000000 00000000`00140001 00000000`00000000 : nt!KiExecuteAllDpcs+0x30e
fffffb89`ee84f990 fffff805`5ba028de     : ffffffff`00000000 ffff9201`75279180 ffff9201`75284440 ffffc10d`1f9980c0 : nt!KiRetireDpcList+0x1f4
fffffb89`ee84fc20 00000000`00000000     : fffffb89`ee850000 fffffb89`ee849000 00000000`00000000 00000000`00000000 : nt!KiIdleLoop+0x9e


SYMBOL_NAME:  serial!SerialGetNextIrpLocked+95

MODULE_NAME: serial

IMAGE_NAME:  serial.sys

STACK_COMMAND:  .thread ; .cxr ; kb

BUCKET_ID_FUNC_OFFSET:  95

FAILURE_BUCKET_ID:  0x10D_7_serial!SerialGetNextIrpLocked

OS_VERSION:  10.0.19041.1

BUILDLAB_STR:  vb_release

OSPLATFORM_TYPE:  x64

OSNAME:  Windows 10

FAILURE_ID_HASH:  {ebf35339-39d1-1ae0-2235-aeaf6a544539}

I read and re-read documentation about how to do this stuff, but, obviously, I have no clue what I'm missing, or what the error message and the call stack suggest.

The driver does work in a sense that the read callback does get invoked and I do get data that I sent to the targeted serial line and I don't get any errors when setting up the read handle for reuse, so I don't really know what's wrong when I keep getting STATUS_SUCCESS all along..

Does anyone see something obvious here?

Thanks and regards,
Milan

milan_durovic · September 5, 2024, 3:14am

UPDATE: the call stack looked to me like the crash was happening while WDF framework was trying to destroy the I/O request I was trying to reuse. So, just as an experiment, I added a call to WdfObjectReference immediately after I marked I/O request as complete in the I/O completion callback function. I'm no longer getting the crashes ?!?

This is kind of strange because I call WdfRequestReuse immediately after I/O request is marked as complete and I sort of expected that this call would take care of keeping the I/O request object alive.

I just fear that there's some kind of a racing condition at play, so even though with the addition of WdfObjectReference it now "works", I could be creating a different problem which is not currently apparent.

Tim_Roberts · September 5, 2024, 3:31am

As a side note, you can install yourself as a filter on ALL serial devices, and simply do nothing unless you happen to be in the one that was chosen. That's a very common filtering technique, and avoids cross-driver-stack issues.

Mark_Roddy · September 5, 2024, 6:53pm

As another side note, there is on microsoft's github driver samples a sample serial driver. Unfortunately it manages to not be the serial driver shipped with windows.