I am getting a strange behavior from the KeAcquireSpinLockForDpc() API. We, or rather the github ZFS project, is making use of it outside of the threaded DPC realm as it seemed an easy way to speedily lock whether the thread was at DISPATCH or lower IRQL levels. What I was not expecting is to see that while the thread was waiting to acquire the lock it could be preempted and reentered, waiting again on the same lock (see stack excerpt #1 below). The thread that actually holds the lock is itself preempted (see stack #2) and the I/Os going through deadlock with all other interesting threads waiting to get the lock in PrintBuffer too. I/Os are coming through a StorPort interface and I see that the KeAcquireSpinLockForDpc() routine is tagged as HwStorPortProhibitedDDIs in the compliance rules. It would help me to understand the effect of KeAcquireSpinLockForDpc() on the thread reentrancy I see here, if it is the cause.
As always, thanks for helping.
Thierry Laurent
DataCore Software Corp.
stack #1: thread being reentered while waiting for the lock (the acquire lock is in the PrintBuffer routine).
4.001560 ffffd98de769b5c0 0003a1f RUNNING +0xfffff801d2959003
nt!KxWaitForSpinLockAndAcquire+0xf4f6d
nt!KeAcquireSpinLockAtDpcLevel+0x1f
nt!KeAcquireSpinLockForDpc+0x2b
ZFSin!printBuffer+0x65
ZFSin!wzvol_HwStartIo+0x21
storport!RaidAdapterPostScatterGatherExecute+0x2e7
storport!RaUnitStartIo+0x1b7
storport!RaidRestartIoQueue+0x9a
storport!RaidAdapterRestartQueues+0x81
storport!RaidPauseTimerDpcRoutine+0x1e
nt!KiRetireDpcList+0x731
nt!KxRetireDpcList+0x5
nt!KiDispatchInterruptContinue
nt!KiDpcInterruptBypass+0x25
nt!KiInterruptDispatchNoLockNoEtw+0xb1
nt!KxWaitForSpinLockAndAcquire+0x18
nt!KeAcquireSpinLockAtDpcLevel+0x1f
nt!KeAcquireSpinLockForDpc+0x2b
ZFSin!printBuffer+0x65
ZFSin!dispatcher+0xa8
nt!IovCallDriver+0x252
nt!IofCallDriver+0x72
storport!RaSendIrpSynchronous+0x4d
storport!RaidUnitResetUnit+0x16f
storport!RaidUnitHierarchicalReset+0x4a
storport!RaidHierarchicalResetWorkRoutine+0x66
nt!IopProcessWorkItem+0xf0
nt!ExpWorkerThread+0xe9
nt!PspSystemThreadStartup+0x41
nt!KiStartSystemThread+0x16
stack #2: thread being interrupted while doing the PrintBuffer job after acquiring the lock.
e2c.001240 ffffd98def9fe080 0004f03 READY nt!KxDispatchInterrupt+0x122
nt!KiDpcInterrupt+0x2a3
ZFSin!addbuffer+0x1dc
ZFSin!printBuffer+0x73
ZFSin!dispatcher+0xa8
nt!IovCallDriver+0x252
nt!IofCallDriver+0x72
CLASSPNP!SubmitTransferPacket+0x201
CLASSPNP!ServiceTransferRequest+0x29d
CLASSPNP!ClassReadWrite+0x164
nt!IovCallDriver+0x252
nt!IofCallDriver+0x72
DcsDf!DiskPerfReadWrite+0x1fe
nt!IovCallDriver+0x252
nt!IofCallDriver+0x72
DcsPMF!PMFReadWrite+0x23c
nt!IovCallDriver+0x252
nt!IofCallDriver+0x72
partmgr!PmGlobalDispatch+0xf7
nt!IovCallDriver+0x252
nt!IofCallDriver+0x72
partmgr!PartitionIo+0x177
partmgr!PmGlobalDispatch+0x63
nt!IovCallDriver+0x252
nt!IofCallDriver+0x72
volmgr!VmReadWrite+0x109
nt!IovCallDriver+0x252
nt!IofCallDriver+0x72
nt!IovCallDriver+0x252
nt!IofCallDriver+0x72
volsnap!VolSnapReadFilter+0x61
nt!IovCallDriver+0x252
nt!IofCallDriver+0x72
DcsPMF!PMFReadWrite+0x23c
nt!IovCallDriver+0x252
nt!IofCallDriver+0x72
nt!RawReadWriteDeviceControl+0x9e
nt!RawDispatch+0x78
nt!IovCallDriver+0x252
nt!IofCallDriver+0x72
FLTMGR!FltpLegacyProcessingAfterPreCallbacksCompleted+0x1a6
FLTMGR!FltpDispatch+0xb6
nt!IovCallDriver+0x252
nt!IofCallDriver+0x72
nt!IopSynchronousServiceTail+0x1a0
nt!NtReadFile+0x670
nt!KiSystemServiceCopyEnd+0x13
ntdll!NtReadFile+0x14
KERNELBASE!ReadFile+0x74
DiskTest+0x2edb
DiskTest+0x6bff
DiskTest+0x8262
KERNEL32!BaseThreadInitThunk+0x14
ntdll!RtlUserThreadStart+0x21