In my disk upper-filter driver, I was using normal spin-locks. Things were working fine( including WHQL tests). Then I stumbled upon "queued spin locks". Greed had me in its grip, on reading that they are more efficient.
I changed all the ordinary spin-locks to queued spin locks. Things shattered.
After enabling driver verifier, I get to see an assert which declares timeout for DPC watchdog.
I wonder what went wrong.
Output of "analyze -v", and "running -it" are below. Appreciate the help.
0: kd> !analyze -v
Unknown bugcheck code (0)
Unknown bugcheck description
Arguments:
Arg1: 00000000
Arg2: 00000000
Arg3: 00000000
Arg4: 00000000
Debugging Details:
PROCESS_NAME: System
DPC_TIMEOUT_TYPE: DPC_QUEUE_EXECUTION_TIMEOUT_EXCEEDED
DPC_TIME_LIMIT: 784
FAULTING_IP:
nt!KeAccumulateTicks+3c5
82a80bf4 cd2c int 2Ch
EXCEPTION_RECORD: ffffffff -- (.exr 0xffffffffffffffff)
ExceptionAddress: 82a80bf4 (nt!KeAccumulateTicks+0x000003c5)
ExceptionCode: c0000420 (Assertion failure)
ExceptionFlags: 00000000
NumberParameters: 0
Assertion: *** DPC watchdog timeout
This is NOT a break in update time
This is most likely a BUG in an ISR
Perform a stack trace to find the culprit
The period will be doubled on continuation
Use gh to continue!!
ERROR_CODE: (NTSTATUS) 0xc0000420 - An assertion failure has occurred.
EXCEPTION_CODE: (NTSTATUS) 0xc0000420 - An assertion failure has occurred.
DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT
BUGCHECK_STR: 0x0
CURRENT_IRQL: 1c
LAST_CONTROL_TRANSFER: from 82a800be to 82a80bf4
STACK_TEXT:
99f52a38 82a800be 00002711 00000000 00001600 nt!KeAccumulateTicks+0x3c5
99f52a78 82a7ff6b 82e1a960 73a66d18 00000000 nt!KeUpdateRunTime+0x145
99f52ad4 82a84c17 82b46c02 82b46c02 000000d1 nt!KeUpdateSystemTime+0x613
99f52ad4 82e1a960 82b46c02 82b46c02 000000d1 nt!KeUpdateSystemTimeAssist+0x13
99f52b5c 82d42976 00000000 91755960 99f52b02 hal!KeReleaseQueuedSpinLock+0x60
99f52b70 86bec474 00000000 91755960 91755960 nt!VerifierKeReleaseInStackQueuedSpinLock+0x68
99f52c24 86be9e7a 8c98ee60 ba588ff0 00000000 myfltr!processItem+0x144
99f52c50 82c0ef5e 00000000 83158a51 00000000 myfltr!WorkerThreadRoutine+0xba
99f52c90 82ab6219 86be9dc0 00000000 00000000 nt!PspSystemThreadStartup+0x9e
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x19
STACK_COMMAND: kb
FOLLOWUP_IP:
myfltr!DataMigrationWorker+144
86bec474 8b45d0 mov eax,dword ptr [ebp-30h]
SYMBOL_STACK_INDEX: 6
SYMBOL_NAME: myfltr!processItem+144
FOLLOWUP_NAME: MachineOwner
MODULE_NAME: myfltr
IMAGE_NAME: myfltr.sys
DEBUG_FLR_IMAGE_TIMESTAMP: 50e5531f
FAILURE_BUCKET_ID: 0x0_VRF_myfltr!processItem+144
BUCKET_ID: 0x0_VRF_myfltr!processItem+144
Followup: MachineOwner
0: kd> !running -it
System Processors: (0000000f)
Idle Processors: (0000000e)
Prcbs Current Next
0 82b30d20 91755960 859d3798 ................
ChildEBP RetAddr
99f52a38 82a800be nt!KeAccumulateTicks+0x3c5
99f52a78 82a7ff6b nt!KeUpdateRunTime+0x145
99f52ad4 82a84c17 nt!KeUpdateSystemTime+0x613
99f52ad4 82e1a960 nt!KeUpdateSystemTimeAssist+0x13
99f52b5c 82d42976 hal!KeReleaseQueuedSpinLock+0x60
99f52b70 86bec474 nt!VerifierKeReleaseInStackQueuedSpinLock+0x68
99f52c24 86be9e7a myfltr!myfltr!processItem+0x144
99f52c50 82c0ef5e myfltr!myfltr!WorkerThreadRoutine+0xba
99f52c90 82ab6219 nt!PspSystemThreadStartup+0x9e
00000000 00000000 nt!KiThreadStartup+0x19
1 807c6120 807cb800 ................
ChildEBP RetAddr
807e2c24 00000000 nt!KiIdleLoop+0x1a
2 88b00120 88b05800 ................
ChildEBP RetAddr
88b1cc24 00000000 nt!KiIdleLoop+0x1a
3 88b37120 88b3c800 ................
ChildEBP RetAddr
88b53c24 00000000 nt!KiIdleLoop+0x1a