retry: replace three hand-rolled doubling loops with backon
This commit is contained in:
parent
e92f118bda
commit
0f67ec34b1
7 changed files with 141 additions and 83 deletions
2
Cargo.lock
generated
2
Cargo.lock
generated
|
|
@ -1664,6 +1664,7 @@ dependencies = [
|
||||||
"anyhow",
|
"anyhow",
|
||||||
"async-nats",
|
"async-nats",
|
||||||
"axum",
|
"axum",
|
||||||
|
"backon",
|
||||||
"chrono",
|
"chrono",
|
||||||
"clap",
|
"clap",
|
||||||
"futures-util",
|
"futures-util",
|
||||||
|
|
@ -1762,6 +1763,7 @@ dependencies = [
|
||||||
"anyhow",
|
"anyhow",
|
||||||
"async-nats",
|
"async-nats",
|
||||||
"axum",
|
"axum",
|
||||||
|
"backon",
|
||||||
"base64",
|
"base64",
|
||||||
"chrono",
|
"chrono",
|
||||||
"clap",
|
"clap",
|
||||||
|
|
|
||||||
|
|
@ -81,6 +81,7 @@ unescaped_backticks = "deny"
|
||||||
anyhow = "1"
|
anyhow = "1"
|
||||||
libc = "0.2"
|
libc = "0.2"
|
||||||
axum = { version = "0.8", features = ["ws"] }
|
axum = { version = "0.8", features = ["ws"] }
|
||||||
|
backon = "1"
|
||||||
base64 = "0.22"
|
base64 = "0.22"
|
||||||
chrono = { version = "0.4", default-features = false, features = [
|
chrono = { version = "0.4", default-features = false, features = [
|
||||||
"clock",
|
"clock",
|
||||||
|
|
|
||||||
|
|
@ -14,6 +14,7 @@ anyhow.workspace = true
|
||||||
# handling live in `swarm-queue-client` below.
|
# handling live in `swarm-queue-client` below.
|
||||||
async-nats = { workspace = true, features = ["jetstream"] }
|
async-nats = { workspace = true, features = ["jetstream"] }
|
||||||
axum.workspace = true
|
axum.workspace = true
|
||||||
|
backon.workspace = true
|
||||||
chrono.workspace = true
|
chrono.workspace = true
|
||||||
reqwest.workspace = true
|
reqwest.workspace = true
|
||||||
hyper.workspace = true
|
hyper.workspace = true
|
||||||
|
|
|
||||||
|
|
@ -22,6 +22,7 @@ use std::path::Path;
|
||||||
use std::time::Duration;
|
use std::time::Duration;
|
||||||
|
|
||||||
use async_nats::jetstream::context::PublishErrorKind;
|
use async_nats::jetstream::context::PublishErrorKind;
|
||||||
|
use backon::{ExponentialBuilder, Retryable};
|
||||||
|
|
||||||
/// Where the agent's NixOS config puts the icon
|
/// Where the agent's NixOS config puts the icon
|
||||||
/// (`services.hyperhive.agent.icon`), and the file `GET /icon` serves. Absent
|
/// (`services.hyperhive.agent.icon`), and the file `GET /icon` serves. Absent
|
||||||
|
|
@ -29,7 +30,7 @@ use async_nats::jetstream::context::PublishErrorKind;
|
||||||
const ICON_PATH: &str = "/etc/hyperhive/icon.svg";
|
const ICON_PATH: &str = "/etc/hyperhive/icon.svg";
|
||||||
|
|
||||||
/// First retry delay after a failed write, doubled per failure up to
|
/// First retry delay after a failed write, doubled per failure up to
|
||||||
/// [`MAX_RETRY`].
|
/// [`MAX_RETRY`], with no cap on the number of tries.
|
||||||
const FIRST_RETRY: Duration = Duration::from_secs(5);
|
const FIRST_RETRY: Duration = Duration::from_secs(5);
|
||||||
|
|
||||||
/// Longest wait between retries.
|
/// Longest wait between retries.
|
||||||
|
|
@ -80,27 +81,33 @@ async fn run(agent: String) {
|
||||||
}
|
}
|
||||||
};
|
};
|
||||||
let js = async_nats::jetstream::new(client.clone());
|
let js = async_nats::jetstream::new(client.clone());
|
||||||
let mut delay = FIRST_RETRY;
|
let written = (|| write(&client, &js, &subject, &icon))
|
||||||
loop {
|
.retry(
|
||||||
match write(&client, &js, &subject, &icon).await {
|
ExponentialBuilder::default()
|
||||||
Ok(()) => {
|
.with_min_delay(FIRST_RETRY)
|
||||||
tracing::info!(
|
.with_max_delay(MAX_RETRY)
|
||||||
subject,
|
.without_max_times(),
|
||||||
set = matches!(icon, Icon::Set(_)),
|
)
|
||||||
"published this agent's icon"
|
.when(|failure| matches!(failure, Failure::Retry(_)))
|
||||||
);
|
.notify(|failure, delay| {
|
||||||
return;
|
if let Failure::Retry(e) = failure {
|
||||||
}
|
|
||||||
Err(Failure::TooLarge(e)) => {
|
|
||||||
tracing::warn!(error = %e, "the agent icon is over the queue's payload limit; not publishing it");
|
|
||||||
return;
|
|
||||||
}
|
|
||||||
Err(Failure::Retry(e)) => {
|
|
||||||
tracing::warn!(error = e, retry_in = ?delay, "publishing the agent icon failed");
|
tracing::warn!(error = e, retry_in = ?delay, "publishing the agent icon failed");
|
||||||
}
|
}
|
||||||
|
})
|
||||||
|
.await;
|
||||||
|
match written {
|
||||||
|
Ok(()) => tracing::info!(
|
||||||
|
subject,
|
||||||
|
set = matches!(icon, Icon::Set(_)),
|
||||||
|
"published this agent's icon"
|
||||||
|
),
|
||||||
|
Err(Failure::TooLarge(e)) => {
|
||||||
|
tracing::warn!(error = %e, "the agent icon is over the queue's payload limit; not publishing it");
|
||||||
|
}
|
||||||
|
// Only a `TooLarge` ends the retries.
|
||||||
|
Err(Failure::Retry(e)) => {
|
||||||
|
tracing::error!(error = e, "gave up publishing the agent icon");
|
||||||
}
|
}
|
||||||
tokio::time::sleep(delay).await;
|
|
||||||
delay = (delay * 2).min(MAX_RETRY);
|
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
|
|
||||||
|
|
@ -21,6 +21,7 @@ use std::net::SocketAddr;
|
||||||
use std::path::{Path, PathBuf};
|
use std::path::{Path, PathBuf};
|
||||||
use std::sync::atomic::AtomicBool;
|
use std::sync::atomic::AtomicBool;
|
||||||
use std::sync::{Arc, Mutex};
|
use std::sync::{Arc, Mutex};
|
||||||
|
use std::time::Duration;
|
||||||
|
|
||||||
use anyhow::{Context, Result};
|
use anyhow::{Context, Result};
|
||||||
use axum::{
|
use axum::{
|
||||||
|
|
@ -29,6 +30,7 @@ use axum::{
|
||||||
response::{IntoResponse, Response},
|
response::{IntoResponse, Response},
|
||||||
routing::{get, post},
|
routing::{get, post},
|
||||||
};
|
};
|
||||||
|
use backon::{ExponentialBuilder, Retryable};
|
||||||
use tower_http::services::ServeDir;
|
use tower_http::services::ServeDir;
|
||||||
|
|
||||||
use crate::events::Bus;
|
use crate::events::Bus;
|
||||||
|
|
@ -221,38 +223,34 @@ const MAX_BIND_ATTEMPTS: u32 = 12;
|
||||||
/// Retry rationale + dashboard-banner-on-real-collision:
|
/// Retry rationale + dashboard-banner-on-real-collision:
|
||||||
/// see `docs/web-ui/shape.md::Listener bind`.
|
/// see `docs/web-ui/shape.md::Listener bind`.
|
||||||
async fn bind_with_retry(addr: SocketAddr, label: &str) -> Result<tokio::net::TcpListener> {
|
async fn bind_with_retry(addr: SocketAddr, label: &str) -> Result<tokio::net::TcpListener> {
|
||||||
let mut delay_ms = 250u64;
|
let mut retries = 0u32;
|
||||||
let mut attempts = 0u32;
|
let bound = (|| async { try_bind(addr) })
|
||||||
loop {
|
.retry(
|
||||||
match try_bind(addr) {
|
ExponentialBuilder::default()
|
||||||
Ok(l) => {
|
.with_min_delay(Duration::from_millis(250))
|
||||||
if attempts > 0 {
|
.with_max_delay(Duration::from_secs(2))
|
||||||
tracing::info!(
|
.with_max_times((MAX_BIND_ATTEMPTS - 1) as usize),
|
||||||
%addr, attempts,
|
)
|
||||||
"{label}: bind succeeded after retry"
|
.when(|e| e.kind() == std::io::ErrorKind::AddrInUse)
|
||||||
);
|
.notify(|_, delay| {
|
||||||
}
|
retries += 1;
|
||||||
return Ok(l);
|
tracing::warn!(
|
||||||
}
|
%addr, attempt = retries,
|
||||||
Err(e) if e.kind() == std::io::ErrorKind::AddrInUse => {
|
"{label}: AddrInUse, retrying in {}ms", delay.as_millis()
|
||||||
let attempt = attempts + 1;
|
);
|
||||||
if attempt >= MAX_BIND_ATTEMPTS {
|
})
|
||||||
return Err(e).with_context(|| {
|
.await;
|
||||||
format!("bind {label} on {addr}: still AddrInUse after {attempt} attempts")
|
match bound {
|
||||||
});
|
Ok(l) => {
|
||||||
}
|
if retries > 0 {
|
||||||
tracing::warn!(
|
tracing::info!(%addr, attempts = retries, "{label}: bind succeeded after retry");
|
||||||
%addr, attempt,
|
|
||||||
"{label}: AddrInUse, retrying in {delay_ms}ms"
|
|
||||||
);
|
|
||||||
tokio::time::sleep(std::time::Duration::from_millis(delay_ms)).await;
|
|
||||||
attempts += 1;
|
|
||||||
delay_ms = (delay_ms * 2).min(2000);
|
|
||||||
}
|
|
||||||
Err(e) => {
|
|
||||||
return Err(e).with_context(|| format!("bind {label} on {addr}"));
|
|
||||||
}
|
}
|
||||||
|
Ok(l)
|
||||||
}
|
}
|
||||||
|
Err(e) if e.kind() == std::io::ErrorKind::AddrInUse => Err(e).with_context(|| {
|
||||||
|
format!("bind {label} on {addr}: still AddrInUse after {MAX_BIND_ATTEMPTS} attempts")
|
||||||
|
}),
|
||||||
|
Err(e) => Err(e).with_context(|| format!("bind {label} on {addr}")),
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
|
@ -484,10 +482,49 @@ mod tests {
|
||||||
use axum::http::{Request, StatusCode, header};
|
use axum::http::{Request, StatusCode, header};
|
||||||
use tower::ServiceExt;
|
use tower::ServiceExt;
|
||||||
|
|
||||||
use super::{AppState, SigintOutcome, routes, sigint_turn};
|
use super::{AppState, SigintOutcome, bind_with_retry, routes, sigint_turn, try_bind};
|
||||||
use crate::events::Bus;
|
use crate::events::Bus;
|
||||||
use crate::login::LoginState;
|
use crate::login::LoginState;
|
||||||
|
|
||||||
|
/// A port another listener holds for a moment is waited out.
|
||||||
|
#[tokio::test(start_paused = true)]
|
||||||
|
async fn bind_waits_out_a_port_that_is_briefly_held() {
|
||||||
|
let holder = try_bind("127.0.0.1:0".parse().expect("addr")).expect("holder");
|
||||||
|
let addr = holder.local_addr().expect("local addr");
|
||||||
|
let release = tokio::spawn(async move {
|
||||||
|
tokio::time::sleep(Duration::from_secs(1)).await;
|
||||||
|
drop(holder);
|
||||||
|
});
|
||||||
|
let bound = bind_with_retry(addr, "test")
|
||||||
|
.await
|
||||||
|
.expect("bind after release");
|
||||||
|
assert_eq!(bound.local_addr().expect("local addr"), addr);
|
||||||
|
release.await.expect("release task");
|
||||||
|
}
|
||||||
|
|
||||||
|
/// A port that stays held ends in an `AddrInUse` error after 12 attempts:
|
||||||
|
/// 11 waits of 250ms doubling to the 2s cap.
|
||||||
|
#[tokio::test(start_paused = true)]
|
||||||
|
async fn bind_gives_up_when_the_port_stays_held() {
|
||||||
|
let holder = try_bind("127.0.0.1:0".parse().expect("addr")).expect("holder");
|
||||||
|
let addr = holder.local_addr().expect("local addr");
|
||||||
|
let start = tokio::time::Instant::now();
|
||||||
|
let err = bind_with_retry(addr, "test")
|
||||||
|
.await
|
||||||
|
.expect_err("port is held");
|
||||||
|
assert_eq!(
|
||||||
|
start.elapsed(),
|
||||||
|
Duration::from_millis(250 + 500 + 1000 + 8 * 2000)
|
||||||
|
);
|
||||||
|
assert!(err.to_string().contains("after 12 attempts"), "{err:#}");
|
||||||
|
assert_eq!(
|
||||||
|
err.downcast_ref::<std::io::Error>()
|
||||||
|
.map(std::io::Error::kind),
|
||||||
|
Some(std::io::ErrorKind::AddrInUse)
|
||||||
|
);
|
||||||
|
drop(holder);
|
||||||
|
}
|
||||||
|
|
||||||
fn form(path: &str, body: &'static str) -> Request<Body> {
|
fn form(path: &str, body: &'static str) -> Request<Body> {
|
||||||
Request::post(path)
|
Request::post(path)
|
||||||
.header(header::CONTENT_TYPE, "application/x-www-form-urlencoded")
|
.header(header::CONTENT_TYPE, "application/x-www-form-urlencoded")
|
||||||
|
|
|
||||||
|
|
@ -16,6 +16,7 @@ anyhow.workspace = true
|
||||||
# around; the connect itself lives in `swarm-queue-client` below.
|
# around; the connect itself lives in `swarm-queue-client` below.
|
||||||
async-nats.workspace = true
|
async-nats.workspace = true
|
||||||
axum.workspace = true
|
axum.workspace = true
|
||||||
|
backon.workspace = true
|
||||||
chrono.workspace = true
|
chrono.workspace = true
|
||||||
base64.workspace = true
|
base64.workspace = true
|
||||||
reqwest.workspace = true
|
reqwest.workspace = true
|
||||||
|
|
|
||||||
|
|
@ -3,6 +3,7 @@
|
||||||
|
|
||||||
use std::net::SocketAddr;
|
use std::net::SocketAddr;
|
||||||
use std::sync::Arc;
|
use std::sync::Arc;
|
||||||
|
use std::time::Duration;
|
||||||
|
|
||||||
use anyhow::{Context, Result};
|
use anyhow::{Context, Result};
|
||||||
use axum::{
|
use axum::{
|
||||||
|
|
@ -11,6 +12,7 @@ use axum::{
|
||||||
response::{IntoResponse, Response},
|
response::{IntoResponse, Response},
|
||||||
routing::get,
|
routing::get,
|
||||||
};
|
};
|
||||||
|
use backon::{ExponentialBuilder, Retryable};
|
||||||
use utoipa::OpenApi;
|
use utoipa::OpenApi;
|
||||||
use utoipa_axum::{router::OpenApiRouter, routes};
|
use utoipa_axum::{router::OpenApiRouter, routes};
|
||||||
|
|
||||||
|
|
@ -166,41 +168,33 @@ pub async fn serve(port: u16, coord: Arc<Coordinator>) -> Result<()> {
|
||||||
/// `SO_REUSEADDR` bind with retry. Retry mechanics, attempt-cap
|
/// `SO_REUSEADDR` bind with retry. Retry mechanics, attempt-cap
|
||||||
/// rationale, and log-level cadence: `docs/web-ui/shape.md::Listener bind`.
|
/// rationale, and log-level cadence: `docs/web-ui/shape.md::Listener bind`.
|
||||||
async fn bind_with_retry(addr: SocketAddr) -> Result<tokio::net::TcpListener> {
|
async fn bind_with_retry(addr: SocketAddr) -> Result<tokio::net::TcpListener> {
|
||||||
let mut delay_ms = 250u64;
|
let mut retries = 0u32;
|
||||||
let mut attempts = 0u32;
|
let listener = (|| async { try_bind(addr) })
|
||||||
loop {
|
.retry(
|
||||||
match try_bind(addr) {
|
ExponentialBuilder::default()
|
||||||
Ok(l) => {
|
.with_min_delay(Duration::from_millis(250))
|
||||||
if attempts > 0 {
|
.with_max_delay(Duration::from_secs(2))
|
||||||
tracing::info!(
|
.without_max_times(),
|
||||||
%addr, attempts,
|
)
|
||||||
"dashboard: bind succeeded after retry"
|
.when(|e| e.kind() == std::io::ErrorKind::AddrInUse)
|
||||||
);
|
.notify(|_, delay| {
|
||||||
}
|
retries += 1;
|
||||||
return Ok(l);
|
let ms = delay.as_millis();
|
||||||
|
if retries <= 12 {
|
||||||
|
tracing::warn!(%addr, attempt = retries, "dashboard: AddrInUse, retrying in {ms}ms");
|
||||||
|
} else {
|
||||||
|
tracing::info!(
|
||||||
|
%addr, attempt = retries,
|
||||||
|
"dashboard: AddrInUse still holding, retrying in {ms}ms"
|
||||||
|
);
|
||||||
}
|
}
|
||||||
Err(e) if e.kind() == std::io::ErrorKind::AddrInUse => {
|
})
|
||||||
let attempt = attempts + 1;
|
.await
|
||||||
if attempt <= 12 {
|
.with_context(|| format!("bind dashboard on {addr}"))?;
|
||||||
tracing::warn!(
|
if retries > 0 {
|
||||||
%addr, attempt,
|
tracing::info!(%addr, attempts = retries, "dashboard: bind succeeded after retry");
|
||||||
"dashboard: AddrInUse, retrying in {delay_ms}ms"
|
|
||||||
);
|
|
||||||
} else {
|
|
||||||
tracing::info!(
|
|
||||||
%addr, attempt,
|
|
||||||
"dashboard: AddrInUse still holding, retrying in {delay_ms}ms"
|
|
||||||
);
|
|
||||||
}
|
|
||||||
tokio::time::sleep(std::time::Duration::from_millis(delay_ms)).await;
|
|
||||||
attempts += 1;
|
|
||||||
delay_ms = (delay_ms * 2).min(2000);
|
|
||||||
}
|
|
||||||
Err(e) => {
|
|
||||||
return Err(e).with_context(|| format!("bind dashboard on {addr}"));
|
|
||||||
}
|
|
||||||
}
|
|
||||||
}
|
}
|
||||||
|
Ok(listener)
|
||||||
}
|
}
|
||||||
|
|
||||||
fn try_bind(addr: SocketAddr) -> std::io::Result<tokio::net::TcpListener> {
|
fn try_bind(addr: SocketAddr) -> std::io::Result<tokio::net::TcpListener> {
|
||||||
|
|
@ -312,6 +306,21 @@ mod tests {
|
||||||
.unwrap_or_else(|| panic!("no status line in {reply:?}"))
|
.unwrap_or_else(|| panic!("no status line in {reply:?}"))
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// The dashboard never gives up on a held port: a holder that lets go well
|
||||||
|
/// after the attempt count where the log level drops still gets waited out.
|
||||||
|
#[tokio::test(start_paused = true)]
|
||||||
|
async fn bind_keeps_retrying_until_the_port_is_free() {
|
||||||
|
let holder = try_bind("127.0.0.1:0".parse().expect("addr")).expect("holder");
|
||||||
|
let addr = holder.local_addr().expect("local addr");
|
||||||
|
let release = tokio::spawn(async move {
|
||||||
|
tokio::time::sleep(Duration::from_mins(5)).await;
|
||||||
|
drop(holder);
|
||||||
|
});
|
||||||
|
let bound = bind_with_retry(addr).await.expect("bind after release");
|
||||||
|
assert_eq!(bound.local_addr().expect("local addr"), addr);
|
||||||
|
release.await.expect("release task");
|
||||||
|
}
|
||||||
|
|
||||||
#[tokio::test]
|
#[tokio::test]
|
||||||
async fn operator_inbox_route_is_gone() {
|
async fn operator_inbox_route_is_gone() {
|
||||||
assert_eq!(status_of("/health/live").await, 200);
|
assert_eq!(status_of("/health/live").await, 200);
|
||||||
|
|
|
||||||
Loading…
Reference in a new issue