KeSetTimer expiration
in [Device Drivers]
|
Prev: #pragma alloc_text
Next: Build
From: don.walker@honeywell.com on 9 Feb 2006 15:44 I'm using KeSetTimer with a Dpc to implement an ACK/NAK requirement with a timeout. Here's an example of how this is supposed to work. My driver sends a message from the hardware and sets a timer. If the hardware receives an ACK/NAK before the timer expires, my driver cancels the timer and carries out some work. If the timer times out first, then my driver retries and sets the timer again. So the only sticky part is that the time is supposed to be 2 ms, less than the 10 ms resolution that seems to be the NT system constraint. So fine, I just figured I'd set it for 2 ms and expect to get 10 ms response time. Well surprisingly it appears that sometimes the timer expires immediately, not the 10 ms I was expecting. My basis for this statement is that every message I transmit or receive I log and timestamp with a 1 msec timer on my hardware (hardware clock is independent of Motherboard). What I find is that occasionally I transmit back to back (i.e. two transmissions with the exact same timestamp) along with a message stating that the ACK/NAK timer expired. Can someone explain what could be happening here? Below appears the functions I use to setup the timer and DPC followed by the DPC that implements the retries. Thanks. #define RT_ACKNAK_TIMER 2 typedef struct _TIMER_STRUCT { PDEVICE_EXTENSION pDeviceExtension; KDPC DpcObject; // DPC Object KTIMER Timer; // Timer Object PVOID TimerFunc; int Status; // Status of the timer (use the enum) LARGE_INTEGER lastTimeOut; // tracks last TimeOut value passed to StartTimer // used when restarting timer } TIMER_INFO, *PTIMER_INFO; // possible values for the Status variable of the timer info structure enum TIMER_STATUS {TIMER_NOT_INITIALIZED, TIMER_STOPPED, TIMER_STARTED, TIMER_SUSPENDED}; /****************************************************************************** * * FUNCTION: InitializeTimer * * DESCRIPTION: This function initializes a timer, its associated dpc, and * sets the timeout function * * INPUT PARAMETERS: pTimerInfo - Pointer to the timer info object * associated with the timer to * be initialized * * pTimerFunc - Pointer to a function to call when * the timer expires. This function * must be void and take no paremeters * * OUTPUT PARAMETERS: NTSTATUS - NTSTATUS code for the result * of all operations in this function * * IRQL: PASSIVE * * NOTES: * *****************************************************************************/ NTSTATUS InitializeTimer(IN PDEVICE_EXTENSION pDeviceExtension, IN PTIMER_INFO pTimerInfo, PVOID pTimerFunc) { NTSTATUS NtStatus = STATUS_SUCCESS; // Set the function to call when the timer goes off pTimerInfo->TimerFunc = pTimerFunc; // Initialize the dpc associated with the timer KeInitializeDpc(&pTimerInfo->DpcObject, TimerProc, pTimerInfo); // Initialize the timer object itself KeInitializeTimer(&pTimerInfo->Timer); pTimerInfo->Status = TIMER_STOPPED; pTimerInfo->lastTimeOut.LowPart = 0; pTimerInfo->lastTimeOut.HighPart = 0; pTimerInfo->pDeviceExtension = pDeviceExtension; return NtStatus; } /****************************************************************************** * * FUNCTION: StartTimer * * DESCRIPTION: Starts a kernel timer. When the timer expires, the DPC * specified in the InitializeTimer call is run. * * INPUT PARAMETERS: pTimerInfo - Pointer to the timer info object * associated with the timer to * be started * * TimeOut - Time in milliseconds to run the timer * for. Once the timer expires, the timer * procedure will be queued * * OUTPUT PARAMETERS: BOOLEAN * * IRQL: DISPATCH * * NOTES: * *****************************************************************************/ BOOLEAN StartTimer(IN PTIMER_INFO pTimerInfo, long TimeOut) { LARGE_INTEGER LargeTimeOut = RtlConvertLongToLargeInteger(TimeOut * -10000); BOOLEAN ReturnValue; if (pTimerInfo->Status != TIMER_STOPPED) return FALSE; // Attempt to start the timer, if the timer was already set // then it returns true, otherwise it returns false ReturnValue = KeSetTimer(&pTimerInfo->Timer, LargeTimeOut, &pTimerInfo->DpcObject); // Set timer state to started pTimerInfo->Status = TIMER_STARTED; pTimerInfo->lastTimeOut = LargeTimeOut; return ReturnValue; } /****************************************************************************** * * FUNCTION: TwoMsTimerExpired * * DESCRIPTION: This function is called when the activated 2mS timer has * expired. It sets the TX bus to the fail mode. * * INPUT PARAMETERS: Dpc pointer to DPC structure. see DDK documentation. * DeferredContext Pointer to TIMER_INFO structure. * SystemArgument1 Not used. * SystemArgument2 Not used. * * OUTPUT PARAMETERS: none * * IRQL: DISPATCH * * NOTES: * *****************************************************************************/ void TwoMsTimerExpired(IN PKDPC Dpc, IN PVOID DeferredContext, IN PVOID SystemArgument1, IN PVOID SystemArgument2) { PDEVICE_EXTENSION pDeviceExtension; PTCASSIMSTATE p; CS_FILE_PARMS fparms; pDeviceExtension = ((PTIMER_INFO)DeferredContext)->pDeviceExtension; p = &pDeviceExtension->TCAS_Simulator_State; RtlStringCchPrintfA(fparms.Buffer, MAX_WRITE_QUEUE_SIZE, "* ACK/NAK timer expired\n"); fparms.pFileInfo = &pDeviceExtension->Files[TCAS_FILE_TYPE]; // synchronize access to file queue w/ isr KeSynchronizeExecution(pDeviceExtension->pInterruptObject, CRIT_EnQueueFileWrite, (PVOID)&fparms); // Synchronize access to State Data with PASSIVE level and DPC on multiprocessor KeAcquireSpinLockAtDpcLevel(&pDeviceExtension->TCAS_Simulator_State.StateDataLock); // Synchronize access to State Data with ISR KeSynchronizeExecution(pDeviceExtension->pInterruptObject, CRIT_TXBusFail, (PVOID)pDeviceExtension); if (InterlockedExchange(&p->settimer[TCAS_TWOMS_TIMER], 0)) { StartTimer(&p->Timers[TCAS_TWOMS_TIMER], RT_ACKNAK_TIMER); } WriteQueueHasData(p->TCASFile); KeReleaseSpinLockFromDpcLevel(&pDeviceExtension->TCAS_Simulator_State.StateDataLock); }
From: Pavel A. on 9 Feb 2006 21:30 Well, unless you change the OS timer resolution, what you're doing is simply not reliable. Another possibility is increasing the timeout to the current tick value (10 or 15 ms) - and verify that you don't timeout too early using the timestamp timer, QueryPerformanceCounter (in this case go sleep for another tick). If the device really requires 2 ms timeout, it is just not Designed For Windows :) Regardrs, --PA "don.walker(a)honeywell.com" wrote: > I'm using KeSetTimer with a Dpc to implement an ACK/NAK requirement > with a timeout. Here's an example of how this is supposed to work. > > My driver sends a message from the hardware and sets a timer. > If the hardware receives an ACK/NAK before the timer expires, my driver > cancels the timer and carries out some work. > If the timer times out first, then my driver retries and sets the timer > again. > > So the only sticky part is that the time is supposed to be 2 ms, less > than the 10 ms resolution that seems to be the NT system constraint. So > fine, I just figured I'd set it for 2 ms and expect to get 10 ms > response time. > > Well surprisingly it appears that sometimes the timer expires > immediately, not the 10 ms I was expecting. My basis for this statement > is that every message I transmit or receive I log and timestamp with a > 1 msec timer on my hardware (hardware clock is independent of > Motherboard). What I find is that occasionally I transmit back to back > (i.e. two transmissions with the exact same timestamp) along with a > message stating that the ACK/NAK timer expired. Can someone explain > what could be happening here? Below appears the functions I use to > setup the timer and DPC followed by the DPC that implements the > retries. Thanks. > > #define RT_ACKNAK_TIMER 2 > > typedef struct _TIMER_STRUCT > { > PDEVICE_EXTENSION pDeviceExtension; > KDPC DpcObject; // DPC Object > KTIMER Timer; // Timer Object > > PVOID TimerFunc; > > int Status; // Status of the timer (use the > enum) > > LARGE_INTEGER lastTimeOut; // tracks last TimeOut value passed > to StartTimer > // used when restarting timer > } TIMER_INFO, *PTIMER_INFO; > > // possible values for the Status variable of the timer info structure > enum TIMER_STATUS {TIMER_NOT_INITIALIZED, TIMER_STOPPED, TIMER_STARTED, > TIMER_SUSPENDED}; > > /****************************************************************************** > * > * FUNCTION: InitializeTimer > * > * DESCRIPTION: This function initializes a timer, its associated > dpc, and > * sets the timeout function > * > * INPUT PARAMETERS: pTimerInfo - Pointer to the timer info > object > * associated with the timer to > * be initialized > * > * pTimerFunc - Pointer to a function to call > when > * the timer expires. This > function > * must be void and take no > paremeters > * > * OUTPUT PARAMETERS: NTSTATUS - NTSTATUS code for the result > * of all operations in this > function > * > * IRQL: PASSIVE > * > * NOTES: > * > > *****************************************************************************/ > > NTSTATUS InitializeTimer(IN PDEVICE_EXTENSION pDeviceExtension, IN > PTIMER_INFO pTimerInfo, PVOID pTimerFunc) > { > NTSTATUS NtStatus = STATUS_SUCCESS; > > // Set the function to call when the timer goes off > pTimerInfo->TimerFunc = pTimerFunc; > > // Initialize the dpc associated with the timer > KeInitializeDpc(&pTimerInfo->DpcObject, > TimerProc, > pTimerInfo); > > // Initialize the timer object itself > KeInitializeTimer(&pTimerInfo->Timer); > > pTimerInfo->Status = TIMER_STOPPED; > pTimerInfo->lastTimeOut.LowPart = 0; > pTimerInfo->lastTimeOut.HighPart = 0; > pTimerInfo->pDeviceExtension = pDeviceExtension; > > return NtStatus; > } > > /****************************************************************************** > * > * FUNCTION: StartTimer > * > * DESCRIPTION: Starts a kernel timer. When the timer expires, the > DPC > * specified in the InitializeTimer call is run. > * > * INPUT PARAMETERS: pTimerInfo - Pointer to the timer info > object > * associated with the timer to > * be started > * > * TimeOut - Time in milliseconds to run the > timer > * for. Once the timer expires, > the timer > * procedure will be queued > * > * OUTPUT PARAMETERS: BOOLEAN > * > * IRQL: DISPATCH > * > * NOTES: > * > > *****************************************************************************/ > BOOLEAN StartTimer(IN PTIMER_INFO pTimerInfo, long TimeOut) > { > LARGE_INTEGER LargeTimeOut = RtlConvertLongToLargeInteger(TimeOut * > -10000); > BOOLEAN ReturnValue; > > if (pTimerInfo->Status != TIMER_STOPPED) > return FALSE; > > // Attempt to start the timer, if the timer was already set > // then it returns true, otherwise it returns false > ReturnValue = KeSetTimer(&pTimerInfo->Timer, > LargeTimeOut, > &pTimerInfo->DpcObject); > > // Set timer state to started > pTimerInfo->Status = TIMER_STARTED; > pTimerInfo->lastTimeOut = LargeTimeOut; > > return ReturnValue; > } > > /****************************************************************************** > * > * FUNCTION: TwoMsTimerExpired > * > * DESCRIPTION: This function is called when the activated 2mS timer > has > * expired. It sets the TX bus to the fail mode. > * > * INPUT PARAMETERS: Dpc pointer to DPC structure. see DDK > documentation. > * DeferredContext Pointer to TIMER_INFO > structure. > * SystemArgument1 Not used. > * SystemArgument2 Not used. > * > * OUTPUT PARAMETERS: none > * > * IRQL: DISPATCH > * > * NOTES: > * > > *****************************************************************************/ > void TwoMsTimerExpired(IN PKDPC Dpc, > IN PVOID DeferredContext, > IN PVOID SystemArgument1, > IN PVOID SystemArgument2) > { > PDEVICE_EXTENSION pDeviceExtension; > PTCASSIMSTATE p; > CS_FILE_PARMS fparms; > > pDeviceExtension = ((PTIMER_INFO)DeferredContext)->pDeviceExtension; > p = &pDeviceExtension->TCAS_Simulator_State; > > > RtlStringCchPrintfA(fparms.Buffer, MAX_WRITE_QUEUE_SIZE, "* ACK/NAK > timer expired\n"); > fparms.pFileInfo = &pDeviceExtension->Files[TCAS_FILE_TYPE]; > // synchronize access to file queue w/ isr > KeSynchronizeExecution(pDeviceExtension->pInterruptObject, > CRIT_EnQueueFileWrite, > (PVOID)&fparms); > > // Synchronize access to State Data with PASSIVE level and DPC on > multiprocessor > > KeAcquireSpinLockAtDpcLevel(&pDeviceExtension->TCAS_Simulator_State.StateDataLock); > // Synchronize access to State Data with ISR > KeSynchronizeExecution(pDeviceExtension->pInterruptObject, > CRIT_TXBusFail, > (PVOID)pDeviceExtension); > if (InterlockedExchange(&p->settimer[TCAS_TWOMS_TIMER], 0)) > { > StartTimer(&p->Timers[TCAS_TWOMS_TIMER], RT_ACKNAK_TIMER); > } > WriteQueueHasData(p->TCASFile); > > KeReleaseSpinLockFromDpcLevel(&pDeviceExtension->TCAS_Simulator_State.StateDataLock); > } > >
From: Doron Holan [MS] on 10 Feb 2006 01:37 also look at ExSetTimerResolution, you may be able to crank down the resolution to what you need. 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." <pavel_a(a)NOwritemeNO.com> wrote in message news:33EB5032-8FBE-4571-B2F7-5905D26AD4E4(a)microsoft.com... > Well, unless you change the OS timer resolution, what you're doing is > simply not reliable. Another possibility is increasing the timeout to the > current tick value > (10 or 15 ms) - and verify that you don't timeout too early using the > timestamp timer, > QueryPerformanceCounter (in this case go sleep for another tick). > > If the device really requires 2 ms timeout, it is just not Designed For > Windows :) > > Regardrs, > --PA > > > "don.walker(a)honeywell.com" wrote: >> I'm using KeSetTimer with a Dpc to implement an ACK/NAK requirement >> with a timeout. Here's an example of how this is supposed to work. >> >> My driver sends a message from the hardware and sets a timer. >> If the hardware receives an ACK/NAK before the timer expires, my driver >> cancels the timer and carries out some work. >> If the timer times out first, then my driver retries and sets the timer >> again. >> >> So the only sticky part is that the time is supposed to be 2 ms, less >> than the 10 ms resolution that seems to be the NT system constraint. So >> fine, I just figured I'd set it for 2 ms and expect to get 10 ms >> response time. >> >> Well surprisingly it appears that sometimes the timer expires >> immediately, not the 10 ms I was expecting. My basis for this statement >> is that every message I transmit or receive I log and timestamp with a >> 1 msec timer on my hardware (hardware clock is independent of >> Motherboard). What I find is that occasionally I transmit back to back >> (i.e. two transmissions with the exact same timestamp) along with a >> message stating that the ACK/NAK timer expired. Can someone explain >> what could be happening here? Below appears the functions I use to >> setup the timer and DPC followed by the DPC that implements the >> retries. Thanks. >> >> #define RT_ACKNAK_TIMER 2 >> >> typedef struct _TIMER_STRUCT >> { >> PDEVICE_EXTENSION pDeviceExtension; >> KDPC DpcObject; // DPC Object >> KTIMER Timer; // Timer Object >> >> PVOID TimerFunc; >> >> int Status; // Status of the timer (use the >> enum) >> >> LARGE_INTEGER lastTimeOut; // tracks last TimeOut value passed >> to StartTimer >> // used when restarting timer >> } TIMER_INFO, *PTIMER_INFO; >> >> // possible values for the Status variable of the timer info structure >> enum TIMER_STATUS {TIMER_NOT_INITIALIZED, TIMER_STOPPED, TIMER_STARTED, >> TIMER_SUSPENDED}; >> >> /****************************************************************************** >> * >> * FUNCTION: InitializeTimer >> * >> * DESCRIPTION: This function initializes a timer, its associated >> dpc, and >> * sets the timeout function >> * >> * INPUT PARAMETERS: pTimerInfo - Pointer to the timer info >> object >> * associated with the timer to >> * be initialized >> * >> * pTimerFunc - Pointer to a function to call >> when >> * the timer expires. This >> function >> * must be void and take no >> paremeters >> * >> * OUTPUT PARAMETERS: NTSTATUS - NTSTATUS code for the result >> * of all operations in this >> function >> * >> * IRQL: PASSIVE >> * >> * NOTES: >> * >> >> *****************************************************************************/ >> >> NTSTATUS InitializeTimer(IN PDEVICE_EXTENSION pDeviceExtension, IN >> PTIMER_INFO pTimerInfo, PVOID pTimerFunc) >> { >> NTSTATUS NtStatus = STATUS_SUCCESS; >> >> // Set the function to call when the timer goes off >> pTimerInfo->TimerFunc = pTimerFunc; >> >> // Initialize the dpc associated with the timer >> KeInitializeDpc(&pTimerInfo->DpcObject, >> TimerProc, >> pTimerInfo); >> >> // Initialize the timer object itself >> KeInitializeTimer(&pTimerInfo->Timer); >> >> pTimerInfo->Status = TIMER_STOPPED; >> pTimerInfo->lastTimeOut.LowPart = 0; >> pTimerInfo->lastTimeOut.HighPart = 0; >> pTimerInfo->pDeviceExtension = pDeviceExtension; >> >> return NtStatus; >> } >> >> /****************************************************************************** >> * >> * FUNCTION: StartTimer >> * >> * DESCRIPTION: Starts a kernel timer. When the timer expires, the >> DPC >> * specified in the InitializeTimer call is run. >> * >> * INPUT PARAMETERS: pTimerInfo - Pointer to the timer info >> object >> * associated with the timer to >> * be started >> * >> * TimeOut - Time in milliseconds to run the >> timer >> * for. Once the timer expires, >> the timer >> * procedure will be queued >> * >> * OUTPUT PARAMETERS: BOOLEAN >> * >> * IRQL: DISPATCH >> * >> * NOTES: >> * >> >> *****************************************************************************/ >> BOOLEAN StartTimer(IN PTIMER_INFO pTimerInfo, long TimeOut) >> { >> LARGE_INTEGER LargeTimeOut = RtlConvertLongToLargeInteger(TimeOut * >> -10000); >> BOOLEAN ReturnValue; >> >> if (pTimerInfo->Status != TIMER_STOPPED) >> return FALSE; >> >> // Attempt to start the timer, if the timer was already set >> // then it returns true, otherwise it returns false >> ReturnValue = KeSetTimer(&pTimerInfo->Timer, >> LargeTimeOut, >> &pTimerInfo->DpcObject); >> >> // Set timer state to started >> pTimerInfo->Status = TIMER_STARTED; >> pTimerInfo->lastTimeOut = LargeTimeOut; >> >> return ReturnValue; >> } >> >> /****************************************************************************** >> * >> * FUNCTION: TwoMsTimerExpired >> * >> * DESCRIPTION: This function is called when the activated 2mS timer >> has >> * expired. It sets the TX bus to the fail mode. >> * >> * INPUT PARAMETERS: Dpc pointer to DPC structure. see DDK >> documentation. >> * DeferredContext Pointer to TIMER_INFO >> structure. >> * SystemArgument1 Not used. >> * SystemArgument2 Not used. >> * >> * OUTPUT PARAMETERS: none >> * >> * IRQL: DISPATCH >> * >> * NOTES: >> * >> >> *****************************************************************************/ >> void TwoMsTimerExpired(IN PKDPC Dpc, >> IN PVOID DeferredContext, >> IN PVOID SystemArgument1, >> IN PVOID SystemArgument2) >> { >> PDEVICE_EXTENSION pDeviceExtension; >> PTCASSIMSTATE p; >> CS_FILE_PARMS fparms; >> >> pDeviceExtension = ((PTIMER_INFO)DeferredContext)->pDeviceExtension; >> p = &pDeviceExtension->TCAS_Simulator_State; >> >> >> RtlStringCchPrintfA(fparms.Buffer, MAX_WRITE_QUEUE_SIZE, "* ACK/NAK >> timer expired\n"); >> fparms.pFileInfo = &pDeviceExtension->Files[TCAS_FILE_TYPE]; >> // synchronize access to file queue w/ isr >> KeSynchronizeExecution(pDeviceExtension->pInterruptObject, >> CRIT_EnQueueFileWrite, >> (PVOID)&fparms); >> >> // Synchronize access to State Data with PASSIVE level and DPC on >> multiprocessor >> >> KeAcquireSpinLockAtDpcLevel(&pDeviceExtension->TCAS_Simulator_State.StateDataLock); >> // Synchronize access to State Data with ISR >> KeSynchronizeExecution(pDeviceExtension->pInterruptObject, >> CRIT_TXBusFail, >> (PVOID)pDeviceExtension); >> if (InterlockedExchange(&p->settimer[TCAS_TWOMS_TIMER], 0)) >> { >> StartTimer(&p->Timers[TCAS_TWOMS_TIMER], RT_ACKNAK_TIMER); >> } >> WriteQueueHasData(p->TCASFile); >> >> KeReleaseSpinLockFromDpcLevel(&pDeviceExtension->TCAS_Simulator_State.StateDataLock); >> } >> >>
From: don.walker@honeywell.com on 10 Feb 2006 10:17 Well not meeting the 2 ms turnaround is not a big deal. What is a big deal is having the timer timeout immediately. What I want to understand is the timer architecture supposed to behave this way? Or do I have a bug in my driver that is causing this to happen? If I changed my timeout constant to 20 ms would this behavior just go away? I think I'll go try that today and see what happens. I tried 10 ms yesterday and it had no effect on the behavior. In response to the 2 ms comment...I totally agree this protocol is not designed for Windows. However it is a convenient platform for this application so I'll live with the limitations. I can post-process the log file to verify the 2 ms behavior of the remote system.
From: Pavel A. on 11 Feb 2006 13:08
Just a wild guess... are you using the compiler from DDK win2003 Sp1? some earlier VS compilers have a bug in code generation for 64 bit expressions like (TimeOut * -10000) . Rewrite it for example as - (TimeOut * 10000) . --PA <don.walker(a)honeywell.com> wrote in message news:1139584627.012313.6610(a)g14g2000cwa.googlegroups.com... > Well not meeting the 2 ms turnaround is not a big deal. What is a big > deal is having the timer timeout immediately. What I want to understand > is the timer architecture supposed to behave this way? Or do I have a > bug in my driver that is causing this to happen? If I changed my > timeout constant to 20 ms would this behavior just go away? I think > I'll go try that today and see what happens. I tried 10 ms yesterday > and it had no effect on the behavior. > > In response to the 2 ms comment...I totally agree this protocol is not > designed for Windows. However it is a convenient platform for this > application so I'll live with the limitations. I can post-process the > log file to verify the 2 ms behavior of the remote system. > |