From 9258563f9cd6b989f46ed1185baceb92b3459ab7 Mon Sep 17 00:00:00 2001 From: atlas Date: Sat, 17 Oct 2026 01:13:12 +0200 Subject: [PATCH] log the queue-connect and identity-mint failures the alert rules match hh-swarm-queue-connect-failed matched "swarm queue connect failed; this agent publishes nothing upward", which nothing has logged since the harness started retrying its first connect and exiting (235bc481b). The rule now matches the error the harness logs when every attempt has failed, CONNECT_EXHAUSTED in swarm_queue.rs, and its comment and summary describe the retry-then-exit behaviour. A failed MintAgentIdentity node logged nothing: the error reached only the job graph. mint_identity now warns with the agent and the error, and hh-agent-identity-mint-failed fires on that line. Refs #4651 --- Cargo.lock | 1 + docs/swarm/README.md | 9 +++- hive-agent/Cargo.toml | 2 + hive-agent/src/swarm_queue.rs | 63 ++++++++++++++++++++++-- nix/host-modules/swarm-grafana.nix | 27 ++++++++--- swarm-controller/src/main.rs | 78 +++++++++++++++++++++++++++++- 6 files changed, 166 insertions(+), 14 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index c01aff5f..bdc42108 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1695,6 +1695,7 @@ dependencies = [ "tower", "tower-http 0.7.0", "tracing", + "tracing-subscriber", ] [[package]] diff --git a/docs/swarm/README.md b/docs/swarm/README.md index 2ca6acb2..60c72a18 100644 --- a/docs/swarm/README.md +++ b/docs/swarm/README.md @@ -53,7 +53,10 @@ grafana, the controller, authelia, …) → the agent roster and their wanted state, and the job graph. Creating an agent — from the swarm UI or `swarmctl agent create --hive ` — queues its SSO identity, forge user, config repo, store identity and matrix account, then -sends the hive a deploy message. A new agent starts `paused`. +sends the hive a deploy message. A new agent starts `paused`. A store identity +that fails to mint logs `swarm jobq: mint_agent_identity failed` with the agent +and the error, which the Grafana alert rule `hh-agent-identity-mint-failed` +fires on. The agent is still created, without a store identity. `services.hyperhive.deploy.swarm-controller.enable` runs it on this host; `singleHostSwarm` turns it on. **Otherwise off: set it on the one host that @@ -184,7 +187,9 @@ show the agent nor send it anything, so a harness without one stops: certificate) exits at boot with an error naming what's missing. - A harness whose first connect fails tries again after 5 seconds, doubling the wait each time, and logs a warning for each attempt that fails. After the - seventh, about five minutes in, it logs an error and exits. + seventh, about five minutes in, it logs an error and exits. The error reads + `no swarm queue connection; exiting, since this agent cannot run without one`, + and the Grafana alert rule `hh-swarm-queue-connect-failed` fires on it. Either way the harness exits and comes back until the queue accepts it. Once connected, the client reconnects by itself after a dropped connection, reading diff --git a/hive-agent/Cargo.toml b/hive-agent/Cargo.toml index e6680cf2..725630c3 100644 --- a/hive-agent/Cargo.toml +++ b/hive-agent/Cargo.toml @@ -59,6 +59,8 @@ tracing.workspace = true tempfile = "3" tokio = { workspace = true, features = ["test-util"] } tower = { version = "0.5", features = ["util"] } +# A layer that captures `swarm_queue`'s exhausted-connect log event in a test. +tracing-subscriber.workspace = true # Single harness serve-loop binary: `hive-agent` (from `src/main.rs`). # The sibling MCP server is its own bin crate now (`hive-agent-mcp`). diff --git a/hive-agent/src/swarm_queue.rs b/hive-agent/src/swarm_queue.rs index dffff2a4..c6ea3959 100644 --- a/hive-agent/src/swarm_queue.rs +++ b/hive-agent/src/swarm_queue.rs @@ -45,6 +45,13 @@ const CONNECT_BACKOFF: [Duration; 6] = [ Duration::from_secs(160), ]; +/// Logged at `error` once every first-connect attempt has failed, just before +/// the process exits. The Grafana rule `hh-swarm-queue-connect-failed` +/// (`nix/host-modules/swarm-grafana.nix`) matches this exact text: change both +/// together. +const CONNECT_EXHAUSTED: &str = + "no swarm queue connection; exiting, since this agent cannot run without one"; + /// Where to connect, resolved once at boot by [`init`]. static AGENT: OnceLock = OnceLock::new(); @@ -300,14 +307,15 @@ async fn connect_or_exit() -> async_nats::Client { None => Err(anyhow!("swarm_queue::init has not run")), }; connected.unwrap_or_else(|e| { - tracing::error!( - error = format!("{e:#}"), - "no swarm queue connection; exiting, since this agent cannot run without one" - ); + log_connect_exhausted(&e); std::process::exit(1) }) } +fn log_connect_exhausted(e: &anyhow::Error) { + tracing::error!(error = format!("{e:#}"), "{CONNECT_EXHAUSTED}"); +} + /// One connection attempt with this agent's own credential. async fn connect_once(agent: &AgentPath) -> anyhow::Result { let secret = AgentSecret::new(Arc::clone(&agent.store)); @@ -390,10 +398,11 @@ mod tests { use std::time::Duration; use anyhow::anyhow; + use tracing_subscriber::layer::SubscriberExt as _; use super::{ AgentPath, AgentSecret, CONNECT_BACKOFF, SecretSource, StoreSource, agent_path, - connect_as_agent, retry_first_connect, store_source, + connect_as_agent, log_connect_exhausted, retry_first_connect, store_source, }; /// A lookup standing in for a container that was handed a store and the @@ -546,6 +555,50 @@ mod tests { ); } + /// The level and message of every event. + #[derive(Clone, Default)] + struct Messages(Arc>>); + + impl tracing_subscriber::Layer for Messages { + fn on_event( + &self, + event: &tracing::Event<'_>, + _: tracing_subscriber::layer::Context<'_, S>, + ) { + let mut message = String::new(); + event.record( + &mut |field: &tracing::field::Field, value: &dyn std::fmt::Debug| { + if field.name() == "message" { + message = format!("{value:?}"); + } + }, + ); + self.0 + .lock() + .expect("unpoisoned") + .push((*event.metadata().level(), message)); + } + } + + /// The literal is the `_msg` that `hh-swarm-queue-connect-failed` in + /// `nix/host-modules/swarm-grafana.nix` matches. + #[test] + fn an_exhausted_connect_logs_the_line_the_alert_rule_matches() { + let messages = Messages::default(); + let subscriber = tracing_subscriber::registry().with(messages.clone()); + tracing::subscriber::with_default(subscriber, || { + log_connect_exhausted(&anyhow!("7 connection attempts failed")); + }); + assert_eq!( + *messages.0.lock().expect("unpoisoned"), + [( + tracing::Level::ERROR, + "no swarm queue connection; exiting, since this agent cannot run without one" + .to_owned() + )] + ); + } + enum Answer { Value(&'static str), Absent, diff --git a/nix/host-modules/swarm-grafana.nix b/nix/host-modules/swarm-grafana.nix index fee35331..5de9d826 100644 --- a/nix/host-modules/swarm-grafana.nix +++ b/nix/host-modules/swarm-grafana.nix @@ -1497,17 +1497,19 @@ in for = "5m"; summary = "{{ $labels.hive }}/{{ $labels.agent }} is dropping swarm terminal rows: the harness is not connected to the queue"; }) - # Logged once per agent process: the connection is made - # once and never retried, so the agent stays unconnected - # until it restarts. The window is how long the rule - # stays firing after that one line. + # `CONNECT_EXHAUSTED` in hive-agent's swarm_queue.rs, + # logged when the harness's first-connect retries + # (about five minutes) all fail, just before it exits. + # systemd restarts it 30s later, so an agent that never + # connects logs it about every six minutes. The window + # is how long the rule stays firing after the last one. (logCountRule { uid = "hh-swarm-queue-connect-failed"; title = "swarm queue connect failed"; windowSeconds = 3600; - expr = ''_time:1h _msg:"swarm queue connect failed; this agent publishes nothing upward" | stats by (hive, agent) count() as failures''; + expr = ''_time:1h _msg:"no swarm queue connection; exiting, since this agent cannot run without one" | stats by (hive, agent) count() as failures''; for = "0s"; - summary = "{{ $labels.hive }}/{{ $labels.agent }} could not connect to the swarm queue and publishes nothing upward until it restarts"; + summary = "{{ $labels.hive }}/{{ $labels.agent }} could not connect to the swarm queue and its harness exited; systemd starts it again 30s later"; }) (logCountRule { uid = "hh-swarm-agent-state-publish-skipped"; @@ -1553,6 +1555,19 @@ in for = "15m"; summary = "swarm-controller has failed the agent credential renewal pass on consecutive ticks"; }) + # `MINT_IDENTITY_FAILED` in swarm-controller's main.rs, + # logged once per failed `MintAgentIdentity` job node, at + # agent creation or on a certificate renewal; the window + # is how long the rule stays firing after it. Host + # journal records carry the tracing fields as `F_`. + (logCountRule { + uid = "hh-agent-identity-mint-failed"; + title = "agent identity mint failed"; + windowSeconds = 900; + expr = ''_time:15m _SYSTEMD_UNIT:="swarm-controller.service" _msg:"swarm jobq: mint_agent_identity failed" | stats by (F_AGENT) count() as failures''; + for = "0s"; + summary = "swarm-controller failed to mint agent {{ $labels.F_AGENT }}'s store identity; the reason is the `F_ERROR` field of the swarm-controller log line"; + }) # Logged once per refused deploy request, by # `apply_rev` in hive-c0re's swarm_status.rs; the window is # how long the rule stays firing after it. Host journal diff --git a/swarm-controller/src/main.rs b/swarm-controller/src/main.rs index 24bac328..400fbc41 100644 --- a/swarm-controller/src/main.rs +++ b/swarm-controller/src/main.rs @@ -460,6 +460,12 @@ async fn forge_node( }) } +/// Logged at `warn`, with the agent and the error, when [`mint_identity`] +/// fails. The Grafana rule `hh-agent-identity-mint-failed` +/// (`nix/host-modules/swarm-grafana.nix`) matches this exact text: change both +/// together. +const MINT_IDENTITY_FAILED: &str = "swarm jobq: mint_agent_identity failed"; + /// The `MintAgentIdentity` arm, lifted out so `run_swarm_node` stays under /// `clippy::too_many_lines`. async fn mint_identity(agent: &str) -> hive_jobq::scheduler::Outcome { @@ -467,7 +473,11 @@ async fn mint_identity(agent: &str) -> hive_jobq::scheduler::Outcome { match agent_identity::mint_and_verify(agent).await { Ok(()) => Outcome::Done, - Err(e) => Outcome::Failed(format!("{e:#}")), + Err(e) => { + let error = format!("{e:#}"); + tracing::warn!(%agent, %error, "{MINT_IDENTITY_FAILED}"); + Outcome::Failed(error) + } } } @@ -6364,3 +6374,69 @@ mod create_agent_warning_tests { assert_eq!(json, r#"{"node_id":7,"warnings":["name is reserved"]}"#); } } + +#[cfg(test)] +mod mint_identity_tests { + use std::sync::{Arc, Mutex}; + + use hive_jobq::scheduler::Outcome; + use tracing_subscriber::layer::SubscriberExt as _; + + use super::mint_identity; + + /// One event's level and its fields, each by name. + type Event = (tracing::Level, Vec<(String, String)>); + + /// Every event. + #[derive(Clone, Default)] + struct Events(Arc>>); + + impl tracing_subscriber::Layer for Events { + fn on_event( + &self, + event: &tracing::Event<'_>, + _: tracing_subscriber::layer::Context<'_, S>, + ) { + let mut fields = Vec::new(); + event.record( + &mut |field: &tracing::field::Field, value: &dyn std::fmt::Debug| { + fields.push((field.name().to_owned(), format!("{value:?}"))); + }, + ); + self.0 + .lock() + .expect("unpoisoned") + .push((*event.metadata().level(), fields)); + } + } + + /// An agent name the store would refuse fails the mint before any store + /// call, whatever this process's environment holds. The literal is the + /// `_msg` that `hh-agent-identity-mint-failed` in + /// `nix/host-modules/swarm-grafana.nix` matches. + #[tokio::test] + async fn a_failed_mint_logs_the_agent_and_the_error_on_the_line_the_alert_rule_matches() { + let events = Events::default(); + let _guard = + tracing::subscriber::set_default(tracing_subscriber::registry().with(events.clone())); + + let Outcome::Failed(error) = mint_identity("a/b").await else { + panic!("an illegal agent name cannot be minted"); + }; + + let got = events.0.lock().expect("unpoisoned").clone(); + let [(level, fields)] = got.as_slice() else { + panic!("one event, got {got:?}"); + }; + assert_eq!(*level, tracing::Level::WARN); + let field = |name: &str| { + fields + .iter() + .find(|(n, _)| n == name) + .map_or_else(|| panic!("no {name} in {fields:?}"), |(_, v)| v.clone()) + }; + assert_eq!(field("message"), "swarm jobq: mint_agent_identity failed"); + assert_eq!(field("agent"), "a/b"); + assert_eq!(field("error"), error); + } +}