WdfSpinlock related hang...please help

NTDEV
1

Hi,
I have a KMDF1.5 (WDK6000) based upper volume filter and I used
WdfSpinLock to protect my device extension access.
We have been testing this filter for a long time now and it has held up
fine.
recently I encountered an OS hang a couple of times in it’s ioctl path.
I broke in using the debugger and I see a spinlock acquisition hang.
I have examined my code paths for missed unlocks but I couldn’t find
any.
I also examined the wdfspinlock “!wdfspinlock 0x520333e8e08” but it
shows that owning thread is 0x000000000000
I don’t know why this code path(shown in “kb” output) is hanging.

Please help by advicing on how I can debug this.

Thanks
Harish
PS. OS is “Windows Server 2003 Kernel Version 3790 MP (1 procs) Free
x64”

3: kd> kb
RetAddr : Args to Child
: Call Site
fffff80001051e62 : 00000520333252a8 0000000000000005 fffffadfce70c8f0 00000520333e8e08 : nt!KxWaitForSpinLockAndAcquire+0x4 fffffadfc853997c : fffffadfcccdad50 000005203319f9b8
0000000000070000 0000000000000005 :
nt!KeAcquireSpinLockRaiseToDpc+0x1e
fffffadfc803b58b : fffffadfccc171f0 fffffadfc804f1a0 fffffadfcccdad50 fffffadfc84e11af : Wdf01000!imp_WdfSpinLockAcquire+0x100 fffffadfc803b27e : 00000520333e8e08 00000520333252a8
fffffadfce70c8f0 0000000000000005 : dtiw!WdfSpinLockAcquire+0x1b
[f:\winddk\6000\inc\wdf\kmdf\10\wdfsync.h @ 190]
fffffadfc8500291 : 000005203319f9b8 00000520333252a8 0000000000000018 0000000000000000 : dtiw!dtiw_evt_handler_ioctl+0x10e [y:\src\main64\hdps\src\dtiw\kmod\dtiw.c @ 306] fffffadfc84ff776 : 00000520333252a8 00000520333252a8
fffffadfce70c8f0 fffffadfcccdad50 :
Wdf01000!FxIoQueue::DispatchRequestToDriver+0x6d9
fffffadfc84fea8e : fffffadfcce60640 0000000000000000 fffffadfcce60600 fffffadfccef0021 : Wdf01000!FxIoQueue::DispatchEvents+0x83e fffffadfc8505b64 : fffffadfccc8a600 fffffadfccc8a690
000005203319f9b8 00000520333252a8 :
Wdf01000!FxIoQueue::QueueRequest+0x4a6
fffffadfc84e9651 : fffff800011df70e fffffadfcccdad50 fffffadfccc8a690 fffffadfccd24e40 : Wdf01000!FxPkgIo::Dispatch+0x718 fffffadfc79b9453 : 0000000100000000 fffffadfccc8a690
0000000000000000 0000000000000000 : Wdf01000!FxDevice::Dispatch+0xa9
fffffadfc79b9cda : 0000000000000000 00000000c000014f fffffadfccd24e40 fffffadfcc132010 : Fs_Rec!FsRecGetDeviceSectorSize+0xa3 fffff8000108604e : fffffadfcd639e50 fffffadfcd639ea0
000000000000000e fffffadfcc132010 : Fs_Rec!FatRecFsControl+0x6a
fffff800012a3cac : fffffadfc5ac3950 fffffadfccfe09d0 fffffadfc5ac3690 fffffadfc5ac34e4 : nt!IopCheckVpbMounted+0x437 fffff800012b5ba0 : fffffadfccfe09d0 fffffadfccfe0980
fffffadfc5ac3790 0000000000000001 : nt!IopParseDevice+0x74a
fffff800012b7b47 : 0000000000000000 fffffadfc5ac3780 0000000000000040 0000000000000000 : nt!ObpLookupObjectName+0x923 fffff800012bdbb4 : 0000000000000000 0000000000000003
fffffadf00000dd0 0000000000000000 : nt!ObOpenObjectByName+0x180
fffff800012bdd57 : fffffadfce6eba00 fffffadfc5ac3c70 0000000000000000 fffffa800096b3f0 : nt!IopCreateFile+0x630 fffff800012aca69 : 000007ff7f2025f8 fffff683ffbf9010
0000000000000100 fffff80001057896 : nt!IoCreateFile+0x12f
fffff8000104e37d : fffffa800096b3f0 0000000000000000 fffff6fb7dbed078 0000000000000020 : nt!NtOpenFile+0x49 0000000078ef159a : 0000000077d61b77 000000000016fb4d
0000000000000000 00000000021af890 : nt!KiSystemServiceCopyEnd+0x3

3: kd> !wdfspinlock 0x520333e8e08

WDFSPINLOCK fffffadfccc171f0

Irql …: 0x0000000000000000
Owning Thread …: 0x0000000000000000

Acquired At Time Locked Duration Caller’s Address

01 0x0 0x0 @ 0000000000000000
02 0x0 0x206c644d0003000c @ 0000000000000000
03 0x60000 0xe56c694605110003 @ 0000000000000000
04 0xfffffadfcceaa1c0 0x0 @ 0000000040001000
05 0x40002 0xf800c8 @ 0001010000010000
06 0x0 0xfffffadfccc7c4c0 @ e56c694605110011
07 0x1010000010000 0x40002 @ 0000000000000000
08 0x1 0x0 @ 0000000000000000
09 0x1 0x0 @ 0000000000000000
10 0x40000000 0x2061634901060006 @ fffffadfccc17698

2

That’s not really the correct WDFSPINLOCK handle. Don’t forget x64 uses a register calling convention for the first four parameters to any function so kb does NOT show you the true parameters for a call (and the first parameter to any WDf… DDI isn’t a parameter you code, anyway).

Might try a !wdflogdump, or use the !wdfdriverinfo extenstion to show all the object handles- if you don’t have too many wDFSPINLOCKS, the one in use here should become apparent.

3

Also make sure that you release the lock in all code paths, especially in the error cases. If you forget to release you will see hangs like this later

d

Sent using my smartphone, apologies forany typos

-----Original Message-----
From: “Bob Kjelgaard”
To: “Windows System Software Devs Interest List”
Sent: 11/16/07 1:37 PM
Subject: RE:[ntdev] WdfSpinlock related hang…please help

That’s not really the correct WDFSPINLOCK handle. Don’t forget x64 uses a register calling convention for the first four parameters to any function so kb does NOT show you the true parameters for a call (and the first parameter to any WDf… DDI isn’t a parameter you code, anyway).

Might try a !wdflogdump, or use the !wdfdriverinfo extenstion to show all the object handles- if you don’t have too many wDFSPINLOCKS, the one in use here should become apparent.

—
NTDEV is sponsored by OSR

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