Wdf01000!FxVerifierDbgBreakPoint and !wdfkd.wdflogdump

[x BlueRobot]

This one of those obscure commands you'll probably only ever use in very specific circumstances and I happen to only stumble upon this command a few weeks ago. It's really useful when you want to see why driver has crashed the system, in this case it was quite obvious and the driver had been causing several different bugchecks.

KMODE_EXCEPTION_NOT_HANDLED (1e)
This is a very common bugcheck.  Usually the exception address pinpoints
the driver/function that caused the problem.  Always note this address
as well as the link date of the driver/image that contains this address.
Arguments:
Arg1: ffffffff80000003, The exception code that was not handled
Arg2: fffff80112872950, The address that the exception occurred at
Arg3: 0000000000000000, Parameter 0 of the exception
Arg4: 7efefefefefeff63, Parameter 1 of the exception

As we can see we have a pretty generic Stop 0x1E bugcheck. These are due to exceptions being thrown which either have no handler written for them or are unable to be caught using structured exception handling. For example, a page fault is an example of a exception which can't be handled by a try-catch statement.

Let's dump the exception which wasn't handled:

1: kd> !error ffffffff80000003
Error code: (HRESULT) 0x80000003 (2147483651) - One or more arguments are invalid

Interesting?

Let's see which function caused the exception.

1: kd> ln fffff80112872950
Browse module
Set bu breakpoint

(fffff801`12872950)   nt!DbgBreakPoint   |  (fffff801`12872960)   nt!DbgUserBreakPoint

If we read the documentation, it states the following:

In kernel mode, a break exception that is not handled will cause a bug check. You can, however, connect a kernel-mode debugger to a target computer that has stopped responding and has kernel debugging enabled.

This explains why we've received our bugcheck error, however, this isn't very useful in understanding why the crash was caused.

Let's examine the call stack and see what we can find.

1: kd> knL
 # Child-SP          RetAddr           Call Site
00 fffff587`5a22ce58 fffff801`1294cdde nt!KeBugCheckEx
01 fffff587`5a22ce60 fffff801`1287390f nt!KiFatalExceptionHandler+0x22
02 fffff587`5a22cea0 fffff801`126be885 nt!RtlpExecuteHandlerForException+0xf
03 fffff587`5a22ced0 fffff801`126bcf1e nt!RtlDispatchException+0x4a5
04 fffff587`5a22d620 fffff801`1287ca5d nt!KiDispatchException+0x16e
05 fffff587`5a22dcd0 fffff801`12876416 nt!KiExceptionDispatch+0x11d
06 fffff587`5a22deb0 fffff801`12872951 nt!KiBreakpointTrap+0x316 << Actually crash here!
07 fffff587`5a22e048 fffff801`13a2f89b nt!DbgBreakPoint+0x1
08 (Inline Function) --------`-------- Wdf01000!Mx::MxDbgBreakPoint+0x7
09 fffff587`5a22e050 fffff801`13a29e92 Wdf01000!FxVerifierDbgBreakPoint+0x4b
0a fffff587`5a22e090 fffff801`13a6e300 Wdf01000!FxVerifierCheckIrqlLevel+0x1e35a << Verification check
0b fffff587`5a22e0e0 fffff808`344c2e13 Wdf01000!imp_WdfUsbTargetDeviceSendControlTransferSynchronously+0xf0
0c fffff587`5a22e410 fffff808`344c226d sshid+0x2e13 << Problematic driver
0d fffff587`5a22e4d0 fffff801`13a0944d sshid+0x226d
0e (Inline Function) --------`-------- Wdf01000!FxIoQueueIoInternalDeviceControl::Invoke+0x42
0f fffff587`5a22e510 fffff801`13a08eb7 Wdf01000!FxIoQueue::DispatchRequestToDriver+0x16d
10 fffff587`5a22e5b0 fffff801`13a07076 Wdf01000!FxIoQueue::DispatchEvents+0x657
11 (Inline Function) --------`-------- Wdf01000!FxIoQueue::QueueRequest+0x92
12 (Inline Function) --------`-------- Wdf01000!FxPkgIo::DispatchStep2+0x4b6
13 fffff587`5a22e690 fffff801`13a06b2d Wdf01000!FxPkgIo::DispatchStep1+0x536
14 fffff587`5a22e750 fffff801`13a0ac83 Wdf01000!FxPkgIo::Dispatch+0x5d
15 (Inline Function) --------`-------- Wdf01000!DispatchWorker+0x9e
16 (Inline Function) --------`-------- Wdf01000!FxDevice::Dispatch+0xbc
17 fffff587`5a22e7b0 fffff801`128277ba Wdf01000!FxDevice::DispatchWithLock+0x113
18 fffff587`5a22e810 fffff801`1300a0a9 nt!IopfCallDriver+0x56
19 fffff587`5a22e850 fffff801`1289ca25 nt!IovCallDriver+0x275
1a fffff587`5a22e890 fffff808`344d104f nt!IofCallDriver+0x1be925
1b fffff587`5a22e8d0 fffff808`308595df mshidkmdf!HidKmdfPassThrough+0x3f
1c fffff587`5a22e900 fffff808`3085a9ec HIDCLASS!HidpSubmitInterruptRead+0x1af
1d fffff587`5a22e980 fffff801`1300a9d4 HIDCLASS!HidpInterruptReadComplete+0x57c
1e fffff587`5a22ea20 fffff801`1270da09 nt!IovpLocalCompletionRoutine+0x174
1f fffff587`5a22ea80 fffff801`1300a315 nt!IopfCompleteRequest+0x119
20 fffff587`5a22eb90 fffff801`128ae611 nt!IovCompleteRequest+0x1e1
21 fffff587`5a22ec80 fffff801`13a084a8 nt!IofCompleteRequest+0x1a0d51
22 (Inline Function) --------`-------- Wdf01000!FxIrp::CompleteRequest+0xe
23 fffff587`5a22ecb0 fffff801`13a05fec Wdf01000!FxRequest::CompleteInternal+0x228
24 (Inline Function) --------`-------- Wdf01000!FxRequest::Complete+0x31
25 (Inline Function) --------`-------- Wdf01000!FxRequest::CompleteWithInformation+0x3c
26 fffff587`5a22ed40 fffff808`344c52eb Wdf01000!imp_WdfRequestCompleteWithInformation+0x9c
27 fffff587`5a22eda0 fffff808`344c537b sshid+0x52eb
28 fffff587`5a22ede0 fffff808`344c2397 sshid+0x537b
29 fffff587`5a22ee40 fffff801`13a70a68 sshid+0x2397
2a fffff587`5a22eef0 fffff801`13a074d6 Wdf01000!FxUsbPipeContinuousReader::_FxUsbPipeRequestComplete+0x68
2b fffff587`5a22ef70 fffff801`13a0b098 Wdf01000!FxRequestBase::CompleteSubmitted+0xe6
2c (Inline Function) --------`-------- Wdf01000!FxIoTarget::CompleteRequest+0x8
2d (Inline Function) --------`-------- Wdf01000!FxIoTarget::RequestCompletionRoutine+0xa5
2e fffff587`5a22f000 fffff801`127db076 Wdf01000!FxIoTarget::_RequestCompletionRoutine+0xe8
2f fffff587`5a22f070 fffff801`1300a9d4 nt!IopUnloadSafeCompletion+0x56
30 fffff587`5a22f0a0 fffff801`1270da09 nt!IovpLocalCompletionRoutine+0x174
31 fffff587`5a22f100 fffff801`1300a315 nt!IopfCompleteRequest+0x119
32 fffff587`5a22f210 fffff801`128ae611 nt!IovCompleteRequest+0x1e1
33 fffff587`5a22f300 fffff801`13a084a8 nt!IofCompleteRequest+0x1a0d51
34 (Inline Function) --------`-------- Wdf01000!FxIrp::CompleteRequest+0xe
35 fffff587`5a22f330 fffff801`13a07f7b Wdf01000!FxRequest::CompleteInternal+0x228
36 (Inline Function) --------`-------- Wdf01000!FxRequest::Complete+0x31
37 fffff587`5a22f3c0 fffff808`314b7e80 Wdf01000!imp_WdfRequestComplete+0x8b
38 fffff587`5a22f420 fffff808`314b5cf4 USBXHCI!Bulk_Transfer_CompleteCancelable+0x19c
39 fffff587`5a22f480 fffff808`314b4460 USBXHCI!Bulk_ProcessTransferEventWithED1+0x464
3a fffff587`5a22f540 fffff808`314a98d3 USBXHCI!Bulk_EP_TransferEventHandler+0x10
3b fffff587`5a22f570 fffff808`3149ba4f USBXHCI!TR_TransferEventHandler+0x17
3c fffff587`5a22f5a0 fffff808`314bc2f2 USBXHCI!Endpoint_TransferEventHandler+0x167
3d fffff587`5a22f620 fffff808`3149ea3c USBXHCI!UsbDevice_TransferEventHandler+0xa6
3e fffff587`5a22f680 fffff808`3149f55c USBXHCI!Interrupter_DeferredWorkProcessor+0x578
3f fffff587`5a22f780 fffff801`13a026ad USBXHCI!Interrupter_WdfEvtInterruptDpc+0xc
40 (Inline Function) --------`-------- Wdf01000!FxInterrupt::DpcHandler+0x70
41 fffff587`5a22f7b0 fffff801`1276996a Wdf01000!FxInterrupt::_InterruptDpcThunk+0x9d
42 fffff587`5a22f7f0 fffff801`12768fbf nt!KiExecuteAllDpcs+0x30a
43 fffff587`5a22f930 fffff801`1286e64e nt!KiRetireDpcList+0x1ef
44 fffff587`5a22fb60 00000000`00000000 nt!KiIdleLoop+0x7e

We can see where we crashed and also a problematic driver which was called beforehand. The most interesting calls in the stack are Wdf01000!FxVerifierCheckIrqlLevel and Wdf01000!FxVerifierDbgBreakPoint. So, we now know why the breakpoint was called, it's used by the FxVerifierCheckIrqlLevel function to enable a debugger to break in and allow the developer to see why their driver has crashed. Obviously, no debugger was attached at the time of the crash hence why the breakpoint exception is unhandled.

We can assume that the driver has failed the verification check hence why the breakpoint being called, although, we can confirm this for definite by using !wdflogdump extension command.

1: kd> !wdflogdump sshid
Trace searchpath is: 

Trace format prefix is: %7!u!: %!FUNC! - 
Trying to extract TMF information from - C:\ProgramData\dbg\sym\Wdf01000.pdb\066683F62DF745C1C6CD389F00F53E281\Wdf01000.pdb
Gather log: Please wait, this may take a moment (reading 4024 bytes).
% read so far ... 10, 20, 30, 40, 50, 100
There are 39 log entries
--- start of log ---
1: FxIFRStart - FxIFR logging started
2: LockVerifierSection - Increment Lock counter (3) for Verifier Paged Memory from  \REGISTRY\MACHINE\SYSTEM\ControlSet001\Services\sshid from driver globals FFFFE406F770EDE0
3: FxVerifierLock::InitializeLockOrder - Object Type 0x1036 does not have a lock order defined in fx\inc\FxVerifierLock.hpp
4: FxVerifierLock::InitializeLockOrder - Object Type 0x1036 does not have a lock order defined in fx\inc\FxVerifierLock.hpp
5: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering PnP State WdfDevStatePnpInit from WdfDevStatePnpObjectCreated
6: FxPkgPnp::Dispatch - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810, IRP_MJ_PNP, 0x00000000(IRP_MN_START_DEVICE) IRP 0xFFFFE406F708C010
7: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering PnP State WdfDevStatePnpInitStarting from WdfDevStatePnpInit
8: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering PnP State WdfDevStatePnpHardwareAvailable from WdfDevStatePnpInitStarting
9: FxVerifierLock::InitializeLockOrder - Object Type 0x1204 does not have a lock order defined in fx\inc\FxVerifierLock.hpp
10: FxIoTarget::SubmitLocked - ignoring WDFIOTARGET 00001BF908E50288 state, sending WDFREQUEST FFFFF5875A4F6AF0, state WdfIoTargetStarted
11: FxPkgPnp::NotPowerPolicyOwnerEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering not power policy owner state WdfDevStatePwrPolStarting from WdfDevStatePwrPolObjectCreated
12: FxPkgPnp::PowerEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering Power State WdfDevStatePowerStartingCheckDeviceType from WdfDevStatePowerObjectCreated
13: FxPkgPnp::PowerEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering Power State WdfDevStatePowerD0Starting from WdfDevStatePowerStartingCheckDeviceType
14: FxPkgPnp::PowerEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering Power State WdfDevStatePowerD0StartingConnectInterrupt from WdfDevStatePowerD0Starting
15: FxPkgPnp::PowerEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering Power State WdfDevStatePowerD0StartingDmaEnable from WdfDevStatePowerD0StartingConnectInterrupt
16: FxPkgPnp::PowerEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering Power State WdfDevStatePowerD0StartingStartSelfManagedIo from WdfDevStatePowerD0StartingDmaEnable
17: FxPkgIo::ResumeProcessingForPower - Power resume all queues of WDFDEVICE 0x00001BF908FB2F68
18: FxPkgPnp::PowerEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering Power State WdfDevStatePowerDecideD0State from WdfDevStatePowerD0StartingStartSelfManagedIo
19: FxPkgPnp::PowerEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering Power State WdfDevStatePowerD0 from WdfDevStatePowerDecideD0State
20: FxPkgPnp::NotPowerPolicyOwnerEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering not power policy owner state WdfDevStatePwrPolStarted from WdfDevStatePwrPolStarting
21: FxPkgPnp::NotPowerPolicyOwnerEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering not power policy owner state WdfDevStatePwrPolStartingSucceeded from WdfDevStatePwrPolStarted
22: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering PnP State WdfDevStatePnpEnableInterfaces from WdfDevStatePnpHardwareAvailable
23: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 entering PnP State WdfDevStatePnpStarted from WdfDevStatePnpEnableInterfaces
24: FxPkgPnp::Dispatch - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810, IRP_MJ_PNP, 0x00000014(IRP_MN_QUERY_PNP_DEVICE_STATE) IRP 0xFFFFE406F7081010
25: FxPkgFdo::HandleQueryPnpDeviceStateCompletion - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810 returning PNP_DEVICE_STATE 0x0 IRP 0xFFFFE406F7081010
26: FxPkgPnp::Dispatch - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810, IRP_MJ_PNP, 0x00000007(IRP_MN_QUERY_DEVICE_RELATIONS) type 0xFFFFFFFF IRP 0xFFFFE406F7052010
27: FxPkgPnp::Dispatch - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810, IRP_MJ_PNP, 0x00000007(IRP_MN_QUERY_DEVICE_RELATIONS) type 0xFFFFFFFF IRP 0xFFFFE406F7051010
28: FxPkgPnp::Dispatch - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810, IRP_MJ_PNP, 0x00000007(IRP_MN_QUERY_DEVICE_RELATIONS) type TargetDeviceRelation IRP 0xFFFFE406F704A010
29: FxPkgPnp::Dispatch - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810, IRP_MJ_PNP, 0x00000007(IRP_MN_QUERY_DEVICE_RELATIONS) type BusRelations IRP 0xFFFFE406F79D8010
30: FxPkgPnp::HandleQueryBusRelations - WDFDEVICE 00001BF908FB2F68 returning 3 devices in relations FFFF820D1A8B3690
31: FxPkgPnp::Dispatch - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810, IRP_MJ_PNP, 0x00000007(IRP_MN_QUERY_DEVICE_RELATIONS) type BusRelations IRP 0xFFFFE406F708C010
32: FxPkgPnp::HandleQueryBusRelations - WDFDEVICE 00001BF908FB2F68 returning 3 devices in relations FFFF820D1A8B4610
33: FxPkgPnp::Dispatch - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810, IRP_MJ_PNP, 0x00000007(IRP_MN_QUERY_DEVICE_RELATIONS) type BusRelations IRP 0xFFFFE406F7090010
34: FxPkgPnp::HandleQueryBusRelations - WDFDEVICE 00001BF908FB2F68 returning 3 devices in relations FFFF820D1551BAD0
35: FxPkgPnp::Dispatch - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810, IRP_MJ_PNP, 0x00000007(IRP_MN_QUERY_DEVICE_RELATIONS) type BusRelations IRP 0xFFFFE406F710B7D0
36: FxPkgPnp::HandleQueryBusRelations - WDFDEVICE 00001BF908FB2F68 returning 3 devices in relations FFFF820D1551BC10
37: FxPkgPnp::Dispatch - WDFDEVICE 0x00001BF908FB2F68 !devobj 0xFFFFE406F7071810, IRP_MJ_PNP, 0x00000007(IRP_MN_QUERY_DEVICE_RELATIONS) type BusRelations IRP 0xFFFFE406F7088560
38: FxPkgPnp::HandleQueryBusRelations - WDFDEVICE 00001BF908FB2F68 returning 3 devices in relations FFFF820D1551C5D0
39: FxVerifierCheckIrqlLevel - Called at wrong IRQL; at level 2, should be at level 0

As we can see, the HandleQueryBusRelations function was called at IRQL Level 2 rather than Level 0, which means that the driver has failed the IRQL verification check.

1: kd> !irql
Debugger saved IRQL for processor 0x1 -- 2 (DISPATCH_LEVEL)

The solution to the issue is to update or remove the Steel Series keyboard driver:

1: kd> lmvm sshid
Browse full module list
start             end                 module name
fffff808`344c0000 fffff808`344cd000   sshid      (no symbols)           
    Loaded symbol image file: sshid.sys
    Image path: \SystemRoot\System32\drivers\sshid.sys
    Image name: sshid.sys
    Browse all global symbols  functions  data
    Timestamp:        Fri Jul 24 22:14:14 2020 (5F1B4F26)
    CheckSum:         000177F9
    ImageSize:        0000D000
    Translations:     0000.04b0 0000.04e4 0409.04b0 0409.04e4
    Information from resource tables:

References:

verifier & wdf
DbgBreakPoint function (wdm.h) - Windows drivers
https://github.com/microsoft/Window...framework/shared/irphandlers/pnp/fxpkgpnp.cpp
microsoft/Windows-Driver-Frameworks

Original Thread - BSOD multiple_irp_complete_requests - Page 4 - Windows Crashes and Blue Screen of Death (BSOD) Help and Support