rx: Remove RX_CALL_BUSY
authorAndrew Deason <adeason@sinenomine.net>
Thu, 30 Jan 2014 06:40:57 +0000 (00:40 -0600)
committerJeffrey Altman <jaltman@your-file-system.com>
Wed, 11 Feb 2015 14:05:40 +0000 (09:05 -0500)
Commit 23d6287f7f494383891a497038e8c0e870e824bf introduced the
behavior where a client can immediately retry a call if it receives a
"busy" packet from the server (meaning, the call channel is already in
use). This happened via Rx returning the error code RX_CALL_BUSY, and
the caller was supposed to immediately retry the call, so Rx could
reissue the RPC on a different call channel.

However, this behavior makes it more likely for the server to process
an RPC that the client thinks has not been processed. Say the client
issues an RPC, the server replies with a "busy" packet, and the client
resends the original packet before it sees the "busy" packet. In
this case, the server will get the resent packet for the RPC request
and process it, but the client will think the call has failed (and
presumably will retry the call on a new channel). For calls that are
non-idempotent (e.g. MakeDir), this can result in incorrect errors
(e.g. EEXIST) as well as incorrect cache state in the client.

There may be some ways to mitigate at least some of the problems here,
but this kind of "instant" retry behavior is often not really that
helpful. Calls that take a very long time to run on the server are
very rare (and usually indicate some other problem), while the
occasional short-lived "busy" packet is relatively common (sometimes
the server just hasn't cleaned up the call by the time we issue a new
call). So just get rid of the retrying behavior to ensure we don't
continue to encounter any problems like this.

To get rid of this behavior, we remove the RX_CALL_BUSY code, and all
code dealing with processing it. This means removing the RX_CALL_BUSY
handling from the client, as well as removing
rx_SetBusyChannelError(). This effectively reverts most of
23d6287f7f494383891a497038e8c0e870e824bf, and a few other commits
related to RX_CALL_BUSY.

With this change, if all we get from the server are BUSY packets when
we try to issue an RPC, the call will eventually error out with
RX_CALL_TIMEOUT (or hang forever, if no timeouts are configured). This
can be thought of intuitively as similar to "idle dead" behavior,
since we are just waiting for the server to proceed with processing
the call. So, if "idle dead" is configured, we still timeout after the
"idle dead" timeout. And if no idle or hard dead timeout is
configured, we will hang forever; just like if the server started
processing the call but then hangs forever.

Note that not all of 23d6287f7f494383891a497038e8c0e870e824bf is
reverted. Namely, the logic to have rx_NewCall try to pick the "least
busy" channel is retained.

Thanks to Simon Wilkinson for bringing up and discussing this issue in
this thread:
<http://thread.gmane.org/gmane.comp.file-systems.openafs.devel/10931>
<https://lists.openafs.org/pipermail/openafs-devel/2013-April/019297.html>

Change-Id: I272e51f252356aa14bc4b8a3b7c594700deb432c
Reviewed-on: http://gerrit.openafs.org/10784
Reviewed-by: Daria Brashear <shadow@your-file-system.com>
Reviewed-by: Benjamin Kaduk <kaduk@mit.edu>
Tested-by: BuildBot <buildbot@rampaginggeek.com>
Reviewed-by: Jeffrey Altman <jaltman@your-file-system.com>

13 files changed:
src/WINNT/afsd/afsd_init.c
src/WINNT/afsd/cm_conn.c
src/WINNT/afsd/cm_server.c
src/WINNT/afsd/cm_utils.c
src/afs/afs_analyze.c
src/afs/afs_call.c
src/afs/afs_pag_call.c
src/libafsrpc/afsrpc.def
src/libafsrpc/afsrpc.exp
src/libafsrpc/libafsrpc.la.sym
src/rx/rx.c
src/rx/rx.h
src/rx/rx_prototypes.h

index 4c67674..bac4678 100644 (file)
@@ -1506,8 +1506,6 @@ afsd_InitCM(char **reasonP)
         afsi_log("rx_SetUdpBufSize %d", rx_udpbufsize);
     }
 
-    rx_SetBusyChannelError(1);  /* Activate busy call channel reporting */
-
     /* initialize RX, and tell it to listen to the callbackport,
      * which is used for callback RPC messages.
      */
index b888622..817836c 100644 (file)
@@ -971,27 +971,6 @@ cm_Analyze(cm_conn_t *connp,
 
         retry = 2;
     }
-    else if (errorCode == RX_CALL_BUSY) {
-        /*
-         * RPC failed because the selected call channel
-         * is currently busy on the server.  Unconditionally
-         * retry the request so an alternate call channel can be used.
-         */
-       if (connp)
-           _InterlockedAnd(&connp->flags, ~CM_CONN_FLAG_NEW);
-
-        if (serverp)
-            sprintf(addr, "%d.%d.%d.%d",
-                    ((serverp->addr.sin_addr.s_addr & 0xff)),
-                    ((serverp->addr.sin_addr.s_addr & 0xff00)>> 8),
-                    ((serverp->addr.sin_addr.s_addr & 0xff0000)>> 16),
-                    ((serverp->addr.sin_addr.s_addr & 0xff000000)>> 24));
-
-        LogEvent(EVENTLOG_WARNING_TYPE, MSG_RX_BUSY_CALL_CHANNEL, addr);
-        osi_Log1(afsd_logp, "cm_Analyze: Retry RPC due to busy call channel addr[%s]",
-                 osi_LogSaveString(afsd_logp,addr));
-        retry = 2;
-    }
     else if (errorCode == VNOSERVICE) {
         /*
          * The server did not service the RPC.
index 318dd4c..4a9ae48 100644 (file)
@@ -313,14 +313,13 @@ cm_PingServer(cm_server_t *tsp)
     }  /* got an unauthenticated connection to this server */
 
     lock_ObtainMutex(&tsp->mx);
-    if (code >= 0 || code == RXGEN_OPCODE || code == RX_CALL_BUSY) {
+    if (code >= 0 || code == RXGEN_OPCODE) {
        /* mark server as up */
        _InterlockedAnd(&tsp->flags, ~CM_SERVERFLAG_DOWN);
         tsp->downTime = 0;
 
        /* we currently handle 32-bits of capabilities */
-       if (code != RXGEN_OPCODE && code != RX_CALL_BUSY &&
-            caps.Capabilities_len > 0) {
+       if (code != RXGEN_OPCODE && caps.Capabilities_len > 0) {
            tsp->capabilities = caps.Capabilities_val[0];
            xdr_free((xdrproc_t) xdr_Capabilities, &caps);
            caps.Capabilities_len = 0;
@@ -579,15 +578,13 @@ static void cm_CheckServersMulti(afs_uint32 flags, cm_cell_t *cellp)
             lock_ObtainMutex(&tsp->mx);
             wasDown = tsp->flags & CM_SERVERFLAG_DOWN;
 
-            if (results[i] >= 0 || results[i] == RXGEN_OPCODE ||
-                results[i] == RX_CALL_BUSY)  {
+            if (results[i] >= 0 || results[i] == RXGEN_OPCODE) {
                 /* mark server as up */
                 _InterlockedAnd(&tsp->flags, ~CM_SERVERFLAG_DOWN);
                 tsp->downTime = 0;
 
                 /* we currently handle 32-bits of capabilities */
-                if (results[i] != RXGEN_OPCODE && results[i] != RX_CALL_BUSY &&
-                    caps[i].Capabilities_len > 0) {
+                if (results[i] != RXGEN_OPCODE && caps[i].Capabilities_len > 0) {
                     tsp->capabilities = caps[i].Capabilities_val[0];
                     xdr_free((xdrproc_t) xdr_Capabilities, &caps[i]);
                     caps[i].Capabilities_len = 0;
@@ -725,7 +722,7 @@ static void cm_CheckServersMulti(afs_uint32 flags, cm_cell_t *cellp)
             lock_ObtainMutex(&tsp->mx);
             wasDown = tsp->flags & CM_SERVERFLAG_DOWN;
 
-            if (results[i] >= 0 || results[i] == RX_CALL_BUSY)  {
+            if (results[i] >= 0)  {
                 /* mark server as up */
                 _InterlockedAnd(&tsp->flags, ~CM_SERVERFLAG_DOWN);
                 tsp->downTime = 0;
index ea19f7b..f89b84b 100644 (file)
@@ -213,7 +213,6 @@ long cm_MapRPCError(long error, cm_req_t *reqp)
 
     if (error == RX_CALL_DEAD ||
         error == RX_CALL_TIMEOUT ||
-        error == RX_CALL_BUSY ||
         error == RX_MSGSIZE ||
         error == VNOSERVICE)
        error = CM_ERROR_TIMEDOUT;
@@ -281,7 +280,6 @@ long cm_MapRPCErrorRmdir(long error, cm_req_t *reqp)
 
     if (error == RX_CALL_DEAD ||
         error == RX_CALL_TIMEOUT ||
-        error == RX_CALL_BUSY ||
         error == RX_MSGSIZE ||
         error == VNOSERVICE)
        error = CM_ERROR_TIMEDOUT;
@@ -334,7 +332,6 @@ long cm_MapVLRPCError(long error, cm_req_t *reqp)
 
     if (error == RX_CALL_DEAD ||
         error == RX_CALL_TIMEOUT ||
-        error == RX_CALL_BUSY ||
         error == RX_MSGSIZE ||
         error == VNOSERVICE)
        error = CM_ERROR_TIMEDOUT;
index 014bd3e..7dfc4f6 100644 (file)
@@ -621,7 +621,7 @@ afs_Analyze(struct afs_conn *aconn, struct rx_connection *rxconn,
     if (acode == -455)
        acode = 455;
 #endif /* AFS_64BIT_CLIENT */
-    if (acode == RX_MSGSIZE || acode == RX_CALL_BUSY) {
+    if (acode == RX_MSGSIZE) {
        shouldRetry = 1;
        goto out;
     }
index 43d7778..554da85 100644 (file)
@@ -123,8 +123,6 @@ afs_InitSetup(int preallocs)
 
     memset(afs_zeros, 0, AFS_ZEROS);
 
-    rx_SetBusyChannelError(1);  /* turn on busy call error reporting */
-
     /* start RX */
     if(!afscall_set_rxpck_received)
     rx_extraPackets = AFS_NRXPACKETS;  /* smaller # of packets */
index ddc53b8..e38cf93 100644 (file)
@@ -98,7 +98,6 @@ afspag_Init(afs_int32 nfs_server_addr)
     AFS_GLOCK();
 
     afs_InitStats();
-    rx_SetBusyChannelError(1);  /* turn on busy call error reporting */
     rx_Init(htons(7001));
 
     AFS_STATCNT(afs_ResourceInit);
index 53a4118..43a3b2c 100755 (executable)
@@ -293,7 +293,7 @@ EXPORTS
        rx_identity_freeContents                @302
        rx_identity_free                        @303
 
-       rx_SetBusyChannelError                  @304
+;      rx_SetBusyChannelError                  @304
        rx_GetThreadNum                         @305
        rx_SetThreadNum                         @306
 
index 7dd2779..0355bc9 100755 (executable)
@@ -34,7 +34,6 @@ rx_ReleaseCachedConnection
 rx_ServerProc
 rx_StartServer
 rx_WriteProc
-rx_SetBusyChannelError
 rxevent_Init
 rxevent_Post
 rxkad_GetServerInfo
index 4e68dd7..8ea0d04 100644 (file)
@@ -90,7 +90,6 @@ rx_SecurityObjectOf
 rx_ServerProc
 rx_ServiceIdOf
 rx_ServiceOf
-rx_SetBusyChannelError
 rx_SetConnDeadTime
 rx_SetConnHardDeadTime
 rx_SetConnIdleDeadTime
index 13a3892..4bc1d4e 100644 (file)
@@ -204,16 +204,6 @@ static unsigned int rxi_rpc_peer_stat_cnt;
 
 static unsigned int rxi_rpc_process_stat_cnt;
 
-/*
- * rxi_busyChannelError is a boolean.  It indicates whether or not RX_CALL_BUSY
- * errors should be reported to the application when a call channel appears busy
- * (inferred from the receipt of RX_PACKET_TYPE_BUSY packets on the channel),
- * and there are other call channels in the connection that are not busy.
- * If 0, we do not return errors upon receiving busy packets; we just keep
- * trying on the same call channel until we hit a timeout.
- */
-static afs_int32 rxi_busyChannelError = 0;
-
 rx_atomic_t rx_nWaiting = RX_ATOMIC_INIT(0);
 rx_atomic_t rx_nWaited = RX_ATOMIC_INIT(0);
 
@@ -770,20 +760,6 @@ rx_rto_setPeerTimeoutSecs(struct rx_peer *peer, int secs) {
 }
 
 /**
- * Enables or disables the busy call channel error (RX_CALL_BUSY).
- *
- * @param[in] onoff Non-zero to enable busy call channel errors.
- *
- * @pre Neither rx_Init nor rx_InitHost have been called yet
- */
-void
-rx_SetBusyChannelError(afs_int32 onoff)
-{
-    osi_Assert(rx_atomic_test_bit(&rxinit_status, 0));
-    rxi_busyChannelError = onoff ? 1 : 0;
-}
-
-/**
  * Set a delayed ack event on the specified call for the given time
  *
  * @param[in] call - the call on which to set the event
@@ -1571,7 +1547,6 @@ rx_NewCall(struct rx_connection *conn)
        }
        if (i < RX_MAXCALLS) {
            conn->lastBusy[i] = 0;
-           call->flags &= ~RX_CALL_PEER_BUSY;
            break;
        }
         if (!wait)
@@ -2436,7 +2411,12 @@ rx_EndCall(struct rx_call *call, afs_int32 rc)
         MUTEX_ENTER(&conn->conn_call_lock);
         MUTEX_ENTER(&call->lock);
 
-       if (!(call->flags & RX_CALL_PEER_BUSY)) {
+       if (!call->error) {
+           /* While there are some circumstances where a call with an error is
+            * obviously not on a "busy" channel, be conservative (clearing
+            * lastBusy is just best-effort to possibly speed up rx_NewCall).
+            * The call channel is definitely not busy if we just successfully
+            * completed a call on it. */
            conn->lastBusy[call->channel] = 0;
        }
 
@@ -3180,84 +3160,6 @@ rxi_FindConnection(osi_socket socket, afs_uint32 host,
     return conn;
 }
 
-/**
- * Timeout a call on a busy call channel if appropriate.
- *
- * @param[in] call The busy call.
- *
- * @pre 'call' is marked as busy (namely,
- *      call->conn->lastBusy[call->channel] != 0)
- *
- * @pre call->lock is held
- * @pre rxi_busyChannelError is nonzero
- *
- * @note call->lock is dropped and reacquired
- */
-static void
-rxi_CheckBusy(struct rx_call *call)
-{
-    struct rx_connection *conn = call->conn;
-    int channel = call->channel;
-    int freechannel = 0;
-    int i;
-
-    MUTEX_EXIT(&call->lock);
-
-    MUTEX_ENTER(&conn->conn_call_lock);
-
-    /* Are there any other call slots on this conn that we should try? Look for
-     * slots that are empty and are either non-busy, or were marked as busy
-     * longer than conn->secondsUntilDead seconds before this call started. */
-
-    for (i = 0; i < RX_MAXCALLS && !freechannel; i++) {
-       if (i == channel) {
-           /* only look at channels that aren't us */
-           continue;
-       }
-
-       if (conn->lastBusy[i]) {
-           /* if this channel looked busy too recently, don't look at it */
-           if (conn->lastBusy[i] >= call->startTime.sec) {
-               continue;
-           }
-           if (call->startTime.sec - conn->lastBusy[i] < conn->secondsUntilDead) {
-               continue;
-           }
-       }
-
-       if (conn->call[i]) {
-           struct rx_call *tcall = conn->call[i];
-           MUTEX_ENTER(&tcall->lock);
-           if (tcall->state == RX_STATE_DALLY) {
-               freechannel = 1;
-           }
-           MUTEX_EXIT(&tcall->lock);
-       } else {
-           freechannel = 1;
-       }
-    }
-
-    MUTEX_ENTER(&call->lock);
-
-    /* Since the call->lock has been released it is possible that the call may
-     * no longer be busy (the call channel cannot have been reallocated as we
-     * haven't dropped the conn_call_lock) Therefore, we must confirm
-     * that the call state has not changed when deciding whether or not to
-     * force this application thread to retry by forcing a Timeout error. */
-
-    if (freechannel && (call->flags & RX_CALL_PEER_BUSY)) {
-       /* Since 'freechannel' is set, there exists another channel in this
-        * rx_conn that the application thread might be able to use. We know
-        * that we have the correct call since callNumber is unchanged, and we
-        * know that the call is still busy. So, set the call error state to
-        * rxi_busyChannelError so the application can retry the request,
-        * presumably on a less-busy call channel. */
-
-       rxi_CallError(call, RX_CALL_BUSY);
-    }
-    MUTEX_EXIT(&conn->conn_call_lock);
-}
-
 /*!
  * Abort the call if the server is over the busy threshold. This
  * can be used without requiring a call structure be initialised,
@@ -3288,6 +3190,9 @@ rxi_ReceiveClientCall(struct rx_packet *np, struct rx_connection *conn)
     channel = np->header.cid & RX_CHANNELMASK;
     MUTEX_ENTER(&conn->conn_call_lock);
     call = conn->call[channel];
+    if (np->header.type == RX_PACKET_TYPE_BUSY) {
+       conn->lastBusy[channel] = clock_Sec();
+    }
     if (!call || conn->callNumber[channel] != np->header.callNumber) {
        MUTEX_EXIT(&conn->conn_call_lock);
        if (rx_stats_active)
@@ -3635,23 +3540,13 @@ rxi_ReceivePacket(struct rx_packet *np, osi_socket socket,
        putConnection(conn);
        return np;              /* xmitting; drop packet */
     }
-    case RX_PACKET_TYPE_BUSY: {
-       struct clock busyTime;
-       clock_NewTime();
-       clock_GetTime(&busyTime);
-
-       MUTEX_EXIT(&call->lock);
-
-       MUTEX_ENTER(&conn->conn_call_lock);
-       MUTEX_ENTER(&call->lock);
-       conn->lastBusy[call->channel] = busyTime.sec;
-       call->flags |= RX_CALL_PEER_BUSY;
-       MUTEX_EXIT(&call->lock);
-       MUTEX_EXIT(&conn->conn_call_lock);
-
-       putConnection(conn);
-       return np;
-    }
+    case RX_PACKET_TYPE_BUSY:
+       /* Mostly ignore BUSY packets. We will update lastReceiveTime below,
+        * so we don't think the endpoint is completely dead, but otherwise
+        * just act as if we never saw anything. If all we get are BUSY packets
+        * back, then we will eventually error out with RX_CALL_TIMEOUT if the
+        * connection is configured with idle/hard timeouts. */
+       break;
 
     case RX_PACKET_TYPE_ACKALL:
        /* All packets acknowledged, so we can drop all packets previously
@@ -3670,8 +3565,6 @@ rxi_ReceivePacket(struct rx_packet *np, osi_socket socket,
      * the packet will be delivered to the user before any get time is required
      * (if not, then the time won't actually be re-evaluated here). */
     call->lastReceiveTime = clock_Sec();
-    /* we've received a legit packet, so the channel is not busy */
-    call->flags &= ~RX_CALL_PEER_BUSY;
     MUTEX_EXIT(&call->lock);
     putConnection(conn);
     return np;
@@ -5150,33 +5043,25 @@ static struct rx_packet *
 rxi_SendCallAbort(struct rx_call *call, struct rx_packet *packet,
                  int istack, int force)
 {
-    afs_int32 error, cerror;
+    afs_int32 error;
     struct clock when, now;
 
     if (!call->error)
        return packet;
 
-    switch (call->error) {
-    case RX_CALL_BUSY:
-        cerror = RX_CALL_TIMEOUT;
-        break;
-    default:
-        cerror = call->error;
-    }
-
     /* Clients should never delay abort messages */
     if (rx_IsClientConn(call->conn))
        force = 1;
 
-    if (call->abortCode != cerror) {
-       call->abortCode = cerror;
+    if (call->abortCode != call->error) {
+       call->abortCode = call->error;
        call->abortCount = 0;
     }
 
     if (force || rxi_callAbortThreshhold == 0
        || call->abortCount < rxi_callAbortThreshhold) {
        rxi_CancelDelayedAbortEvent(call);
-       error = htonl(cerror);
+       error = htonl(call->error);
        call->abortCount++;
        packet =
            rxi_SendSpecial(call, call->conn, packet, RX_PACKET_TYPE_ABORT,
@@ -5391,16 +5276,6 @@ rxi_ResetCall(struct rx_call *call, int newcall)
     }
     call->flags = 0;
 
-    if (!newcall && (flags & RX_CALL_PEER_BUSY)) {
-       /* The call channel is still busy; resetting the call doesn't change
-        * that. However, if 'newcall' is set, we are processing a call
-        * structure that has either been recycled from the free list, or has
-        * been newly allocated. So, RX_CALL_PEER_BUSY is not relevant if
-        * 'newcall' is set, since it describes a completely different call
-        * channel which we do not care about. */
-       call->flags |= RX_CALL_PEER_BUSY;
-    }
-
     rxi_ClearReceiveQueue(call);
     /* why init the queue if you just emptied it? queue_Init(&call->rq); */
 
@@ -6042,10 +5917,6 @@ rxi_Resend(struct rxevent *event, void *arg0, void *arg1, int istack)
 
     rxi_CheckPeerDead(call);
 
-    if (rxi_busyChannelError && (call->flags & RX_CALL_PEER_BUSY)) {
-       rxi_CheckBusy(call);
-    }
-
     if (opr_queue_IsEmpty(&call->tq)) {
        /* Nothing to do. This means that we've been raced, and that an
         * ACK has come in between when we were triggered, and when we
index f4ad3dc..6bbf574 100644 (file)
@@ -165,8 +165,7 @@ extern u_short rx_PortOf(struct rx_peer *peer);
 #define RX_CALL_IOVEC_WAIT     16384   /* waiting thread is using an iovec */
 #define RX_CALL_HAVE_LAST      32768   /* Last packet has been received */
 #define RX_CALL_NEED_START     0x10000 /* tells rxi_Start to start again */
-#define RX_CALL_PEER_BUSY      0x20000 /* the last packet we received on this call was a
-                                         * BUSY packet; i.e. the channel for this call is busy */
+/* 0x20000 was RX_CALL_PEER_BUSY */
 #define RX_CALL_ACKALL_SENT     0x40000 /* ACKALL has been sent on the call */
 #define RX_CALL_FLUSH          0x80000 /* Transmit queue should be flushed to peer */
 #endif
@@ -492,11 +491,8 @@ struct rx_ackPacket {
 /* The value -9 was previously used for RX_CALL_IDLE but is now free for
  * reuse. */
 
-/*
- * Busy call channel error.  This error is never sent on the wire.
- * rxi_SendCallAbort() translates RX_CALL_BUSY to RX_CALL_TIMEOUT.
- */
-#define RX_CALL_BUSY                (-10)
+/* The value -10 was previously used for RX_CALL_BUSY but is now free for
+ * reuse. */
 
 /* transient failure detected ( possibly the server is restarting ) */
 /* this should be equal to VRESTARTING ( util/errors.h ) for old clients to work */
index ee831c6..68beade 100644 (file)
@@ -24,7 +24,6 @@ extern void rx_rto_setPeerTimeoutSecs(struct rx_peer *, int secs);
 
 extern int rx_Init(u_int port);
 extern int rx_InitHost(u_int host, u_int port);
-extern void rx_SetBusyChannelError(afs_int32 onoff);
 #ifdef AFS_NT40_ENV
 extern void rx_DebugOnOff(int on);
 extern void rx_StatsOnOff(int on);