path: root/private/nw/rdr/timer.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

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

//
//  When we want to stop the timer, set TimerStop to TRUE. When the timer
//  is stopped TimerStopped will be set to the signalled state.
//

BOOLEAN TimerStop;
KEVENT TimerStopped;

VOID
TimerDPC(
    IN PKDPC Dpc,
    IN PVOID Context,
    IN PVOID SystemArgument1,
    IN PVOID SystemArgument2
    );

#ifdef ALLOC_PRAGMA
#pragma alloc_text( PAGE, StartTimer )
#pragma alloc_text( PAGE, StopTimer )

#endif


VOID
StartTimer(
    VOID
    )
/*++

Routine Description:

    This routine starts the timer ticking.

Arguments:

    None.

Return Value:

    None.

--*/
{
    PAGED_CODE();

    //
    //  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.
    //

    TimerStop = FALSE;

    KeInitializeEvent( &TimerStopped, SynchronizationEvent, FALSE );
    KeInitializeDpc( &NwDpc, TimerDPC, NULL );
    KeInitializeTimer( &Timer );

    (VOID)KeSetTimer(&Timer, DueTime, &NwDpc);

    DebugTrace(+0, Dbg, "StartTimer\n", 0);
}


VOID
StopTimer(
    VOID
    )
/*++

Routine Description:

    This routine stops the timer.  It blocks until the timer has stopped.

Arguments:

    None.

Return Value:

    None.

--*/
{
    PAGED_CODE();

    if (TimerStop == FALSE) {
        TimerStop = TRUE;

        DebugTrace(+0, Dbg, "StopTimer\n", 0);
        KeWaitForSingleObject (&TimerStopped, Executive, KernelMode, FALSE, NULL);
    }
}


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;

    if ( TimerStop ) {
        KeSetEvent( &TimerStopped, 0, FALSE );
        return;
    }

    //
    //  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 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.
                //
                //  BUGBUG - This will cause a timeout error.
                //

                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_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 {

                    //
                    //  Attempt to reroute the request.
                    //

                    SetFlag( pIrpContext->Flags, IRP_FLAG_REROUTE_ATTEMPTED );

                    if ( BooleanFlagOn(
                            pIrpContext->Flags,
                            IRP_FLAG_BURST_PACKET ) ) {
                        pIrpContext->PostProcessRoutine = NewRouteBurstRetry;
                    } else {
                        pIrpContext->PostProcessRoutine = NewRouteRetry;
                    }

                    NwPostToFsp( pIrpContext, FALSE );
                }
            }

        } 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 ) &&
        ( 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 );

        //
        //  BUGBUG surely we can't use the key like this to control the number
        //  of retries.
        //

        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.
    //

    (VOID)KeSetTimer ( &Timer, DueTime, &NwDpc);

    //DebugTrace(-1, Dbg, "TimerDpc\n", 0);
    return;

    UNREFERENCED_PARAMETER (Dpc);
    UNREFERENCED_PARAMETER (Context);
    UNREFERENCED_PARAMETER (SystemArgument1);
    UNREFERENCED_PARAMETER (SystemArgument2);

}