MAINT-6336: Better retry and timeout logic when logging in to the vivox server and connecting to a session.

1 files changed, 78 insertions, 45 deletions

diff --git a/indra/newview/llvoicevivox.cpp b/indra/newview/llvoicevivox.cpp
index c9661dfb11..e015d4fa5e 100755
--- a/indra/newview/llvoicevivox.cpp
+++ b/indra/newview/llvoicevivox.cpp
@@ -80,39 +80,49 @@
 extern LLMenuBarGL* gMenuBarView;
 extern void handle_voice_morphing_subscribe();
 
-const F32 VOLUME_SCALE_VIVOX = 0.01f;
+namespace {
+    const F32 VOLUME_SCALE_VIVOX = 0.01f;
 
-const F32 SPEAKING_TIMEOUT = 1.f;
+    const F32 SPEAKING_TIMEOUT = 1.f;
 
-static const std::string VOICE_SERVER_TYPE = "Vivox";
+    static const std::string VOICE_SERVER_TYPE = "Vivox";
 
-// Don't retry connecting to the daemon more frequently than this:
-const F32 CONNECT_THROTTLE_SECONDS = 1.0f;
+    // Don't retry connecting to the daemon more frequently than this:
+    const F32 CONNECT_THROTTLE_SECONDS = 1.0f;
 
-// Don't send positional updates more frequently than this:
-const F32 UPDATE_THROTTLE_SECONDS = 0.5f;
+    // Don't send positional updates more frequently than this:
+    const F32 UPDATE_THROTTLE_SECONDS = 0.5f;
 
-const F32 LOGIN_RETRY_SECONDS = 10.0f;
-const int MAX_LOGIN_RETRIES = 12;
+    const F32 LOGIN_ATTEMPT_TIMEOUT = 5.0f;
+    const int LOGIN_RETRY_MAX = 5;
+    const F32 LOGIN_RETRY_TIMEOUT = 4.0f;
 
-// Cosine of a "trivially" small angle
-const F32 MINUSCULE_ANGLE_COS = 0.999f;
+    const int PROVISION_RETRY_MAX = 5;
+    const F32 PROVISION_RETRY_TIMEOUT = 2.0;
 
-// Defines the maximum number of times(in a row) "stateJoiningSession" case for spatial channel is reached in stateMachine()
-// which is treated as normal. The is the number of frames to wait for a channel join before giving up.  This was changed 
-// from the original count of 50 for two reason.  Modern PCs have higher frame rates and sometimes the SLVoice process 
-// backs up processing join requests.  There is a log statement that records when channel joins take longer than 100 frames.
-const int MAX_NORMAL_JOINING_SPATIAL_NUM = 1500;
+    // Cosine of a "trivially" small angle
+    const F32 MINUSCULE_ANGLE_COS = 0.999f;
 
-// How often to check for expired voice fonts in seconds
-const F32 VOICE_FONT_EXPIRY_INTERVAL = 10.f;
-// Time of day at which Vivox expires voice font subscriptions.
-// Used to replace the time portion of received expiry timestamps.
-static const std::string VOICE_FONT_EXPIRY_TIME = "T05:00:00Z";
+    const F32 SESSION_JOIN_TIMEOUT = 10.0f;
 
-// Maximum length of capture buffer recordings in seconds.
-const F32 CAPTURE_BUFFER_MAX_TIME = 10.f;
+    // Defines the maximum number of times(in a row) "stateJoiningSession" case for spatial channel is reached in stateMachine()
+    // which is treated as normal. The is the number of frames to wait for a channel join before giving up.  This was changed 
+    // from the original count of 50 for two reason.  Modern PCs have higher frame rates and sometimes the SLVoice process 
+    // backs up processing join requests.  There is a log statement that records when channel joins take longer than 100 frames.
+    const int MAX_NORMAL_JOINING_SPATIAL_NUM = 1500;
 
+    // How often to check for expired voice fonts in seconds
+    const F32 VOICE_FONT_EXPIRY_INTERVAL = 10.f;
+    // Time of day at which Vivox expires voice font subscriptions.
+    // Used to replace the time portion of received expiry timestamps.
+    static const std::string VOICE_FONT_EXPIRY_TIME = "T05:00:00Z";
+
+    // Maximum length of capture buffer recordings in seconds.
+    const F32 CAPTURE_BUFFER_MAX_TIME = 10.f;
+
+    const int ERROR_VIVOX_OBJECT_NOT_FOUND = 1001;
+    const int ERROR_VIVOX_NOT_LOGGED_IN = 1007;
+}
 
 static int scale_mic_volume(float volume)
 {
@@ -129,8 +139,6 @@ static int scale_speaker_volume(float volume)
 	
 }
 
-const int ERROR_VIVOX_OBJECT_NOT_FOUND = 1001;
-const int ERROR_VIVOX_NOT_LOGGED_IN = 1007;
 
 ///////////////////////////////////////////////////////////////////////////////////////////////
 
@@ -546,7 +554,7 @@ void LLVivoxVoiceClient::voiceControlCoro()
         // if we hit this and mRelogRequested is true, that indicates
         // that we attempted to relog into Vivox and were rejected.
         // Rather than just quit out of voice, we will tear it down (above)
-        // and then reconstruct the voice connecino from scratch.
+        // and then reconstruct the voice connecion from scratch.
         if (mRelogRequested)
         {
             while (isGatewayRunning())
@@ -784,13 +792,15 @@ bool LLVivoxVoiceClient::provisionVoiceAccount()
 
         if (status == LLCore::HttpStatus(404))
         {
-            if (++retryCount > 5)
+            if (++retryCount > PROVISION_RETRY_MAX)
             {
-                LL_WARNS("Voice") << "Could not access voice provision cap after 5 attempts." << LL_ENDL;
+                LL_WARNS("Voice") << "Could not access voice provision cap after " << PROVISION_RETRY_MAX << " attempts." << LL_ENDL;
                 return false;
             }
-            LL_WARNS("Voice") << "Provision CAP 404.  Retrying in 1.0" << LL_ENDL;
-            llcoro::suspendUntilTimeout(1.0);
+
+            F32 timeout = pow(PROVISION_RETRY_TIMEOUT, static_cast<float>(retryCount));
+            LL_WARNS("Voice") << "Provision CAP 404.  Retrying in " << timeout << " seconds." << LL_ENDL;
+            llcoro::suspendUntilTimeout(timeout);
 
             continue;
         }
@@ -888,21 +898,29 @@ bool LLVivoxVoiceClient::breakVoiceConnection(bool corowait)
 
 bool LLVivoxVoiceClient::loginToVivox()
 {
-    int loginRetryCount(0);
     LLEventPump &voicePump = LLEventPumps::instance().obtain("vivoxClientPump");
 
+    LLSD timeoutResult;
+    timeoutResult["login"] = LLSD::String("timeout");
+
+    LLEventTimeout voicePumpTimeout(voicePump);
+
+    int loginRetryCount(0);
+
     bool response_ok(false);
     bool account_login(false);
     bool send_login(true);
 
     do 
     {
+
         mIsLoggingIn = true;
         if (send_login)
             loginSendMessage();
 
         send_login = false;
 
+        voicePumpTimeout.eventAfter(LOGIN_ATTEMPT_TIMEOUT, timeoutResult);
         LLSD result = llcoro::suspendUntilEventOn(voicePump);
         LL_DEBUGS("Voice") << "event=" << ll_pretty_print_sd(result) << LL_ENDL;
 
@@ -910,16 +928,16 @@ bool LLVivoxVoiceClient::loginToVivox()
         {
             std::string loginresp = result["login"];
 
-            if (loginresp == "retry")
+            if ((loginresp == "retry") || (loginresp == "timeout"))
             {
-                if (!loginRetryCount)
+                if ((!loginRetryCount) && (loginresp != "timeout"))
                 {   // on first retry notify user
                     notifyStatusObservers(LLVoiceClientStatusObserver::STATUS_LOGIN_RETRY);
                 }
 
-                if ((++loginRetryCount > MAX_LOGIN_RETRIES) || (!result["login_retry"]))
+                if ((++loginRetryCount > LOGIN_RETRY_MAX) || (loginresp == "timeout"))
                 {
-                    LL_WARNS("Voice") << "too many login retries, giving up." << LL_ENDL;
+                    LL_WARNS("Voice") << "too many login retries or timeout connecting, giving up." << LL_ENDL;
                     LLSD args;
                     std::stringstream errs;
                     errs << mVoiceAccountServerURI << "\n:UDP: 3478, 3479, 5060, 5062, 12000-17000";
@@ -942,8 +960,10 @@ bool LLVivoxVoiceClient::loginToVivox()
                 account_login = false;
                 send_login = true;
 
-                LL_INFOS("Voice") << "will retry login in " << LOGIN_RETRY_SECONDS << " seconds." << LL_ENDL;
-                llcoro::suspendUntilTimeout(LOGIN_RETRY_SECONDS);
+                F32 timeout = pow(LOGIN_RETRY_TIMEOUT, static_cast<float>(loginRetryCount)) - 1.0f;
+
+                LL_INFOS("Voice") << "will retry login in " << timeout << " seconds." << LL_ENDL;
+                llcoro::suspendUntilTimeout(timeout);
             }
             else if (loginresp == "failed")
             {
@@ -982,7 +1002,6 @@ bool LLVivoxVoiceClient::loginToVivox()
 
 void LLVivoxVoiceClient::logoutOfVivox(bool wait)
 {
-    LLEventPump &voicePump = LLEventPumps::instance().obtain("vivoxClientPump");
 
     if (!mIsLoggedIn)
         return;
@@ -995,7 +1014,14 @@ void LLVivoxVoiceClient::logoutOfVivox(bool wait)
 
     if (wait)
     {
-        LLSD result = llcoro::suspendUntilEventOn(voicePump);
+        LLEventPump &voicePump = LLEventPumps::instance().obtain("vivoxClientPump");
+        LLSD timeoutResult;
+        timeoutResult["logout"] = LLSD::String("timeout");
+
+        LLEventTimeout voicePumpTimeout(voicePump);
+
+        voicePumpTimeout.eventAfter(LOGIN_ATTEMPT_TIMEOUT, timeoutResult);
+        LLSD result = llcoro::suspendUntilEventOn(voicePumpTimeout);
 
         LL_DEBUGS("Voice") << "event=" << ll_pretty_print_sd(result) << LL_ENDL;
 
@@ -1194,13 +1220,20 @@ bool LLVivoxVoiceClient::addAndJoinSession(const sessionStatePtr_t &nextSession)
     bool added(true);
     bool joined(false);
 
+    LLSD timeoutResult;
+    timeoutResult["session"] = LLSD::String("timeout");
+
+    LLEventTimeout voicePumpTimeout(voicePump);
+
+
     // It appears that I need to wait for BOTH the SessionGroup.AddSession response and the SessionStateChangeEvent with state 4
     // before continuing from this state.  They can happen in either order, and if I don't wait for both, things can get stuck.
     // For now, the SessionGroup.AddSession response handler sets mSessionHandle and the SessionStateChangeEvent handler transitions to stateSessionJoined.
     // This is a cheap way to make sure both have happened before proceeding.
     do
     {
-        result = llcoro::suspendUntilEventOn(voicePump);
+        voicePumpTimeout.eventAfter(SESSION_JOIN_TIMEOUT, timeoutResult);
+        result = llcoro::suspendUntilEventOn(voicePumpTimeout);
 
         LL_DEBUGS("Voice") << "event=" << ll_pretty_print_sd(result) << LL_ENDL;
         if (result.has("session"))
@@ -1219,10 +1252,10 @@ bool LLVivoxVoiceClient::addAndJoinSession(const sessionStatePtr_t &nextSession)
                 added = true;
             else if (message == "joined")
                 joined = true;
-            else if ((message == "failed") || (message == "removed"))
+            else if ((message == "failed") || (message == "removed") || (message == "timeout"))
             {   // we will get a removed message if a voice call is declined.
                 
-                if (message == "failed")
+                if (message == "failed") 
                 {
                     int reason = result["reason"].asInteger();
                     LL_WARNS("Voice") << "Add and join failed for reason " << reason << LL_ENDL;
@@ -1638,8 +1671,8 @@ int LLVivoxVoiceClient::voiceRecordBuffer()
     LLSD result;
 
     captureBufferRecordStartSendMessage();
-
     notifyVoiceFontObservers();
+
     do
     {
         result = llcoro::suspendUntilEventOn(voicePump);
@@ -1667,11 +1700,11 @@ int LLVivoxVoiceClient::voicePlaybackBuffer()
 
     LLEventPump &voicePump = LLEventPumps::instance().obtain("vivoxClientPump");
     LLEventTimeout timeout(voicePump);
-    timeout.eventAfter(CAPTURE_BUFFER_MAX_TIME, timeoutResult);
     LLSD result;
 
     do
     {
+        timeout.eventAfter(CAPTURE_BUFFER_MAX_TIME, timeoutResult);
         captureBufferPlayStartSendMessage(mPreviewVoiceFont);
 
         // Store the voice font being previewed, so that we know to restart if it changes.
@@ -1682,7 +1715,7 @@ int LLVivoxVoiceClient::voicePlaybackBuffer()
             // Update UI, should really use a separate callback.
             notifyVoiceFontObservers();
 
-            result = llcoro::suspendUntilEventOn(voicePump);
+            result = llcoro::suspendUntilEventOn(timeout);
             LL_DEBUGS("Voice") << "event=" << ll_pretty_print_sd(result) << LL_ENDL;
         } while (!result.has("recplay"));