Merge pull request #2032 from holochain/backoff-fix

fix broken backoff code

CHANGELOG-UNRELEASED.md

@@ -14,5 +14,6 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm
 
 ### Fixed
 
-### Security
+- Fixes bugs in the sim2 connecting handling. Backoff timing and reset was broken.
 
+### Security

crates/cli/src/cli/sim2h_client.rs

@@ -46,7 +46,7 @@ pub fn sim2h_client(url_string: String, message_string: String) -> Result<(), St
         }
     });
     let timeout = std::time::Instant::now()
-        .checked_add(std::time::Duration::from_millis(10000))
+        .checked_add(std::time::Duration::from_millis(60000))
         .unwrap();
     loop {
         std::thread::sleep(std::time::Duration::from_millis(10));
@@ -134,7 +134,7 @@ impl Job {
 
 fn await_in_stream_connect(connect_uri: &Url2) -> Result<InStreamWss<InStreamTcp>, String> {
     let timeout = std::time::Instant::now()
-        .checked_add(std::time::Duration::from_millis(10000))
+        .checked_add(std::time::Duration::from_millis(60000))
         .unwrap();
 
     let mut read_frame = WsFrame::default();

crates/in_stream/src/ws.rs

@@ -72,7 +72,7 @@ impl<Sub: InStreamListenerStd> InStreamListener<&mut WsFrame, WsFrame>
         let stream: Sub::StreamStd = self.sub.accept_std()?;
 
         let s = stream.into_std_stream();
-        println!("ws: calling accept on {:?}", s);
+        log::debug!("ws: calling accept on {:?}", s);
         let res = tungstenite::accept(s);
         let mut out = InStreamWss::priv_new(Url2::default());
         match out.priv_proc_wss_srv_result(res) {

crates/net/src/sim2h_worker.rs

@@ -29,9 +29,8 @@ use std::{convert::TryFrom, time::Instant};
 use url::Url;
 use url2::prelude::*;
 
-const INITIAL_CONNECTION_TIMEOUT_MS: u64 = 1000;
+const INITIAL_CONNECTION_TIMEOUT_MS: u64 = 2000; // The real initial is 4 seconds because one backoff happens to start
 const MAX_CONNECTION_TIMEOUT_MS: u64 = 60000;
-//const RECONNECT_INTERVAL: Duration = Duration::from_secs(20);
 const SIM2H_WORKER_INTERNAL_REQUEST_ID: &str = "SIM2H_WORKER";
 
 fn connect(url: Lib3hUri, timeout_ms: u64) -> NetResult<TcpWss> {
@@ -82,7 +81,7 @@ impl Sim2hWorker {
         agent_id: Address,
         conductor_api: ConductorApi,
     ) -> NetResult<Self> {
-        let reconnect_interval = Duration::from_secs(INITIAL_CONNECTION_TIMEOUT_MS);
+        let reconnect_interval = Duration::from_millis(INITIAL_CONNECTION_TIMEOUT_MS);
         let mut instance = Self {
             handler,
             connection: None,
@@ -113,21 +112,36 @@ impl Sim2hWorker {
         Ok(instance)
     }
 
+    fn backoff(&mut self) {
+        let new_backoff = std::cmp::max(
+            MAX_CONNECTION_TIMEOUT_MS,
+            self.connection_timeout_backoff * 2,
+        );
+        if self.connection_timeout_backoff != new_backoff {
+            self.inner_set_backoff(self.connection_timeout_backoff * 2);
+        }
+    }
+
+    fn inner_set_backoff(&mut self, backoff: u64) {
+        self.connection_timeout_backoff = backoff;
+        debug!(
+            "BACKOFF setting reconnect interval to {}",
+            self.connection_timeout_backoff
+        );
+        self.reconnect_interval = Duration::from_millis(self.connection_timeout_backoff)
+    }
+
+    fn reset_backoff(&mut self) {
+        if self.connection_timeout_backoff > INITIAL_CONNECTION_TIMEOUT_MS {
+            self.inner_set_backoff(INITIAL_CONNECTION_TIMEOUT_MS);
+        }
+    }
+
     /// check to see if we need to re-connect
-    /// if we don't have a ready connection within RECONNECT_INTERVAL
+    /// if we don't have a ready connection within reconnect_interval
     fn check_reconnect(&mut self) {
         if self.connection_ready() {
-            // if the connection is ready and the backoff interval is greater than initial
-            // means we have actually succeed in connection after a backoff so
-            // now we can reset the backoff
-            if self.connection_timeout_backoff > INITIAL_CONNECTION_TIMEOUT_MS {
-                debug!(
-                    "resetting reconnect interval to {}",
-                    INITIAL_CONNECTION_TIMEOUT_MS
-                );
-                self.connection_timeout_backoff = INITIAL_CONNECTION_TIMEOUT_MS;
-                self.reconnect_interval = Duration::from_secs(self.connection_timeout_backoff)
-            }
+            self.reset_backoff();
             return;
         }
 
@@ -137,23 +151,12 @@ impl Sim2hWorker {
 
         //if self.connection.is_none() {
         warn!(
-            "attempting reconnect, connection state: {:?}",
+            "BACKOFF attempting reconnect, connection state: {:?}",
             self.connection
         );
         //}
 
-        if self.connection_timeout_backoff < MAX_CONNECTION_TIMEOUT_MS {
-            debug!(
-                "attempting reconnect, connection state: {:?}",
-                self.connection
-            );
-            self.connection_timeout_backoff *= 2;
-            debug!(
-                "increasing reconnect interval to {}",
-                self.connection_timeout_backoff
-            );
-            self.reconnect_interval = Duration::from_secs(self.connection_timeout_backoff)
-        }
+        self.backoff();
 
         self.time_of_last_connection_attempt = Instant::now();
         self.connection = None;
@@ -517,6 +520,7 @@ impl NetWorker for Sim2hWorker {
         }
 
         if self.connection_ready() {
+            self.reset_backoff();
             if self.try_send_from_outgoing_buffer() {
                 did_something = true;
             }