EvtIoCanceledOnQueue and WdfIoQueueStopAndPurge

Marek_Dabek-2 · November 19, 2013, 9:36am

I recently have a 10D BSOD - WDF Violation during cancelling requests on queue.

The scenario is as follows:

There is a queue Q configured as follows: Manual, Power-managed, PowerOn, Passive Only, Can accept, Can dispatch, Dispatching, ExecutionLevelPassive, SynchronizationScopeNone

The EvtIoCanceledOnQueue is called on a request R on the queue Q
The cancel is not yet completed but the WdfIoQueueStopAndPurge on queue Q is called by another driver thread.

The WDF_QUEUE_FATAL_ERROR_DATA contains the following information:

Queue: Queue Q Handler
Request: NULL
Status: C0000010 (STATUS_INVALID_DEVICE_REQUEST)

What kind of violation is being committed?
Is there a need to synchronize between EvtIoCanceledOnQueue and WdfIoQueueStopAndPurge?
Why the Request in the WDF_QUEUE_FATAL_ERROR_DATA is set to NULL not to the request R?

Doron_Holan · November 19, 2013, 10:07am

Output of

!analyze -v
!wdfkd.wdflogdump (your driver name)

Please

d

Bent from my phone

From: xxxxx@gmail.com mailto:xxxxx
Sent: ?11/?19/?2013 6:36 AM
To: Windows System Software Devs Interest Listmailto:xxxxx
Subject: [ntdev] EvtIoCanceledOnQueue and WdfIoQueueStopAndPurge

I recently have a 10D BSOD - WDF Violation during cancelling requests on queue.

The scenario is as follows:

There is a queue Q configured as follows: Manual, Power-managed, PowerOn, Passive Only, Can accept, Can dispatch, Dispatching, ExecutionLevelPassive, SynchronizationScopeNone

1. The EvtIoCanceledOnQueue is called on a request R on the queue Q
2. The cancel is not yet completed but the WdfIoQueueStopAndPurge on queue Q is called by another driver thread.

The WDF_QUEUE_FATAL_ERROR_DATA contains the following information:
- Queue: Queue Q Handler
- Request: NULL
- Status: C0000010 (STATUS_INVALID_DEVICE_REQUEST)

1. What kind of violation is being committed?
2. Is there a need to synchronize between EvtIoCanceledOnQueue and WdfIoQueueStopAndPurge?
3. Why the Request in the WDF_QUEUE_FATAL_ERROR_DATA is set to NULL not to the request R?

—
NTDEV is sponsored by OSR

Visit the list at: http://www.osronline.com/showlists.cfm?list=ntdev

OSR is HIRING!! See http://www.osr.com/careers

For our schedule of WDF, WDM, debugging and other seminars visit:
http://www.osr.com/seminars

To unsubscribe, visit the List Server section of OSR Online at http://www.osronline.com/page.cfm?name=ListServer</mailto:xxxxx></mailto:xxxxx>

Marek_Dabek-2 · November 19, 2013, 10:21am

!analyze -v:
*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************

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: 000000000000000a, A fatal error has occurred while processing a request on the
queue.
Arg2: fffff88003193620, Pointer to a WDF_QUEUE_FATAL_ERROR_DATA structure.
Arg3: 0000000000000000, Reserved.
Arg4: fffffa801708a010, Reserved.

Debugging Details:

BUGCHECK_STR: 0x10D_a

DEFAULT_BUCKET_ID: WIN7_DRIVER_FAULT

PROCESS_NAME: System

CURRENT_IRQL: 0

LAST_CONTROL_TRANSFER: from fffff88000ef336b to fffff80002ce5d00

STACK_TEXT:
fffff880031935e8 fffff88000ef336b : 000000000000010d 000000000000000a fffff88003193620 0000000000000000 : nt!KeBugCheckEx
fffff880031935f0 fffff88000ede91d : fffffa8016c1b000 fffffa8018f0eb80 0000057fe70f1478 0000000000001003 : Wdf01000!FxIoQueue::FatalError+0x5b
fffff88003193650 fffff8800524d650 : fffffa8018f0eb80 fffffa80169f9e60 0000000000000001 fffff8800527c218 : Wdf01000!imp_WdfIoQueueStopAndPurge+0x115
fffff880031936b0 fffff8800528887b : 0000000000000000 fffffa8018eb6970 fffffa8016c1b0c0 0000000000000001 : driver!DoSomething0A+0x37c
fffff88003193740 fffff88005287fdf : fffff880031937e8 0000000000000008 0000000000000000 fffffa801902f460 : driver!DoSomething10+0x39f
fffff880031937b0 fffff88005232bdd : 00000000c0000184 fffffa801902f460 0000000000000000 0000000000000000 : driver!DoSomething9+0x1a7
fffff88003193810 fffff8800525ccca : fffffa80186ad620 fffffa80186ad5f0 fffff880031939f8 fffffa80186ad5f0 : driver!DoSomething8+0x129
fffff88003193880 fffff8800529f805 : fffffa80186ad5f0 fffffa80186ad620 0000057fe7df03a8 00000000000007ff : driver!DoSomething7+0x2e
fffff880031938b0 fffff880052a0c21 : fffffa8016c282d0 fffff8800527c218 fffff8800527c218 fffff880031939f8 : driver!DoSomething6+0x1b9
fffff88003193920 fffff880052636af : fffffa80186ad5f0 fffffa8016c282d0 0000000000000003 0000000000000003 : driver!DoSomething5+0x179
fffff88003193990 fffff88007a85646 : fffffa8016cae400 0000000000000000 fffff88007aa2558 fffffa801747f560 : driver!DoSomething4+0x223
fffff880031939f0 fffff88007a6f945 : fffffa8016cae400 fffff88000000000 fffff88007ac2970 fffff880000003e7 : driver2!DoSomething3+0xb2
fffff88003193a30 fffff88007a6c4b4 : fffffa8016cae400 0000000000000002 0000000000000002 0000000000000001 : driver2!DoSomething2+0x199
fffff88003193a90 fffff88007a8b080 : fffffa80066da100 0000000000000000 0000000000000002 0000000000000100 : driver2!DoSomething1+0x418
fffff88003193b10 fffff80002fdc0c3 : fffffa8016cae2b0 fffff80002e83260 fffffa80066bb610 fffffa80066da1a0 : driver2!WorkerRoutine+0x68
fffff88003193b40 fffff80002cf0021 : fffffa80066bb600 fffff80002fdc001 fffff80002ee4800 0000000000000001 : nt!IopProcessWorkItem+0x23
fffff88003193b70 fffff80002f8232e : 0000000000000000 fffffa80066da1a0 0000000000000080 fffffa80066b4740 : nt!ExpWorkerThread+0x111
fffff88003193c00 fffff80002cd7666 : fffff88002fd7180 fffffa80066da1a0 fffff88002fe1fc0 0000000000000000 : nt!PspSystemThreadStartup+0x5a
fffff88003193c40 0000000000000000 : fffff88003194000 fffff8800318e000 fffff880031938a0 0000000000000000 : nt!KxStartSystemThread+0x16

STACK_COMMAND: kb

FOLLOWUP_IP:
driver!DoSomething0A+37c
fffff880`0524d650 488b842498000000 mov rax,qword ptr [rsp+98h]

FAULTING_SOURCE_LINE_NUMBER: 4524

SYMBOL_STACK_INDEX: 3

SYMBOL_NAME: driver!driver!DoSomething0A+37c+37c

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: driver

IMAGE_NAME: driver.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 528b675e

FAILURE_BUCKET_ID: X64_0x10D_a_driver!driver!DoSomething0A+37c

BUCKET_ID: X64_0x10D_a_driver!driver!DoSomething0A+37c

Followup: MachineOwner

!wdfkd.wdflogdump
42140: FxIoQueue::ProcessCancelledRequestsOnQueue - Calling CanceledOnQueue routine for WDFREQUEST 0x0000057FE7DB07B8 on WDFQUEUE 0x0000057FE70F1478
42141: FxIoQueue::ProcessCancelledRequestsOnQueue - Calling CanceledOnQueue routine for WDFREQUEST 0x0000057FE70A2C48 on WDFQUEUE 0x0000057FE95DFFD8
42142: FxPowerIdleMachine::ProcessEventLocked - WDFDEVICE 0x0000057FE93D7FD8 !devobj 0xFFFFFA80182DF670 entering power idle state FxIdleDecrementIo from FxIdleBusy
42143: FxPowerIdleMachine::ProcessEventLocked - WDFDEVICE 0x0000057FE93D7FD8 !devobj 0xFFFFFA80182DF670 entering power idle state FxIdleBusy from FxIdleDecrementIo
42144: imp_WdfDeviceIndicateWakeStatus - WDFDEVICE 0x0000057FE936B758 No request to complete STATUS_INVALID_DEVICE_REQUEST
42145: imp_WdfDeviceIndicateWakeStatus - WDFDEVICE 0x0000057FE936B758 No request to complete STATUS_INVALID_DEVICE_REQUEST
42146: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FE95DFFD8 not in dispatching state, current state is WdfIoQueueAcceptRequests
42147: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FE70E29F8 not in dispatching state, current state is WdfIoQueueAcceptRequests
42148: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FE95DFFD8 not in dispatching state, current state is WdfIoQueueAcceptRequests
42149: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FE70E29F8 not in dispatching state, current state is WdfIoQueueAcceptRequests
42150: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FE71DFB98 not in dispatching state, current state is WdfIoQueueAcceptRequests
42151: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FE8BA6428 not in dispatching state, current state is WdfIoQueueAcceptRequests
42152: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FE71DFB98 not in dispatching state, current state is WdfIoQueueAcceptRequests
42153: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FE8BA6428 not in dispatching state, current state is WdfIoQueueAcceptRequests
42154: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FF98873A8 not in dispatching state, current state is WdfIoQueueAcceptRequests
42155: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FE70F1478 not in dispatching state, current state is WdfIoQueueAcceptRequests
42156: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FF98873A8 not in dispatching state, current state is WdfIoQueueAcceptRequests
42157: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FE70F1478 not in dispatching state, current state is WdfIoQueueAcceptRequests
42158: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FE95DFFD8 not in dispatching state, current state is WdfIoQueueAcceptRequests
42159: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FE70E29F8 not in dispatching state, current state is WdfIoQueueAcceptRequests
42160: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FE71DFB98 not in dispatching state, current state is WdfIoQueueAcceptRequests
42161: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FE8BA6428 not in dispatching state, current state is WdfIoQueueAcceptRequests
42162: FxIoQueue::DispatchEvents - WDFQUEUE 0x0000057FF98873A8 not in dispatching state, current state is WdfIoQueueAcceptRequests
42163: FxIoQueue::QueueIdle - WDFQUEUE 0x0000057FE70F1478 already has a IdleComplete callback registered 0xFFFFF8800524E724, 0xc0000010(STATUS_INVALID_DEVICE_REQUEST)

Marek_Dabek-2 · November 19, 2013, 10:58am

I’ve found the issue the failing WdfIoQueueStopAndPurge is called but there is another WdfIoQueueStopAndPurge which is not completed, yet.