We’re using KMDF 1.5 (WDK6000) to develop a driver. And now we meet a strange bugcheck caused by WdfDeviceEnqueueRequest() after we running our driver over night. Here is one of the dumps from debugger:
0: kd> !analyze -v
*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************
IRQL_NOT_LESS_OR_EQUAL (a)
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 a kernel debugger is available get the stack backtrace.
Arguments:
Arg1: 00000080, memory referenced
Arg2: 00000002, IRQL
Arg3: 00000001, value 0 = read operation, 1 = write operation
Arg4: 80887fe0, address which referenced memory
Debugging Details:
WRITE_ADDRESS: 00000080
CURRENT_IRQL: 2
FAULTING_IP:
nt!KefAcquireSpinLockAtDpcLevel+0
80887fe0 f00fba2900 lock bts dword ptr [ecx],0
DEFAULT_BUCKET_ID: DRIVER_FAULT
BUGCHECK_STR: 0xA
PROCESS_NAME: drsdemo.exe
TRAP_FRAME: f618f9b8 – (.trap 0xfffffffff618f9b8)
ErrCode = 00000002
eax=00000000 ebx=80887fe0 ecx=00000080 edx=00000000 esi=834377c8 edi=80a56ff0
eip=80887fe0 esp=f618fa2c ebp=f618fa50 iopl=0 nv up ei pl zr na pe nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010246
nt!KefAcquireSpinLockAtDpcLevel:
80887fe0 f00fba2900 lock bts dword ptr [ecx],0 ds:0023:00000080=???
Resetting default scope
LAST_CONTROL_TRANSFER: from 80826165 to 80871660
STACK_TEXT:
f618f5b4 80826165 00000003 00000000 0000000a nt!RtlpBreakWithStatusInstruction
f618f600 8082703a 00000003 00000080 80887fe0 nt!KiBugCheckDebugBreak+0x19
f618f998 8088bde3 0000000a 00000080 00000002 nt!KeBugCheck2+0x5b2
f618f998 80887fe0 0000000a 00000080 00000002 nt!KiTrap0E+0x2a7
f618fa28 f70b5aaf 83437b60 83437b60 00000000 nt!KefAcquireSpinLockAtDpcLevel
f618fa50 f708eeb8 f618fa78 00000080 f618fa7c Wdf01000!FxVerifierLock::Lock+0x135
f618fa60 f70c8d78 f618fa78 83437b60 81b2f7d8 Wdf01000!FxNonPagedObject::Lock+0x23
f618fa7c f70ca157 81b2f7d8 f70ee188 85fedc70 Wdf01000!FxIoQueue::QueueRequestFromForward+0x28
f618faa0 f70ac112 83439878 81b2f700 7cbc6780 Wdf01000!FxPkgIo::EnqueueRequest+0x21f
f618fac0 f70771fa 00fedd28 7cbc6780 7e4d0820 Wdf01000!imp_WdfDeviceEnqueueRequest+0xd2
f618fad4 f70770b3 7cbc6780 7e4d0820 f6eff5f3 HifnDrs!WdfDeviceEnqueueRequest+0x1a [c:\winddk\6000\inc\wdf\kmdf\10\wdfdevice.h @ 2759]
f618fc04 f70c9d39 7cbc6780 7e4d0820 81b66e00 HifnDrs!DrsEvtIoInCallerContext+0x13e3 [c:\bobcat\trunk\drsdriver\hifndrs.c @ 929]
f618fc2c f70b8d9a 81b66e00 f618fc4c 8081dcdf Wdf01000!FxPkgIo::Dispatch+0x249
f618fc38 8081dcdf 83438b98 81b66e00 81acf7b0 Wdf01000!FxDevice::Dispatch+0x7f
f618fc4c 808f47b7 81b66e70 81acf7b0 81b66e00 nt!IofCallDriver+0x45
f618fc60 808f5535 83438b98 81b66e00 81acf7b0 nt!IopSynchronousServiceTail+0x10b
f618fd00 808ee104 000007a8 00000000 00000000 nt!IopXxxControlFile+0x5db
f618fd34 80888c7c 000007a8 00000000 00000000 nt!NtDeviceIoControlFile+0x2a
f618fd34 7c82ed54 000007a8 00000000 00000000 nt!KiFastCallEntry+0xfc
0006fbf8 7c8213e4 77e416f1 000007a8 00000000 ntdll!KiFastSystemCallRet
0006fbfc 77e416f1 000007a8 00000000 00000000 ntdll!NtDeviceIoControlFile+0xc
0006fc60 010078c9 000007a8 0022e500 0006fdbc kernel32!DeviceIoControl+0x137
0006fc98 01007bb9 000007a8 0006fdbc 00000020 drsdemo!DRDEMO::drDataOp+0xd9 [c:\bobcat\trunk\drsdemo\drsdemo.cpp @ 953]
0006fcc0 01008fc6 000007a8 0006fdbc 00000020 drsdemo!DRDEMO::drDataPassthru+0x29 [c:\bobcat\trunk\drsdemo\drsdemo.cpp @ 1214]
0006ff48 0100da88 0140f994 00000001 00000000 drsdemo!DRDEMO::drFuncTest+0xac6 [c:\bobcat\trunk\drsdemo\drsdemo.cpp @ 2576]
0006ff7c 0100dc5e 00000009 002524c0 00252af8 drsdemo!main+0x2a8 [c:\bobcat\trunk\drsdemo\drsdemo.cpp @ 5339]
0006ffc0 77e523e5 00000000 00000000 7ffde000 drsdemo!__mainCRTStartup+0x102 [d:\vistartm\base\crts\crtw32\dllstuff\crtexe.c @ 716]
0006fff0 00000000 0100dd9c 00000000 78746341 kernel32!BaseProcessStart+0x23
STACK_COMMAND: kb
FOLLOWUP_IP:
Wdf01000!FxVerifierLock::Lock+135
f70b5aaf 8b45f8 mov eax,dword ptr [ebp-8]
SYMBOL_STACK_INDEX: 5
FOLLOWUP_NAME: MachineOwner
MODULE_NAME: Wdf01000
IMAGE_NAME: Wdf01000.sys
DEBUG_FLR_IMAGE_TIMESTAMP: 4549b23a
SYMBOL_NAME: Wdf01000!FxVerifierLock::Lock+135
FAILURE_BUCKET_ID: 0xA_W_Wdf01000!FxVerifierLock::Lock+135
BUCKET_ID: 0xA_W_Wdf01000!FxVerifierLock::Lock+135
Followup: MachineOwner
0: kd> !wdfdevice 7cbc6780
Dumping WDFDEVICE 0x7cbc6780
WDM PDEVICE_OBJECTs: self 83438b98
Control WDFDEVICE
0: kd> !wdfhandle 7cbc6780 70
Dumping WDFHANDLE 0x7cbc6780
Handle type is WDFDEVICE
Refcount: 1
Contexts:
context: dt 0x83439a40 CONTROL_DEVICE_CONTEXT (size is 0x18 bytes)
Parent: !wdfhandle 79f803b8, type is WDFDRIVER
Child WDFHANDLEs of 0x7cbc6780:
WDFDEVICE 0x7cbc6780
dt FxDevice 0x83439878
context: dt 0x83439a40 CONTROL_DEVICE_CONTEXT (size is 0x18 bytes)
WDF INTERNAL
dt FxDefaultIrpHandler 0x83439368
WDF INTERNAL
dt FxPkgGeneral 0x83438048
WDF INTERNAL
dt FxWmiIrpHandler 0x83438f18
WDF INTERNAL
dt FxPkgIo 0x83438d68
WDFQUEUE 0x7cbc7718
dt FxIoQueue 0x834388e0
WDFQUEUE 0x7cbc8498
dt FxIoQueue 0x83437b60
WDFSPINLOCK 0x7cbc7eb0
dt FxSpinLock 0x83438148
WDFWAITLOCK 0x7cbc5e70
dt FxWaitLock 0x8343a188
WDFFILEOBJECT 0x7e43c190
dt FxFileObject 0x81bc3e68
context: dt 0x81bc3ec8 FILEOBJ_CONTEXT (size is 0x4 bytes)
WDFREQUEST 0x7e4d0820
dt FxRequest 0x81b2f7d8
context: dt 0x81b2f890 REQUEST_CONTEXT (size is 0x30 bytes)
WDFHANDLE 0x79fee050
dt FxObject 0x86011fa8
WDFHANDLE 0x7e4fe2f0
dt FxObject 0x81b01d08
!wdftagtracker 0x834395b0
State history:
[0] FxObjectStateCreated (0x1)
!wdfobject 0x83439878
0: kd> !WDFQUEUE 0x7cbc8498
Dumping WDFQUEUE 0x7cbc8498
=========================
Parallel, Not power-managed, PowerOn, Can accept, Can dispatch, ExecutionLevelDispatch, SynchronizationScopeNone
Number of driver owned requests: 0
Number of waiting requests: 0
EvtIoDeviceControl: (0xf7077320) HifnDrs!DrsEvtIoDeviceControl
-------------------------------------------------------------------------------------------------------
From the information above, we guess that there was something messed up. The nt!KefAcquireSpinLockAtDpcLevel tried to accquire the spin lock of 83437b60, but it was actually the FxIoQueue of WDFQUEUE 0x7cbc8498.
Can anyone please give us any suggestion about where we messed up?