Windows: Log cell along with volume id for server errors
[openafs.git] / src / WINNT / afsd / cm_conn.c
index 0d450d9..a284cf2 100644 (file)
@@ -27,9 +27,11 @@ DWORD RDRtimeout = CM_CONN_DEFAULTRDRTIMEOUT;
 unsigned short ConnDeadtimeout = CM_CONN_CONNDEADTIME;
 unsigned short HardDeadtimeout = CM_CONN_HARDDEADTIME;
 unsigned short IdleDeadtimeout = CM_CONN_IDLEDEADTIME;
+unsigned short NatPingInterval = CM_CONN_NATPINGINTERVAL;
 
 #define LANMAN_WKS_PARAM_KEY "SYSTEM\\CurrentControlSet\\Services\\lanmanworkstation\\parameters"
 #define LANMAN_WKS_SESSION_TIMEOUT "SessTimeout"
+#define LANMAN_WKS_EXT_SESSION_TIMEOUT "ExtendedSessTimeout"
 
 afs_uint32 cryptall = 0;
 afs_uint32 cm_anonvldb = 0;
@@ -63,11 +65,36 @@ void cm_InitConn(void)
                            0, KEY_QUERY_VALUE, &parmKey);
        if (code == ERROR_SUCCESS)
         {
-           dummyLen = sizeof(DWORD);
-           code = RegQueryValueEx(parmKey, LANMAN_WKS_SESSION_TIMEOUT, NULL, NULL, 
-                                  (BYTE *) &dwValue, &dummyLen);
-           if (code == ERROR_SUCCESS)
-                RDRtimeout = dwValue;
+            BOOL extTimeouts = msftSMBRedirectorSupportsExtendedTimeouts();
+
+            if (extTimeouts) {
+                /* 
+                 * The default value is 1000 seconds.  However, this default
+                 * will not apply to "\\AFS" unless "AFS" is listed in 
+                 * ServersWithExtendedSessTimeout which we will add when we
+                 * create the ExtendedSessTimeout value in smb_Init()
+                 */
+                dummyLen = sizeof(DWORD);
+                code = RegQueryValueEx(parmKey, 
+                                       LANMAN_WKS_EXT_SESSION_TIMEOUT,
+                                        NULL, NULL,
+                                        (BYTE *) &dwValue, &dummyLen);
+                if (code == ERROR_SUCCESS) {
+                    RDRtimeout = dwValue;
+                    afsi_log("lanmanworkstation : ExtSessTimeout %u", RDRtimeout);
+                }
+            } 
+            if (!extTimeouts || code != ERROR_SUCCESS) {
+                dummyLen = sizeof(DWORD);
+                code = RegQueryValueEx(parmKey, 
+                                       LANMAN_WKS_SESSION_TIMEOUT,
+                                       NULL, NULL,
+                                       (BYTE *) &dwValue, &dummyLen);
+                if (code == ERROR_SUCCESS) {
+                    RDRtimeout = dwValue;
+                    afsi_log("lanmanworkstation : SessTimeout %u", RDRtimeout);
+                }
+            }
            RegCloseKey(parmKey);
         }
 
@@ -95,20 +122,37 @@ void cm_InitConn(void)
                 IdleDeadtimeout = (unsigned short)dwValue;
                 afsi_log("IdleDeadTimeout is %d", IdleDeadtimeout);
             }
+           dummyLen = sizeof(DWORD);
+           code = RegQueryValueEx(parmKey, "NatPingInterval", NULL, NULL,
+                                   (BYTE *) &dwValue, &dummyLen);
+           if (code == ERROR_SUCCESS) {
+                NatPingInterval = (unsigned short)dwValue;
+            }
+            afsi_log("NatPingInterval is %d", NatPingInterval);
             RegCloseKey(parmKey);
        }
 
-       afsi_log("lanmanworkstation : SessTimeout %u", RDRtimeout);
+        /* 
+         * If these values were not set via cpp macro or obtained 
+         * from the registry, we use a value that is derived from
+         * the smb redirector session timeout (RDRtimeout).
+         *
+         * The UNIX cache manager uses 120 seconds for the hard dead
+         * timeout and 50 seconds for the connection and idle timeouts.
+         *
+         * We base our values on those while making sure we leave 
+         * enough time for overhead.  
+         */
        if (ConnDeadtimeout == 0) {
-           ConnDeadtimeout = (unsigned short) (RDRtimeout / 2);
+           ConnDeadtimeout = (unsigned short) ((RDRtimeout / 2) < 50 ? (RDRtimeout / 2) : 50);
             afsi_log("ConnDeadTimeout is %d", ConnDeadtimeout);
         }
        if (HardDeadtimeout == 0) {
-           HardDeadtimeout = (unsigned short) RDRtimeout;
+           HardDeadtimeout = (unsigned short) (RDRtimeout > 125 ? 120 : (RDRtimeout - 5));
             afsi_log("HardDeadTimeout is %d", HardDeadtimeout);
         }
-       if (ConnDeadtimeout == 0) {
-           IdleDeadtimeout = (unsigned short) RDRtimeout;
+       if (IdleDeadtimeout == 0) {
+           IdleDeadtimeout = (unsigned short) ConnDeadtimeout;
             afsi_log("IdleDeadTimeout is %d", IdleDeadtimeout);
         }
        osi_EndOnce(&once);
@@ -117,7 +161,7 @@ void cm_InitConn(void)
 
 void cm_InitReq(cm_req_t *reqp)
 {
-       memset((char *)reqp, 0, sizeof(cm_req_t));
+       memset(reqp, 0, sizeof(cm_req_t));
        reqp->startTime = GetTickCount();
 }
 
@@ -141,12 +185,12 @@ static long cm_GetServerList(struct cm_fid *fidp, struct cm_user *userp,
     if (code) 
         return code;
     
-    *serversppp = cm_GetVolServers(volp, fidp->volume);
+    *serversppp = cm_GetVolServers(volp, fidp->volume, userp, reqp);
 
     lock_ObtainRead(&cm_volumeLock);
     cm_PutVolume(volp);
     lock_ReleaseRead(&cm_volumeLock);
-    return 0;
+    return (*serversppp ? 0 : CM_ERROR_NOSUCHVOLUME);
 }
 
 /*
@@ -186,6 +230,9 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
     long code;
     char addr[16]="unknown";
     int forcing_new = 0;
+    int location_updated = 0;
+    char *format;
+    DWORD msgID;
 
     osi_Log2(afsd_logp, "cm_Analyze connp 0x%p, code 0x%x",
              connp, errorCode);
@@ -216,14 +263,9 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
     /* if timeout - check that it did not exceed the HardDead timeout
      * and retry */
     
-    /* timeleft - get if from reqp the same way as cmXonnByMServers does */
+    /* timeleft - get it from reqp the same way as cm_ConnByMServers does */
     timeUsed = (GetTickCount() - reqp->startTime) / 1000;
-           
-    /* leave 5 seconds margin for sleep */
-    if (reqp->flags & CM_REQ_NORETRY)
-        timeLeft = 0;
-    else
-        timeLeft = HardDeadtimeout - timeUsed;
+    timeLeft = HardDeadtimeout - timeUsed;
 
     /* get a pointer to the cell */
     if (errorCode) {
@@ -232,6 +274,8 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
         if (cellp == NULL && serversp) {
             struct cm_serverRef * refp;
             for ( refp=serversp ; cellp == NULL && refp != NULL; refp=refp->next) {
+                if (refp->status == srv_deleted)
+                    continue;
                 if ( refp->server )
                     cellp = refp->server->cellp;
             }
@@ -266,30 +310,39 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
      */
     else if (errorCode == CM_ERROR_NOSUCHVOLUME) {
        osi_Log0(afsd_logp, "cm_Analyze passed CM_ERROR_NOSUCHVOLUME.");
-        if (timeLeft > 7) {
-            thrd_Sleep(5000);
-            
-            retry = 1;
-
-            if (fidp != NULL)   /* Not a VLDB call */
-                cm_ForceUpdateVolume(fidp, userp, reqp);
-        }
+        /* 
+         * The VNOVOL or VL_NOENT error has already been translated
+         * to CM_ERROR_NOSUCHVOLUME.  There is nothing for us to do.
+         */
     }
 
     else if (errorCode == CM_ERROR_ALLDOWN) {
-       osi_Log0(afsd_logp, "cm_Analyze passed CM_ERROR_ALLDOWN.");
        /* Servers marked DOWN will be restored by the background daemon
         * thread as they become available.  The volume status is 
          * updated as the server state changes.
         */
+        if (fidp) {
+            osi_Log2(afsd_logp, "cm_Analyze passed CM_ERROR_DOWN (FS cell %s vol 0x%x)",
+                      cellp->name, fidp->volume);
+            msgID = MSG_ALL_SERVERS_DOWN;
+            format = "All servers are unreachable when accessing cell %s volume %d.";
+           LogEvent(EVENTLOG_WARNING_TYPE, msgID, cellp->name, fidp->volume);
+        } else {
+            osi_Log0(afsd_logp, "cm_Analyze passed CM_ERROR_ALLDOWN (VL Server)");
+        }
     }
 
     else if (errorCode == CM_ERROR_ALLOFFLINE) {
-        osi_Log0(afsd_logp, "cm_Analyze passed CM_ERROR_ALLOFFLINE.");
         /* Volume instances marked offline will be restored by the 
          * background daemon thread as they become available 
          */
         if (fidp) {
+            osi_Log2(afsd_logp, "cm_Analyze passed CM_ERROR_ALLOFFLINE (FS cell %s vol 0x%x)",
+                      cellp->name, fidp->volume);
+            msgID = MSG_ALL_SERVERS_OFFLINE;
+            format = "All servers are offline when accessing cell %s volume %d.";
+           LogEvent(EVENTLOG_WARNING_TYPE, msgID, cellp->name, fidp->volume);
+
             code = cm_FindVolumeByID(cellp, fidp->volume, userp, reqp, 
                                       CM_GETVOL_FLAG_NO_LRU_UPDATE, 
                                       &volp);
@@ -308,15 +361,21 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
                 lock_ReleaseRead(&cm_volumeLock);
                 volp = NULL;
             }
-        } 
+        } else {
+            osi_Log0(afsd_logp, "cm_Analyze passed CM_ERROR_ALLOFFLINE (VL Server)");
+        }
     }
     else if (errorCode == CM_ERROR_ALLBUSY) {
         /* Volumes that are busy cannot be determined to be non-busy 
          * without actually attempting to access them.
          */
-       osi_Log0(afsd_logp, "cm_Analyze passed CM_ERROR_ALLBUSY.");
-
         if (fidp) { /* File Server query */
+            osi_Log2(afsd_logp, "cm_Analyze passed CM_ERROR_ALLBUSY (FS cell %s vol 0x%x)",
+                     cellp->name, fidp->volume);
+            msgID = MSG_ALL_SERVERS_BUSY;
+            format = "All servers are busy when accessing cell %s volume %d.";
+           LogEvent(EVENTLOG_WARNING_TYPE, msgID, cellp->name, fidp->volume);
+
             code = cm_FindVolumeByID(cellp, fidp->volume, userp, reqp, 
                                      CM_GETVOL_FLAG_NO_LRU_UPDATE, 
                                      &volp);
@@ -339,14 +398,17 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
                         }
                         lock_ObtainWrite(&cm_serverLock);
                         for (tsrp = serversp; tsrp; tsrp=tsrp->next) {
+                            if (tsrp->status == srv_deleted)
+                                continue;
                             if (tsrp->status == srv_busy) {
                                 tsrp->status = srv_not_busy;
                             }       
                         }
                         lock_ReleaseWrite(&cm_serverLock);
                         if (free_svr_list) {
-                            cm_FreeServerList(&serversp, 0);
-                            *serverspp = serversp;
+                            cm_FreeServerList(serverspp, 0);
+                            serversp = NULL;
+                            free_svr_list = 0;
                         }
 
                         cm_UpdateVolumeStatus(volp, fidp->volume);
@@ -362,12 +424,16 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
                 volp = NULL;
             }
         } else {    /* VL Server query */
+            osi_Log0(afsd_logp, "cm_Analyze passed CM_ERROR_ALLBUSY (VL Server).");
+
             if (timeLeft > 7) {
                 thrd_Sleep(5000);
 
                 if (serversp) {
                     lock_ObtainWrite(&cm_serverLock);
                     for (tsrp = serversp; tsrp; tsrp=tsrp->next) {
+                        if (tsrp->status == srv_deleted)
+                            continue;
                         if (tsrp->status == srv_busy) {
                             tsrp->status = srv_not_busy;
                         }
@@ -388,8 +454,34 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
                 free_svr_list = 1;
             }
         }
+
+        switch ( errorCode ) {
+        case VBUSY:
+           msgID = MSG_SERVER_REPORTS_VBUSY;
+            format = "Server %s reported busy when accessing volume %d in cell %s.";
+            break;
+        case VRESTARTING:
+           msgID = MSG_SERVER_REPORTS_VRESTARTING;
+            format = "Server %s reported restarting when accessing volume %d in cell %s.";
+            break;
+        }
+
+        if (serverp && fidp) {
+            /* Log server being offline for this volume */
+            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));
+
+           osi_Log3(afsd_logp, format, osi_LogSaveString(afsd_logp,addr), fidp->volume, cellp->name);
+           LogEvent(EVENTLOG_WARNING_TYPE, msgID, addr, fidp->volume, cellp->name);
+        }
+
         lock_ObtainWrite(&cm_serverLock);
         for (tsrp = serversp; tsrp; tsrp=tsrp->next) {
+            if (tsrp->status == srv_deleted)
+                continue;
             if (tsrp->server == serverp && tsrp->status == srv_not_busy) {
                 tsrp->status = srv_busy;
                 if (fidp) { /* File Server query */
@@ -415,8 +507,9 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
         }
 
         if (free_svr_list) {
-            cm_FreeServerList(&serversp, 0);
-            *serverspp = serversp;
+            cm_FreeServerList(serverspp, 0);
+            serversp = NULL;
+            free_svr_list = 0;
         }
         retry = 1;
     }
@@ -425,95 +518,134 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
     else if (errorCode == VNOVOL || errorCode == VMOVED || errorCode == VOFFLINE ||
              errorCode == VSALVAGE || errorCode == VNOSERVICE || errorCode == VIO) 
     {       
-        char addr[16];
-        char *format;
-       DWORD msgID;
+        /* In case of timeout */
+        reqp->volumeError = errorCode;
+
         switch ( errorCode ) {
         case VNOVOL:
            msgID = MSG_SERVER_REPORTS_VNOVOL;
-            format = "Server %s reported volume %d as not attached.";
+            format = "Server %s reported volume %d in cell %s as not attached (does not exist).";
             break;
         case VMOVED:
            msgID = MSG_SERVER_REPORTS_VMOVED;
-            format = "Server %s reported volume %d as moved.";
+            format = "Server %s reported volume %d in cell %s as moved.";
             break;
         case VOFFLINE:
            msgID = MSG_SERVER_REPORTS_VOFFLINE;
-            format = "Server %s reported volume %d as offline.";
+            format = "Server %s reported volume %d in cell %s as offline.";
             break;
         case VSALVAGE:
            msgID = MSG_SERVER_REPORTS_VSALVAGE;
-            format = "Server %s reported volume %d as needs salvage.";
+            format = "Server %s reported volume %d in cell %s as needs salvage.";
             break;
         case VNOSERVICE:
            msgID = MSG_SERVER_REPORTS_VNOSERVICE;
-            format = "Server %s reported volume %d as not in service.";
+            format = "Server %s reported volume %d in cell %s as not in service.";
             break;
         case VIO:
            msgID = MSG_SERVER_REPORTS_VIO;
-            format = "Server %s reported volume %d as temporarily unaccessible.";
+            format = "Server %s reported volume %d in cell %s as temporarily unaccessible.";
             break;
         }
 
-        if (serverp && fidp) {
-            /* Log server being offline for this volume */
-            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)); 
+        if (fidp) { /* File Server query */
+            if (serverp) {
+                /* Log server being offline for this volume */
+                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));
+
+                osi_Log3(afsd_logp, format, osi_LogSaveString(afsd_logp,addr), fidp->volume, cellp->name);
+                LogEvent(EVENTLOG_WARNING_TYPE, msgID, addr, fidp->volume, cellp->name);
+            }
 
-           osi_Log2(afsd_logp, format, osi_LogSaveString(afsd_logp,addr), fidp->volume);
-           LogEvent(EVENTLOG_WARNING_TYPE, msgID, addr, fidp->volume);
-        }
+            code = cm_FindVolumeByID(cellp, fidp->volume, userp, reqp,
+                                      CM_GETVOL_FLAG_NO_LRU_UPDATE,
+                                      &volp);
+            if (code == 0)
+                statep = cm_VolumeStateByID(volp, fidp->volume);
 
-        /* Mark server offline for this volume */
-        if (!serversp && fidp) {
-            code = cm_GetServerList(fidp, userp, reqp, &serverspp);
-            if (code == 0) {
-                serversp = *serverspp;
-                free_svr_list = 1;
+            if ((errorCode == VMOVED || errorCode == VNOVOL || errorCode == VOFFLINE) &&
+                !(reqp->flags & CM_REQ_VOLUME_UPDATED))
+            {
+                code = cm_ForceUpdateVolume(fidp, userp, reqp);
+                if (code == 0)
+                    location_updated = 1;
+
+                /* Even if the update fails, there might still be another replica */
+
+                reqp->flags |= CM_REQ_VOLUME_UPDATED;
+                osi_Log3(afsd_logp, "cm_Analyze called cm_ForceUpdateVolume cell %u vol %u code 0x%x",
+                        fidp->cell, fidp->volume, code);
+            }
+
+            if (statep) {
+                cm_UpdateVolumeStatus(volp, statep->ID);
+                osi_Log3(afsd_logp, "cm_Analyze NewVolState cell %u vol %u state %u",
+                         fidp->cell, fidp->volume, statep->state);
+            }
+
+            if (volp) {
+                lock_ObtainRead(&cm_volumeLock);
+                cm_PutVolume(volp);
+                lock_ReleaseRead(&cm_volumeLock);
+                volp = NULL;
+            }
+
+            /*
+             * Mark server offline for this volume or delete the volume
+             * from the server list if it was moved or is not present.
+             */
+            if (!serversp || location_updated) {
+                code = cm_GetServerList(fidp, userp, reqp, &serverspp);
+                if (code == 0) {
+                    serversp = *serverspp;
+                    free_svr_list = 1;
+                }
             }
         }
 
         lock_ObtainWrite(&cm_serverLock);
         for (tsrp = serversp; tsrp; tsrp=tsrp->next) {
+            if (tsrp->status == srv_deleted)
+                continue;
+
+            sprintf(addr, "%d.%d.%d.%d",
+                     ((tsrp->server->addr.sin_addr.s_addr & 0xff)),
+                     ((tsrp->server->addr.sin_addr.s_addr & 0xff00)>> 8),
+                     ((tsrp->server->addr.sin_addr.s_addr & 0xff0000)>> 16),
+                     ((tsrp->server->addr.sin_addr.s_addr & 0xff000000)>> 24));
+
             if (tsrp->server == serverp) {
                 /* REDIRECT */
-                if (errorCode == VMOVED) {
+                if (errorCode == VMOVED || errorCode == VNOVOL) {
+                    osi_Log2(afsd_logp, "volume %d not present on server %s",
+                             fidp->volume, osi_LogSaveString(afsd_logp,addr));
                     tsrp->status = srv_deleted;
+                    if (fidp)
+                        cm_RemoveVolumeFromServer(serverp, fidp->volume);
                 } else {
+                    osi_Log2(afsd_logp, "volume %d instance on server %s marked offline",
+                             fidp->volume, osi_LogSaveString(afsd_logp,addr));
                     tsrp->status = srv_offline;
                 }
-
-                if (fidp) { /* File Server query */
-                    lock_ReleaseWrite(&cm_serverLock);
-                    code = cm_FindVolumeByID(cellp, fidp->volume, userp, reqp, 
-                                             CM_GETVOL_FLAG_NO_LRU_UPDATE, 
-                                             &volp);
-                    if (code == 0)
-                        cm_VolumeStateByID(volp, fidp->volume);
-                    lock_ObtainWrite(&cm_serverLock);
-                }   
+                /* break; */
+            } else {
+                osi_Log3(afsd_logp, "volume %d exists on server %s with status %u",
+                         fidp->volume, osi_LogSaveString(afsd_logp,addr), tsrp->status);
             }
-        }   
-        lock_ReleaseWrite(&cm_serverLock);
-
-        if (fidp && errorCode == VMOVED)
-            cm_ForceUpdateVolume(fidp, userp, reqp);
-
-        if (statep) {
-            cm_UpdateVolumeStatus(volp, statep->ID);
-            lock_ObtainRead(&cm_volumeLock);
-            cm_PutVolume(volp);
-            lock_ReleaseRead(&cm_volumeLock);
-            volp = NULL;
         }
+        lock_ReleaseWrite(&cm_serverLock);
 
+        /* Free the server list before cm_ForceUpdateVolume is called */
         if (free_svr_list) {
-            cm_FreeServerList(&serversp, 0);
-            *serverspp = serversp;
+            cm_FreeServerList(serverspp, 0);
+            serversp = NULL;
+            free_svr_list = 0;
         }
+
         if ( timeLeft > 2 )
             retry = 1;
     } else if ( errorCode == VNOVNODE ) {
@@ -554,47 +686,108 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
 
     /* RX codes */
     else if (errorCode == RX_CALL_TIMEOUT) {
-        /* server took longer than hardDeadTime 
+        /* RPC took longer than hardDeadTime or the server
+         * reported idle for longer than idleDeadTime
          * don't mark server as down but don't retry
          * this is to prevent the SMB session from timing out
          * In addition, we log an event to the event log 
          */
 
         if (serverp) {
-        /* Log server being offline for this volume */
-        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_HARD_DEAD_TIME_EXCEEDED, addr);
-         
-        osi_Log1(afsd_logp, "cm_Analyze: hardDeadTime exceeded addr[%s]",
-                osi_LogSaveString(afsd_logp,addr));
-        reqp->tokenIdleErrorServp = serverp;
-        reqp->idleError++;
-        retry = 1;
+            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_HARD_DEAD_TIME_EXCEEDED, addr);
+            osi_Log1(afsd_logp, "cm_Analyze: hardDeadTime or idleDeadtime exceeded addr[%s]",
+                     osi_LogSaveString(afsd_logp,addr));
+            reqp->tokenIdleErrorServp = serverp;
+            reqp->idleError++;
+        }
+
+        if (timeLeft > 2) {
+            if (!fidp) { /* vldb */
+                retry = 1;
+            } else { /* file */
+                cm_volume_t *volp = cm_GetVolumeByFID(fidp);
+                if (volp) {
+                    if (fidp->volume == cm_GetROVolumeID(volp))
+                        retry = 1;
+                    cm_PutVolume(volp);
+                }
+            }
+        }
     }
+    else if (errorCode == RX_MSGSIZE) {
+        /*
+         * RPC failed because a transmitted rx packet
+         * may have grown larger than the path mtu.
+         * Force a retry and the Rx library will try
+         * with a smaller mtu size.
+         */
+
+        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_MSGSIZE_EXCEEDED, addr);
+            osi_Log1(afsd_logp, "cm_Analyze: Path MTU may have been exceeded addr[%s]",
+                     osi_LogSaveString(afsd_logp,addr));
+        }
+
+        if (timeLeft > 2)
+            retry = 1;
     }
     else if (errorCode >= -64 && errorCode < 0) {
         /* mark server as down */
-        lock_ObtainMutex(&serverp->mx);
-       if (reqp->flags & CM_REQ_NEW_CONN_FORCED) {
-            if (!(serverp->flags & CM_SERVERFLAG_DOWN)) {
-                serverp->flags |= CM_SERVERFLAG_DOWN;
-                serverp->downTime = time(NULL);
+        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));
+
+        if (errorCode == RX_CALL_DEAD)
+            osi_Log2(afsd_logp, "cm_Analyze: Rx Call Dead addr[%s] forcedNew[%s]",
+                     osi_LogSaveString(afsd_logp,addr), 
+                     (reqp->flags & CM_REQ_NEW_CONN_FORCED ? "yes" : "no"));
+        else
+            osi_Log3(afsd_logp, "cm_Analyze: Rx Misc Error[%d] addr[%s] forcedNew[%s]",
+                     errorCode,
+                     osi_LogSaveString(afsd_logp,addr), 
+                     (reqp->flags & CM_REQ_NEW_CONN_FORCED ? "yes" : "no"));
+
+        if (serverp) {
+            lock_ObtainMutex(&serverp->mx);
+            if (errorCode == RX_CALL_DEAD &&
+                (reqp->flags & CM_REQ_NEW_CONN_FORCED)) {
+                if (!(serverp->flags & CM_SERVERFLAG_DOWN)) {
+                    serverp->flags |= CM_SERVERFLAG_DOWN;
+                    serverp->downTime = time(NULL);
+                }
+            } else {
+                if (reqp->flags & CM_REQ_NEW_CONN_FORCED) {
+                    reqp->tokenIdleErrorServp = serverp;
+                    reqp->tokenError = errorCode;
+                } else {
+                    reqp->flags |= CM_REQ_NEW_CONN_FORCED;
+                    forcing_new = 1;
+                }
             }
-        } else {
-           reqp->flags |= CM_REQ_NEW_CONN_FORCED;
-           forcing_new = 1;
-       }
-        lock_ReleaseMutex(&serverp->mx);
-       cm_ForceNewConnections(serverp);
+            lock_ReleaseMutex(&serverp->mx);
+            cm_ForceNewConnections(serverp);
+        }
         if ( timeLeft > 2 )
             retry = 1;
     }
     else if (errorCode == RXKADEXPIRED) {
+        osi_Log1(afsd_logp, "cm_Analyze: rxkad error code 0x%x (RXKADEXPIRED)",
+                 errorCode);
         if (!dead_session) {
             lock_ObtainMutex(&userp->mx);
             ucellp = cm_GetUCell(userp, serverp->cellp);
@@ -609,10 +802,42 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
                 retry = 1;
         }
     } else if (errorCode >= ERROR_TABLE_BASE_RXK && errorCode < ERROR_TABLE_BASE_RXK + 256) {
+        char * s = "unknown error";
+        switch ( errorCode ) {
+        case RXKADINCONSISTENCY: s = "RXKADINCONSISTENCY"; break;
+        case RXKADPACKETSHORT  : s = "RXKADPACKETSHORT";   break;
+        case RXKADLEVELFAIL    : s = "RXKADLEVELFAIL";     break;
+        case RXKADTICKETLEN    : s = "RXKADTICKETLEN";     break;
+        case RXKADOUTOFSEQUENCE: s = "RXKADOUTOFSEQUENCE"; break;
+        case RXKADNOAUTH       : s = "RXKADNOAUTH";        break;
+        case RXKADBADKEY       : s = "RXKADBADKEY";        break;
+        case RXKADBADTICKET    : s = "RXKADBADTICKET";     break;
+        case RXKADUNKNOWNKEY   : s = "RXKADUNKNOWNKEY";    break;
+        case RXKADEXPIRED      : s = "RXKADEXPIRED";       break;
+        case RXKADSEALEDINCON  : s = "RXKADSEALEDINCON";   break;
+        case RXKADDATALEN      : s = "RXKADDATALEN";       break;
+        case RXKADILLEGALLEVEL : s = "RXKADILLEGALLEVEL";  break;
+        }
+        osi_Log2(afsd_logp, "cm_Analyze: rxkad error code 0x%x (%s)",
+                  errorCode, s);
+
         if (serverp) {
-        reqp->tokenIdleErrorServp = serverp;
-        reqp->tokenError = errorCode;
-        retry = 1;
+            reqp->tokenIdleErrorServp = serverp;
+            reqp->tokenError = errorCode;
+            retry = 1;
+        }
+    } else if (errorCode >= ERROR_TABLE_BASE_U && errorCode < ERROR_TABLE_BASE_U + 256) {
+        /*
+         * We received a ubik error.  its possible that the server we are
+         * communicating with has a corrupted database or is partitioned
+         * from the rest of the servers and another server might be able
+         * to answer our query.  Therefore, we will retry the request
+         * and force the use of another server.
+         */
+        if (serverp) {
+            reqp->tokenIdleErrorServp = serverp;
+            reqp->tokenError = errorCode;
+            retry = 1;
         }
     } else if (errorCode == VICECONNBAD || errorCode == VICETOKENDEAD) {
        cm_ForceNewConnections(serverp);
@@ -622,19 +847,6 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
         if (errorCode) {
             char * s = "unknown error";
             switch ( errorCode ) {
-            case RXKADINCONSISTENCY: s = "RXKADINCONSISTENCY"; break;
-            case RXKADPACKETSHORT  : s = "RXKADPACKETSHORT";   break;
-            case RXKADLEVELFAIL    : s = "RXKADLEVELFAIL";     break;
-            case RXKADTICKETLEN    : s = "RXKADTICKETLEN";     break;
-            case RXKADOUTOFSEQUENCE: s = "RXKADOUTOFSEQUENCE"; break;
-            case RXKADNOAUTH       : s = "RXKADNOAUTH";        break;
-            case RXKADBADKEY       : s = "RXKADBADKEY";        break;
-            case RXKADBADTICKET    : s = "RXKADBADTICKET";     break;
-            case RXKADUNKNOWNKEY   : s = "RXKADUNKNOWNKEY";    break;
-            case RXKADEXPIRED      : s = "RXKADEXPIRED";       break;
-            case RXKADSEALEDINCON  : s = "RXKADSEALEDINCON";   break;
-            case RXKADDATALEN      : s = "RXKADDATALEN";       break;
-            case RXKADILLEGALLEVEL : s = "RXKADILLEGALLEVEL";  break;
             case VSALVAGE          : s = "VSALVAGE";           break;
             case VNOVNODE          : s = "VNOVNODE";           break;
             case VNOVOL            : s = "VNOVOL";             break;
@@ -760,11 +972,20 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
     else if (retry && dead_session)
         retry = 0;
 
-  out:
     /* drop this on the way out */
     if (connp)
         cm_PutConn(connp);
 
+    /* 
+     * clear the volume updated flag if we succeed.
+     * this way the flag will not prevent a subsequent volume 
+     * from being updated if necessary.
+     */
+    if (errorCode == 0)
+    {
+        reqp->flags &= ~CM_REQ_VOLUME_UPDATED;
+    }
+
     /* retry until we fail to find a connection */
     return retry;
 }
@@ -797,6 +1018,9 @@ long cm_ConnByMServers(cm_serverRef_t *serversp, cm_user_t *usersp,
 
     lock_ObtainRead(&cm_serverLock);
     for (tsrp = serversp; tsrp; tsrp=tsrp->next) {
+        if (tsrp->status == srv_deleted)
+            continue;
+
         tsp = tsrp->server;
         if (reqp->tokenIdleErrorServp) {
             /* 
@@ -814,9 +1038,7 @@ long cm_ConnByMServers(cm_serverRef_t *serversp, cm_user_t *usersp,
             lock_ReleaseRead(&cm_serverLock);
             if (!(tsp->flags & CM_SERVERFLAG_DOWN)) {
                 allDown = 0;
-                if (tsrp->status == srv_deleted) {
-                    /* skip this entry.  no longer valid. */;
-                } else if (tsrp->status == srv_busy) {
+                if (tsrp->status == srv_busy) {
                     allOffline = 0;
                     someBusy = 1;
                 } else if (tsrp->status == srv_offline) {
@@ -856,14 +1078,21 @@ long cm_ConnByMServers(cm_serverRef_t *serversp, cm_user_t *usersp,
     lock_ReleaseRead(&cm_serverLock);
 
     if (firstError == 0) {
-        if (allDown) 
+        if (allDown) {
             firstError = (reqp->tokenError ? reqp->tokenError : 
                           (reqp->idleError ? RX_CALL_TIMEOUT : CM_ERROR_ALLDOWN));
-        else if (allBusy) 
+            /*
+             * if we experienced either a token error or and idle dead time error
+             * and now all of the servers are down, we have either tried them
+             * all or lost connectivity.  Clear the error we are returning so
+             * we will not return it indefinitely if the request is retried.
+             */
+            reqp->idleError = reqp->tokenError = 0;
+        } else if (allBusy) {
             firstError = CM_ERROR_ALLBUSY;
-       else if (allOffline || (someBusy && someOffline))
+       } else if (allOffline || (someBusy && someOffline)) {
            firstError = CM_ERROR_ALLOFFLINE;
-        else {
+        } else {
             osi_Log0(afsd_logp, "cm_ConnByMServers returning impossible error TIMEDOUT");
             firstError = CM_ERROR_TIMEDOUT;
         }
@@ -889,6 +1118,7 @@ void cm_GCConnections(cm_server_t *serverp)
             cm_PutServer(tcp->serverp);
             cm_ReleaseUser(userp);
             *lcpp = tcp->nextp;
+            rx_SetConnSecondsUntilNatPing(tcp->rxconnp, 0);
             rx_DestroyConnection(tcp->rxconnp);
             lock_FinalizeMutex(&tcp->mx);
             free(tcp);
@@ -909,15 +1139,22 @@ static void cm_NewRXConnection(cm_conn_t *tcp, cm_ucell_t *ucellp,
     int secIndex;
     struct rx_securityClass *secObjp;
 
-    if (serverp->type == CM_SERVER_VLDB) {
-        port = htons(7003);
+    port = serverp->addr.sin_port;
+    switch (serverp->type) {
+    case CM_SERVER_VLDB:
+        if (port == 0)
+            port = htons(7003);
         serviceID = 52;
-    }
-    else {
-        osi_assertx(serverp->type == CM_SERVER_FILE, "incorrect server type");
-        port = htons(7000);
+        break;
+    case CM_SERVER_FILE:
+        if (port == 0)
+            port = htons(7000);
         serviceID = 1;
+        break;
+    default:
+        osi_panic("unknown server type", __FILE__, __LINE__);
     }
+
     if (ucellp->flags & CM_UCELLFLAG_RXKAD) {
         secIndex = 2;
         switch (cryptall) {
@@ -941,13 +1178,27 @@ static void cm_NewRXConnection(cm_conn_t *tcp, cm_ucell_t *ucellp,
     }
     osi_assertx(secObjp != NULL, "null rx_securityClass");
     tcp->rxconnp = rx_NewConnection(serverp->addr.sin_addr.s_addr,
-                                  port,
-                                  serviceID,
-                                  secObjp,
-                                  secIndex);
+                                    port,
+                                    serviceID,
+                                    secObjp,
+                                    secIndex);
     rx_SetConnDeadTime(tcp->rxconnp, ConnDeadtimeout);
     rx_SetConnHardDeadTime(tcp->rxconnp, HardDeadtimeout);
     rx_SetConnIdleDeadTime(tcp->rxconnp, IdleDeadtimeout);
+
+    /*
+     * Let the Rx library know that we can auto-retry if an
+     * RX_MSGSIZE error is returned.
+     */
+    rx_SetMsgsizeRetryErr(tcp->rxconnp, RX_MSGSIZE);
+    /*
+     * Attempt to limit NAT pings to the anonymous file server connections.
+     * Only file servers implement client callbacks and we only need one ping
+     * to be sent to each server.
+     */
+    if (NatPingInterval && serverp->type == CM_SERVER_FILE && secIndex == 0)
+        rx_SetConnSecondsUntilNatPing(tcp->rxconnp, NatPingInterval);
+
     tcp->ucgen = ucellp->gen;
     if (secObjp)
         rxs_Release(secObjp);   /* Decrement the initial refCount */
@@ -1012,6 +1263,7 @@ long cm_ConnByServer(cm_server_t *serverp, cm_user_t *userp, cm_conn_t **connpp)
             else
                 osi_Log0(afsd_logp, "cm_ConnByServer replace connection due to crypt change");
            tcp->flags &= ~CM_CONN_FLAG_FORCE_NEW;
+            rx_SetConnSecondsUntilNatPing(tcp->rxconnp, 0);
             rx_DestroyConnection(tcp->rxconnp);
             cm_NewRXConnection(tcp, ucellp, serverp);
         }
@@ -1043,6 +1295,8 @@ long cm_ServerAvailable(struct cm_fid *fidp, struct cm_user *userp)
 
     lock_ObtainRead(&cm_serverLock);
     for (tsrp = *serverspp; tsrp; tsrp=tsrp->next) {
+        if (tsrp->status == srv_deleted)
+            continue;
         tsp = tsrp->server;
         if (!(tsp->flags & CM_SERVERFLAG_DOWN)) {
            allDown = 0;
@@ -1102,7 +1356,7 @@ long cm_ConnFromVolume(struct cm_volume *volp, unsigned long volid, struct cm_us
 
     *connpp = NULL;
 
-    serverspp = cm_GetVolServers(volp, volid);
+    serverspp = cm_GetVolServers(volp, volid, userp, reqp);
 
     code = cm_ConnByMServers(*serverspp, userp, reqp, connpp);
     cm_FreeServerList(serverspp, 0);