Hello,
I develop a VPN network driver, which is based on NetAdapterCx and Winsock Kernel. The driver creates virtual network adapter and connects to the remote VPN server. It works as a pipe - reads packets from virtual adapter, encrypts and sends to the remote. Receives packets from remote, decrypts and indicates to the system. I have been using it for a months and haven’t seen bug checks for a long time, and today the day has finally came.
According to dump, I got bug check at indicating packet to the system while in WSK’s WskReceiveEvent callback. This particular code has been executed without any issues for quite a lot of times, and today something has happened which I don’t yet quite understand what.
*******************************************************************************
* *
* 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: 00000001000000ab, memory referenced
Arg2: 0000000000000002, IRQL
Arg3: 0000000000000000, value 0 = read operation, 1 = write operation
Arg4: fffff80722fdaaae, address which referenced memory
FAULTING_SOURCE_LINE: c:\EWDK11\Program Files\Windows Kits\10\Include\wdf\kmdf\1.15\wdfobject.h
FAULTING_SOURCE_FILE: c:\EWDK11\Program Files\Windows Kits\10\Include\wdf\kmdf\1.15\wdfobject.h
FAULTING_SOURCE_LINE_NUMBER: 564
FAULTING_SOURCE_CODE:
560: PCWDF_OBJECT_CONTEXT_TYPE_INFO TypeInfo
561: )
562: {
563: return ((PFN_WDFOBJECTGETTYPEDCONTEXTWORKER) WdfFunctions[WdfObjectGetTypedContextWorkerTableIndex])(WdfDriverGlobals, Handle, TypeInfo);
> 564: }
565:
566: //
567: // WDF Function: WdfObjectAllocateContext
568: //
569: typedef
SYMBOL_NAME: ovpn_dco!WdfObjectGetTypedContextWorker+46
MODULE_NAME: ovpn_dco
IMAGE_NAME: ovpn-dco.sys
STACK_COMMAND: .thread ; .cxr ; kb
BUCKET_ID_FUNC_OFFSET: 46
FAILURE_BUCKET_ID: AV_ovpn_dco!WdfObjectGetTypedContextWorker
OS_VERSION: 10.0.19041.1
BUILDLAB_STR: vb_release
OSPLATFORM_TYPE: x64
OSNAME: Windows 10
FAILURE_ID_HASH: {587e3cb2-8844-a268-b29c-71dac9f54604}
0: kd> kn
# Child-SP RetAddr Call Site
00 fffff909`c5a55608 fffff807`20a0a869 nt!KeBugCheckEx
01 fffff909`c5a55610 fffff807`20a06b69 nt!KiBugCheckDispatch+0x69
02 fffff909`c5a55750 fffff807`22fdaaae nt!KiPageFault+0x469
03 fffff909`c5a558e0 fffff807`23008468 Wdf01000!FxIFR+0x1e [minkernel\wdf\framework\kmdf\src\core\tracing.cpp @ 389]
04 fffff909`c5a55950 fffff807`22feda1a Wdf01000!WPP_IFR_SF_sq+0x154 [minkernel\wdf\framework\kmdf\src\core\objfre\amd64\FxDevicePdoApi.tmh @ 887]
05 (Inline Function) --------`-------- Wdf01000!FxObjectGetTypedContext+0x1b891 [minkernel\wdf\framework\shared\object\handleapi.cpp @ 541]
06 fffff909`c5a559c0 fffff807`2f243886 Wdf01000!imp_WdfObjectGetTypedContextWorker+0x1b8ba [minkernel\wdf\framework\shared\object\handleapi.cpp @ 679]
07 fffff909`c5a55a10 fffff807`2f2437fa ovpn_dco!WdfObjectGetTypedContextWorker+0x46 [c:\EWDK11\Program Files\Windows Kits\10\Include\wdf\kmdf\1.15\wdfobject.h @ 564]
08 fffff909`c5a55a50 fffff807`2f242cce ovpn_dco!OvpnGetRxQueueContext+0x1a [C:\Users\lev\Projects\ovpn-dco-win\rxqueue.h @ 38]
09 fffff909`c5a55a80 fffff807`2f250e74 ovpn_dco!OvpnAdapterNotifyRx+0xfe [C:\Users\lev\Projects\ovpn-dco-win\adapter.cpp @ 214]
0a fffff909`c5a55b20 fffff807`2f251a75 ovpn_dco!OvpnSocketDataPacketReceived+0x504 [C:\Users\lev\Projects\ovpn-dco-win\socket.cpp @ 202]
0b fffff909`c5a55c40 fffff807`2f24e444 ovpn_dco!OvpnSocketProcessIncomingPacket+0x95 [C:\Users\lev\Projects\ovpn-dco-win\socket.cpp @ 222]
0c fffff909`c5a55c80 fffff807`2e8844bd ovpn_dco!OvpnSocketTcpReceiveEvent+0x314 [C:\Users\lev\Projects\ovpn-dco-win\socket.cpp @ 377]
0d fffff909`c5a55d30 fffff807`23f32838 afd!WskProTLEVENTReceive+0xed
0e fffff909`c5a55df0 fffff807`23f31ea5 tcpip!TcpIndicateData+0x138
0f fffff909`c5a55f30 fffff807`23f315b5 tcpip!TcpDeliverDataToClient+0x5b5
10 fffff909`c5a560b0 fffff807`23f35d5b tcpip!TcpDeliverReceive+0xe5
11 fffff909`c5a561b0 fffff807`23f34aff tcpip!TcpTcbFastDatagram+0xfcb
12 fffff909`c5a56380 fffff807`23f33e9f tcpip!TcpTcbReceive+0x18f
13 fffff909`c5a565d0 fffff807`23f3306d tcpip!TcpMatchReceive+0x51f
14 fffff909`c5a56880 fffff807`23f5c702 tcpip!TcpReceive+0x44d
15 fffff909`c5a56970 fffff807`23f23d21 tcpip!TcpNlClientReceiveDatagrams+0x22
16 fffff909`c5a569b0 fffff807`23f2066b tcpip!IppProcessDeliverList+0xc1
17 fffff909`c5a56a90 fffff807`23f1fbef tcpip!IppReceiveHeaderBatch+0x21b
18 fffff909`c5a56b90 fffff807`23f1cf2c tcpip!IppFlcReceivePacketsCore+0x32f
19 fffff909`c5a56cb0 fffff807`23f64120 tcpip!IpFlcReceivePackets+0xc
1a fffff909`c5a56ce0 fffff807`23f6371c tcpip!FlpReceiveNonPreValidatedNetBufferListChain+0x270
1b fffff909`c5a56de0 fffff807`208dae28 tcpip!FlReceiveNetBufferListChainCalloutRoutine+0x17c
1c fffff909`c5a56f30 fffff807`208dad9d nt!KeExpandKernelStackAndCalloutInternal+0x78
1d fffff909`c5a56fa0 fffff807`23f3f6dd nt!KeExpandKernelStackAndCalloutEx+0x1d
1e fffff909`c5a56fe0 fffff807`23f3edbd tcpip!NetioExpandKernelStackAndCallout+0x8d
1f fffff909`c5a57040 fffff807`239b1eb1 tcpip!FlReceiveNetBufferListChain+0x46d
20 fffff909`c5a572f0 fffff807`239b1ccb ndis!ndisMIndicateNetBufferListsToOpen+0x141
21 fffff909`c5a573d0 fffff807`239b7ef1 ndis!ndisMTopReceiveNetBufferLists+0x22b
22 fffff909`c5a57450 fffff807`239edfef ndis!ndisCallReceiveHandler+0x61
23 fffff909`c5a574a0 fffff807`239b4a94 ndis!ndisInvokeNextReceiveHandler+0x1df
24 fffff909`c5a57570 fffff807`41ec32d0 ndis!NdisMIndicateReceiveNetBufferLists+0x104
25 fffff909`c5a57600 fffff807`41e88251 wdiwifi!CPort::IndicateFrames+0x2d8
26 fffff909`c5a576a0 fffff807`41e6bbb7 wdiwifi!CAdapter::IndicateFrames+0x141
27 fffff909`c5a57710 fffff807`41e6c2f6 wdiwifi!CRxMgr::RxProcessAndIndicateNblChain+0x7f7
28 fffff909`c5a57830 fffff807`41e68192 wdiwifi!CRxMgr::RxInOrderDataInd+0x35a
29 fffff909`c5a578d0 fffff807`415e2053 wdiwifi!AdapterRxInorderDataInd+0x92
2a fffff909`c5a57920 ffffb18a`9871b650 Netwtw06+0x52053
2b fffff909`c5a57928 00000000`00000001 0xffffb18a`9871b650
2c fffff909`c5a57930 00000000`00000000 0x1
The problematic part of my code is seem to be this one:
NTSTATUS OvpnAdapterNotifyRx(NETADAPTER netAdapter)
{
if (netAdapter == WDF_NO_HANDLE) {
LOG_ERROR("Adapter not initialized");
return STATUS_DEVICE_NOT_READY;
}
NETPACKETQUEUE rxQueue = OvpnGetAdapterContext(netAdapter)->RxQueue;
POVPN_RXQUEUE queueContext = OvpnGetRxQueueContext(rxQueue);
if (InterlockedExchange(&queueContext->NotificationEnabled, FALSE) == TRUE)
NetRxQueueNotifyMoreReceivedPacketsAvailable(rxQueue);
return STATUS_SUCCESS;
}
As you see, idea is to notify NetAdapter that there are packets available and bug check happened inside OvpnGetRxQueueContext(), which is a generated macro:
typedef struct _OVPN_RXQUEUE
{
POVPN_ADAPTER Adapter;
NET_RING_COLLECTION const * Rings;
NET_EXTENSION VirtualAddressExtension;
NET_EXTENSION ChecksumExtension;
LONG NotificationEnabled = 0;
} OVPN_RXQUEUE, * POVPN_RXQUEUE;
WDF_DECLARE_CONTEXT_TYPE_WITH_NAME(OVPN_RXQUEUE, OvpnGetRxQueueContext);
What puzzles me is that my driver’s internal state looks a bit odd in this dump:
fffff909`c5a55c40 device = 0xffffb18a`ba7ca320
0: kd> dx -id 0,0,ffffb18a91102080 -r1 ((ovpn_dco!OVPN_DEVICE *)0xffffb18aba7ca320)
((ovpn_dco!OVPN_DEVICE *)0xffffb18aba7ca320) : 0xffffb18aba7ca320 [Type: OVPN_DEVICE *]
[+0x000] SpinLock : 1 [Type: long]
[+0x008] WdfDevice : 0x4e7545835fc8 [Type: WDFDEVICE__ *]
[+0x010] PendingReadsQueue : 0x4e7559520508 [Type: WDFQUEUE__ *]
[+0x018] PendingWritesQueue : 0x4e7545612508 [Type: WDFQUEUE__ *]
[+0x020] PendingNewPeerQueue : 0x4e7541eab508 [Type: WDFQUEUE__ *]
[+0x028] DataRxBufferQueue : 0xffffb18a9bb9fb10 [Type: OVPN_BUFFER_QUEUE__ *]
[+0x030] ControlRxBufferQueue : 0xffffb18a9bb9fb40 [Type: OVPN_BUFFER_QUEUE__ *]
[+0x038] RxBufferPool : 0xffffb18abc4e6f50 [Type: OVPN_RX_BUFFER_POOL__ *]
[+0x040] TxBufferPool : 0xffffb18abc4e6c50 [Type: OVPN_TX_BUFFER_POOL__ *]
[+0x048] Stats [Type: _OVPN_STATS]
[+0x088] KeepaliveInterval : 12 [Type: long]
[+0x08c] KeepaliveTimeout : 50 [Type: long]
[+0x090] KeepaliveXmitTimer : 0x4e7543d191b8 [Type: WDFTIMER__ *]
[+0x098] KeepaliveRecvTimer : 0x4e755a00f1b8 [Type: WDFTIMER__ *]
[+0x0a0] MSS : 0x56a [Type: unsigned short]
[+0x0a8] CryptoContext [Type: OvpnCryptoContext]
[+0x370] Socket [Type: OvpnSocket]
[+0x1388] Adapter : Unable to read memory at Address 0xffffb18aba7cb6a8
[+0x1390] UserspacePid : Unable to read memory at Address 0xffffb18aba7cb6b0
Why do I see “Unable to read memory” for the last two members? Those are an integer and a handle:
_Guarded_by_(SpinLock)
NETADAPTER Adapter;
// pid of userspace process which called NEW_PEER
_Interlocked_
LONG UserspacePid;
Now, I got this error while uninstalling software, which also uninstalls the driver. I wonder if TCP receive was invoked in the middle of de-initialization, however there I think I have locks in place and I explicitly set values to zeros and WDF_NO_HANDLE.
Any ideas what is going on there and how can I debug this further?