Google Groups no longer supports new Usenet posts or subscriptions. Historical content remains viewable.
Dismiss

KMDF DPC Synchronization

68 views
Skip to first unread message

Daniel Knueven

unread,
Sep 9, 2008, 8:28:00 PM9/9/08
to
I am using the latest WDK on XP SP2. When my device initializes, it create a
main device and 7 other control devices with option
WdfSynchronizationScopeDevice set. I have a set of read/write buffers for
each control device. When an ISR goes off, I schedule a DPC. The DPC can put
stuff in/out of the read/write buffers. When a read/write request comes in
for the control devices, they also put stuff in/out of the buffers.

Will KMDF make sure no read/write call for any device in my driver is
running before it will allow the DPC to run? Right now I am using a spin
lock, but now that I think about it, that might be a bad idea right? If a
read operation has the spin lock when the DPC runs, that might cause dead
lock? Am I better off raising my IRQL to DPC level when accessing the buffers
from read/write event calls?

Thanks,
-Daniel

Kalle Olavi Niemitalo

unread,
Sep 10, 2008, 2:29:36 AM9/10/08
to
Daniel Knueven <Daniel...@discussions.microsoft.com> writes:

> Will KMDF make sure no read/write call for any device in my driver is
> running before it will allow the DPC to run?

I don't know about that.

> Right now I am using a spin lock, but now that I think about
> it, that might be a bad idea right? If a read operation has the
> spin lock when the DPC runs, that might cause dead lock?

KeAcquireSpinLock and WdfSpinLockAcquire raise IRQL to
DISPATCH_LEVEL, so your DPC cannot start on that processor until
you release the spin lock. If the DPC starts on another
processor, then it should wait without a deadlock.

> Am I better off raising my IRQL to DPC level when accessing the buffers
> from read/write event calls?

Raising IRQL to DISPATCH_LEVEL on one processor does not raise it
on other processors. So it does not prevent the DPC and the
read/write event code from running at the same time on different
processors. The spin lock sure seems safer here.

Alternatively, you might be able to implement your buffer
manipulation with interlocked operations and allow the DPC and
the read/write event code to access the buffers at the same time.

Pavel A.

unread,
Sep 10, 2008, 4:24:51 AM9/10/08
to
If you consider your buffers as a resource,
protecting it with a spinlock is ok.
Just raising to dispatch is not very heplful, because
this won't prevent other CPUs to touch the resource.
Yes, spinlocks can cause deadlock, so design the code
paths carefully. It takes some time to get used to it.

--PA

Daniel Knueven

unread,
Sep 10, 2008, 3:04:25 PM9/10/08
to
Thanks for the info. So if using a spin lock is a good thing for this, I
think I might have misunderstanding of what a spinlock can do.

Ok, so my DPC is executing and it claims the buffer spinlock. It sees a
pending read and can now copy data into the read request buffer and complete
the read request. As soon as it completes the read request and before the DPC
completes, I get a read event call. To make things worse, that read call
tries to claim the same spin lock and it actually gets it! Then the read call
says, no data, save the request for later, releases the spin lock and return.
The DPC continues executing and tries to free the spin lock and KMDF throws
an exception saying the spin lock is being released by a different thread
than what acquired it.

How can a read event interrupt a DPC? How can a spin lock be claimed twice
from different threads?

Thanks,
-Daniel

Doron Holan [MSFT]

unread,
Sep 10, 2008, 4:48:54 PM9/10/08
to
you have a bug if you think that the read path is able to acquire an already
held spinlock. are you sure you are using the same spinlcok in the dpc and
read routine? also, remember that with device level sync, that is only
scoped to a particular device instnace, not across many of them.

btw, why are you creating 7 control devices?

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.


"Daniel Knueven" <Daniel...@discussions.microsoft.com> wrote in message
news:5C84E84B-E97C-42F8...@microsoft.com...

Daniel Knueven

unread,
Sep 10, 2008, 6:49:00 PM9/10/08
to
When I'm in my DPC, I eventually complete a read request using
WdfRequestCompleteWithPriorityBoost. I think that call is then immediately
dequeuing the next request and calling my event function in the context of
the DPC before it returns to the DPC. And that's fine. It's on the same
thread which explains why the spinlock is allowing it to be claimed twice
without blocking. The thing that puzzles me is when the DPC tries to release
the spinlock for the second time, the framework throws an exception saying
I'm trying to release it from a different thread. So, the question is, can a
spinlock be acquired twice in the same thread, then released twice from that
thread? Or is that a big no-no?

Each control device represents a serial port. It's not a windows standard
serial port. The main device is used for DMA. I've got 2 DMA channels to feed
all 7 ports and the DMA scatter gather list has to be in FPGA memory and is
fixed, two descriptors for each port (read/write). If I had more time to play
with plug and play and device enumeration, I would. For now, I just wanted 7
sequential IO queues so each port can independently read/write.

Thanks,
-Daniel

David Craig

unread,
Sep 11, 2008, 12:33:00 AM9/11/08
to
You will need to post some code and maybe some pointers showing major
pointers for structures and data. You have some error(s) in your
understanding of Windows kernel mode drivers.

1. A spinlock will 'spin' until the spinlock is released.
2. ANY thread can release a spinlock.
3. The thread running will not change what a spinlock call does. It is not
a mutex.

I gather from your post that you have 7 serial ports. You also have two DMA
channels for transferring data to or from the selected port. You don't say
but can we assume you have one register set where the programming of the
chip/ASIC can be done? If so, you need a spinlock (global) that each device
must grab to program their information into the chip. You also need a way
to count from zero to two to indicate the status of the DMA channels. When
zero, both are available and when 2 both are in use. The count may also
need a spinlock to protect it, though interlocked increment/decrement could
work too. Serial port designs, depending upon buffer sizes may require a
read always be queued for active ports, though how you can do more than one
is hard to understand. If you have very large, several KB at least, buffers
on the chip that can hold serial data.


"Daniel Knueven" <Daniel...@discussions.microsoft.com> wrote in message

news:2580C64E-3D2A-4A26...@microsoft.com...

Daniel Knueven

unread,
Sep 11, 2008, 1:22:04 PM9/11/08
to
I confirmed my problem is a multiple claiming of a single spin lock. I added
some test code to the initialization of my driver that acquired a spin lock
twice and the released it twice. On the second release the framework throws
an exception saying I’ve tried to release the spin lock from a thread where
it wasn’t acquired. I think it’s not keeping track of the fact I’ve claimed
it twice on the same thread.

Is there is way to check if my thread has already claimed the spin lock?

My driver is interfacing to a PLx9056. I’ve been working from the example in
the WDK that specifically talks to that chip. I’ve dedicated one DMA channel
to read and one to write. The DMA goes on in the background independent of
the serial port IO stuff. When something comes in the DMA channel, I have to
move it to one of the serial buffers. This is where the spin lock comes into
play. The spin lock ensures my DMA DPC doesn’t access the serial buffers at
the same time as a serial port IO request.

My spin lock is being claimed by the DPC then processing the DMA data. As a
result, the DPC needs to complete an IO request. When it does, the
WdfRequestComplete call dequeues the next IO request and immediately calls
the event handler for that queue in the context of the DPC. The IO request
event handler acquires the spin lock since it’s currently on the same thread
as the DPC. When the read event is done, it releases the spin lock and
returns. The DPC continues and eventually releases the spin lock. When the
DPC tries to release the spin lock, the frame work throws an exception saying
I’ve tried to release a spin lock from a different thread then where it was
claimed. So, I need a way to avoid claiming the same spin lock more than once.

See my next post for the driver log and crash dump analysis.

Thanks,
-Daniel

Daniel Knueven

unread,
Sep 11, 2008, 1:24:11 PM9/11/08
to
Here we have the driver initialization

---> Info Init DriverEntry
Info Init CLUB WDF Driver
Info Init Built Sep 11 2008 12:49:39
Info Init Creating WDF driver object
<--- Info Init DriverEntry, status: 00000000
---> Info Init PLxEvtDeviceAdd
Info Init Creating main WDF device
Info Init AddDevice PDO (0x8A1FEC88) FDO (0x8A02A020), DevExt
(0x8A1A1E58)
---> Info Pnp PLxInitializeDeviceExtension
Info Pnp Create IOCTL WDF IO queue
Info Pnp Create DMA Channel spin locks
Info Pnp Create DMA statistics spin lock
---> Info Pnp PLxInterruptCreate
<--- Info Pnp PLxInterruptCreate
<--- Info Pnp PLxInitializeDeviceExtension

This next part creates a serial ports
I've removed the 6 other occurances to save space

---> Info Init CreateSerialPort
Info Init Creating serial port 0 WDF device
Info Init Assigning NT name: \Device\CLUBCOM00
Info Init Creating device
Info Init Creating symbolic link: \Device\CLUBCOM00 ->
\DosDevices\CLUBCOM00
---> Info Init PLxCreateSerialPortAllocBuffers
Info Init Allocating read buffer
Info Init Requested buffer size: 4096
Info Init Adjusted buffer size: 4096
Info Init Allocating write buffer
Info Init Requested buffer size: 4096
Info Init Adjusted buffer size: 4096
<--- Info Init PLxCreateSerialPortAllocBuffers, status: 00000000

Here we get our hardware resources, setup and start DMA

<--- Info Init PLxEvtDeviceAdd, status: 00000000
---> Info Init PLxEvtDevicePrepareHardware
---> Info Pnp PLxDevicePrepareHardware
Info Pnp Enumerating hardware
Info Pnp Memory Resource [FE1FFC00-FE1FFE00] BAR0
Info Pnp Port Resource [0000DC00-0000DD00] BAR1
Info Pnp Memory Resource [FE1C0000-FE1E0000] BAR2
Info Pnp Memory Resource [FE1A0000-FE1C0000] BAR3
Info Pnp IO mapping hardware
Info Pnp Registers F7AA7C00, length 512
Info Pnp SRAM B6BF5000, length 131072
<--- Info Pnp PLxDevicePrepareHardware, status 00000000
---> Info DMA PLxDMAInit
---> Info DMA PLxDMAInitChannel
Info DMA Setting up DMA mode register for channel 0
F7AA7C80=00130743
<--- Info DMA PLxDMAInitChannel
---> Info DMA PLxDMAInitChannel
Info DMA Setting up DMA mode register for channel 1
F7AA7C94=00130743
<--- Info DMA PLxDMAInitChannel
---> Info DMA PLxDMASetupDescriptorsLocalBusRead
Info DMA Allocated descriptor 0 contiguous memory at virtual
address: F7AA8000, physical: 00001000, size: 256
Info DMA Allocated descriptor 1 contiguous memory at virtual
address: F7A8C000, physical: 00002000, size: 256
Info DMA Allocated descriptor 2 contiguous memory at virtual
address: B7A4C000, physical: 00005000, size: 40960
Info DMA Allocated descriptor 3 contiguous memory at virtual
address: F7AA9000, physical: 00003000, size: 512
Info DMA Allocated descriptor 4 contiguous memory at virtual
address: F7AA5000, physical: 0000F000, size: 512
Info DMA Allocated descriptor 5 contiguous memory at virtual
address: F7A88000, physical: 00010000, size: 512
Info DMA Allocated descriptor 6 contiguous memory at virtual
address: F7AAA000, physical: 00011000, size: 512
Info DMA Descriptor 0 (B6BFD000) setup: SIZ: 00000000, PAR:
00003000, LAR: 0000C400, DPR: 00008018
Info DMA Descriptor 1 (B6BFD010) setup: SIZ: 00000000, PAR:
0000F000, LAR: 0000C800, DPR: 00008028
Info DMA Descriptor 2 (B6BFD020) setup: SIZ: 00000000, PAR:
00010000, LAR: 0000CC00, DPR: 00008038
Info DMA Descriptor 3 (B6BFD030) setup: SIZ: 00000000, PAR:
00011000, LAR: 0000D000, DPR: 00008048
Info DMA Descriptor 4 (B6BFD040) setup: SIZ: 00000000, PAR:
00002000, LAR: 0000D400, DPR: 00008058
Info DMA Descriptor 5 (B6BFD050) setup: SIZ: 00000000, PAR:
00001000, LAR: 0000D800, DPR: 00008068
Info DMA Descriptor 6 (B6BFD060) setup: SIZ: 00000000, PAR:
00005000, LAR: 00010000, DPR: 0000000A
<--- Info DMA PLxDMASetupDescriptorsLocalBusRead, status: 00000000
---> Info DMA PLxDMASetupDescriptorsPCIWrite
Info DMA Allocated DMA write descriptor memory align: 0, V
addr: F7AB3000, P addr: 00012000, size: 128
Info DMA Allocated DMA page memory: V addr: F7A8B000, P addr:
00013000, size: 256
Info DMA Allocated DMA page memory: V addr: F7AB4000, P addr:
00014000, size: 256
Info DMA Allocated DMA page memory: V addr: B7924000, P addr:
00085000, size: 40960
Info DMA Allocated DMA page memory: V addr: F7A8D000, P addr:
00015000, size: 512
Info DMA Allocated DMA page memory: V addr: F7AB0000, P addr:
00016000, size: 512
Info DMA Allocated DMA page memory: V addr: F7A83000, P addr:
00017000, size: 512
Info DMA Allocated DMA page memory: V addr: F7AAC000, P addr:
00018000, size: 512
Info DMA Descriptor 0 setup: SIZ: 00000000, PAR: 00015000,
LAR: 0000C400, DPR: 00012011
Info DMA Descriptor 1 setup: SIZ: 00000000, PAR: 00016000,
LAR: 0000C800, DPR: 00012021
Info DMA Descriptor 2 setup: SIZ: 00000000, PAR: 00017000,
LAR: 0000CC00, DPR: 00012031
Info DMA Descriptor 3 setup: SIZ: 00000000, PAR: 00018000,
LAR: 0000D000, DPR: 00012041
Info DMA Descriptor 4 setup: SIZ: 00000000, PAR: 00014000,
LAR: 0000D400, DPR: 00012051
Info DMA Descriptor 5 setup: SIZ: 00000000, PAR: 00013000,
LAR: 0000D800, DPR: 00012061
Info DMA Descriptor 6 setup: SIZ: 00000000, PAR: 00085000,
LAR: 00010000, DPR: 00000003
<--- Info DMA PLxDMASetupDescriptorsPCIWrite
<--- Info DMA PLxDMAInit
<--- Info Init PLxEvtDevicePrepareHardware, status: 00000000
---> Info Power PLxEvtDeviceD0Entry
<--- Info Power PLxEvtDeviceD0Entry
---> Info Interupt PLxEvtInterruptEnable
Info Interupt PLxEvtInterruptEnable: Interrupt 0x763C1FB0, Device
0x75E5E368
Info Interupt Starting read channel DMA
Info Interupt Setting DMA channel first descriptor pointer
F7AA7C90=00008008
Info Interupt Enabled and starting read DMA CSR F7AA7CA8=03
Info Interupt Starting write channel DMA
Info Interupt Setting DMA channel first descriptor pointer
F7AA7CA4=00012001
Info Interupt Enabled and starting write DMA CSR F7AA7CA9=03
Info Interupt INTCSR=0F0D0180
Info Interupt Reseting/enabling FPGA DMA
<--- Info Interupt PLxEvtInterruptEnable

Here we get the first IO read request
no DMA data yet so we save the request for later

---> Info Read PLxEvtIoRead: Request 75E60BE0, IRQL level: 2,
Thread: 8A0507F0
Info Read Acquire port read spinlock: 7601D748
Info Read Got read buffer: BA0F7AE4, size: 1023
Info Read Buffer empty, waiting for data
Info Read Release port read spinlock: 7601D748
<--- Info Read PLxEvtIoRead, status: 00000000

Since I'm working with the demo board,
I have to kick the DMA off by hand through
writing some memory on the card
I'm putting a string in memory to be DMAed
Then triggering the DMA descriptors to cause the DMA to fire
I've removed most of this to reduce the size of the post

---> Info IOCTL PLxEvtIoCtl
Info IOCTL Got input memory buffer: 89C51840, size: 22
Info IOCTL IOCTL Code = Write memory 32bit
---> Info IOCTL PLxIoCtlCLUBMemoryWrite32
Info IOCTL Wrote memory 00010000-0001000E
<--- Info IOCTL PLxIoCtlCLUBMemoryWrite32, status: 00000000
Info IOCTL Completing IOCTL, status: 00000000, size: 22
<--- Info IOCTL PLxEvtIoCtl

.. Lots more IOCTL stuff

---> Info IOCTL PLxEvtIoCtl
Info IOCTL Got input memory buffer: 8A1B2840, size: 8
Info IOCTL IOCTL Code = Write register 32bit
---> Info IOCTL PLxIoCtlCLUBRegisterWrite32
Info IOCTL Wrote register: 00008000=80000000
<--- Info IOCTL PLxIoCtlCLUBRegisterWrite32, status: 00000000
Info IOCTL Completing IOCTL, status: 00000000, size: 4
<--- Info IOCTL PLxEvtIoCtl

As soon as the last register is written the DMA kicks off
and the DMA complete interupt fires
I check the DMA interupt complete bits and see it's for me
I queue a DPC to process the DMA data

---> Info Interupt PLxEvtInterruptIsr, msg id: 0
Info Interupt Interrupt for DMA Channel 0
Info Interupt Queuing DPC call
<--- Info Interupt PLxEvtInterruptIsr, handled: Yes

The first time arround the DPC finished before the read event
function is called, so all is well

---> Info DPC EvtInterruptDpc, IRQL: 2, Thread: 8A1C9A28
Info DPC Acquire statistics spinlock: 75E4F8D8
Info DPC Acquire interupt lock: 763C1FB0
Info DPC Entering DPC sycned section
Info DPC Read DMA channel finished
Info DPC Acquire read DMA channel spinlock: 7601D748
Info DPC Read page (0) size: 0
Info DPC Read page (1) size: 0
Info DPC Read page (2) size: 10
---> Info DPC PLxProcessReadPage
---> Info Read PLxIoRead: Request 75E60BE0, size: 10
Info Read Got read buffer: 1023
Info Read Copied 10 bytes out of buffer
Info Read IO completed, size: 10
<--- Info Read PLxIoRead
Info DPC All DMA data went to pending read request
<--- Info DPC PLxProcessReadPage
Info DPC Read page (3) size: 0
Info DPC Read page (4) size: 0
Info DPC Read page (5) size: 0
Info DPC Read page (6) size: 0
Info DPC Release read DMA channel spinlock: 7601D748
Info DPC Setting DMA read channel first descriptor pointer
F7AA7C90=00008008
Info DPC Enabled and starting read DMA CSR F7AA7CA8=03
Info DPC Leaving DPC sycned section
Info DPC Release interupt lock: 763C1FB0
Info DPC Release statistics spinlock: 75E4F8D8
<--- Info DPC EvtInterruptDpc

Here is the next read request, notice it's AFTER the DPC is done

---> Info Read PLxEvtIoRead: Request 75E60BE0, IRQL level: 2,
Thread: 8A0507F0
Info Read Acquire port read spinlock: 7601D748
Info Read Got read buffer: F7A9FAE4, size: 1023
Info Read Buffer empty, waiting for data
Info Read Release port read spinlock: 7601D748
<--- Info Read PLxEvtIoRead, status: 00000000

I kick off another DMA by hand

---> Info IOCTL PLxEvtIoCtl
Info IOCTL Got input memory buffer: 8A1B2840, size: 8
Info IOCTL IOCTL Code = Write register 32bit
---> Info IOCTL PLxIoCtlCLUBRegisterWrite32
Info IOCTL Wrote register: 00008060=0000000E
<--- Info IOCTL PLxIoCtlCLUBRegisterWrite32, status: 00000000
Info IOCTL Completing IOCTL, status: 00000000, size: 4
<--- Info IOCTL PLxEvtIoCtl

More removed IOCTL calls...

---> Info IOCTL PLxEvtIoCtl
Info IOCTL Got input memory buffer: 8A1B2840, size: 8
Info IOCTL IOCTL Code = Write register 32bit
---> Info IOCTL PLxIoCtlCLUBRegisterWrite32
Info IOCTL Wrote register: 00008000=80000000
<--- Info IOCTL PLxIoCtlCLUBRegisterWrite32, status: 00000000
Info IOCTL Completing IOCTL, status: 00000000, size: 4
<--- Info IOCTL PLxEvtIoCtl

Here's our interupt, queue the DPC

---> Info Interupt PLxEvtInterruptIsr, msg id: 0
Info Interupt Interrupt for DMA Channel 0
Info Interupt Queuing DPC call
<--- Info Interupt PLxEvtInterruptIsr, handled: Yes

Here's the DPC and where the trouble starts

---> Info DPC EvtInterruptDpc, IRQL: 2, Thread: 8A1C9A28 ***
Info DPC Acquire statistics spinlock: 75E4F8D8
Info DPC Acquire interupt lock: 763C1FB0
Info DPC Entering DPC sycned section
Info DPC Read DMA channel finished

Here is the spin lock being claimed by the DPC

Info DPC Acquire read DMA channel spinlock: 7601D748 ###
Info DPC Read page (0) size: 0
Info DPC Read page (1) size: 0
Info DPC Read page (2) size: 10
---> Info DPC PLxProcessReadPage
---> Info Read PLxIoRead: Request 75E60BE0, size: 10
Info Read Got read buffer: 1023
Info Read Copied 10 bytes out of buffer
Info Read IO completed, size: 10

Instead of the DPC finishing this time, the WdfRequestComplete
seems to call the read event function in the context of the DPC
Notice the thread is the same as the DPC thread, see the ***

---> Info Read PLxEvtIoRead: Request 75F375B0, IRQL level: 2,
Thread: 8A1C9A28 ***

Here is the spin lock being claimed by the read event function

Info Read Acquire port read spinlock: 7601D748 ###
Info Read Got read buffer: F7AABAE4, size: 1023
Info Read Buffer empty, waiting for data

Here is the spin lock being released by the read event function

Info Read Release port read spinlock: 7601D748 ###
<--- Info Read PLxEvtIoRead, status: 00000000
<--- Info Read PLxIoRead
Info DPC All DMA data went to pending read request
<--- Info DPC PLxProcessReadPage
Info DPC Read page (3) size: 0
Info DPC Read page (4) size: 0
Info DPC Read page (5) size: 0
Info DPC Read page (6) size: 0

Here is the spin lock being released by the DPC

Info DPC Release read DMA channel spinlock: 7601D748 ###

And here is the crash dump

*** Fatal System Error: 0x0000010d
(0x0000000B,0x7601D748,0x00000001,0x8A1000E0)

Break instruction exception - code 80000003 (first chance)

A fatal system error has occurred.
Debugger entered on first try; Bugcheck callbacks have not been invoked.

A fatal system error has occurred.

Connected to Windows XP 2600 x86 compatible target, ptr64 FALSE
Loading Kernel Symbols
.....................................................................................................
Loading User Symbols
....................
Loading unloaded module list
.....
*******************************************************************************
*
*
* Bugcheck Analysis
*
*
*
*******************************************************************************

Use !analyze -v to get detailed debugging information.

BugCheck 10D, {b, 7601d748, 1, 8a1000e0}

*** ERROR: Module load completed but symbols could not be loaded for
wdf01000.sys

Probably caused by : CLUB.sys ( CLUB!WdfSpinLockRelease+16 )

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

nt!RtlpBreakWithStatusInstruction:
804e3b25 cc int 3
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: 0000000b, An attempt to acquire or release a lock was invalid. In this
case, Parameter 3 further specifies the error that has been
made.
Arg2: 7601d748, A WDF spinlock handle.
Arg3: 00000001, The spin lock is being released by a thread which did not
acquire it.
Arg4: 8a1000e0, Reserved.

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

BUGCHECK_STR: 0x10D_b

DEFAULT_BUCKET_ID: DRIVER_FAULT

PROCESS_NAME: CLUBSerialTerm.

LAST_CONTROL_TRANSFER: from 805328e7 to 804e3b25

STACK_TEXT:
f78a2a74 805328e7 00000003 f78a2dd0 00000000 nt!RtlpBreakWithStatusInstruction
f78a2ac0 805333be 00000003 89fe28b0 7601d748 nt!KiBugCheckDebugBreak+0x19
f78a2ea0 805339ae 0000010d 0000000b 7601d748 nt!KeBugCheck2+0x574
f78a2ec0 b6c3f70c 0000010d 0000000b 7601d748 nt!KeBugCheckEx+0x1b
WARNING: Stack unwind information not available. Following frames may be
wrong.
f78a2edc b6c7aa4b 8a1000e0 0000000b 7601d748 wdf01000+0x2a70c
f78a2f08 b6c70ff4 00000000 f78a2f24 b7da2076 wdf01000+0x65a4b
f78a2f14 b7da2076 89fe28b0 7601d748 f78a2fa4 wdf01000+0x5bff4
f78a2f24 b7da0e99 7601d748 89c3e048 00000000 CLUB!WdfSpinLockRelease+0x16
[c:\winddk\6001.18001\inc\wdf\kmdf\1.7\wdfsync.h @ 276]
f78a2fa4 b6c687e0 763c1fb0 75e5e368 806ee737 CLUB!PLxEvtInterruptDpc+0x379
[y:\dknueven_hunt1\source\common\clubdriver\sys\isrdpc.c @ 220]
f78a2fc0 b6c6885b 89c3e048 00000000 ffdff980 wdf01000+0x537e0
f78a2fd0 804dc179 89c3e094 89c3e048 89c3e048 wdf01000+0x5385b
f78a2ff4 804dbe2d b7973acc 00000000 00000000 nt!KiRetireDpcList+0x46
f78a2ff8 b7973acc 00000000 00000000 00000000 nt!KiDispatchInterrupt+0x2a
804dbe2d 00000000 00000009 bb835675 00000128 0xb7973acc


STACK_COMMAND: kb

FOLLOWUP_IP:
CLUB!WdfSpinLockRelease+16 [c:\winddk\6001.18001\inc\wdf\kmdf\1.7\wdfsync.h
@ 276]
b7da2076 5d pop ebp

FAULTING_SOURCE_CODE:
272: WDFSPINLOCK SpinLock
273: )
274: {
275: ((PFN_WDFSPINLOCKRELEASE)
WdfFunctions[WdfSpinLockReleaseTableIndex])(WdfDriverGlobals, SpinLock);
> 276: }
277:
278:
279:
280: #endif // (NTDDI_VERSION >= NTDDI_WIN2K)
281:


SYMBOL_STACK_INDEX: 7

SYMBOL_NAME: CLUB!WdfSpinLockRelease+16

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: CLUB

IMAGE_NAME: CLUB.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 48c94c26

FAILURE_BUCKET_ID: 0x10D_b_CLUB!WdfSpinLockRelease+16

BUCKET_ID: 0x10D_b_CLUB!WdfSpinLockRelease+16

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

Pavel A.

unread,
Sep 11, 2008, 1:37:37 PM9/11/08
to
Daniel Knueven wrote:
> I confirmed my problem is a multiple claiming of a single spin lock. I added
> some test code to the initialization of my driver that acquired a spin lock
> twice and the released it twice. On the second release the framework throws
> an exception saying I’ve tried to release the spin lock from a thread where
> it wasn’t acquired.

So you debug on UP machine. A MP machine
would deadlock at the moment of second acquire of the spinlock.

> Is there is way to check if my thread has already claimed the spin lock?

Yes, KeTryToAcquireSpinLockAtDpcLevel().
But what really helps is static analysis of code paths.
Spinlocks are not meant to be "opportunistic locks".

--PA

Daniel Knueven

unread,
Sep 11, 2008, 3:29:00 PM9/11/08
to
So, you are saying the following code SHOULD cause a bug check?

WdfSpinLockAcquire(...);
WdfSpinLockAcquire(...);
WdfSpinLockRelease(...);
WdfSpinLockRelease(...);

If so, is there a locking mechanism that can handle this?

Thanks,
-Daniel

Pavel A.

unread,
Sep 11, 2008, 4:56:59 PM9/11/08
to
Daniel Knueven wrote:
> So, you are saying the following code SHOULD cause a bug check?
>
> WdfSpinLockAcquire(...);
> WdfSpinLockAcquire(...);
> WdfSpinLockRelease(...);
> WdfSpinLockRelease(...);

Deadlock. The driver verifier may bugcheck instead, if it detects this.

> If so, is there a locking mechanism that can handle this?

Wait locks. But better try not to acquire locks recursively.

--PA

Doron Holan [MSFT]

unread,
Sep 11, 2008, 5:17:46 PM9/11/08
to
a spinlock cannot be acquired recursively on the same thread. a KMDF
WDFSPINLOCK enforces that the same thread that acquired a spinlock releases
it. there are 2 error messages in the release path

"WDFSPINLOCK %p being released by thread 0x%p, but was
never acquired!"
and
"WDFSPINLOCK 0x%p not owned by thread 0x%p, owned by
thread 0x%p"

which one are you seeing?


--
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.


"Pavel A." <pav...@NOfastmailNO.fm> wrote in message
news:eRzeMEFF...@TK2MSFTNGP02.phx.gbl...

Daniel Knueven

unread,
Sep 11, 2008, 5:21:01 PM9/11/08
to
So, you have to garuntee that no spin lock ever gets double acquired even by
the same thread. Man, we aren't in Win32 land anymore! :)

Thanks,
-Daniel

Daniel Knueven

unread,
Sep 11, 2008, 5:24:12 PM9/11/08
to
Is there a reason the same thread can acquire a spin lock twice?

I made a seperate post in this thread with the driver output and crash dump
info. Second from the bottom. Here is the WDF crash info:

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: 0000000b, An attempt to acquire or release a lock was invalid. In this
case, Parameter 3 further specifies the error that has been
made.
Arg2: 7601d748, A WDF spinlock handle.
Arg3: 00000001, The spin lock is being released by a thread which did not
acquire it.
Arg4: 8a1000e0, Reserved.

Doron Holan [MSFT]

unread,
Sep 12, 2008, 1:40:52 PM9/12/08
to
well, this is pretty clear. you acquired the lock on thread A and then
released it on thread B. this can easil lead to a leaking of IRQL on thread
A (since it most likely raised irql to dispatch to acquire the lock). it is
a pretty poor design to leave a lock held and return and have another thread
release it later, i would strongly suggest you change this design

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.

"Daniel Knueven" <Daniel...@discussions.microsoft.com> wrote in message

news:A32F79CD-DCFF-4AD3...@microsoft.com...

Daniel Knueven

unread,
Sep 12, 2008, 2:21:02 PM9/12/08
to
It's getting claimed twice on thread A. It's then being released twice on
thread A. On the second release, that is where the exception is being thrown
by the framework. The error message being generated is missleading. Try doing
this right after you create a spinlock:

WdfSpinlockAcquire(...);
WdfSpinlockAcquire(...);
WdfSpinlockRelease(...);
WdfSpinlockRelease(...);

I put this in my init code right after creating the spin lock and I got the
same error about releasing the spinlock from the wrong thread.

Thanks,
-Daniel

Kalle Olavi Niemitalo

unread,
Sep 12, 2008, 4:14:39 PM9/12/08
to
Daniel Knueven <Daniel...@discussions.microsoft.com> writes:

> My spin lock is being claimed by the DPC then processing the DMA data. As a
> result, the DPC needs to complete an IO request. When it does, the
> WdfRequestComplete call dequeues the next IO request and immediately calls
> the event handler for that queue in the context of the DPC. The IO request
> event handler acquires the spin lock since it’s currently on the same thread
> as the DPC.

In WDM, one is not supposed to call IoCompleteRequest while
holding a spin lock. I wonder if the same applies to
WdfRequestComplete in KMDF. Certainly I would attempt to change
the DPC to release the lock before it completes the request.

Daniel Knueven

unread,
Sep 12, 2008, 4:35:01 PM9/12/08
to
That's good to know. Is there a list of rules like this some where?

I've updated my code so the complete happens outside the spinlock.

Thanks,
-Daniel

Doron Holan [MSFT]

unread,
Sep 12, 2008, 5:15:11 PM9/12/08
to
just like wdm, you are not supposed to complete a request while holding your
own spinlock. doing so can lead you to deadlock if the receiver of the irp
you just completed sends another irp to you in the same context and you try
to acquire the same lock you are still holding

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.


"Kalle Olavi Niemitalo" <k...@iki.fi> wrote in message
news:87r67pu...@Astalo.kon.iki.fi...

Doron Holan [MSFT]

unread,
Sep 12, 2008, 5:14:02 PM9/12/08
to
acquiring a spinlock on a UP machine is purely a raise in IRQL, nothing
more. this means that a double acquire will succeed accidentally. you
cannot recursively acquire a spinlock on the same thread. on an MP machine
you would have never gotten past the second acquire on the same thread.

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.


"Daniel Knueven" <Daniel...@discussions.microsoft.com> wrote in message

news:2ABD896E-85C1-4EA9...@microsoft.com...

David Craig

unread,
Sep 12, 2008, 5:33:05 PM9/12/08
to
Under IoCompleteRequest which is the only method of completing a request
says:
Never call IoCompleteRequest while holding a spin lock. Attempting to
complete an IRP while holding a spin lock can cause deadlocks.

KMDF is a wrapper around much of the standard NT Kernel routines, but it has
to use those routines to interface with the OS. You could read Walter
Oney's book or the NT4 device driver book from OSR which will provide an
uderstanding of the NT Kernel environment. The second book was written
before PnP and power logic was introduced and the first book has references
to the 9x implementation of WDM which was far more restrictive than with
2000 and later versions.

Also use the checked kernel and driver verifier to ensure you are not
violating the rules. Prefast also will catch some errors.

"Daniel Knueven" <Daniel...@discussions.microsoft.com> wrote in message

news:2186A6CD-02DF-43C0...@microsoft.com...

Pavel A.

unread,
Sep 12, 2008, 5:50:58 PM9/12/08
to
"Doron Holan [MSFT]" <dor...@online.microsoft.com> wrote in message
news:OPy77xRF...@TK2MSFTNGP03.phx.gbl...

> acquiring a spinlock on a UP machine is purely a raise in IRQL, nothing
> more. this means that a double acquire will succeed accidentally. you
> cannot recursively acquire a spinlock on the same thread. on an MP
> machine you would have never gotten past the second acquire on the same
> thread.


So, I've asked Daniel if the has a UP machine....

Checking in WdfSpinlockRelease that the thread is same as acquired the lock,
is a simple but effective sanity check.
Since WdfSpinlockAcquire raises to DISPATCH, the CPU can't do any thread
switches until the lock is released, so the thread id must stay same.
Otherwise he may be releasing the lock twice, or a wrong lock, etc.

--PA

Kalle Olavi Niemitalo

unread,
Sep 12, 2008, 5:56:42 PM9/12/08
to
Daniel Knueven <Daniel...@discussions.microsoft.com> writes:

> That's good to know. Is there a list of rules like this some where?

I don't know about a list. That particular rule is mentioned on
the IoCompleteRequest reference page.

http://msdn.microsoft.com/en-us/library/aa490590.aspx

However there is no similar rule on the WdfRequestComplete page
and I didn't find one in "Completing I/O Requests" or
"Using Framework Locks" either.

http://msdn.microsoft.com/en-us/library/aa492074.aspx
http://msdn.microsoft.com/en-us/library/aa490080.aspx
http://msdn.microsoft.com/en-us/library/aa490057.aspx

I can imagine WdfSpinLockAcquire incrementing a per-processor
counter, WdfRequestComplete putting requests on a list when the
counter is nonzero, and WdfSpinLockRelease finally calling
IoCompleteRequest when the counter becomes zero. But that would
be complex and not work if the driver uses WDM spin lock
functions directly, so I guess KMDF isn't implemented like that.

Pavel A.

unread,
Sep 12, 2008, 7:07:10 PM9/12/08
to
They could simply say in the WDF book that KMDF is just a
wrapper around same basic NT kernel objects, so
all you knew about WDM still applies.
But doing so would require from the readers to learn WDM first,
and the only available WDM book was Walter Oney's. So perhaps it's better to
tell nothing.

And... perhaps WDM is not just a wrapper or another toolkit.
Rather, it's the emerging DDI of new Windows version that
will have completely different layer below it, and different unwritten
rules? Go figure.

--PA


"Kalle Olavi Niemitalo" <k...@iki.fi> wrote in message

news:87ej3pu...@Astalo.kon.iki.fi...

Pavel A.

unread,
Sep 14, 2008, 4:38:42 AM9/14/08
to
Correction... this should be WDF , not WDM

Pavel A. wrote:
> They could simply say in the WDF book that KMDF is just a
> wrapper around same basic NT kernel objects, so
> all you knew about WDM still applies.
> But doing so would require from the readers to learn WDM first,
> and the only available WDM book was Walter Oney's. So perhaps it's
> better to tell nothing.
>

> And... perhaps WDF is not just a wrapper or another toolkit.

Doron Holan [MSFT]

unread,
Sep 15, 2008, 2:27:15 PM9/15/08
to
KMDF does not do the IRQL raise, it will call KeAcquireSpinLock which will
do the IRQL raise.... but your point about checking for thread ownership on
acquire is a good one . i will suggest it to the team

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.


"Pavel A." <pav...@12fastmail34.fm> wrote in message
news:u4MB8HSF...@TK2MSFTNGP02.phx.gbl...

0 new messages