Problem with DPC

NTDEV
1

Hello,

I'm writing a PCI card driver currently. But I always run into a DPC Watchdog timeout during my DPC.

What I want to archive is the following:
I have an Windows-API which provides a function to "attach" to an interrupt. This means it just calles the driver and blocks execution. The driver takes the request and puts it into a manual queue.
The time an interrupts occurres, the ISR just confirms and disables the interrupt. It then queues the DPC.
In the DPC the next waiting API request is pulled from the manual queue, the interrupt is enabled again and the request is completed.

Additional the API and the driver exchange a counter to be able to track interrupts.

The code for ISR and DPC is the following:

BOOLEAN EvtInterruptIsr(
WDFINTERRUPT Interrupt,
ULONG MessageID) //Message ID used by MSI
{
BOOLEAN bRetVal = FALSE;

SDN_INTERRUPT_DATA idInterruptData = {0}; //(PSDN_INTERRUPT_DATA)&((psaMappedResources->pbMappedMemory)[SDN_IFPC_ADR_SCRATCHPAD]);
SDN_IFPC_INT_STATE iisInterruptState = {0};
ULONG ulCnt = 0;
ULONG ulIntMask = 1u;
WDFDEVICE wdDevice = WdfInterruptGetDevice(Interrupt);
PDEVICE_CONTEXT pDevCtx = GetDeviceContext(wdDevice);
ULONG ulRegister = 0;
ULONG ulCurrentOffset = 0;
ULONG ulCurrentOffsetInBytes = 0;
ULONG ulIpr = 0;
PBYTE pbCurrentChunkAddress = NULL;

/* Abbreviations*/
PBYTE pbMappedMem = pDevCtx->pbMappedMemory;

ulCurrentOffsetInBytes = SDN_IFPC_ADR_SCRATCHPAD * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
idInterruptData.ulCounter = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

ulCurrentOffsetInBytes = (SDN_IFPC_ADR_SCRATCHPAD + 1) * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
idInterruptData.ulFlags = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

ulCurrentOffsetInBytes = SDN_IFPC_ADR_INT_STATE * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
iisInterruptState.ulMagicNr = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

ulCurrentOffsetInBytes = (SDN_IFPC_ADR_INT_STATE + 1) * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
iisInterruptState.ulIsr = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

ulCurrentOffsetInBytes = (SDN_IFPC_ADR_INT_STATE + 2) * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
iisInterruptState.ulIpr = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

ulCurrentOffsetInBytes = (SDN_IFPC_ADR_INT_STATE + 3) * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
iisInterruptState.ulIcrEna = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

/* Store the interrupt reason*/
ulIpr = iisInterruptState.ulIpr;
idInterruptData.ulFlags |= ulIpr;

/* Acknowledge interrupts*/
for(ulCnt =0; ulCnt < 16; ulCnt++)
{
/* Is interrupt pending?*/
if((ulIpr & (ulIntMask << ulCnt)) > 0)
{
KdPrint((__DRIVER_NAME "\nWhohoo! Our interrupt!\n"));

bRetVal = TRUE;

/* Should interrupt be enabled*/
if((iisInterruptState.ulIcrEna & (ulIntMask << ulCnt)) > 0)
{
KdPrint(("####Interrupt %d!####\n", ulCnt));
/* Acknowledge and disabled currently. Will be enable in the DPC again.*/
ulRegister = SDN_IFPC_FLAG_ACK;// | SDN_IFPC_FLAG_ENABLE;
pDevCtx->ulInterruptsToReenable |= (1 << ulCnt);

ulCurrentOffset = SDN_IFPC_ADR_INT_CTRL + ulCnt;
ulCurrentOffsetInBytes = ulCurrentOffset * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress, ulRegister);
} /* if((piisInterruptState->uiIcrEna & (ulIntMask << i)) > 0)*/
else
{
KdPrint((__DRIVER_NAME "####Interrupt shouldnt be enabled %d / 0x%x!!!\n", ulCnt, iisInterruptState.ulIcrEna));
/* Acknowledge and keep disabled*/
ulRegister = SDN_IFPC_FLAG_ACK | SDN_IFPC_FLAG_DISABLE;

ulCurrentOffset = SDN_IFPC_ADR_INT_CTRL + ulCnt;
ulCurrentOffsetInBytes = ulCurrentOffset * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress, ulRegister);
}/* else [if((piisInterruptState->uiIcrEna & (ulIntMask << i)) > 0)]*/
} /* if((pidInterruptData->uiFlags & (ulIntMask << i)) > 0)*/
} /* for(ulCnt =0; ulCnt < 16; ulCnt++)*/

if(bRetVal == TRUE)
{
idInterruptData.ulCounter++;

ulCurrentOffsetInBytes = SDN_IFPC_ADR_SCRATCHPAD * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress, idInterruptData.ulCounter);

ulCurrentOffsetInBytes = (SDN_IFPC_ADR_SCRATCHPAD + 1) * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress, idInterruptData.ulFlags);

WdfInterruptQueueDpcForIsr(Interrupt);
} /* if(bRetVal == TRUE)*/

//KdPrint((__DRIVER_NAME "<-- EvtInterruptIsr\n"));

return bRetVal;
}

VOID EvtInterruptDpc(
WDFINTERRUPT Interrupt,
WDFDEVICE Device)
{
NTSTATUS nsStatus = STATUS_SUCCESS;

PDEVICE_CONTEXT pdcDevContext = GetDeviceContext(Device);
WDFREQUEST wrRequest;
ULONG ulCnt = 0;

ULONG ulRegister = 0;
ULONG ulCurrentOffset = 0;
ULONG ulCurrentOffsetInBytes = 0;
PBYTE pbCurrentChunkAddress = NULL;
SDN_INTERRUPT_DATA idInterruptData = {0};
ULONG ulBitShift = 0;
ULONG ulBitResult = 0;

PBYTE pbMappedMem = pdcDevContext->pbMappedMemory;
WDFMEMORY wmOutMemory;

KdPrint((__DRIVER_NAME "--> EvtInterruptDpc\n"));

pdcDevContext = GetDeviceContext(Device);

WdfInterruptAcquireLock(pdcDevContext->Interrupt);
do
{
/* Get next request*/
nsStatus = WdfIoQueueRetrieveNextRequest(pdcDevContext->ISRNotificationQueue, &wrRequest);

if(NT_SUCCESS(nsStatus))
{
nsStatus = WdfRequestRetrieveOutputMemory(wrRequest, &wmOutMemory);

ulCurrentOffsetInBytes = SDN_IFPC_ADR_SCRATCHPAD * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
idInterruptData.ulCounter = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

ulCurrentOffsetInBytes = (SDN_IFPC_ADR_SCRATCHPAD + 1) * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
idInterruptData.ulFlags = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

nsStatus = WdfMemoryCopyFromBuffer(
wmOutMemory,
0,
&idInterruptData,
sizeof(SDN_INTERRUPT_DATA));

ulCurrentOffsetInBytes = (SDN_IFPC_ADR_SCRATCHPAD + 1) * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress, 0);

WdfRequestSetInformation(wrRequest, sizeof(SDN_INTERRUPT_DATA));
/* If request dequeued successfully -> complete request*/
WdfRequestComplete(wrRequest, nsStatus);
}
else if(nsStatus != STATUS_NO_MORE_ENTRIES)
{
KdPrint((__DRIVER_NAME "!!! WdfIoQueueRetrieveNextRequest with 0x%08x !!!\n", nsStatus));
}
} while(NT_SUCCESS(nsStatus));

if(nsStatus == STATUS_NO_MORE_ENTRIES)
{
nsStatus = STATUS_SUCCESS;
}

/* Reenable interrupts*/
for(ulCnt = 0; ulCnt < 16; ulCnt++)
{
KdPrint(("#### Check Interrupt %d ####\n", ulCnt));
ulBitShift = (1 << ulCnt);
ulBitResult = (pdcDevContext->ulInterruptsToReenable) & ulBitShift;
if(ulBitResult > 0)
{
pdcDevContext->ulInterruptsToReenable &= ~(1 << ulCnt);
ulCurrentOffset = SDN_IFPC_ADR_INT_CTRL + ulCnt;
ulCurrentOffsetInBytes = ulCurrentOffset * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
ulRegister = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);
ulRegister |= SDN_IFPC_FLAG_ENABLE;
WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress, ulRegister);
KdPrint(("####Interrupt %d reenabled!####\n", ulCnt));
}
else
{
KdPrint(("#### Don't need to enable Interrupt %s ####\n", ulCnt));
}
}

KdPrint(("#### All interrupts checked ####\n"));
WdfInterruptReleaseLock(pdcDevContext->Interrupt);

KdPrint((__DRIVER_NAME "<-- EvtInterruptDpc\n"));
}

The last output I see is "#### Check Interrupt 0 ####" (Note: I just enable and trigger Interrupt 0. All other interrupts are neither enabled nor triggered)

And if I debug KdPrint(("#### Check Interrupt %d ####\n", ulCnt)); is the last command executed.

Here is the call stack:

Call Site

00 nt! ?? ::FNODOBFM::string'+0x4f3a 01 nt!KeUpdateSystemTime+0x377 02 hal!HalpHpetClockInterrupt+0x8d 03 nt!KiInterruptDispatchNoLock+0x163 (TrapFrame @ fffff80000ba1f00)
04 nt!KxWaitForSpinLockAndAcquire+0x20
05 nt!KeAcquireSpinLockAtDpcLevel+0x6f
06 nt!KiScanInterruptObjectList+0x5c
07 nt!KiChainedDispatch+0x128 (TrapFrame @ fffff80000ba2160) 08 nt!KeThawExecution+0x26b 09 nt!KdExitDebugger+0x7a 0a nt! ?? ::FNODOBFM::string'+0x19d81
0b nt!KdpTrap+0x2b
0c nt!KiDispatchException+0x126
0d nt!KiExceptionDispatch+0xc2
0e nt!KiBreakpointTrap+0xf4 (TrapFrame @ fffff80000ba2cb0) 0f SiDaNetPCI!EvtInterruptDpc+0x1ef [c:\projekte\siemenshc\sidanet\driver\sidanet_interrupts.c @ 308] 10 Wdf01000!FxInterrupt::_InterruptDpcThunk+0x53 11 nt!KiRetireDpcList+0x1bc 12 nt!KyRetireDpcList+0x5 (TrapFrame @ fffff80000ba2e70)
13 nt!KiDispatchInterruptContinue
14 nt!KiDpcInterruptBypass+0x13
15 nt!KiInterruptDispatchNoLock+0x1fc (TrapFrame @ fffff88004cf2890) 16 igdkmd64!hybDriverEntry+0x2856b7 17 igdkmd64!hybDriverEntry+0x54aa0 18 igdkmd64!hybDriverEntry+0x1091a2 19 igdkmd64!hybDriverEntry+0x117306 1a igdkmd64!hybDriverEntry+0x1181cf 1b igdkmd64!hybDriverEntry+0x1185a8 1c igdkmd64!hybDriverEntry+0xfbc40 1d igdkmd64!hybDriverEntry+0xfc264 1e igdkmd64!hybDriverEntry+0x1190d 1f dxgkrnl!DXGCONTEXT::Render+0x5f9 20 dxgkrnl!DxgkRender+0x3e7 21 win32k!NtGdiDdDDIRender+0x12 22 nt!KiSystemServiceCopyEnd+0x13 (TrapFrame @ fffff88004cf3c20)
23 0x7fefe9113fa 24 0x7fef79319dd

I have no idea why the DPC freezes right behind the KdPrint command... Can somebody help me out on this?

Thanks,
Torben

2

Acquiring the interrupt lock caused your deadlock.
While you’re holding the interrupt lock after calling WdfInterruptAcquireLock, your options are very limited, because the current IRQL is greater than DISPATCH_LEVEL. You CANNOT call WdfIoQueueRetrieveNextRequest. You CANNOT complete the IO requests while holding ANY lock. Holding the interrupt lock is ESPECIALLY dangerous, because it raises IRQL. Any function that acquires a normal spinlock will lower the IRQL down to DISPATCH_LEVEL.

As soon as you re-enable your first interrupt, the ISR gets fired again (because the IRQL was lowered back to DISPATCH_LEVEL). But because the lock is held, the ISR will deadlock on trying to re-acquire it.

3

None of the request APIs you are calling with the interrupt spinlock held are callable at DIRQL. You need to reractir so that you acquire the interruptlock only to touch hw and devext state, the restoutside of that specific lock. And run prefast on your driver, it would have found these issues.

d

debt from my phone

From: xxxxx@conplement.de
Sent: 2/2/2012 2:51 AM
To: Windows System Software Devs Interest List
Subject: [ntdev] Problem with DPC

Hello,

I'm writing a PCI card driver currently. But I always run into a DPC Watchdog timeout during my DPC.

What I want to archive is the following:
I have an Windows-API which provides a function to "attach" to an interrupt. This means it just calles the driver and blocks execution. The driver takes the request and puts it into a manual queue.
The time an interrupts occurres, the ISR just confirms and disables the interrupt. It then queues the DPC.
In the DPC the next waiting API request is pulled from the manual queue, the interrupt is enabled again and the request is completed.

Additional the API and the driver exchange a counter to be able to track interrupts.

The code for ISR and DPC is the following:

BOOLEAN EvtInterruptIsr(
WDFINTERRUPT Interrupt,
ULONG MessageID) //Message ID used by MSI
{
BOOLEAN bRetVal = FALSE;

SDN_INTERRUPT_DATA idInterruptData = {0}; //(PSDN_INTERRUPT_DATA)&((psaMappedResources->pbMappedMemory)[SDN_IFPC_ADR_SCRATCHPAD]);
SDN_IFPC_INT_STATE iisInterruptState = {0};
ULONG ulCnt = 0;
ULONG ulIntMask = 1u;
WDFDEVICE wdDevice = WdfInterruptGetDevice(Interrupt);
PDEVICE_CONTEXT pDevCtx = GetDeviceContext(wdDevice);
ULONG ulRegister = 0;
ULONG ulCurrentOffset = 0;
ULONG ulCurrentOffsetInBytes = 0;
ULONG ulIpr = 0;
PBYTE pbCurrentChunkAddress = NULL;

/* Abbreviations*/
PBYTE pbMappedMem = pDevCtx->pbMappedMemory;

ulCurrentOffsetInBytes = SDN_IFPC_ADR_SCRATCHPAD * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
idInterruptData.ulCounter = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

ulCurrentOffsetInBytes = (SDN_IFPC_ADR_SCRATCHPAD + 1) * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
idInterruptData.ulFlags = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

ulCurrentOffsetInBytes = SDN_IFPC_ADR_INT_STATE * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
iisInterruptState.ulMagicNr = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

ulCurrentOffsetInBytes = (SDN_IFPC_ADR_INT_STATE + 1) * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
iisInterruptState.ulIsr = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

ulCurrentOffsetInBytes = (SDN_IFPC_ADR_INT_STATE + 2) * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
iisInterruptState.ulIpr = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

ulCurrentOffsetInBytes = (SDN_IFPC_ADR_INT_STATE + 3) * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
iisInterruptState.ulIcrEna = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

/* Store the interrupt reason*/
ulIpr = iisInterruptState.ulIpr;
idInterruptData.ulFlags |= ulIpr;

/* Acknowledge interrupts*/
for(ulCnt =0; ulCnt < 16; ulCnt++)
{
/* Is interrupt pending?*/
if((ulIpr & (ulIntMask << ulCnt)) > 0)
{
KdPrint((__DRIVER_NAME "\nWhohoo! Our interrupt!\n"));

bRetVal = TRUE;

/* Should interrupt be enabled*/
if((iisInterruptState.ulIcrEna & (ulIntMask << ulCnt)) > 0)
{
KdPrint(("####Interrupt %d!####\n", ulCnt));
/* Acknowledge and disabled currently. Will be enable in the DPC again.*/
ulRegister = SDN_IFPC_FLAG_ACK;// | SDN_IFPC_FLAG_ENABLE;
pDevCtx->ulInterruptsToReenable |= (1 << ulCnt);

ulCurrentOffset = SDN_IFPC_ADR_INT_CTRL + ulCnt;
ulCurrentOffsetInBytes = ulCurrentOffset * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress, ulRegister);
} /* if((piisInterruptState->uiIcrEna & (ulIntMask << i)) > 0)*/
else
{
KdPrint((__DRIVER_NAME "####Interrupt shouldnt be enabled %d / 0x%x!!!\n", ulCnt, iisInterruptState.ulIcrEna));
/* Acknowledge and keep disabled*/
ulRegister = SDN_IFPC_FLAG_ACK | SDN_IFPC_FLAG_DISABLE;

ulCurrentOffset = SDN_IFPC_ADR_INT_CTRL + ulCnt;
ulCurrentOffsetInBytes = ulCurrentOffset * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress, ulRegister);
}/* else [if((piisInterruptState->uiIcrEna & (ulIntMask << i)) > 0)]*/
} /* if((pidInterruptData->uiFlags & (ulIntMask << i)) > 0)*/
} /* for(ulCnt =0; ulCnt < 16; ulCnt++)*/

if(bRetVal == TRUE)
{
idInterruptData.ulCounter++;

ulCurrentOffsetInBytes = SDN_IFPC_ADR_SCRATCHPAD * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress, idInterruptData.ulCounter);

ulCurrentOffsetInBytes = (SDN_IFPC_ADR_SCRATCHPAD + 1) * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress, idInterruptData.ulFlags);

WdfInterruptQueueDpcForIsr(Interrupt);
} /* if(bRetVal == TRUE)*/

//KdPrint((__DRIVER_NAME "<-- EvtInterruptIsr\n"));

return bRetVal;
}

VOID EvtInterruptDpc(
WDFINTERRUPT Interrupt,
WDFDEVICE Device)
{
NTSTATUS nsStatus = STATUS_SUCCESS;

PDEVICE_CONTEXT pdcDevContext = GetDeviceContext(Device);
WDFREQUEST wrRequest;
ULONG ulCnt = 0;

ULONG ulRegister = 0;
ULONG ulCurrentOffset = 0;
ULONG ulCurrentOffsetInBytes = 0;
PBYTE pbCurrentChunkAddress = NULL;
SDN_INTERRUPT_DATA idInterruptData = {0};
ULONG ulBitShift = 0;
ULONG ulBitResult = 0;

PBYTE pbMappedMem = pdcDevContext->pbMappedMemory;
WDFMEMORY wmOutMemory;

KdPrint((__DRIVER_NAME "--> EvtInterruptDpc\n"));

pdcDevContext = GetDeviceContext(Device);

WdfInterruptAcquireLock(pdcDevContext->Interrupt);
do
{
/* Get next request*/
nsStatus = WdfIoQueueRetrieveNextRequest(pdcDevContext->ISRNotificationQueue, &wrRequest);

if(NT_SUCCESS(nsStatus))
{
nsStatus = WdfRequestRetrieveOutputMemory(wrRequest, &wmOutMemory);

ulCurrentOffsetInBytes = SDN_IFPC_ADR_SCRATCHPAD * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
idInterruptData.ulCounter = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

ulCurrentOffsetInBytes = (SDN_IFPC_ADR_SCRATCHPAD + 1) * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
idInterruptData.ulFlags = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);

nsStatus = WdfMemoryCopyFromBuffer(
wmOutMemory,
0,
&idInterruptData,
sizeof(SDN_INTERRUPT_DATA));

ulCurrentOffsetInBytes = (SDN_IFPC_ADR_SCRATCHPAD + 1) * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress, 0);

WdfRequestSetInformation(wrRequest, sizeof(SDN_INTERRUPT_DATA));
/* If request dequeued successfully -> complete request*/
WdfRequestComplete(wrRequest, nsStatus);
}
else if(nsStatus != STATUS_NO_MORE_ENTRIES)
{
KdPrint((__DRIVER_NAME "!!! WdfIoQueueRetrieveNextRequest with 0x%08x !!!\n", nsStatus));
}
} while(NT_SUCCESS(nsStatus));

if(nsStatus == STATUS_NO_MORE_ENTRIES)
{
nsStatus = STATUS_SUCCESS;
}

/* Reenable interrupts*/
for(ulCnt = 0; ulCnt < 16; ulCnt++)
{
KdPrint(("#### Check Interrupt %d ####\n", ulCnt));
ulBitShift = (1 << ulCnt);
ulBitResult = (pdcDevContext->ulInterruptsToReenable) & ulBitShift;
if(ulBitResult > 0)
{
pdcDevContext->ulInterruptsToReenable &= ~(1 << ulCnt);
ulCurrentOffset = SDN_IFPC_ADR_INT_CTRL + ulCnt;
ulCurrentOffsetInBytes = ulCurrentOffset * SDN_ADDRESS_WIDTH;
pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
ulRegister = READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);
ulRegister |= SDN_IFPC_FLAG_ENABLE;
WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress, ulRegister);
KdPrint(("####Interrupt %d reenabled!####\n", ulCnt));
}
else
{
KdPrint(("#### Don't need to enable Interrupt %s ####\n", ulCnt));
}
}

KdPrint(("#### All interrupts checked ####\n"));
WdfInterruptReleaseLock(pdcDevContext->Interrupt);

KdPrint((__DRIVER_NAME "<-- EvtInterruptDpc\n"));
}

The last output I see is "#### Check Interrupt 0 ####" (Note: I just enable and trigger Interrupt 0. All other interrupts are neither enabled nor triggered)

And if I debug KdPrint(("#### Check Interrupt %d ####\n", ulCnt)); is the last command executed.

Here is the call stack:

Call Site

00 nt! ?? ::FNODOBFM::string'+0x4f3a 01 nt!KeUpdateSystemTime+0x377 02 hal!HalpHpetClockInterrupt+0x8d 03 nt!KiInterruptDispatchNoLock+0x163 (TrapFrame @ fffff80000ba1f00)
04 nt!KxWaitForSpinLockAndAcquire+0x20
05 nt!KeAcquireSpinLockAtDpcLevel+0x6f
06 nt!KiScanInterruptObjectList+0x5c
07 nt!KiChainedDispatch+0x128 (TrapFrame @ fffff80000ba2160) 08 nt!KeThawExecution+0x26b 09 nt!KdExitDebugger+0x7a 0a nt! ?? ::FNODOBFM::string'+0x19d81
0b nt!KdpTrap+0x2b
0c nt!KiDispatchException+0x126
0d nt!KiExceptionDispatch+0xc2
0e nt!KiBreakpointTrap+0xf4 (TrapFrame @ fffff80000ba2cb0) 0f SiDaNetPCI!EvtInterruptDpc+0x1ef [c:\projekte\siemenshc\sidanet\driver\sidanet_interrupts.c @ 308] 10 Wdf01000!FxInterrupt::_InterruptDpcThunk+0x53 11 nt!KiRetireDpcList+0x1bc 12 nt!KyRetireDpcList+0x5 (TrapFrame @ fffff80000ba2e70)
13 nt!KiDispatchInterruptContinue
14 nt!KiDpcInterruptBypass+0x13
15 nt!KiInterruptDispatchNoLock+0x1fc (TrapFrame @ fffff88004cf2890) 16 igdkmd64!hybDriverEntry+0x2856b7 17 igdkmd64!hybDriverEntry+0x54aa0 18 igdkmd64!hybDriverEntry+0x1091a2 19 igdkmd64!hybDriverEntry+0x117306 1a igdkmd64!hybDriverEntry+0x1181cf 1b igdkmd64!hybDriverEntry+0x1185a8 1c igdkmd64!hybDriverEntry+0xfbc40 1d igdkmd64!hybDriverEntry+0xfc264 1e igdkmd64!hybDriverEntry+0x1190d 1f dxgkrnl!DXGCONTEXT::Render+0x5f9 20 dxgkrnl!DxgkRender+0x3e7 21 win32k!NtGdiDdDDIRender+0x12 22 nt!KiSystemServiceCopyEnd+0x13 (TrapFrame @ fffff88004cf3c20)
23 0x7fefe9113fa 24 0x7fef79319dd

I have no idea why the DPC freezes right behind the KdPrint command... Can somebody help me out on this?

Thanks,
Torben

NTDEV is sponsored by OSR

For our schedule of WDF, WDM, debugging and other seminars visit:

To unsubscribe, visit the List Server section of OSR Online at ListServer/Forum

4

Hello,

thanks for the requests. I was ble to figure out the problem during the day by myself because I got “lucky” and the driver crashed on another routine with usefull informations…

Well, I am running preFAST but it doesn’t mention the error… (?) I even disabled the filter to be sure but there is no error concerning this issue.

Thanks a lot.
Torben

5

You need to enable the Driver Verifier, and I recommend to run it on checked OS build.

6

>
I’m not sure what you are trying to accomplush here. Typically, your
driver should “attach” (not a usual descripition) to the interrupt when it
is handling the IRP_MJ_PNP:IRP_MN_??? (I’m drawing a blank on the name)
event, working from the translated resources. Using a user-level API to
do this sounds dangerous.

Your model is also a bit odd in that you don’t remove a requst from the
queue until DPC time; typically, you enqueue a request, which will be
dequeued and the device started to handle that request; when the request
is completed in the DPC, you ask for another request to be dequeued, and
that takes care of restarting the device. You are, it appears, attempting
to impose on Windows a model which is quite different than the usual
model, but you have not indicated why the “classical model” is unsuitable.
What happens if your device interrupts but there is no IRP in the queueto
deal with it? It appears that you treat this as an “out of memory”
condition, which it most certainly is not. You have shown code, but told
us nothing relevant about the device, for example, how often it
interrupts. If it interrups more than once every couple seconds, I can’t
see how it is even going to be possible to write a working application
that uses synchronous I/O, because you will almost never have an IRP
present when the interrupt occurs. By attempting to rotate the “classical
model” through some fourth dimension, it has been distorted beyond
recognition. My first reaction upon trying to read this code (and trying
to reverse-engineer the device specs from it) would be to throw it all out
anf rewrite it to follow the classical model of device drivers. I can’t
see how to ever make this code actually work reliably.

Notr that there are classical models for drivers where the interrupts come
in faster than the IRPs; these use internal kernel buffering to hold onto
the data (the serial port is one exemplar of this class). You absolutely,
positively must assume that if you device is enabled for interrupts that
(a) it is only enabled because there is a guaranteed IRP, which is why it
was enabled, or (b) you have internal buffering. Note if you use internal
buffering, instantaneous device state becomes irrelevant; for example, if
you get a parity error on the device for input operation N, then all the
data which is buffered for operations reported as such; only when you get a request to finally retirieve the
packet for operation N do you complete it with a “device had an errer”
completion.

Why do you think your API “blocks execution”? You don’t have any say in
that; if the user opens a handle using FILE_FLAG_OVERLAPPED, it is the I/O
Manager that deals with blocking, and the user has explicitly told it to
NOT block. You have no control over this decision.

Also, a couple style points. EVERY KdPrint should start out with the
driver name on the line; not only is it easier to process visually, but if
you save the log to a file it is now trivial to write a little script to
extract your lines (Perl, Python, awk, or other scripting language you
like). I find statements like “if(e == TRUE)” to be extremely peculiar,
because e is obviously a boolean variable, and there is never a sensible
reason to compare a boolean variable to a boolean literal! That should be
written “if(e)” because that is all that is necessary. In user space, it
could fail because many functions that claim to be boolean return 0 for
FALSE and non-zero (but not necesarily the literal 1) for not-false.
joe
Hello,
>
> I’m writing a PCI card driver currently. But I always run into a DPC
> Watchdog timeout during my DPC.
>
> What I want to archive is the following:
> I have an Windows-API which provides a function to “attach” to an
> interrupt. This means it just calles the driver and blocks execution. The
> driver takes the request and puts it into a manual queue.
> The time an interrupts occurres, the ISR just confirms and disables the
> interrupt. It then queues the DPC.
> In the DPC the next waiting API request is pulled from the manual queue,
> the interrupt is enabled again and the request is completed.
>
> Additional the API and the driver exchange a counter to be able to track
> interrupts.
>
> The code for ISR and DPC is the following:
>
> BOOLEAN EvtInterruptIsr(
> WDFINTERRUPT Interrupt,
> ULONG MessageID) //Message ID used by MSI
> {
> BOOLEAN bRetVal = FALSE;
>
> SDN_INTERRUPT_DATA idInterruptData = {0};
> //(PSDN_INTERRUPT_DATA)&((psaMappedResources->pbMappedMemory)[SDN_IFPC_ADR_SCRATCHPAD]);
> SDN_IFPC_INT_STATE iisInterruptState = {0};
> ULONG ulCnt = 0;
> ULONG ulIntMask = 1u;
> WDFDEVICE wdDevice = WdfInterruptGetDevice(Interrupt);
> PDEVICE_CONTEXT pDevCtx = GetDeviceContext(wdDevice);
> ULONG ulRegister = 0;
> ULONG ulCurrentOffset = 0;
> ULONG ulCurrentOffsetInBytes = 0;
> ULONG ulIpr = 0;
> PBYTE pbCurrentChunkAddress = NULL;
>
> /* Abbreviations*/
> PBYTE pbMappedMem = pDevCtx->pbMappedMemory;
>
> ulCurrentOffsetInBytes = SDN_IFPC_ADR_SCRATCHPAD
> SDN_ADDRESS_WIDTH;
> pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
> idInterruptData.ulCounter =
> READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);
>
> ulCurrentOffsetInBytes = (SDN_IFPC_ADR_SCRATCHPAD + 1)
> SDN_ADDRESS_WIDTH;
> pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
> idInterruptData.ulFlags =
> READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);
>
> ulCurrentOffsetInBytes = SDN_IFPC_ADR_INT_STATE * SDN_ADDRESS_WIDTH;
> pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
> iisInterruptState.ulMagicNr =
> READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);
>
> ulCurrentOffsetInBytes = (SDN_IFPC_ADR_INT_STATE + 1)
> SDN_ADDRESS_WIDTH;
> pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
> iisInterruptState.ulIsr =
> READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);
>
> ulCurrentOffsetInBytes = (SDN_IFPC_ADR_INT_STATE + 2)
> SDN_ADDRESS_WIDTH;
> pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
> iisInterruptState.ulIpr =
> READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);
>
> ulCurrentOffsetInBytes = (SDN_IFPC_ADR_INT_STATE + 3)
> SDN_ADDRESS_WIDTH;
> pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
> iisInterruptState.ulIcrEna =
> READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);
>
> / Store the interrupt reason/
> ulIpr = iisInterruptState.ulIpr;
> idInterruptData.ulFlags |= ulIpr;
>
> / Acknowledge interrupts/
> for(ulCnt =0; ulCnt < 16; ulCnt++)
> {
> / Is interrupt pending?/
> if((ulIpr & (ulIntMask << ulCnt)) > 0)
> {
> KdPrint((__DRIVER_NAME “\nWhohoo! Our interrupt!\n”));
>
> bRetVal = TRUE;
>
> / Should interrupt be enabled*/
> if((iisInterruptState.ulIcrEna & (ulIntMask << ulCnt)) > 0)
> {
> KdPrint((“####Interrupt %d!####\n”, ulCnt));
> /* Acknowledge and disabled currently. Will be enable in
> the DPC again./
> ulRegister = SDN_IFPC_FLAG_ACK;// | SDN_IFPC_FLAG_ENABLE;
> pDevCtx->ulInterruptsToReenable |= (1 << ulCnt);
>
> ulCurrentOffset = SDN_IFPC_ADR_INT_CTRL + ulCnt;
> ulCurrentOffsetInBytes = ulCurrentOffset
> SDN_ADDRESS_WIDTH;
> pbCurrentChunkAddress =
> &(pbMappedMem[ulCurrentOffsetInBytes]);
> WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress,
> ulRegister);
> } / if((piisInterruptState->uiIcrEna & (ulIntMask << i)) >
> 0)/
> else
> {
> KdPrint((__DRIVER_NAME “####Interrupt shouldnt be enabled %d /
> 0x%x!!!\n”, ulCnt, iisInterruptState.ulIcrEna));
> /* Acknowledge and keep disabled*/
> ulRegister = SDN_IFPC_FLAG_ACK | SDN_IFPC_FLAG_DISABLE;
>
> ulCurrentOffset = SDN_IFPC_ADR_INT_CTRL + ulCnt;
> ulCurrentOffsetInBytes = ulCurrentOffset
> SDN_ADDRESS_WIDTH;
> pbCurrentChunkAddress =
> &(pbMappedMem[ulCurrentOffsetInBytes]);
> WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress,
> ulRegister);
> }/ else [if((piisInterruptState->uiIcrEna & (ulIntMask << i))
> > 0)]/
> } / if((pidInterruptData->uiFlags & (ulIntMask << i)) > 0)/
> } / for(ulCnt =0; ulCnt < 16; ulCnt++)/
>
> if(bRetVal == TRUE)
> {
> idInterruptData.ulCounter++;
>
> ulCurrentOffsetInBytes = SDN_IFPC_ADR_SCRATCHPAD
> SDN_ADDRESS_WIDTH;
> pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
> WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress,
> idInterruptData.ulCounter);
>
> ulCurrentOffsetInBytes = (SDN_IFPC_ADR_SCRATCHPAD + 1)
> SDN_ADDRESS_WIDTH;
> pbCurrentChunkAddress = &(pbMappedMem[ulCurrentOffsetInBytes]);
> WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress,
> idInterruptData.ulFlags);
>
> WdfInterruptQueueDpcForIsr(Interrupt);
> } / if(bRetVal == TRUE)/
>
> //KdPrint((__DRIVER_NAME “<– EvtInterruptIsr\n”));
>
> return bRetVal;
> }
>
> VOID EvtInterruptDpc(
> WDFINTERRUPT Interrupt,
> WDFDEVICE Device)
> {
> NTSTATUS nsStatus = STATUS_SUCCESS;
>
> PDEVICE_CONTEXT pdcDevContext = GetDeviceContext(Device);
> WDFREQUEST wrRequest;
> ULONG ulCnt = 0;
>
> ULONG ulRegister = 0;
> ULONG ulCurrentOffset = 0;
> ULONG ulCurrentOffsetInBytes = 0;
> PBYTE pbCurrentChunkAddress = NULL;
> SDN_INTERRUPT_DATA idInterruptData = {0};
> ULONG ulBitShift = 0;
> ULONG ulBitResult = 0;
>
> PBYTE pbMappedMem = pdcDevContext->pbMappedMemory;
> WDFMEMORY wmOutMemory;
>
> KdPrint((__DRIVER_NAME “–> EvtInterruptDpc\n”));
>
> pdcDevContext = GetDeviceContext(Device);
>
> WdfInterruptAcquireLock(pdcDevContext->Interrupt);
> do
> {
> / Get next request*/
> nsStatus =
> WdfIoQueueRetrieveNextRequest(pdcDevContext->ISRNotificationQueue,
> &wrRequest);
>
> if(NT_SUCCESS(nsStatus))
> {
> nsStatus = WdfRequestRetrieveOutputMemory(wrRequest,
> &wmOutMemory);
>
> ulCurrentOffsetInBytes = SDN_IFPC_ADR_SCRATCHPAD
> SDN_ADDRESS_WIDTH;
> pbCurrentChunkAddress =
> &(pbMappedMem[ulCurrentOffsetInBytes]);
> idInterruptData.ulCounter =
> READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);
>
> ulCurrentOffsetInBytes = (SDN_IFPC_ADR_SCRATCHPAD + 1)
> SDN_ADDRESS_WIDTH;
> pbCurrentChunkAddress =
> &(pbMappedMem[ulCurrentOffsetInBytes]);
> idInterruptData.ulFlags =
> READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);
>
> nsStatus = WdfMemoryCopyFromBuffer(
> wmOutMemory,
> 0,
> &idInterruptData,
> sizeof(SDN_INTERRUPT_DATA));
>
> ulCurrentOffsetInBytes = (SDN_IFPC_ADR_SCRATCHPAD + 1)
> SDN_ADDRESS_WIDTH;
> pbCurrentChunkAddress =
> &(pbMappedMem[ulCurrentOffsetInBytes]);
> WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress, 0);
>
> WdfRequestSetInformation(wrRequest,
> sizeof(SDN_INTERRUPT_DATA));
> / If request dequeued successfully -> complete request/
> WdfRequestComplete(wrRequest, nsStatus);
> }
> else if(nsStatus != STATUS_NO_MORE_ENTRIES)
> {
> KdPrint((__DRIVER_NAME “!!! WdfIoQueueRetrieveNextRequest with
> 0x%08x !!!\n”, nsStatus));
> }
> } while(NT_SUCCESS(nsStatus));
>
> if(nsStatus == STATUS_NO_MORE_ENTRIES)
> {
> nsStatus = STATUS_SUCCESS;
> }
>
> / Reenable interrupts*/
> for(ulCnt = 0; ulCnt < 16; ulCnt++)
> {
> KdPrint((“#### Check Interrupt %d ####\n”, ulCnt));
> ulBitShift = (1 << ulCnt);
> ulBitResult = (pdcDevContext->ulInterruptsToReenable) & ulBitShift;
> if(ulBitResult > 0)
> {
> pdcDevContext->ulInterruptsToReenable &= ~(1 << ulCnt);
> ulCurrentOffset = SDN_IFPC_ADR_INT_CTRL + ulCnt;
> ulCurrentOffsetInBytes = ulCurrentOffset * SDN_ADDRESS_WIDTH;
> pbCurrentChunkAddress =
> &(pbMappedMem[ulCurrentOffsetInBytes]);
> ulRegister =
> READ_REGISTER_ULONG((PULONG)pbCurrentChunkAddress);
> ulRegister |= SDN_IFPC_FLAG_ENABLE;
> WRITE_REGISTER_ULONG((PULONG)pbCurrentChunkAddress,
> ulRegister);
> KdPrint((“####Interrupt %d reenabled!####\n”, ulCnt));
> }
> else
> {
> KdPrint((“#### Don’t need to enable Interrupt %s ####\n”,
> ulCnt));
> }
> }
>
> KdPrint((“#### All interrupts checked ####\n”));
> WdfInterruptReleaseLock(pdcDevContext->Interrupt);
>
> KdPrint((__DRIVER_NAME “<– EvtInterruptDpc\n”));
> }
>
> The last output I see is “#### Check Interrupt 0 ####” (Note: I just
> enable and trigger Interrupt 0. All other interrupts are neither enabled
> nor triggered)
>
> And if I debug KdPrint((“#### Check Interrupt %d ####\n”, ulCnt)); is the
> last command executed.
>
> Here is the call stack:
> # Call Site
> 00 nt! ?? ::FNODOBFM::string'+0x4f3a<br>&gt; 01 nt!KeUpdateSystemTime+0x377<br>&gt; 02 hal!HalpHpetClockInterrupt+0x8d<br>&gt; 03 nt!KiInterruptDispatchNoLock+0x163 (TrapFrame @ fffff80000ba1f00)
> 04 nt!KxWaitForSpinLockAndAcquire+0x20
> 05 nt!KeAcquireSpinLockAtDpcLevel+0x6f
> 06 nt!KiScanInterruptObjectList+0x5c
> 07 nt!KiChainedDispatch+0x128 (TrapFrame @ fffff80000ba2160)<br>&gt; 08 nt!KeThawExecution+0x26b<br>&gt; 09 nt!KdExitDebugger+0x7a<br>&gt; 0a nt! ?? ::FNODOBFM::string’+0x19d81
> 0b nt!KdpTrap+0x2b
> 0c nt!KiDispatchException+0x126
> 0d nt!KiExceptionDispatch+0xc2
> 0e nt!KiBreakpointTrap+0xf4 (TrapFrame @ fffff80000ba2cb0)<br>&gt; 0f SiDaNetPCI!EvtInterruptDpc+0x1ef<br>&gt; [c:\projekte\siemenshc\sidanet\driver\sidanet_interrupts.c @ 308]<br>&gt; 10 Wdf01000!FxInterrupt::_InterruptDpcThunk+0x53<br>&gt; 11 nt!KiRetireDpcList+0x1bc<br>&gt; 12 nt!KyRetireDpcList+0x5 (TrapFrame @ fffff80000ba2e70)
> 13 nt!KiDispatchInterruptContinue
> 14 nt!KiDpcInterruptBypass+0x13
> 15 nt!KiInterruptDispatchNoLock+0x1fc (TrapFrame @ fffff88004cf2890)<br>&gt; 16 igdkmd64!hybDriverEntry+0x2856b7<br>&gt; 17 igdkmd64!hybDriverEntry+0x54aa0<br>&gt; 18 igdkmd64!hybDriverEntry+0x1091a2<br>&gt; 19 igdkmd64!hybDriverEntry+0x117306<br>&gt; 1a igdkmd64!hybDriverEntry+0x1181cf<br>&gt; 1b igdkmd64!hybDriverEntry+0x1185a8<br>&gt; 1c igdkmd64!hybDriverEntry+0xfbc40<br>&gt; 1d igdkmd64!hybDriverEntry+0xfc264<br>&gt; 1e igdkmd64!hybDriverEntry+0x1190d<br>&gt; 1f dxgkrnl!DXGCONTEXT::Render+0x5f9<br>&gt; 20 dxgkrnl!DxgkRender+0x3e7<br>&gt; 21 win32k!NtGdiDdDDIRender+0x12<br>&gt; 22 nt!KiSystemServiceCopyEnd+0x13 (TrapFrame @ fffff88004cf3c20)
> 23 0x7fefe9113fa<br>&gt; 24 0x7fef79319dd
>
> I have no idea why the DPC freezes right behind the KdPrint command… Can
> somebody help me out on this?
>
> Thanks,
> Torben
>
> —
> 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
>