Prev: regarding the smart card reader driver not getting any IOCTL calls.
Next: Vista QOS testing
From: jrb1400 on 7 Aug 2007 17:06
Hi All,

I am using KMDF/WDF and Windows XP SP2.

My device has some IOCTL operations that wait for hardware and some that
map/unmap memory for user space access.

I get a Bugcheck 10D (0x00000002,0x86282754,0x00000000,0x8621C370) under
these conditions:
- One IOCTL operation is in progress waiting for a hardware response.
- The interrupt from the hardware has been received and the ISR has executed
- The DPC has been requested but NOT executed yet
- MmUnmapLockedPages is called from a different IOCTL

I do NOT get the bugcheck under these conditions:
- One IOCTL operation is in progress waiting for a hardware response.
- The interrupt from the hardware has NOT been received yet and the ISR/DPC
has NOT been executed
- MmUnmapLockedPages is called from a different IOCTL


The bugcheck 10D (parameter1 =2) implies WDF_VIOLATION / An attempt is being
made to acquire a lock that is currently being held.

I have tried surrounding the MmUnmapLockedPages with calls to
WdfInterruptAcquireLock(devContext->WdfInterrupt); and
WdfInterruptReleaseLock(devContext->WdfInterrupt); but that didn't have any
effect.


The stack trace looks like something inside the WDF library is invoking the
bugcheck as a part of the dispatch operation.

kd> kv
ChildEBP RetAddr Args to Child
f7a2eb20 805328e7 00000003 f7a2ee7c 00000000
nt!RtlpBreakWithStatusInstruction (FPO: [1,0,0])
f7a2eb6c 805333be 00000003 f71e04a4 861c109c nt!KiBugCheckDebugBreak+0x19
(FPO: [Non-Fpo])
f7a2ef4c 805339ae 0000010d 00000002 861c109c nt!KeBugCheck2+0x574 (FPO:
[Non-Fpo])
*** ERROR: Module load completed but symbols could not be loaded for
Wdf01000.sys
f7a2ef6c f71a1e81 0000010d 00000002 861c109c nt!KeBugCheckEx+0x1b (FPO:
[Non-Fpo])
WARNING: Stack unwind information not available. Following frames may be
wrong.
f7a2ef88 f71ac517 86216108 00000002 861c109c Wdf01000+0x29e81
f7a2efa8 f71ca995 f7a2efbc 86231980 86246a60 Wdf01000+0x34517
f7a2efc0 f71caa37 861bb048 00000000 ffdff980 Wdf01000+0x52995
f7a2efd0 804dc179 861bb094 861bb048 861bb048 Wdf01000+0x52a37
f7a2eff4 804dbe2d a2926a00 00000000 00000000 nt!KiRetireDpcList+0x46 (FPO:
[0,0,0])
f7a2eff8 a2926a00 00000000 00000000 00000000 nt!KiDispatchInterrupt+0x2a
(FPO: [Uses EBP] [0,0,1])
804dbe2d 00000000 00000009 bb835675 00000128 0xa2926a00



Questions:

(1) What lock could I possibly be holding ? It allows me to acquire my own
interrupt lock, so I'm guessing that it might be one of the framework's
internal spin locks
(2) How can I get the symbols for the WDF01000 module? That may help me
understand things a bit better. I installed the XP SP2 symbols.

I'm using WdfSynchronizationScopeDevice.


Thanks very much for your help !

Jay

From: Doron Holan [MSFT] on 8 Aug 2007 01:04
first, fix your symbols so you have a legible call stack.
second, send the output !analyze -v so we can see all of the bugcheck
parameters and analysis
third, run !wdfkd.wdflogdump <your driver>, it will give you more
information

d

--
Please do not send e-mail directly to this alias. this alias is for
newsgroup purposes only.
This posting is provided "AS IS" with no warranties, and confers no rights.


"jrb1400" <jrb1400(a)discussions.microsoft.com> wrote in message
news:DE1D73D9-32F5-402A-844E-E7819563540A(a)microsoft.com...
> Hi All,
>
> I am using KMDF/WDF and Windows XP SP2.
>
> My device has some IOCTL operations that wait for hardware and some that
> map/unmap memory for user space access.
>
> I get a Bugcheck 10D (0x00000002,0x86282754,0x00000000,0x8621C370) under
> these conditions:
> - One IOCTL operation is in progress waiting for a hardware response.
> - The interrupt from the hardware has been received and the ISR has
> executed
> - The DPC has been requested but NOT executed yet
> - MmUnmapLockedPages is called from a different IOCTL
>
> I do NOT get the bugcheck under these conditions:
> - One IOCTL operation is in progress waiting for a hardware response.
> - The interrupt from the hardware has NOT been received yet and the
> ISR/DPC
> has NOT been executed
> - MmUnmapLockedPages is called from a different IOCTL
>
>
> The bugcheck 10D (parameter1 =2) implies WDF_VIOLATION / An attempt is
> being
> made to acquire a lock that is currently being held.
>
> I have tried surrounding the MmUnmapLockedPages with calls to
> WdfInterruptAcquireLock(devContext->WdfInterrupt); and
> WdfInterruptReleaseLock(devContext->WdfInterrupt); but that didn't have
> any
> effect.
>
>
> The stack trace looks like something inside the WDF library is invoking
> the
> bugcheck as a part of the dispatch operation.
>
> kd> kv
> ChildEBP RetAddr Args to Child
> f7a2eb20 805328e7 00000003 f7a2ee7c 00000000
> nt!RtlpBreakWithStatusInstruction (FPO: [1,0,0])
> f7a2eb6c 805333be 00000003 f71e04a4 861c109c nt!KiBugCheckDebugBreak+0x19
> (FPO: [Non-Fpo])
> f7a2ef4c 805339ae 0000010d 00000002 861c109c nt!KeBugCheck2+0x574 (FPO:
> [Non-Fpo])
> *** ERROR: Module load completed but symbols could not be loaded for
> Wdf01000.sys
> f7a2ef6c f71a1e81 0000010d 00000002 861c109c nt!KeBugCheckEx+0x1b (FPO:
> [Non-Fpo])
> WARNING: Stack unwind information not available. Following frames may be
> wrong.
> f7a2ef88 f71ac517 86216108 00000002 861c109c Wdf01000+0x29e81
> f7a2efa8 f71ca995 f7a2efbc 86231980 86246a60 Wdf01000+0x34517
> f7a2efc0 f71caa37 861bb048 00000000 ffdff980 Wdf01000+0x52995
> f7a2efd0 804dc179 861bb094 861bb048 861bb048 Wdf01000+0x52a37
> f7a2eff4 804dbe2d a2926a00 00000000 00000000 nt!KiRetireDpcList+0x46 (FPO:
> [0,0,0])
> f7a2eff8 a2926a00 00000000 00000000 00000000 nt!KiDispatchInterrupt+0x2a
> (FPO: [Uses EBP] [0,0,1])
> 804dbe2d 00000000 00000009 bb835675 00000128 0xa2926a00
>
>
>
> Questions:
>
> (1) What lock could I possibly be holding ? It allows me to acquire my
> own
> interrupt lock, so I'm guessing that it might be one of the framework's
> internal spin locks
> (2) How can I get the symbols for the WDF01000 module? That may help me
> understand things a bit better. I installed the XP SP2 symbols.
>
> I'm using WdfSynchronizationScopeDevice.
>
>
> Thanks very much for your help !
>
> Jay
>

From: jrb1400 on 8 Aug 2007 12:08
Hi Doron,

Thanks very much for looking into this.

Perhaps I can provide a bit more background. I need to map an area of
memory into user space that I can use for device-controlled DMA transfers to
a frame buffer. My approach is based on an OSR article in this topic, and I
realize that the Map/Unmap operations must be done in the user's context.
My device is the top-level device, so I implemented this as IOCTL operations.
Perhaps I have a design flaw here.

Also as a part of this bugcheck investigation, I ran driver verifier and got
a verifier bugcheck indicating that I can't call MmMapLockedPagesSpecifyCache
for UserMode with IRQL > APC_LEVEL. Perhaps the same is true for
MmUnmapLockedPages. In an attempt to get around this, I tried to set my
device attributes ExecutionLevel to WdfExecutionLevelPassive, but that caused
an immediate bugcheck. Apparently I can't use SynchronizationScopeDevice
with WdfExecutionLevelPassive (is that right?)

To reiterate a few things,
- I only get the bugcheck 010D if MmUnmapLockedPages is called between the
ISR and the DPC execution that services a different IOCTL
- I can comment out the MmUnmapLockedPages and do not get the bugcheck.

The additional analysis information you requested is shown below. The
WDFLogDump shows a "Recursive acquire of callback lock!" at the end.
Thanks very much for your help.

Jay






kd> !analyze -v
*******************************************************************************
*
*
* Bugcheck Analysis
*
*
*
*******************************************************************************

WDF_VIOLATION (10d)
The Kernel-Mode Driver Framework has detected 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: 00000002, An attempt is being made to acquire a lock that is currently
being held. The lock in question can be determined by examining
the caller's stack.
Arg2: 861c463c, Reserved.
Arg3: 00000000, Reserved.
Arg4: 8621b1a8, Reserved.

Debugging Details:
------------------


DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0x10D

PROCESS_NAME: IGEvapi.exe

MANAGED_STACK: !dumpstack -EE
OS Thread Id: 0x0 (0)
ReadVirtual: f7a2eb24 not properly sign extended
TEB information is not available so a stack size of 0xFFFF is assumed
Current frame:
ChildEBP RetAddr Caller,Callee
ReadVirtual: f7a2eba4 not properly sign extended
...... [........there were dozens of these items - I deleted them from
this post]
ReadVirtual: a2b07000 not properly sign extended

LAST_CONTROL_TRANSFER: from 805328e7 to 804e3b25

STACK_TEXT:
f7a2eb20 805328e7 00000003 f7a2ee7c 00000000 nt!RtlpBreakWithStatusInstruction
f7a2eb6c 805333be 00000003 f71e04a4 861c463c nt!KiBugCheckDebugBreak+0x19
f7a2ef4c 805339ae 0000010d 00000002 861c463c nt!KeBugCheck2+0x574
f7a2ef6c f71a1e81 0000010d 00000002 861c463c nt!KeBugCheckEx+0x1b
f7a2ef88 f71ac517 8621b1a8 00000002 861c463c Wdf01000!FxVerifierBugCheck+0x24
f7a2efa8 f71ca995 f7a2efbc 85713020 862539f0
Wdf01000!FxCallbackSpinLock::Lock+0x63
f7a2efc0 f71caa37 861c0bd0 00000000 ffdff980
Wdf01000!FxInterrupt::DpcHandler+0x1d
f7a2efd0 804dc179 861c0c1c 861c0bd0 861c0bd0
Wdf01000!FxInterrupt::_InterruptDpcThunk+0x13
f7a2eff4 804dbe2d a2b06a00 00000000 00000000 nt!KiRetireDpcList+0x46
f7a2eff8 a2b06a00 00000000 00000000 00000000 nt!KiDispatchInterrupt+0x2a
WARNING: Frame IP not in any known module. Following frames may be wrong.
804dbe2d 00000000 00000009 bb835675 00000128 0xa2b06a00


STACK_COMMAND: kb

FOLLOWUP_IP:
Wdf01000!FxVerifierBugCheck+24
f71a1e81 cc int 3

SYMBOL_STACK_INDEX: 4

SYMBOL_NAME: Wdf01000!FxVerifierBugCheck+24

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: Wdf01000

IMAGE_NAME: Wdf01000.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 4549b23a

FAILURE_BUCKET_ID: 0x10D_Wdf01000!FxVerifierBugCheck+24

BUCKET_ID: 0x10D_Wdf01000!FxVerifierBugCheck+24

Followup: MachineOwner
---------









kd> !wdflogdump igedriver
Trace searchpath is:

Trace format prefix is: %7!u!: %!FUNC! -
TMF file used for formatting IFR log is:
C:\winDDK\6000\tools\tracing\i386\wdf01005.tmf
Log at 861c1000
Gather log: Please wait, this may take a moment (reading 4032 bytes).
% read so far ... 10, 20, 30, 40, 50, 60, 70, 80, 90, 100
There are 111 log entries
--- start of log ---
63088: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50 dispatched
to driver
63089: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
63090: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
63091: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
63092: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
WDFREQUEST 79D2DD50
63093: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
0x79E3F2F0
63094: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
0x79E3F2F0
63095: FxIoQueue::DispatchRequestToDriver - Calling driver
EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
63096: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
63097: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
63098: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
Information 0x00000004
63099: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
STATUS_SUCCESS
63100: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
0x862A08B8 with Information 0x4, STATUS_SUCCESS
63101: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
WDFREQUEST 0x79D2DD50
63102: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50 dispatched
to driver
63103: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
63104: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
63105: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
63106: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
WDFREQUEST 79D2DD50
63107: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
0x79E3F2F0
63108: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
0x79E3F2F0
63109: FxIoQueue::DispatchRequestToDriver - Calling driver
EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
63110: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
63111: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
63112: imp_WdfRequestMarkCancelable - Enter: WDFREQUEST 0x79D2DD50
63113: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50 dispatched
to driver
63114: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
63115: imp_WdfRequestUnmarkCancelable - Enter: WDFREQUEST 0x79D2DD50
63116: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
63117: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
Information 0x00000114
63118: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
STATUS_SUCCESS
63119: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
0x862A08B8 with Information 0x114, STATUS_SUCCESS
63120: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
WDFREQUEST 0x79D2DD50
63121: FxIoQueue::DispatchEvents - Presentation lock for WDFQUEUE 0x79E3F2F0
is already held, deferring to dpc or workitem
63122: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
63123: FxIoQueue::_DeferredDispatchDpcThunk - Dispatching requests from DPC
63124: FxIoQueue::DispatchEvents - Thread 80559320 is processing WDFQUEUE
0x79E3F2F0
63125: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
63126: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
63127: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
WDFREQUEST 79D2DD50
63128: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
0x79E3F2F0
63129: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
0x79E3F2F0
63130: FxIoQueue::DispatchRequestToDriver - Calling driver
EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
63131: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
63132: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
63133: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
Information 0x00000004
63134: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
STATUS_SUCCESS
63135: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
0x862A08B8 with Information 0x4, STATUS_SUCCESS
63136: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
WDFREQUEST 0x79D2DD50
63137: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50 dispatched
to driver
63138: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
63139: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
63140: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
63141: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
WDFREQUEST 79D2DD50
63142: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
0x79E3F2F0
63143: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
0x79E3F2F0
63144: FxIoQueue::DispatchRequestToDriver - Calling driver
EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
63145: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
63146: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
63147: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
Information 0x00000004
63148: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
STATUS_SUCCESS
63149: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
0x862A08B8 with Information 0x4, STATUS_SUCCESS
63150: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
WDFREQUEST 0x79D2DD50
63151: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50 dispatched
to driver
63152: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
63153: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
63154: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
63155: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
WDFREQUEST 79D2DD50
63156: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
0x79E3F2F0
63157: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
0x79E3F2F0
63158: FxIoQueue::DispatchRequestToDriver - Calling driver
EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
63159: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
63160: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
63161: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
Information 0x00000004
63162: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
STATUS_SUCCESS
63163: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
0x862A08B8 with Information 0x4, STATUS_SUCCESS
63164: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
WDFREQUEST 0x79D2DD50
63165: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50 dispatched
to driver
63166: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
63167: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
63168: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
63169: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
WDFREQUEST 79D2DD50
63170: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
0x79E3F2F0
63171: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
0x79E3F2F0
63172: FxIoQueue::DispatchRequestToDriver - Calling driver
EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
63173: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
63174: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
63175: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
Information 0x00000004
63176: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
STATUS_SUCCESS
63177: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
0x862A08B8 with Information 0x4, STATUS_SUCCESS
63178: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
WDFREQUEST 0x79D2DD50
63179: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50 dispatched
to driver
63180: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
63181: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
63182: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
63183: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
WDFREQUEST 79D2DD50
63184: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
0x79E3F2F0
63185: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
0x79E3F2F0
63186: FxIoQueue::DispatchRequestToDriver - Calling driver
EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
63187: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
63188: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
63189: imp_WdfRequestMarkCancelable - Enter: WDFREQUEST 0x79D2DD50
63190: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50 dispatched
to driver
63191: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x85689148
63192: FxDevice::AllocateRequestMemory - Allocating FxRequest* 863D4BA0,
WDFREQUEST 79C2B458
63193: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79C2B458 on WDFQUEUE
0x79E3F2F0
63194: FxIoQueue::DispatchEvents - Thread 85680020 is processing WDFQUEUE
0x79E3F2F0
63195: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
63196: FxIoQueue::DispatchRequestToDriver - Calling driver
EvtIoDeviceControl for WDFREQUEST 0x79C2B458
63197: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79C2B458
63198: FxCallbackSpinLock::Lock - Recursive Acquire of callback lock!
0x861C463C
---- end of log ----












"Doron Holan [MSFT]" wrote:

> first, fix your symbols so you have a legible call stack.
> second, send the output !analyze -v so we can see all of the bugcheck
> parameters and analysis
> third, run !wdfkd.wdflogdump <your driver>, it will give you more
> information
>
> d
>
> --
> Please do not send e-mail directly to this alias. this alias is for
> newsgroup purposes only.
> This posting is provided "AS IS" with no warranties, and confers no rights.
>
>
>



From: Doron Holan [MSFT] on 8 Aug 2007 13:20
in what function are you mapping pages into user mode? in your EvtIoXxx
callback? or in EvtIoInCallerContext? You will need to abandon device
level locking. instead, you should use queue types (sequential, parallel)
and your own locks. this way you will get io at passive level.

d

--
Please do not send e-mail directly to this alias. this alias is for
newsgroup purposes only.
This posting is provided "AS IS" with no warranties, and confers no rights.


"jrb1400" <jrb1400(a)discussions.microsoft.com> wrote in message
news:1427A13E-9D40-4039-A432-EA093A628822(a)microsoft.com...
> Hi Doron,
>
> Thanks very much for looking into this.
>
> Perhaps I can provide a bit more background. I need to map an area of
> memory into user space that I can use for device-controlled DMA transfers
> to
> a frame buffer. My approach is based on an OSR article in this topic,
> and I
> realize that the Map/Unmap operations must be done in the user's context.
> My device is the top-level device, so I implemented this as IOCTL
> operations.
> Perhaps I have a design flaw here.
>
> Also as a part of this bugcheck investigation, I ran driver verifier and
> got
> a verifier bugcheck indicating that I can't call
> MmMapLockedPagesSpecifyCache
> for UserMode with IRQL > APC_LEVEL. Perhaps the same is true for
> MmUnmapLockedPages. In an attempt to get around this, I tried to set my
> device attributes ExecutionLevel to WdfExecutionLevelPassive, but that
> caused
> an immediate bugcheck. Apparently I can't use SynchronizationScopeDevice
> with WdfExecutionLevelPassive (is that right?)
>
> To reiterate a few things,
> - I only get the bugcheck 010D if MmUnmapLockedPages is called between the
> ISR and the DPC execution that services a different IOCTL
> - I can comment out the MmUnmapLockedPages and do not get the bugcheck.
>
> The additional analysis information you requested is shown below. The
> WDFLogDump shows a "Recursive acquire of callback lock!" at the end.
> Thanks very much for your help.
>
> Jay
>
>
>
>
>
>
> kd> !analyze -v
> *******************************************************************************
> *
> *
> * Bugcheck Analysis
> *
> *
> *
> *******************************************************************************
>
> WDF_VIOLATION (10d)
> The Kernel-Mode Driver Framework has detected 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: 00000002, An attempt is being made to acquire a lock that is
> currently
> being held. The lock in question can be determined by examining
> the caller's stack.
> Arg2: 861c463c, Reserved.
> Arg3: 00000000, Reserved.
> Arg4: 8621b1a8, Reserved.
>
> Debugging Details:
> ------------------
>
>
> DEFAULT_BUCKET_ID: DRIVER_FAULT
>
> BUGCHECK_STR: 0x10D
>
> PROCESS_NAME: IGEvapi.exe
>
> MANAGED_STACK: !dumpstack -EE
> OS Thread Id: 0x0 (0)
> ReadVirtual: f7a2eb24 not properly sign extended
> TEB information is not available so a stack size of 0xFFFF is assumed
> Current frame:
> ChildEBP RetAddr Caller,Callee
> ReadVirtual: f7a2eba4 not properly sign extended
> ...... [........there were dozens of these items - I deleted them from
> this post]
> ReadVirtual: a2b07000 not properly sign extended
>
> LAST_CONTROL_TRANSFER: from 805328e7 to 804e3b25
>
> STACK_TEXT:
> f7a2eb20 805328e7 00000003 f7a2ee7c 00000000
> nt!RtlpBreakWithStatusInstruction
> f7a2eb6c 805333be 00000003 f71e04a4 861c463c nt!KiBugCheckDebugBreak+0x19
> f7a2ef4c 805339ae 0000010d 00000002 861c463c nt!KeBugCheck2+0x574
> f7a2ef6c f71a1e81 0000010d 00000002 861c463c nt!KeBugCheckEx+0x1b
> f7a2ef88 f71ac517 8621b1a8 00000002 861c463c
> Wdf01000!FxVerifierBugCheck+0x24
> f7a2efa8 f71ca995 f7a2efbc 85713020 862539f0
> Wdf01000!FxCallbackSpinLock::Lock+0x63
> f7a2efc0 f71caa37 861c0bd0 00000000 ffdff980
> Wdf01000!FxInterrupt::DpcHandler+0x1d
> f7a2efd0 804dc179 861c0c1c 861c0bd0 861c0bd0
> Wdf01000!FxInterrupt::_InterruptDpcThunk+0x13
> f7a2eff4 804dbe2d a2b06a00 00000000 00000000 nt!KiRetireDpcList+0x46
> f7a2eff8 a2b06a00 00000000 00000000 00000000 nt!KiDispatchInterrupt+0x2a
> WARNING: Frame IP not in any known module. Following frames may be wrong.
> 804dbe2d 00000000 00000009 bb835675 00000128 0xa2b06a00
>
>
> STACK_COMMAND: kb
>
> FOLLOWUP_IP:
> Wdf01000!FxVerifierBugCheck+24
> f71a1e81 cc int 3
>
> SYMBOL_STACK_INDEX: 4
>
> SYMBOL_NAME: Wdf01000!FxVerifierBugCheck+24
>
> FOLLOWUP_NAME: MachineOwner
>
> MODULE_NAME: Wdf01000
>
> IMAGE_NAME: Wdf01000.sys
>
> DEBUG_FLR_IMAGE_TIMESTAMP: 4549b23a
>
> FAILURE_BUCKET_ID: 0x10D_Wdf01000!FxVerifierBugCheck+24
>
> BUCKET_ID: 0x10D_Wdf01000!FxVerifierBugCheck+24
>
> Followup: MachineOwner
> ---------
>
>
>
>
>
>
>
>
>
> kd> !wdflogdump igedriver
> Trace searchpath is:
>
> Trace format prefix is: %7!u!: %!FUNC! -
> TMF file used for formatting IFR log is:
> C:\winDDK\6000\tools\tracing\i386\wdf01005.tmf
> Log at 861c1000
> Gather log: Please wait, this may take a moment (reading 4032 bytes).
> % read so far ... 10, 20, 30, 40, 50, 60, 70, 80, 90, 100
> There are 111 log entries
> --- start of log ---
> 63088: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63089: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
> 63090: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63091: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
> 63092: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
> WDFREQUEST 79D2DD50
> 63093: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
> 0x79E3F2F0
> 63094: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
> 0x79E3F2F0
> 63095: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
> 63096: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63097: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63098: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
> Information 0x00000004
> 63099: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
> STATUS_SUCCESS
> 63100: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
> 0x862A08B8 with Information 0x4, STATUS_SUCCESS
> 63101: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
> WDFREQUEST 0x79D2DD50
> 63102: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63103: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
> 63104: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63105: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
> 63106: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
> WDFREQUEST 79D2DD50
> 63107: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
> 0x79E3F2F0
> 63108: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
> 0x79E3F2F0
> 63109: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
> 63110: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63111: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63112: imp_WdfRequestMarkCancelable - Enter: WDFREQUEST 0x79D2DD50
> 63113: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63114: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63115: imp_WdfRequestUnmarkCancelable - Enter: WDFREQUEST 0x79D2DD50
> 63116: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63117: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
> Information 0x00000114
> 63118: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
> STATUS_SUCCESS
> 63119: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
> 0x862A08B8 with Information 0x114, STATUS_SUCCESS
> 63120: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
> WDFREQUEST 0x79D2DD50
> 63121: FxIoQueue::DispatchEvents - Presentation lock for WDFQUEUE
> 0x79E3F2F0
> is already held, deferring to dpc or workitem
> 63122: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
> 63123: FxIoQueue::_DeferredDispatchDpcThunk - Dispatching requests from
> DPC
> 63124: FxIoQueue::DispatchEvents - Thread 80559320 is processing WDFQUEUE
> 0x79E3F2F0
> 63125: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63126: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
> 63127: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
> WDFREQUEST 79D2DD50
> 63128: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
> 0x79E3F2F0
> 63129: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
> 0x79E3F2F0
> 63130: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
> 63131: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63132: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63133: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
> Information 0x00000004
> 63134: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
> STATUS_SUCCESS
> 63135: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
> 0x862A08B8 with Information 0x4, STATUS_SUCCESS
> 63136: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
> WDFREQUEST 0x79D2DD50
> 63137: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63138: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
> 63139: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63140: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
> 63141: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
> WDFREQUEST 79D2DD50
> 63142: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
> 0x79E3F2F0
> 63143: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
> 0x79E3F2F0
> 63144: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
> 63145: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63146: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63147: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
> Information 0x00000004
> 63148: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
> STATUS_SUCCESS
> 63149: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
> 0x862A08B8 with Information 0x4, STATUS_SUCCESS
> 63150: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
> WDFREQUEST 0x79D2DD50
> 63151: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63152: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
> 63153: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63154: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
> 63155: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
> WDFREQUEST 79D2DD50
> 63156: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
> 0x79E3F2F0
> 63157: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
> 0x79E3F2F0
> 63158: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
> 63159: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63160: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63161: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
> Information 0x00000004
> 63162: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
> STATUS_SUCCESS
> 63163: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
> 0x862A08B8 with Information 0x4, STATUS_SUCCESS
> 63164: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
> WDFREQUEST 0x79D2DD50
> 63165: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63166: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
> 63167: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63168: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
> 63169: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
> WDFREQUEST 79D2DD50
> 63170: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
> 0x79E3F2F0
> 63171: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
> 0x79E3F2F0
> 63172: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
> 63173: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63174: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63175: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
> Information 0x00000004
> 63176: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
> STATUS_SUCCESS
> 63177: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
> 0x862A08B8 with Information 0x4, STATUS_SUCCESS
> 63178: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
> WDFREQUEST 0x79D2DD50
> 63179: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63180: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
> 63181: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63182: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
> 63183: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
> WDFREQUEST 79D2DD50
> 63184: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
> 0x79E3F2F0
> 63185: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
> 0x79E3F2F0
> 63186: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
> 63187: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63188: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63189: imp_WdfRequestMarkCancelable - Enter: WDFREQUEST 0x79D2DD50
> 63190: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63191: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x85689148
> 63192: FxDevice::AllocateRequestMemory - Allocating FxRequest* 863D4BA0,
> WDFREQUEST 79C2B458
> 63193: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79C2B458 on WDFQUEUE
> 0x79E3F2F0
> 63194: FxIoQueue::DispatchEvents - Thread 85680020 is processing WDFQUEUE
> 0x79E3F2F0
> 63195: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63196: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79C2B458
> 63197: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79C2B458
> 63198: FxCallbackSpinLock::Lock - Recursive Acquire of callback lock!
> 0x861C463C
> ---- end of log ----
>
>
>
>
>
>
>
>
>
>
>
>
> "Doron Holan [MSFT]" wrote:
>
>> first, fix your symbols so you have a legible call stack.
>> second, send the output !analyze -v so we can see all of the bugcheck
>> parameters and analysis
>> third, run !wdfkd.wdflogdump <your driver>, it will give you more
>> information
>>
>> d
>>
>> --
>> Please do not send e-mail directly to this alias. this alias is for
>> newsgroup purposes only.
>> This posting is provided "AS IS" with no warranties, and confers no
>> rights.
>>
>>
>>
>
>
>

From: Eliyas Yakub [MSFT] on 8 Aug 2007 17:54
> Apparently I can't use SynchronizationScopeDevice with
> WdfExecutionLevelPassive (is that right?)

Nope that's not right. The only restriction if you opt for passive-level
execution on the device is that you will not be able to get your IsrForDpc
or TimerDpc to be synchronized with the I/O dispatch routines because these
routines run at DISPATCH_LEVEL.

The thing to remember when you map/unmap buffer in the user process is that
when the ioctl call is made to your driver, you should do that in the
context of the caller. You are guaranteed to be in the caller context only
in the EvtIoInCallerContext callback. If you try to do that from the
EvtIoDispatch routines of queue, it wouldn't work because queue can dispatch
requests from a thread different context (worker thread or timer dpc, etc).

-Eliyas


"jrb1400" <jrb1400(a)discussions.microsoft.com> wrote in message
news:1427A13E-9D40-4039-A432-EA093A628822(a)microsoft.com...
> Hi Doron,
>
> Thanks very much for looking into this.
>
> Perhaps I can provide a bit more background. I need to map an area of
> memory into user space that I can use for device-controlled DMA transfers
> to
> a frame buffer. My approach is based on an OSR article in this topic,
> and I
> realize that the Map/Unmap operations must be done in the user's context.
> My device is the top-level device, so I implemented this as IOCTL
> operations.
> Perhaps I have a design flaw here.
>
> Also as a part of this bugcheck investigation, I ran driver verifier and
> got
> a verifier bugcheck indicating that I can't call
> MmMapLockedPagesSpecifyCache
> for UserMode with IRQL > APC_LEVEL. Perhaps the same is true for
> MmUnmapLockedPages. In an attempt to get around this, I tried to set my
> device attributes ExecutionLevel to WdfExecutionLevelPassive, but that
> caused
> an immediate bugcheck. Apparently I can't use SynchronizationScopeDevice
> with WdfExecutionLevelPassive (is that right?)
>
> To reiterate a few things,
> - I only get the bugcheck 010D if MmUnmapLockedPages is called between the
> ISR and the DPC execution that services a different IOCTL
> - I can comment out the MmUnmapLockedPages and do not get the bugcheck.
>
> The additional analysis information you requested is shown below. The
> WDFLogDump shows a "Recursive acquire of callback lock!" at the end.
> Thanks very much for your help.
>
> Jay
>
>
>
>
>
>
> kd> !analyze -v
> *******************************************************************************
> *
> *
> * Bugcheck Analysis
> *
> *
> *
> *******************************************************************************
>
> WDF_VIOLATION (10d)
> The Kernel-Mode Driver Framework has detected 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: 00000002, An attempt is being made to acquire a lock that is
> currently
> being held. The lock in question can be determined by examining
> the caller's stack.
> Arg2: 861c463c, Reserved.
> Arg3: 00000000, Reserved.
> Arg4: 8621b1a8, Reserved.
>
> Debugging Details:
> ------------------
>
>
> DEFAULT_BUCKET_ID: DRIVER_FAULT
>
> BUGCHECK_STR: 0x10D
>
> PROCESS_NAME: IGEvapi.exe
>
> MANAGED_STACK: !dumpstack -EE
> OS Thread Id: 0x0 (0)
> ReadVirtual: f7a2eb24 not properly sign extended
> TEB information is not available so a stack size of 0xFFFF is assumed
> Current frame:
> ChildEBP RetAddr Caller,Callee
> ReadVirtual: f7a2eba4 not properly sign extended
> ...... [........there were dozens of these items - I deleted them from
> this post]
> ReadVirtual: a2b07000 not properly sign extended
>
> LAST_CONTROL_TRANSFER: from 805328e7 to 804e3b25
>
> STACK_TEXT:
> f7a2eb20 805328e7 00000003 f7a2ee7c 00000000
> nt!RtlpBreakWithStatusInstruction
> f7a2eb6c 805333be 00000003 f71e04a4 861c463c nt!KiBugCheckDebugBreak+0x19
> f7a2ef4c 805339ae 0000010d 00000002 861c463c nt!KeBugCheck2+0x574
> f7a2ef6c f71a1e81 0000010d 00000002 861c463c nt!KeBugCheckEx+0x1b
> f7a2ef88 f71ac517 8621b1a8 00000002 861c463c
> Wdf01000!FxVerifierBugCheck+0x24
> f7a2efa8 f71ca995 f7a2efbc 85713020 862539f0
> Wdf01000!FxCallbackSpinLock::Lock+0x63
> f7a2efc0 f71caa37 861c0bd0 00000000 ffdff980
> Wdf01000!FxInterrupt::DpcHandler+0x1d
> f7a2efd0 804dc179 861c0c1c 861c0bd0 861c0bd0
> Wdf01000!FxInterrupt::_InterruptDpcThunk+0x13
> f7a2eff4 804dbe2d a2b06a00 00000000 00000000 nt!KiRetireDpcList+0x46
> f7a2eff8 a2b06a00 00000000 00000000 00000000 nt!KiDispatchInterrupt+0x2a
> WARNING: Frame IP not in any known module. Following frames may be wrong.
> 804dbe2d 00000000 00000009 bb835675 00000128 0xa2b06a00
>
>
> STACK_COMMAND: kb
>
> FOLLOWUP_IP:
> Wdf01000!FxVerifierBugCheck+24
> f71a1e81 cc int 3
>
> SYMBOL_STACK_INDEX: 4
>
> SYMBOL_NAME: Wdf01000!FxVerifierBugCheck+24
>
> FOLLOWUP_NAME: MachineOwner
>
> MODULE_NAME: Wdf01000
>
> IMAGE_NAME: Wdf01000.sys
>
> DEBUG_FLR_IMAGE_TIMESTAMP: 4549b23a
>
> FAILURE_BUCKET_ID: 0x10D_Wdf01000!FxVerifierBugCheck+24
>
> BUCKET_ID: 0x10D_Wdf01000!FxVerifierBugCheck+24
>
> Followup: MachineOwner
> ---------
>
>
>
>
>
>
>
>
>
> kd> !wdflogdump igedriver
> Trace searchpath is:
>
> Trace format prefix is: %7!u!: %!FUNC! -
> TMF file used for formatting IFR log is:
> C:\winDDK\6000\tools\tracing\i386\wdf01005.tmf
> Log at 861c1000
> Gather log: Please wait, this may take a moment (reading 4032 bytes).
> % read so far ... 10, 20, 30, 40, 50, 60, 70, 80, 90, 100
> There are 111 log entries
> --- start of log ---
> 63088: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63089: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
> 63090: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63091: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
> 63092: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
> WDFREQUEST 79D2DD50
> 63093: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
> 0x79E3F2F0
> 63094: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
> 0x79E3F2F0
> 63095: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
> 63096: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63097: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63098: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
> Information 0x00000004
> 63099: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
> STATUS_SUCCESS
> 63100: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
> 0x862A08B8 with Information 0x4, STATUS_SUCCESS
> 63101: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
> WDFREQUEST 0x79D2DD50
> 63102: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63103: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
> 63104: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63105: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
> 63106: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
> WDFREQUEST 79D2DD50
> 63107: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
> 0x79E3F2F0
> 63108: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
> 0x79E3F2F0
> 63109: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
> 63110: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63111: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63112: imp_WdfRequestMarkCancelable - Enter: WDFREQUEST 0x79D2DD50
> 63113: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63114: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63115: imp_WdfRequestUnmarkCancelable - Enter: WDFREQUEST 0x79D2DD50
> 63116: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63117: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
> Information 0x00000114
> 63118: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
> STATUS_SUCCESS
> 63119: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
> 0x862A08B8 with Information 0x114, STATUS_SUCCESS
> 63120: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
> WDFREQUEST 0x79D2DD50
> 63121: FxIoQueue::DispatchEvents - Presentation lock for WDFQUEUE
> 0x79E3F2F0
> is already held, deferring to dpc or workitem
> 63122: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
> 63123: FxIoQueue::_DeferredDispatchDpcThunk - Dispatching requests from
> DPC
> 63124: FxIoQueue::DispatchEvents - Thread 80559320 is processing WDFQUEUE
> 0x79E3F2F0
> 63125: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63126: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
> 63127: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
> WDFREQUEST 79D2DD50
> 63128: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
> 0x79E3F2F0
> 63129: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
> 0x79E3F2F0
> 63130: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
> 63131: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63132: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63133: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
> Information 0x00000004
> 63134: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
> STATUS_SUCCESS
> 63135: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
> 0x862A08B8 with Information 0x4, STATUS_SUCCESS
> 63136: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
> WDFREQUEST 0x79D2DD50
> 63137: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63138: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
> 63139: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63140: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
> 63141: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
> WDFREQUEST 79D2DD50
> 63142: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
> 0x79E3F2F0
> 63143: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
> 0x79E3F2F0
> 63144: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
> 63145: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63146: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63147: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
> Information 0x00000004
> 63148: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
> STATUS_SUCCESS
> 63149: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
> 0x862A08B8 with Information 0x4, STATUS_SUCCESS
> 63150: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
> WDFREQUEST 0x79D2DD50
> 63151: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63152: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
> 63153: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63154: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
> 63155: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
> WDFREQUEST 79D2DD50
> 63156: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
> 0x79E3F2F0
> 63157: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
> 0x79E3F2F0
> 63158: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
> 63159: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63160: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63161: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
> Information 0x00000004
> 63162: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
> STATUS_SUCCESS
> 63163: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
> 0x862A08B8 with Information 0x4, STATUS_SUCCESS
> 63164: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
> WDFREQUEST 0x79D2DD50
> 63165: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63166: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
> 63167: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63168: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
> 63169: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
> WDFREQUEST 79D2DD50
> 63170: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
> 0x79E3F2F0
> 63171: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
> 0x79E3F2F0
> 63172: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
> 63173: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63174: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63175: imp_WdfRequestSetInformation - Enter: WDFREQUEST 0x79D2DD50,
> Information 0x00000004
> 63176: imp_WdfRequestComplete - Completing WDFREQUEST 0x79D2DD50,
> STATUS_SUCCESS
> 63177: FxRequest::Complete - Completing WDFREQUEST 0x79D2DD50 for IRP
> 0x862A08B8 with Information 0x4, STATUS_SUCCESS
> 63178: FxIoQueue::RequestCompletedCallback - Enter: WDFQUEUE 0x79E3F2F0,
> WDFREQUEST 0x79D2DD50
> 63179: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63180: FxDevice::FreeRequestMemory - Free FxRequest* 862D22A8 memory
> 63181: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63182: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x862A08B8
> 63183: FxDevice::AllocateRequestMemory - Allocating FxRequest* 862D22A8,
> WDFREQUEST 79D2DD50
> 63184: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79D2DD50 on WDFQUEUE
> 0x79E3F2F0
> 63185: FxIoQueue::DispatchEvents - Thread 856E2020 is processing WDFQUEUE
> 0x79E3F2F0
> 63186: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79D2DD50
> 63187: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63188: imp_WdfRequestRetrieveOutputBuffer - Enter: WDFREQUEST 0x79D2DD50
> 63189: imp_WdfRequestMarkCancelable - Enter: WDFREQUEST 0x79D2DD50
> 63190: FxIoQueue::DispatchRequestToDriver - WDFREQUEST 0x79D2DD50
> dispatched
> to driver
> 63191: FxPkgIo::Dispatch - WDFDEVICE 0x79E3BA10 !devobj 0x861C4240
> 0x0000000e(IRP_MJ_DEVICE_CONTROL), IRP_MN 0, IRP 0x85689148
> 63192: FxDevice::AllocateRequestMemory - Allocating FxRequest* 863D4BA0,
> WDFREQUEST 79C2B458
> 63193: FxIoQueue::QueueRequest - Queuing WDFREQUEST 0x79C2B458 on WDFQUEUE
> 0x79E3F2F0
> 63194: FxIoQueue::DispatchEvents - Thread 85680020 is processing WDFQUEUE
> 0x79E3F2F0
> 63195: FxIoQueue::DispatchEvents - No requests on WDFQUEUE 0x79E3F2F0
> 63196: FxIoQueue::DispatchRequestToDriver - Calling driver
> EvtIoDeviceControl for WDFREQUEST 0x79C2B458
> 63197: imp_WdfRequestRetrieveInputBuffer - Enter: WDFREQUEST 0x79C2B458
> 63198: FxCallbackSpinLock::Lock - Recursive Acquire of callback lock!
> 0x861C463C
> ---- end of log ----
>
>
>
>
>
>
>
>
>
>
>
>
> "Doron Holan [MSFT]" wrote:
>
>> first, fix your symbols so you have a legible call stack.
>> second, send the output !analyze -v so we can see all of the bugcheck
>> parameters and analysis
>> third, run !wdfkd.wdflogdump <your driver>, it will give you more
>> information
>>
>> d
>>
>> --
>> Please do not send e-mail directly to this alias. this alias is for
>> newsgroup purposes only.
>> This posting is provided "AS IS" with no warranties, and confers no
>> rights.
>>
>>
>>
>
>
>

 | 
Pages: 1
Prev: regarding the smart card reader driver not getting any IOCTL calls.
Next: Vista QOS testing