daemon: rate-limit failed recycles, add metric + tests

Address review feedback on proactive max-age recycling:

- Blocker: a failed recycle attempt kept the existing connection (good)
  but did not update any timestamp, so is_expired() stayed true and every
  subsequent request re-attempted the recycle first -- each failed
  attempt blocking up to DAEMON_CONNECTION_TIMEOUT under the connection
  mutex. During a sustained "new connections fail" event this turned
  every fast RPC into a request paying a full connect timeout. Now a
  failed attempt records last_recycle_attempt and a cooldown
  (DAEMON_CONN_RECYCLE_COOLDOWN, default 30s) gates retries, so the old
  socket keeps serving requests at full speed between attempts.

- Extract the recycle decision into a pure `recycle_due()` helper and
  cover it with unit tests (max-age boundary, None, and cooldown).

- Add a daemon_rpc_conn_recycled{result="ok|failed"} counter so recycle
  behavior is observable in prod.

- tcp_connect_once no longer warns per-attempt; it returns one
  descriptive error that callers log, avoiding double log lines on the
  recycle path. The startup/error loop logs that error + backoff.

- Document in --daemon-rpc-conn-max-age help that the reconnect is inline
  on the request path, so the value should be generous (minutes).

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>

Author: DeviaVir

src/config.rs

@@ -182,7 +182,7 @@ impl Config {
             .arg(
                 Arg::with_name("daemon_rpc_conn_max_age")
                     .long("daemon-rpc-conn-max-age")
-                    .help("Max age (in seconds) of a daemon RPC TCP connection before it is proactively recycled. Recycling re-establishes the connection, letting a load balancer (e.g. a Kubernetes ClusterSetIP) re-select a backend after node rotations. 0 = unlimited / never recycle (default)")
+                    .help("Max age (in seconds) of a daemon RPC TCP connection before it is proactively recycled. Recycling re-establishes the connection, letting a load balancer (e.g. a Kubernetes ClusterSetIP) re-select a backend after node rotations. The reconnect happens inline on the next request, so prefer a generous value (minutes, not seconds) to avoid periodic latency spikes. 0 = unlimited / never recycle (default)")
                     .default_value("0")
                     .takes_value(true),
             )

src/daemon.rs

@@ -24,7 +24,7 @@ use elements::encode::{deserialize, serialize_hex};
 use electrs_macros::trace;
 
 use crate::chain::{Block, BlockHash, BlockHeader, Network, Transaction, Txid};
-use crate::metrics::{HistogramOpts, HistogramVec, Metrics};
+use crate::metrics::{CounterVec, HistogramOpts, HistogramVec, MetricOpts, Metrics};
 use crate::signal::Waiter;
 use crate::util::{HeaderList, DEFAULT_BLOCKHASH};
 
@@ -40,6 +40,11 @@ lazy_static! {
     static ref DAEMON_WRITE_TIMEOUT: Duration = Duration::from_secs(
         env::var("DAEMON_WRITE_TIMEOUT").map_or(10 * 60, |s| s.parse().unwrap())
     );
+    // Minimum delay between *failed* proactive max-age recycle attempts, so that a sustained
+    // inability to open new connections doesn't make every request pay a connect timeout.
+    static ref DAEMON_CONN_RECYCLE_COOLDOWN: Duration = Duration::from_secs(
+        env::var("DAEMON_CONN_RECYCLE_COOLDOWN").map_or(30, |s| s.parse().unwrap())
+    );
 }
 
 const MAX_ATTEMPTS: u32 = 5;
@@ -196,6 +201,9 @@ struct Connection {
     established: Instant,
     // Maximum age of a connection before it is proactively recycled, or None for unlimited.
     max_age: Option<Duration>,
+    // When the last *failed* proactive recycle attempt happened, used to rate-limit retries
+    // (see `DAEMON_CONN_RECYCLE_COOLDOWN`). None until a recycle attempt fails.
+    last_recycle_attempt: Option<Instant>,
 }
 
 fn configure_stream(conn: &TcpStream) {
@@ -220,33 +228,26 @@ fn tcp_connect_once(
         }
         Err(err) => err,
     };
-    let suffix = if fallback.is_some() {
-        " (trying fallback...)"
-    } else {
-        ""
-    };
-    warn!(
-        "failed to connect to primary daemon at {}: {}{}",
-        primary, primary_err, suffix
-    );
+    // Return a single descriptive error and let the caller decide how to log it, rather than
+    // warning per-attempt here (which would double-log on the best-effort recycle path).
     match fallback {
-        Some(fallback_addr) => match TcpStream::connect_timeout(&fallback_addr, *DAEMON_CONNECTION_TIMEOUT) {
-            Ok(conn) => {
-                info!("connected to fallback daemon at {}", fallback_addr);
-                configure_stream(&conn);
-                Ok((conn, fallback_addr))
-            }
-            Err(fallback_err) => {
-                warn!(
-                    "failed to connect to fallback daemon at {}: {}",
-                    fallback_addr, fallback_err
-                );
-                bail!(ErrorKind::Connection(format!(
+        Some(fallback_addr) => {
+            debug!(
+                "primary daemon at {} unreachable ({}), trying fallback {}",
+                primary, primary_err, fallback_addr
+            );
+            match TcpStream::connect_timeout(&fallback_addr, *DAEMON_CONNECTION_TIMEOUT) {
+                Ok(conn) => {
+                    info!("connected to fallback daemon at {}", fallback_addr);
+                    configure_stream(&conn);
+                    Ok((conn, fallback_addr))
+                }
+                Err(fallback_err) => bail!(ErrorKind::Connection(format!(
                     "failed to connect to primary daemon at {} ({}) and fallback at {} ({})",
                     primary, primary_err, fallback_addr, fallback_err
-                )))
+                ))),
             }
-        },
+        }
         None => bail!(ErrorKind::Connection(format!(
             "failed to connect to daemon at {}: {}",
             primary, primary_err
@@ -266,15 +267,36 @@ fn tcp_connect(
     loop {
         match tcp_connect_once(primary, fallback) {
             Ok(res) => return Ok(res),
-            Err(_) => {
-                warn!("backoff 3 seconds before next attempt");
+            Err(err) => {
+                warn!(
+                    "{}; backoff 3 seconds before next attempt",
+                    err.display_chain()
+                );
                 signal.wait(Duration::from_secs(3), false)?;
                 continue;
             }
         }
     }
 }
 
+/// Decide whether an expired connection is due for a (re)attempt at proactive recycling.
+/// Returns false when no max age is configured, when the connection is younger than the max
+/// age, or when a previous recycle attempt failed less than `cooldown` ago (to avoid paying a
+/// connect timeout on every request during a sustained connect failure). Pure for testability.
+fn recycle_due(
+    age: Duration,
+    max_age: Option<Duration>,
+    since_last_attempt: Option<Duration>,
+    cooldown: Duration,
+) -> bool {
+    match max_age {
+        None => false,
+        Some(max_age) => {
+            age >= max_age && since_last_attempt.map_or(true, |since| since >= cooldown)
+        }
+    }
+}
+
 impl Connection {
     #[trace]
     fn new(
@@ -313,6 +335,7 @@ impl Connection {
             signal,
             established: Instant::now(),
             max_age,
+            last_recycle_attempt: None,
         })
     }
 
@@ -345,11 +368,16 @@ impl Connection {
         )
     }
 
-    /// Whether this connection has exceeded its configured `max_age` and should be recycled.
+    /// Whether this connection is due to be proactively recycled now: it has exceeded its
+    /// configured `max_age` and no recent recycle attempt has failed within the cooldown.
     /// Always false when no max age is configured (unlimited).
-    fn is_expired(&self) -> bool {
-        self.max_age
-            .map_or(false, |max_age| self.established.elapsed() >= max_age)
+    fn should_recycle(&self) -> bool {
+        recycle_due(
+            self.established.elapsed(),
+            self.max_age,
+            self.last_recycle_attempt.map(|at| at.elapsed()),
+            *DAEMON_CONN_RECYCLE_COOLDOWN,
+        )
     }
 
     #[trace]
@@ -462,6 +490,7 @@ pub struct Daemon {
     // monitoring
     latency: HistogramVec,
     size: HistogramVec,
+    conn_recycle: CounterVec,
 }
 
 impl Daemon {
@@ -506,6 +535,13 @@ impl Daemon {
                 HistogramOpts::new("daemon_bytes", "Bitcoind RPC size (in bytes)"),
                 &["method", "dir"],
             ),
+            conn_recycle: metrics.counter_vec(
+                MetricOpts::new(
+                    "daemon_rpc_conn_recycled",
+                    "Proactive daemon RPC connection recycle attempts (by result)",
+                ),
+                &["result"],
+            ),
         };
         let network_info = daemon.getnetworkinfo()?;
         info!("{:?}", network_info);
@@ -551,6 +587,7 @@ impl Daemon {
             rpc_threads: self.rpc_threads.clone(),
             latency: self.latency.clone(),
             size: self.size.clone(),
+            conn_recycle: self.conn_recycle.clone(),
         })
     }
 
@@ -597,7 +634,7 @@ impl Daemon {
         // the TCP connection lets a fronting load balancer (e.g. a Kubernetes ClusterSetIP)
         // re-select a backend, so a long-lived connection does not stay pinned to a stale
         // endpoint after node rotations. No-op when no max age is configured (the default).
-        if conn.is_expired() {
+        if conn.should_recycle() {
             match conn.try_reconnect_once() {
                 Ok(new_conn) => {
                     debug!(
@@ -606,12 +643,16 @@ impl Daemon {
                         conn.established.elapsed()
                     );
                     *conn = new_conn;
+                    self.conn_recycle.with_label_values(&["ok"]).inc();
                 }
                 Err(err) => {
                     // Recycling is best-effort: if no fresh socket is available (e.g. a
                     // transient load-balancer hiccup), keep using the existing healthy
-                    // connection and retry recycling on a later request, rather than
-                    // blocking requests while the connection is still usable.
+                    // connection rather than blocking requests while it is still usable.
+                    // Record the failed attempt so we don't retry (and pay a connect timeout)
+                    // on every subsequent request; the next attempt waits out the cooldown.
+                    conn.last_recycle_attempt = Some(Instant::now());
+                    self.conn_recycle.with_label_values(&["failed"]).inc();
                     warn!(
                         "failed recycling expired daemon RPC connection, keeping existing connection: {}",
                         err.display_chain()
@@ -996,3 +1037,44 @@ impl Daemon {
         Ok(relayfee * 100_000f64)
     }
 }
+
+#[cfg(test)]
+mod tests {
+    use super::recycle_due;
+    use std::time::Duration;
+
+    const COOLDOWN: Duration = Duration::from_secs(30);
+    const MAX_AGE: Option<Duration> = Some(Duration::from_secs(60));
+
+    fn secs(n: u64) -> Duration {
+        Duration::from_secs(n)
+    }
+
+    #[test]
+    fn no_max_age_never_recycles() {
+        // Unlimited (the default): never recycle, regardless of age.
+        assert!(!recycle_due(secs(10_000), None, None, COOLDOWN));
+    }
+
+    #[test]
+    fn younger_than_max_age_does_not_recycle() {
+        assert!(!recycle_due(secs(5), MAX_AGE, None, COOLDOWN));
+    }
+
+    #[test]
+    fn expired_with_no_prior_attempt_recycles() {
+        assert!(recycle_due(secs(61), MAX_AGE, None, COOLDOWN));
+    }
+
+    #[test]
+    fn expired_within_cooldown_waits() {
+        // A recent failed attempt should suppress retries until the cooldown elapses,
+        // even though the connection is well past its max age.
+        assert!(!recycle_due(secs(600), MAX_AGE, Some(secs(5)), COOLDOWN));
+    }
+
+    #[test]
+    fn expired_after_cooldown_retries() {
+        assert!(recycle_due(secs(600), MAX_AGE, Some(secs(31)), COOLDOWN));
+    }
+}