feat(fips): fallback telemetry — per-reason counters in fips.status + last-transport recording on all dial sites

Phase A2 of docs/FIPS-UPTIME-AND-UI-STATE-PLAN.md (RC6). Fallbacks to Tor
were debug!-only and uncounted, so "FIPS uptime" was unfalsifiable and
paths that were 100% Tor by construction went unnoticed for months.

- fips::telemetry: process-lifetime counters for FIPS successes and the
  six fallback reasons (no_npub, service_inactive, dns_fail, connect_fail,
  http_404, http_5xx), exposed as `dial_stats` in fips.status
- dial.rs: every fallback branch now counts + logs at info! with a
  `reason` field (resolve/connect/status branches)
- PeerRequest::record_transport(data_dir): opt-in hook that writes the
  transport actually used to federation storage off the hot path — wired
  into the dial sites that never recorded (DWN sync ×3, mesh blob fetch,
  federation deploy notify, onion-rotation notify, node messages via a
  new send_to_peer data-dir param)

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
archipelago 2026-07-27 20:54:35 -04:00
parent eb2fc0f37b
commit e24e0a6473
12 changed files with 267 additions and 11 deletions

View File

@ -465,6 +465,7 @@ impl RpcHandler {
signing_key.as_ref().map(|i| i.signing_key()),
Some(&peer.pubkey),
data.server_info.name.as_deref(),
Some(&self.config.data_dir),
)
.await
}

View File

@ -866,7 +866,8 @@ impl RpcHandler {
)
.service(crate::settings::transport::PeerService::Peers)
.timeout(std::time::Duration::from_secs(30))
.fips_timeout(std::time::Duration::from_secs(6));
.fips_timeout(std::time::Duration::from_secs(6))
.record_transport(&self.config.data_dir);
match req.send_json(&body).await {
Ok((resp, transport)) if resp.status().is_success() => {

View File

@ -13,7 +13,14 @@ use anyhow::Result;
impl RpcHandler {
pub(super) async fn handle_fips_status(&self) -> Result<serde_json::Value> {
let status = fips::FipsStatus::query(&self.config.data_dir).await;
Ok(serde_json::to_value(status)?)
let mut v = serde_json::to_value(status)?;
// Dial outcome counters (process-lifetime): how often peer dials
// used FIPS vs fell back to Tor, broken down by reason. This is
// the observability that makes "FIPS uptime" measurable.
if let Some(obj) = v.as_object_mut() {
obj.insert("dial_stats".to_string(), fips::telemetry::snapshot());
}
Ok(v)
}
/// Everything the companion app needs to join this node's mesh, embedded

View File

@ -821,6 +821,7 @@ impl RpcHandler {
.service(crate::settings::transport::PeerService::MeshFileSharing)
.timeout(std::time::Duration::from_secs(120))
.fips_timeout(std::time::Duration::from_secs(8))
.record_transport(&self.config.data_dir)
.send_get()
.await
.map_err(|e| anyhow::anyhow!("Fetch failed: {}", e))?;

View File

@ -137,6 +137,7 @@ impl RpcHandler {
None,
None,
None,
Some(&self.config.data_dir),
)
.await?;
@ -225,6 +226,7 @@ impl RpcHandler {
signing_key.as_ref().map(|i| i.signing_key()),
Some(&req.from_pubkey),
data.server_info.name.as_deref(),
Some(&self.config.data_dir),
)
.await
{

View File

@ -133,6 +133,7 @@ impl RpcHandler {
Some(node_id.signing_key()),
recipient_pubkey.as_deref(),
node_name.as_deref(),
Some(&self.config.data_dir),
)
.await?;
Ok(serde_json::json!({ "ok": true, "sent_to": onion }))

View File

@ -499,7 +499,8 @@ pub(super) async fn notify_federation_peers_address_change(
)
.service(crate::settings::transport::PeerService::Peers)
.timeout(std::time::Duration::from_secs(30))
.fips_timeout(std::time::Duration::from_secs(6));
.fips_timeout(std::time::Duration::from_secs(6))
.record_transport(data_dir);
match req.send_json(&payload).await {
Ok((_, transport)) => {
info!(peer_did = %peer.did, transport = %transport, "Notified peer of address change")

View File

@ -24,6 +24,7 @@
//! ```
#![allow(dead_code)]
use super::telemetry::{self, FallbackReason};
use anyhow::{Context, Result};
use std::net::{IpAddr, Ipv6Addr};
use std::time::Duration;
@ -317,6 +318,11 @@ pub struct PeerRequest<'a> {
/// large content download needs so its long FIPS transfer isn't truncated.
pub fips_timeout: Option<std::time::Duration>,
pub service: Option<crate::settings::transport::PeerService>,
/// When set, the transport that actually served this request is written
/// to federation storage (`record_peer_transport`, matched by onion) so
/// the per-peer FIPS/Tor badge reflects reality. Opt-in because not
/// every caller has a data dir in scope.
pub record_data_dir: Option<std::path::PathBuf>,
}
impl<'a> PeerRequest<'a> {
@ -329,6 +335,31 @@ impl<'a> PeerRequest<'a> {
timeout: std::time::Duration::from_secs(30),
fips_timeout: None,
service: None,
record_data_dir: None,
}
}
/// Record the transport that serves this request into federation storage
/// (matched by this request's onion host). Best-effort, off the hot path.
pub fn record_transport(mut self, data_dir: impl Into<std::path::PathBuf>) -> Self {
self.record_data_dir = Some(data_dir.into());
self
}
fn spawn_record(&self, kind: crate::transport::TransportKind) {
if let Some(dir) = &self.record_data_dir {
let dir = dir.clone();
let onion = self.onion_host.to_string();
let transport = kind.to_string();
tokio::spawn(async move {
let _ = crate::federation::record_peer_transport(
&dir,
None,
Some(&onion),
&transport,
)
.await;
});
}
}
@ -389,8 +420,22 @@ impl<'a> PeerRequest<'a> {
// fix (404 path-not-served / 5xx) and we're allowed to
// fall back. FIPS-only never falls back.
if pref == TransportPref::Fips || !fips_should_fall_back(resp.status()) {
telemetry::record_fips_ok();
self.spawn_record(crate::transport::TransportKind::Fips);
return Ok((resp, crate::transport::TransportKind::Fips));
}
let reason = if resp.status() == reqwest::StatusCode::NOT_FOUND {
FallbackReason::Http404
} else {
FallbackReason::Http5xx
};
telemetry::record_fallback(reason);
tracing::info!(
reason = reason.key(),
status = %resp.status(),
"FIPS POST {} answered but status triggers Tor fallback",
self.path
);
}
None => {
if pref == TransportPref::Fips {
@ -402,6 +447,7 @@ impl<'a> PeerRequest<'a> {
}
}
let resp = self.send_tor_post_json(body).await?;
self.spawn_record(crate::transport::TransportKind::Tor);
Ok((resp, crate::transport::TransportKind::Tor))
}
@ -413,8 +459,22 @@ impl<'a> PeerRequest<'a> {
match self.try_fips_get().await? {
Some(resp) => {
if pref == TransportPref::Fips || !fips_should_fall_back(resp.status()) {
telemetry::record_fips_ok();
self.spawn_record(crate::transport::TransportKind::Fips);
return Ok((resp, crate::transport::TransportKind::Fips));
}
let reason = if resp.status() == reqwest::StatusCode::NOT_FOUND {
FallbackReason::Http404
} else {
FallbackReason::Http5xx
};
telemetry::record_fallback(reason);
tracing::info!(
reason = reason.key(),
status = %resp.status(),
"FIPS GET {} answered but status triggers Tor fallback",
self.path
);
}
None => {
if pref == TransportPref::Fips {
@ -426,6 +486,7 @@ impl<'a> PeerRequest<'a> {
}
}
let resp = self.send_tor_get().await?;
self.spawn_record(crate::transport::TransportKind::Tor);
Ok((resp, crate::transport::TransportKind::Tor))
}
@ -434,15 +495,23 @@ impl<'a> PeerRequest<'a> {
body: &B,
) -> Result<Option<reqwest::Response>> {
let Some(npub) = self.fips_npub else {
telemetry::record_fallback(FallbackReason::NoNpub);
return Ok(None);
};
if !is_service_active().await {
telemetry::record_fallback(FallbackReason::ServiceInactive);
return Ok(None);
}
let base = match peer_base_url(npub).await {
Ok(b) => b,
Err(e) => {
tracing::debug!("FIPS resolve for {} failed: {}", npub, e);
telemetry::record_fallback(FallbackReason::DnsFail);
tracing::info!(
reason = FallbackReason::DnsFail.key(),
"FIPS resolve for {} failed: {}, falling back to Tor",
npub,
e
);
return Ok(None);
}
};
@ -467,7 +536,9 @@ impl<'a> PeerRequest<'a> {
match tokio::time::timeout(budget, send_with_retry(rb)).await {
Ok(Ok(r)) => Ok(Some(r)),
Ok(Err(e)) => {
tracing::debug!(
telemetry::record_fallback(FallbackReason::ConnectFail);
tracing::info!(
reason = FallbackReason::ConnectFail.key(),
"FIPS POST {} failed after retry: {}, falling back to Tor",
url,
e
@ -475,7 +546,9 @@ impl<'a> PeerRequest<'a> {
Ok(None)
}
Err(_) => {
tracing::debug!(
telemetry::record_fallback(FallbackReason::ConnectFail);
tracing::info!(
reason = FallbackReason::ConnectFail.key(),
"FIPS POST {} exceeded attempt budget {:?}, falling back to Tor",
url,
budget
@ -487,15 +560,23 @@ impl<'a> PeerRequest<'a> {
async fn try_fips_get(&self) -> Result<Option<reqwest::Response>> {
let Some(npub) = self.fips_npub else {
telemetry::record_fallback(FallbackReason::NoNpub);
return Ok(None);
};
if !is_service_active().await {
telemetry::record_fallback(FallbackReason::ServiceInactive);
return Ok(None);
}
let base = match peer_base_url(npub).await {
Ok(b) => b,
Err(e) => {
tracing::debug!("FIPS resolve for {} failed: {}", npub, e);
telemetry::record_fallback(FallbackReason::DnsFail);
tracing::info!(
reason = FallbackReason::DnsFail.key(),
"FIPS resolve for {} failed: {}, falling back to Tor",
npub,
e
);
return Ok(None);
}
};
@ -516,7 +597,9 @@ impl<'a> PeerRequest<'a> {
match tokio::time::timeout(budget, send_with_retry(rb)).await {
Ok(Ok(r)) => Ok(Some(r)),
Ok(Err(e)) => {
tracing::debug!(
telemetry::record_fallback(FallbackReason::ConnectFail);
tracing::info!(
reason = FallbackReason::ConnectFail.key(),
"FIPS GET {} failed after retry: {}, falling back to Tor",
url,
e
@ -524,7 +607,9 @@ impl<'a> PeerRequest<'a> {
Ok(None)
}
Err(_) => {
tracing::debug!(
telemetry::record_fallback(FallbackReason::ConnectFail);
tracing::info!(
reason = FallbackReason::ConnectFail.key(),
"FIPS GET {} exceeded attempt budget {:?}, falling back to Tor",
url,
budget

View File

@ -31,6 +31,7 @@ pub mod config;
pub mod dial;
pub mod iface;
pub mod service;
pub mod telemetry;
pub mod update;
use serde::{Deserialize, Serialize};

View File

@ -0,0 +1,144 @@
//! In-process counters for FIPS dial outcomes.
//!
//! Every peer dial that could have used FIPS either succeeds over FIPS or
//! falls back to Tor for one of six reasons (F1F6). Before these counters
//! existed, fallbacks were `debug!`-only and invisible in production, which
//! made "FIPS uptime" unfalsifiable — several paths were 100% Tor for months
//! (dead ports, firewalled listeners, allowlist 404s) and nothing surfaced
//! it. The counters are process-lifetime (reset on restart) and exposed via
//! `fips.status` as `dial_stats`, so a fleet-wide fallback regression shows
//! up on the dashboard instead of as vague slowness.
use std::sync::atomic::{AtomicU64, Ordering};
/// Why a FIPS-capable dial fell back to Tor.
#[derive(Clone, Copy, Debug, PartialEq, Eq)]
pub enum FallbackReason {
/// F1 — no FIPS npub known for the peer (never meshed, or pre-npub
/// federation record). Expected for non-FIPS peers; high counts here
/// mean npub propagation is broken, not the transport.
NoNpub,
/// F2 — the local FIPS daemon service isn't active.
ServiceInactive,
/// F3 — the local FIPS DNS resolver couldn't resolve the peer's npub
/// (daemon up but peer not in the identity cache / mesh unreachable).
DnsFail,
/// F4 — TCP/HTTP dial to the peer's ULA failed or exceeded the FIPS
/// attempt budget (firewalled :5679, cold hole-punch, peer down).
ConnectFail,
/// F5 — peer answered over FIPS with 404: its listener doesn't serve
/// this path (older build / stricter allowlist).
Http404,
/// F6 — peer answered over FIPS with a 5xx server error.
Http5xx,
}
impl FallbackReason {
pub fn key(self) -> &'static str {
match self {
Self::NoNpub => "no_npub",
Self::ServiceInactive => "service_inactive",
Self::DnsFail => "dns_fail",
Self::ConnectFail => "connect_fail",
Self::Http404 => "http_404",
Self::Http5xx => "http_5xx",
}
}
}
static FIPS_OK: AtomicU64 = AtomicU64::new(0);
static NO_NPUB: AtomicU64 = AtomicU64::new(0);
static SERVICE_INACTIVE: AtomicU64 = AtomicU64::new(0);
static DNS_FAIL: AtomicU64 = AtomicU64::new(0);
static CONNECT_FAIL: AtomicU64 = AtomicU64::new(0);
static HTTP_404: AtomicU64 = AtomicU64::new(0);
static HTTP_5XX: AtomicU64 = AtomicU64::new(0);
fn counter(reason: FallbackReason) -> &'static AtomicU64 {
match reason {
FallbackReason::NoNpub => &NO_NPUB,
FallbackReason::ServiceInactive => &SERVICE_INACTIVE,
FallbackReason::DnsFail => &DNS_FAIL,
FallbackReason::ConnectFail => &CONNECT_FAIL,
FallbackReason::Http404 => &HTTP_404,
FallbackReason::Http5xx => &HTTP_5XX,
}
}
/// A dial completed over FIPS (any HTTP status that wasn't a fallback
/// trigger — the peer was reached on the mesh).
pub fn record_fips_ok() {
FIPS_OK.fetch_add(1, Ordering::Relaxed);
}
/// A FIPS-capable dial fell back to Tor.
pub fn record_fallback(reason: FallbackReason) {
counter(reason).fetch_add(1, Ordering::Relaxed);
}
/// Snapshot for `fips.status` (`dial_stats`). Process-lifetime counts.
pub fn snapshot() -> serde_json::Value {
let f1 = NO_NPUB.load(Ordering::Relaxed);
let f2 = SERVICE_INACTIVE.load(Ordering::Relaxed);
let f3 = DNS_FAIL.load(Ordering::Relaxed);
let f4 = CONNECT_FAIL.load(Ordering::Relaxed);
let f5 = HTTP_404.load(Ordering::Relaxed);
let f6 = HTTP_5XX.load(Ordering::Relaxed);
serde_json::json!({
"fips_ok": FIPS_OK.load(Ordering::Relaxed),
"fallbacks": {
"no_npub": f1,
"service_inactive": f2,
"dns_fail": f3,
"connect_fail": f4,
"http_404": f5,
"http_5xx": f6,
"total": f1 + f2 + f3 + f4 + f5 + f6,
},
})
}
#[cfg(test)]
mod tests {
use super::*;
#[test]
fn snapshot_counts_recorded_events() {
// Counters are global; assert deltas rather than absolutes so this
// test stays correct alongside any other test that dials.
let before = snapshot();
record_fips_ok();
record_fallback(FallbackReason::ConnectFail);
record_fallback(FallbackReason::Http404);
let after = snapshot();
let d = |v: &serde_json::Value, path: &[&str]| -> u64 {
let mut cur = v;
for p in path {
cur = &cur[p];
}
cur.as_u64().unwrap()
};
assert_eq!(d(&after, &["fips_ok"]) - d(&before, &["fips_ok"]), 1);
assert_eq!(
d(&after, &["fallbacks", "connect_fail"]) - d(&before, &["fallbacks", "connect_fail"]),
1
);
assert_eq!(
d(&after, &["fallbacks", "http_404"]) - d(&before, &["fallbacks", "http_404"]),
1
);
assert!(d(&after, &["fallbacks", "total"]) >= 2);
}
#[test]
fn reason_keys_are_stable() {
// These strings are the fips.status API surface — renaming one is a
// breaking change for the UI.
assert_eq!(FallbackReason::NoNpub.key(), "no_npub");
assert_eq!(FallbackReason::ServiceInactive.key(), "service_inactive");
assert_eq!(FallbackReason::DnsFail.key(), "dns_fail");
assert_eq!(FallbackReason::ConnectFail.key(), "connect_fail");
assert_eq!(FallbackReason::Http404.key(), "http_404");
assert_eq!(FallbackReason::Http5xx.key(), "http_5xx");
}
}

View File

@ -134,6 +134,7 @@ pub async fn sync_with_peers(data_dir: &Path, peer_onions: &[String]) -> Result<
for onion in &unique_onions {
let fips_npub = crate::federation::fips_npub_for_onion(data_dir, onion).await;
match sync_single_peer(
data_dir,
fips_npub.as_deref(),
&store,
onion,
@ -173,6 +174,7 @@ pub async fn sync_with_peers(data_dir: &Path, peer_onions: &[String]) -> Result<
/// Sync with a single peer: pull their messages and push ours.
/// Each HTTP call picks FIPS when a npub is known, otherwise Tor.
async fn sync_single_peer(
data_dir: &Path,
fips_npub: Option<&str>,
store: &crate::network::dwn_store::DwnStore,
onion: &str,
@ -187,6 +189,7 @@ async fn sync_single_peer(
.service(crate::settings::transport::PeerService::Federation)
.timeout(std::time::Duration::from_secs(30))
.fips_timeout(std::time::Duration::from_secs(6))
.record_transport(data_dir)
.send_get()
.await
.context("Peer DWN unreachable")?;
@ -213,6 +216,7 @@ async fn sync_single_peer(
.service(crate::settings::transport::PeerService::Federation)
.timeout(std::time::Duration::from_secs(30))
.fips_timeout(std::time::Duration::from_secs(6))
.record_transport(data_dir)
.send_json(&pull_body)
.await
.context("Failed to query peer DWN")?;
@ -272,6 +276,7 @@ async fn sync_single_peer(
.service(crate::settings::transport::PeerService::Federation)
.timeout(std::time::Duration::from_secs(30))
.fips_timeout(std::time::Duration::from_secs(6))
.record_transport(data_dir)
.send_json(&push_body)
.await
{

View File

@ -342,6 +342,9 @@ pub async fn send_to_peer(
signing_key: Option<&ed25519_dalek::SigningKey>,
recipient_pubkey: Option<&str>,
from_name: Option<&str>,
// Federation data dir for last-transport recording; None skips recording
// (callers without a data dir in scope).
record_data_dir: Option<&std::path::Path>,
) -> Result<()> {
validate_onion(onion)?;
@ -370,11 +373,15 @@ pub async fn send_to_peer(
body["from_name"] = serde_json::Value::String(name.to_string());
}
let (resp, transport) =
let mut req =
crate::fips::dial::PeerRequest::new(fips_npub, onion, "/archipelago/node-message")
.service(crate::settings::transport::PeerService::Messaging)
.timeout(std::time::Duration::from_secs(60))
.fips_timeout(std::time::Duration::from_secs(8))
.fips_timeout(std::time::Duration::from_secs(8));
if let Some(dir) = record_data_dir {
req = req.record_transport(dir);
}
let (resp, transport) = req
.send_json(&body)
.await
.map_err(|e| {