585 lines
16 KiB
C
585 lines
16 KiB
C
/*++
|
||
|
||
Copyright (c) 1993 Microsoft Corporation
|
||
|
||
Module Name:
|
||
|
||
timer.c
|
||
|
||
Abstract:
|
||
|
||
This module contains code which implements the receive and send timeouts
|
||
for each connection.
|
||
|
||
Author:
|
||
|
||
Colin Watson [ColinW] 21-Feb-1993
|
||
Anoop Anantha [AnoopA] 24-Jun-1998
|
||
|
||
Environment:
|
||
|
||
Kernel mode
|
||
|
||
Revision History:
|
||
|
||
--*/
|
||
|
||
#include "procs.h"
|
||
|
||
//
|
||
// The debug trace level
|
||
//
|
||
|
||
#define Dbg (DEBUG_TRACE_TIMER)
|
||
|
||
LARGE_INTEGER DueTime;
|
||
KDPC NwDpc; // DPC object for timeouts.
|
||
KTIMER Timer; // kernel timer for this request.
|
||
ULONG ScavengerTickCount;
|
||
|
||
BOOLEAN WorkerRunning = FALSE;
|
||
WORK_QUEUE_ITEM WorkItem;
|
||
|
||
#ifdef NWDBG
|
||
BOOLEAN DisableTimer = FALSE;
|
||
#endif
|
||
|
||
//
|
||
// TimerStop reflects the state of the timer.
|
||
//
|
||
|
||
BOOLEAN TimerStop = TRUE;
|
||
|
||
VOID
|
||
TimerDPC(
|
||
IN PKDPC Dpc,
|
||
IN PVOID Context,
|
||
IN PVOID SystemArgument1,
|
||
IN PVOID SystemArgument2
|
||
);
|
||
|
||
#if 0
|
||
|
||
//
|
||
// Not Pageable because it may be called from PnPSetPower() and because
|
||
// it holds a spinlock
|
||
//
|
||
|
||
StartTimer (VOID)
|
||
StopTimer (VOID)
|
||
#endif
|
||
|
||
|
||
|
||
VOID
|
||
StartTimer(
|
||
VOID
|
||
)
|
||
/*++
|
||
|
||
Routine Description:
|
||
|
||
This routine starts the timer ticking.
|
||
|
||
Arguments:
|
||
|
||
None.
|
||
|
||
Return Value:
|
||
|
||
None.
|
||
|
||
--*/
|
||
{
|
||
KIRQL OldIrql;
|
||
|
||
DebugTrace(+0, Dbg, "Entering StartTimer\n", 0);
|
||
|
||
KeAcquireSpinLock( &NwTimerSpinLock, &OldIrql );
|
||
|
||
if (TimerStop) {
|
||
|
||
//
|
||
// We need 18.21 ticks per second
|
||
//
|
||
|
||
DueTime.QuadPart = (( 100000 * MILLISECONDS ) / 1821) * -1;
|
||
|
||
//
|
||
// This is the first connection with timeouts specified.
|
||
// Set up the timer so that every 500 milliseconds we scan all the
|
||
// connections for timed out receive and sends.
|
||
//
|
||
|
||
KeInitializeDpc( &NwDpc, TimerDPC, NULL );
|
||
KeInitializeTimer( &Timer );
|
||
|
||
(VOID)KeSetTimer(&Timer, DueTime, &NwDpc);
|
||
TimerStop = FALSE;
|
||
|
||
DebugTrace(+0, Dbg, "StartTimer started timer\n", 0);
|
||
|
||
}
|
||
|
||
KeReleaseSpinLock( &NwTimerSpinLock, OldIrql );
|
||
}
|
||
|
||
|
||
VOID
|
||
StopTimer(
|
||
VOID
|
||
)
|
||
/*++
|
||
|
||
Routine Description:
|
||
|
||
This routine stops the timer. It blocks until the timer has stopped.
|
||
|
||
Arguments:
|
||
|
||
None.
|
||
|
||
Return Value:
|
||
|
||
None.
|
||
|
||
--*/
|
||
{
|
||
KIRQL OldIrql;
|
||
|
||
DebugTrace(+0, Dbg, "Entering StopTimer\n", 0);
|
||
|
||
KeAcquireSpinLock( &NwTimerSpinLock, &OldIrql );
|
||
|
||
if (!TimerStop) {
|
||
|
||
KeCancelTimer( &Timer );
|
||
TimerStop = TRUE;
|
||
DebugTrace(+0, Dbg, "StopTimer stopped timer\n", 0);
|
||
}
|
||
|
||
KeReleaseSpinLock( &NwTimerSpinLock, OldIrql );
|
||
|
||
}
|
||
|
||
|
||
VOID
|
||
TimerDPC(
|
||
IN PKDPC Dpc,
|
||
IN PVOID Context,
|
||
IN PVOID SystemArgument1,
|
||
IN PVOID SystemArgument2
|
||
)
|
||
/*++
|
||
|
||
Routine Description:
|
||
|
||
This routine is called to search for timed out send and receive
|
||
requests. This routine is called at DPC level.
|
||
|
||
Arguments:
|
||
|
||
Dpc - Unused.
|
||
Context - Unused.
|
||
SystemArgument1 - Unused.
|
||
SystemArgument2 - Unused.
|
||
|
||
Return Value:
|
||
|
||
None.
|
||
|
||
--*/
|
||
|
||
{
|
||
PLIST_ENTRY ScbQueueEntry;
|
||
PLIST_ENTRY NextScbQueueEntry;
|
||
PLIST_ENTRY IrpContextEntry;
|
||
PLIST_ENTRY NextIrpContextEntry;
|
||
SHORT RetryCount;
|
||
PIRP_CONTEXT pIrpContext;
|
||
LARGE_INTEGER CurrentTime = {0, 0};
|
||
WCHAR AnonymousName[] = L"UNKNOWN";
|
||
PWCHAR ServerLogName;
|
||
PWORK_CONTEXT workContext;
|
||
|
||
|
||
//
|
||
// For each Server see if there is a timeout to process.
|
||
//
|
||
|
||
#ifdef NWDBG
|
||
if ( DisableTimer ) {
|
||
//
|
||
// Reset the timer to run for another tick.
|
||
//
|
||
|
||
(VOID)KeSetTimer ( &Timer, DueTime, &NwDpc);
|
||
|
||
return;
|
||
}
|
||
#endif
|
||
|
||
//DebugTrace(+1, Dbg, "TimerDpc....\n", 0);
|
||
|
||
//
|
||
// Scan through the Scb's looking for timed out requests.
|
||
//
|
||
|
||
KeAcquireSpinLockAtDpcLevel( &ScbSpinLock );
|
||
|
||
ScbQueueEntry = ScbQueue.Flink;
|
||
|
||
if (ScbQueueEntry != &ScbQueue) {
|
||
PNONPAGED_SCB pNpScb = CONTAINING_RECORD(ScbQueueEntry,
|
||
NONPAGED_SCB,
|
||
ScbLinks);
|
||
NwQuietReferenceScb( pNpScb );
|
||
}
|
||
|
||
for (;
|
||
ScbQueueEntry != &ScbQueue ;
|
||
ScbQueueEntry = NextScbQueueEntry ) {
|
||
|
||
PNONPAGED_SCB pNpScb = CONTAINING_RECORD(ScbQueueEntry,
|
||
NONPAGED_SCB,
|
||
ScbLinks);
|
||
|
||
// Obtain a pointer to the next SCB in the SCB list before
|
||
// dereferencing the current one.
|
||
//
|
||
|
||
NextScbQueueEntry = pNpScb->ScbLinks.Flink;
|
||
|
||
if (NextScbQueueEntry != &ScbQueue) {
|
||
PNONPAGED_SCB pNextNpScb = CONTAINING_RECORD(NextScbQueueEntry,
|
||
NONPAGED_SCB,
|
||
ScbLinks);
|
||
//
|
||
// Reference the next entry in the list to ensure the scavenger
|
||
// doesn't put it on another list or destroy it.
|
||
//
|
||
|
||
NwQuietReferenceScb( pNextNpScb );
|
||
}
|
||
|
||
KeReleaseSpinLockFromDpcLevel( &ScbSpinLock );
|
||
|
||
//
|
||
// Acquire the Scb specific spin lock to protect access
|
||
// the the Scb fields.
|
||
//
|
||
|
||
KeAcquireSpinLockAtDpcLevel( &pNpScb->NpScbSpinLock );
|
||
|
||
//
|
||
// Look at the first request on the queue only (since it is
|
||
// the only active request).
|
||
//
|
||
|
||
if ( ( !IsListEmpty( &pNpScb->Requests )) &&
|
||
( !pNpScb->Sending ) &&
|
||
( pNpScb->OkToReceive ) &&
|
||
( --pNpScb->TimeOut <= 0 ) ) {
|
||
|
||
PIRP_CONTEXT pIrpContext;
|
||
|
||
//
|
||
// This request has timed out. Try to retransmit the request.
|
||
//
|
||
|
||
pIrpContext = CONTAINING_RECORD(
|
||
pNpScb->Requests.Flink,
|
||
IRP_CONTEXT,
|
||
NextRequest);
|
||
|
||
pNpScb->TimeOut = pNpScb->MaxTimeOut;
|
||
|
||
//
|
||
// Check the retry count while we own the spin lock.
|
||
//
|
||
|
||
RetryCount = --pNpScb->RetryCount;
|
||
NwQuietDereferenceScb( pNpScb );
|
||
|
||
//
|
||
// Set OkToReceive to FALSE, so that if we receive a response
|
||
// right now, our receive handler won't handle the response
|
||
// and cause IRP context to be freed.
|
||
//
|
||
|
||
pNpScb->OkToReceive = FALSE;
|
||
KeReleaseSpinLockFromDpcLevel( &pNpScb->NpScbSpinLock );
|
||
|
||
if ( pIrpContext->pOriginalIrp->Cancel ) {
|
||
|
||
//
|
||
// This IRP has been cancelled. Call the callback routine.
|
||
//
|
||
|
||
DebugTrace(+0, Dbg, "Timer cancel IRP %X\n", pIrpContext->pOriginalIrp );
|
||
pIrpContext->pEx( pIrpContext, 0, NULL );
|
||
|
||
} else if ( RetryCount >= 0) {
|
||
|
||
//
|
||
// We're not out of retries. Resend the request packet.
|
||
//
|
||
// First adjust the send timeout up. Adjust the timeout
|
||
// more slowly on a close by server.
|
||
//
|
||
|
||
if ( pNpScb->SendTimeout < pNpScb->MaxTimeOut ) {
|
||
if ( pNpScb->TickCount <= 4 ) {
|
||
pNpScb->SendTimeout++;
|
||
} else {
|
||
pNpScb->SendTimeout = pNpScb->SendTimeout * 3 / 2;
|
||
if ( pNpScb->SendTimeout > pNpScb->MaxTimeOut ) {
|
||
pNpScb->SendTimeout = pNpScb->MaxTimeOut;
|
||
}
|
||
}
|
||
}
|
||
|
||
pNpScb->TimeOut = pNpScb->SendTimeout;
|
||
DebugTrace(+0, Dbg, "Adjusting send timeout: %x\n", pIrpContext );
|
||
DebugTrace(+0, Dbg, "Adjusting send timeout to: %d\n", pNpScb->TimeOut );
|
||
|
||
if ( pIrpContext->TimeoutRoutine != NULL ) {
|
||
|
||
DebugTrace(+0, Dbg, "Timeout Routine, retry %x\n", RetryCount+1);
|
||
DebugTrace(+0, Dbg, "Calling TimeoutRoutine, %x\n", pIrpContext->TimeoutRoutine);
|
||
pIrpContext->TimeoutRoutine( pIrpContext );
|
||
|
||
} else {
|
||
|
||
DebugTrace(+0, Dbg, "Resending Packet, retry %x\n", RetryCount+1);
|
||
PreparePacket( pIrpContext, pIrpContext->pOriginalIrp, pIrpContext->TxMdl );
|
||
|
||
SetFlag( pIrpContext->Flags, IRP_FLAG_RETRY_SEND );
|
||
SendNow( pIrpContext );
|
||
}
|
||
|
||
Stats.FailedSessions++;
|
||
|
||
} else {
|
||
|
||
ASSERT( pIrpContext->pEx != NULL );
|
||
|
||
//
|
||
// We are out of retries.
|
||
//
|
||
|
||
if ( (!BooleanFlagOn( pIrpContext->Flags, IRP_FLAG_REROUTE_IN_PROGRESS ) &&
|
||
((BooleanFlagOn( pIrpContext->Flags, IRP_FLAG_REROUTE_ATTEMPTED ) ||
|
||
((NwAbsoluteTotalWaitTime != 0) && (pNpScb->TotalWaitTime >= NwAbsoluteTotalWaitTime )))))) {
|
||
|
||
|
||
ClearFlag( pIrpContext->Flags, IRP_FLAG_RETRY_SEND );
|
||
|
||
//
|
||
// He have already attempted to reroute the request.
|
||
// Give up.
|
||
//
|
||
|
||
DebugTrace(+0, Dbg, "Abandon Exchange\n", 0 );
|
||
|
||
if ( pIrpContext->pNpScb != &NwPermanentNpScb ) {
|
||
|
||
//
|
||
// Reset to the attaching state. If the server
|
||
// is dead, the next attempt to open a handle will
|
||
// fail with a better error than unexpected network
|
||
// error.
|
||
//
|
||
|
||
pIrpContext->pNpScb->State = SCB_STATE_ATTACHING;
|
||
|
||
//
|
||
// Determine the CurrentTime. We need to know if
|
||
// TimeOutEventInterval minutes have passed before
|
||
// we log the next time-out event.
|
||
//
|
||
|
||
KeQuerySystemTime( &CurrentTime );
|
||
|
||
if ( CanLogTimeOutEvent( pNpScb->NwNextEventTime,
|
||
CurrentTime
|
||
)) {
|
||
|
||
if ( pNpScb->ServerName.Buffer != NULL ) {
|
||
ServerLogName = pNpScb->ServerName.Buffer;
|
||
} else {
|
||
ServerLogName = &AnonymousName[0];
|
||
}
|
||
|
||
Error(
|
||
EVENT_NWRDR_TIMEOUT,
|
||
STATUS_UNEXPECTED_NETWORK_ERROR,
|
||
NULL,
|
||
0,
|
||
1,
|
||
ServerLogName );
|
||
|
||
//
|
||
// Set the LastEventTime to the CurrentTime
|
||
//
|
||
|
||
UpdateNextEventTime(
|
||
pNpScb->NwNextEventTime,
|
||
CurrentTime,
|
||
TimeOutEventInterval
|
||
);
|
||
}
|
||
|
||
}
|
||
|
||
pIrpContext->ResponseParameters.Error = ERROR_UNEXP_NET_ERR;
|
||
pIrpContext->pEx( pIrpContext, 0, NULL );
|
||
|
||
} else if (!BooleanFlagOn(pIrpContext->Flags, IRP_FLAG_REROUTE_IN_PROGRESS)) {
|
||
|
||
//
|
||
// Attempt to reroute the request if it hasn't already been rerouted
|
||
//
|
||
|
||
SetFlag( pIrpContext->Flags, IRP_FLAG_REROUTE_ATTEMPTED );
|
||
|
||
if ((WorkerThreadRunning == TRUE) && (workContext = AllocateWorkContext())){
|
||
|
||
//
|
||
// Prepare the work context
|
||
//
|
||
|
||
workContext->pIrpC = pIrpContext;
|
||
workContext->NodeWorkCode = NWC_NWC_REROUTE;
|
||
|
||
//
|
||
// and queue it.
|
||
//
|
||
DebugTrace( 0, Dbg, "Queueing reroute work.\n", 0 );
|
||
|
||
//
|
||
// Make sure we don't give up on this IrpContext. Also, reference
|
||
// the SCB so that it doesn't get scavenged.
|
||
//
|
||
|
||
SetFlag( pIrpContext->Flags, IRP_FLAG_REROUTE_IN_PROGRESS );
|
||
NwReferenceScb( pIrpContext->pNpScb );
|
||
|
||
KeInsertQueue( &KernelQueue,
|
||
&workContext->Next
|
||
);
|
||
|
||
} else {
|
||
|
||
//
|
||
// The worker thread is not running or, we could not
|
||
// allocate a work context. Hence, we cannot
|
||
// attempt the reroute.
|
||
//
|
||
pIrpContext->ResponseParameters.Error = ERROR_UNEXP_NET_ERR;
|
||
pIrpContext->pEx( pIrpContext, 0, NULL );
|
||
|
||
}
|
||
|
||
}
|
||
}
|
||
|
||
} else {
|
||
|
||
if ( ( !IsListEmpty( &pNpScb->Requests )) &&
|
||
( !pNpScb->Sending ) &&
|
||
( pNpScb->OkToReceive ) ) {
|
||
|
||
DebugTrace( 0, Dbg, "TimeOut %d\n", pNpScb->TimeOut );
|
||
}
|
||
|
||
//
|
||
// Nothing to do for this SCB. Dereference this SCB and
|
||
// release the spin lock.
|
||
//
|
||
|
||
KeReleaseSpinLockFromDpcLevel( &pNpScb->NpScbSpinLock );
|
||
NwQuietDereferenceScb( pNpScb );
|
||
}
|
||
|
||
KeAcquireSpinLockAtDpcLevel( &ScbSpinLock );
|
||
|
||
}
|
||
|
||
KeReleaseSpinLockFromDpcLevel( &ScbSpinLock );
|
||
|
||
//
|
||
// Now see if the scavenger routine needs to be run.
|
||
// Only ever queue one workitem.
|
||
//
|
||
|
||
KeAcquireSpinLockAtDpcLevel( &NwScavengerSpinLock );
|
||
|
||
NwScavengerTickCount++;
|
||
if (( !WorkerRunning ) && ( !fPoweringDown ) &&
|
||
( NwScavengerTickCount > NwScavengerTickRunCount )) {
|
||
|
||
ExInitializeWorkItem( &WorkItem, NwScavengerRoutine, &WorkItem );
|
||
ExQueueWorkItem( &WorkItem, DelayedWorkQueue );
|
||
NwScavengerTickCount = 0;
|
||
WorkerRunning = TRUE;
|
||
}
|
||
|
||
KeReleaseSpinLockFromDpcLevel( &NwScavengerSpinLock );
|
||
|
||
//
|
||
// Scan the list of pending locks, looking for locks to retry.
|
||
//
|
||
|
||
KeAcquireSpinLockAtDpcLevel( &NwPendingLockSpinLock );
|
||
|
||
for (IrpContextEntry = NwPendingLockList.Flink ;
|
||
IrpContextEntry != &NwPendingLockList ;
|
||
IrpContextEntry = NextIrpContextEntry ) {
|
||
|
||
NextIrpContextEntry = IrpContextEntry->Flink;
|
||
pIrpContext = CONTAINING_RECORD( IrpContextEntry, IRP_CONTEXT, NextRequest );
|
||
|
||
if ( --pIrpContext->Specific.Lock.Key <= 0 ) {
|
||
|
||
//
|
||
// Remove the IRP Context from the queue and reattempt the lock.
|
||
// Set the SEQUENCE_NO_REQUIRED flag so that the packet gets
|
||
// renumbered.
|
||
//
|
||
|
||
RemoveEntryList( &pIrpContext->NextRequest );
|
||
SetFlag( pIrpContext->Flags, IRP_FLAG_SEQUENCE_NO_REQUIRED );
|
||
PrepareAndSendPacket( pIrpContext );
|
||
}
|
||
|
||
}
|
||
|
||
KeReleaseSpinLockFromDpcLevel( &NwPendingLockSpinLock );
|
||
|
||
//
|
||
// Reset the timer to run for another tick if nobody has cancelled it
|
||
// in the meantime.
|
||
//
|
||
|
||
KeAcquireSpinLockAtDpcLevel( &NwTimerSpinLock );
|
||
|
||
if (!TimerStop) {
|
||
(VOID)KeSetTimer ( &Timer, DueTime, &NwDpc);
|
||
}
|
||
|
||
KeReleaseSpinLockFromDpcLevel( &NwTimerSpinLock );
|
||
|
||
//DebugTrace(-1, Dbg, "TimerDpc\n", 0);
|
||
return;
|
||
|
||
UNREFERENCED_PARAMETER (Dpc);
|
||
UNREFERENCED_PARAMETER (Context);
|
||
UNREFERENCED_PARAMETER (SystemArgument1);
|
||
UNREFERENCED_PARAMETER (SystemArgument2);
|
||
|
||
}
|
||
|
||
|
||
|