diff --git a/src/bin/fipsctl.rs b/src/bin/fipsctl.rs index 737dedee..8fb7fe3e 100644 --- a/src/bin/fipsctl.rs +++ b/src/bin/fipsctl.rs @@ -1088,6 +1088,15 @@ fn settled_text(name: &str, stage: &serde_json::Value) -> String { Some(n) => format!("no reply to {n} requests"), None => "no reply".to_string(), }, + "bloom_unconfirmed" => match stage.get("attempts").and_then(|v| v.as_u64()) { + Some(1) => { + "a peer filter claimed this address; 1 request went unanswered".to_string() + } + Some(n) => { + format!("a peer filter claimed this address; {n} requests went unanswered") + } + None => "a peer filter claimed this address; nothing answered for it".to_string(), + }, "already_pending" => "joined a lookup already in flight, which failed".to_string(), other => other.replace('_', " "), }, @@ -1287,9 +1296,34 @@ fn rtt_text(rtt: &serde_json::Value) -> String { /// The closing paragraph, which must not claim reachability it did not observe. fn overall_note(report: &serde_json::Value) -> Option<&'static str> { - if field(report, "overall") != "partial" { - return None; + match field(report, "overall") { + "partial" => partial_note(report), + "failed" => failed_note(report), + _ => None, } +} + +/// A failed probe's closing paragraph. Only the unconfirmed-claim case earns +/// one: it is the reading the operator cannot make from the reason alone, and +/// it is the one that otherwise reads as a network fault. +fn failed_note(report: &serde_json::Value) -> Option<&'static str> { + match field(report.get("discovery")?, "reason") { + "bloom_unconfirmed" => Some( + " A peer's bloom filter claimed this address and then no lookup\n\ + \x20 answered for it. A filter cannot miss a key that IS on the\n\ + \x20 mesh, so an absent address produces exactly this whenever some\n\ + \x20 peer's filter false-positives on it -- the same finding the\n\ + \x20 fast bloom_miss reports, reached the slow way. An address that\n\ + \x20 is present but whose lookups are being lost produces it too.\n\ + \x20 The wait says nothing about which; it is the ladder running to\n\ + \x20 the end.", + ), + _ => None, + } +} + +/// The partial-verdict paragraph, keyed on what the rtt stage settled on. +fn partial_note(report: &serde_json::Value) -> Option<&'static str> { match field(report.get("rtt")?, "reason") { "no_report" => Some( " The handshake completed, so our packets reached them. Nothing has\n\ @@ -1598,6 +1632,97 @@ mod tests { assert_eq!(rows[0].text, "no peer filter holds this address"); } + /// A finished probe of an address that is not on the mesh, under a given + /// gate outcome. `bloom_miss` is the run where no filter claimed it; + /// `bloom_unconfirmed` is the run where one did and no lookup answered. + fn absent_key_report(claimed: bool) -> serde_json::Value { + if claimed { + serde_json::json!({ + "overall": "failed", + "elapsed_ms": 17000, + "bloom": {"verdict": "ok", "reason": null, "elapsed_ms": 1000, "fanout": 1}, + "discovery": {"verdict": "failed", "reason": "bloom_unconfirmed", + "elapsed_ms": 16000, "attempts": 4, + "attempt_timeouts_secs": [1, 2, 4, 8]}, + "path": {"verdict": "skipped", "reason": "not_reached"}, + "session": {"verdict": "skipped", "reason": "not_reached"}, + "rtt": {"verdict": "skipped", "reason": "not_reached"}, + }) + } else { + serde_json::json!({ + "overall": "failed", + "elapsed_ms": 1900, + "bloom": {"verdict": "failed", "reason": "bloom_miss", "elapsed_ms": 1900, + "fanout": null}, + "discovery": {"verdict": "skipped", "reason": "not_reached"}, + "path": {"verdict": "skipped", "reason": "not_reached"}, + "session": {"verdict": "skipped", "reason": "not_reached"}, + "rtt": {"verdict": "skipped", "reason": "not_reached"}, + }) + } + } + + #[test] + fn the_two_absent_key_paths_read_differently_to_the_operator() { + let clean = absent_key_report(false); + let claimed = absent_key_report(true); + + let clean_rows = stage_rows(&clean); + let clean_text = clean_rows[row_at(&clean_rows, "bloom")].text.clone(); + let claimed_rows = stage_rows(&claimed); + let claimed_text = claimed_rows[row_at(&claimed_rows, "discovery")] + .text + .clone(); + + assert_eq!(clean_text, "no peer filter holds this address"); + assert_ne!( + clean_text, claimed_text, + "the two paths must not print the same line" + ); + assert!( + claimed_text.contains("claimed this address"), + "the slow line must say a filter claimed it: {claimed_text}" + ); + assert!( + claimed_text.contains('4'), + "and how many requests went unanswered: {claimed_text}" + ); + + // The line `no_response` used to print. It says nothing about why a + // request went out, which is the whole finding here. + assert_ne!( + claimed_text, "no reply to 4 requests", + "the claimed path must not fall back to the bare no-reply wording" + ); + + // The closing paragraph is where the operator is told what the wait + // meant. Only the claimed path earns one. + let note = overall_note(&claimed).unwrap_or_default(); + assert!( + note.contains("false-positive"), + "the note must name the mechanism: {note}" + ); + assert!( + note.contains("bloom_miss"), + "and tie it to the fast answer: {note}" + ); + assert!(overall_note(&clean).is_none()); + } + + #[test] + fn a_bare_no_response_still_reads_as_a_missing_reply() { + // The reason survives for the case it still describes: the gate's + // answer never arrived, so no claim was ever made. + let mut report = absent_key_report(true); + report["discovery"]["reason"] = serde_json::json!("no_response"); + let rows = stage_rows(&report); + assert_eq!( + rows[row_at(&rows, "discovery")].text, + "no reply to 4 requests" + ); + assert!(overall_note(&report).is_none()); + } + #[test] fn a_failed_path_keeps_the_stages_that_ran_after_it() { // The path preview names no hop and the session succeeds anyway, diff --git a/src/proto/probe/core.rs b/src/proto/probe/core.rs index a6532fd3..7d26e4f9 100644 --- a/src/proto/probe/core.rs +++ b/src/proto/probe/core.rs @@ -408,12 +408,23 @@ impl Probe { let gave_up = self.lookup_was_pending && !obs.lookup_pending; if gave_up || obs.now_ms.saturating_sub(self.stage_started_ms) >= self.budgets.discovery_ms { - let reason = if self.lookup_outcome == Some(LookupOutcomeKind::Deduplicated) { - FailKind::AlreadyPending - } else { - FailKind::NoResponse - }; - self.fail_stage(reason, obs); + self.fail_stage(self.discovery_fail_kind(), obs); + } + } + + /// Which "the lookup did not answer" finding this probe has earned. + /// + /// The gate proceeds only when some peer's filter claimed the target, so + /// a `Sent` lookup that goes unanswered is a claim nobody could confirm. + /// Reporting that as a bare `NoResponse` reads as a network fault and + /// hides the one fact the resolver does know: a filter put the key on the + /// mesh and the mesh disagreed. A joined lookup is its own finding again, + /// because this probe never chose to issue it. + fn discovery_fail_kind(&self) -> FailKind { + match self.lookup_outcome { + Some(LookupOutcomeKind::Deduplicated) => FailKind::AlreadyPending, + Some(LookupOutcomeKind::Sent) => FailKind::BloomUnconfirmed, + _ => FailKind::NoResponse, } } @@ -644,7 +655,8 @@ impl Probe { /// the reason its own budget would have given. fn expire_running_stage(&mut self) { let kind = match self.stage { - Stage::Bloom | Stage::Discovery => FailKind::NoResponse, + Stage::Bloom => FailKind::NoResponse, + Stage::Discovery => self.discovery_fail_kind(), Stage::Path => FailKind::NoNextHop, Stage::Session => { if self.owns_session { diff --git a/src/proto/probe/state.rs b/src/proto/probe/state.rs index 0f6ebe1d..80cd47f7 100644 --- a/src/proto/probe/state.rs +++ b/src/proto/probe/state.rs @@ -64,6 +64,12 @@ pub(crate) enum FailKind { NoTreePeers, /// discovery: the attempt ladder was exhausted, or the budget expired. NoResponse, + /// discovery: the gate proceeded on a peer filter's claim and the lookup + /// was never answered, so the claim was never confirmed. Distinct from + /// `NoResponse` because the reason a request went out at all is part of + /// the finding: a filter cannot miss a key that is present, so on an + /// absent key this is that filter false-positiving. + BloomUnconfirmed, /// path: the two coordinates have different spanning-tree roots. DisjointTrees, /// path: no send-ready peer is strictly closer to the target. @@ -96,6 +102,7 @@ impl FailKind { FailKind::AlreadyPending => "already_pending", FailKind::NoTreePeers => "no_tree_peers", FailKind::NoResponse => "no_response", + FailKind::BloomUnconfirmed => "bloom_unconfirmed", FailKind::DisjointTrees => "disjoint_trees", FailKind::NoNextHop => "no_next_hop", FailKind::Preexisting => "preexisting", diff --git a/src/proto/probe/tests/core.rs b/src/proto/probe/tests/core.rs index cc883665..962b2a1b 100644 --- a/src/proto/probe/tests/core.rs +++ b/src/proto/probe/tests/core.rs @@ -4,8 +4,8 @@ use crate::NodeAddr; use crate::proto::probe::core::{Budgets, Observation, Probe, ProbeAction}; use crate::proto::probe::state::{ - FailKind, LeftIntact, LookupOutcomeKind, NextHopFacts, PathFacts, Preflight, ResolveSource, - RttCounters, StageVerdict, + FailKind, LeftIntact, LookupOutcomeKind, NextHopFacts, Overall, PathFacts, Preflight, + ResolveSource, RttCounters, StageVerdict, }; use crate::proto::routing::RouteClass; @@ -166,7 +166,7 @@ fn discovery_times_out_at_its_own_budget_measured_from_the_request() { assert_eq!(probe.step(&o), vec![ProbeAction::Finish]); let snap = probe.snapshot(); assert_eq!(snap.discovery.verdict, StageVerdict::Failed); - assert_eq!(snap.discovery.reason, Some(FailKind::NoResponse)); + assert_eq!(snap.discovery.reason, Some(FailKind::BloomUnconfirmed)); assert_eq!( snap.bloom.verdict, StageVerdict::Ok, @@ -198,7 +198,7 @@ fn discovery_fails_early_when_the_pending_entry_clears() { assert_eq!(probe.step(&o), vec![ProbeAction::Finish]); assert_eq!( probe.snapshot().discovery.reason, - Some(FailKind::NoResponse) + Some(FailKind::BloomUnconfirmed) ); assert!(T0 + 2_000 < T0 + b.discovery_ms); } @@ -250,6 +250,111 @@ fn each_gate_decision_lands_on_the_stage_that_owns_it() { } } +/// Drive a probe for a key that is **not** on the mesh under a given gate +/// decision, and return the finished snapshot. +/// +/// `BloomMiss` is the run where no peer's filter claimed the key. `Sent` is +/// the run where at least one did — which, for a genuinely absent key, can +/// only be a false positive, since a bloom filter has no false negatives. +/// The mesh then answers nothing and the ladder runs out. +fn absent_key_probe(gate: LookupOutcomeKind) -> crate::proto::probe::ProbeSnapshot { + let mut pre = preflight(); + pre.coords_cached = false; + let mut probe = Probe::new(T0, budgets(), pre); + let claimed = gate == LookupOutcomeKind::Sent; + + for tick in 0..40u64 { + let mut o = obs(T0 + tick * 1_000); + o.coords_cached = false; + if tick > 0 { + o.lookup_outcome = Some(gate); + } + // The claimed run holds a pending entry while the ladder retries, then + // clears it with no coordinates: nobody answered for the address. + o.lookup_pending = claimed && tick < 16; + if probe.step(&o).contains(&ProbeAction::Finish) { + break; + } + } + probe.snapshot() +} + +#[test] +fn absent_key_names_the_filter_claim_instead_of_collapsing_into_no_response() { + let clean = absent_key_probe(LookupOutcomeKind::BloomMiss); + let claimed = absent_key_probe(LookupOutcomeKind::Sent); + + assert_eq!( + clean.bloom.verdict, + StageVerdict::Failed, + "no filter claimed it, so the bloom stage is where it ended" + ); + assert_eq!( + claimed.bloom.verdict, + StageVerdict::Ok, + "a filter claimed it, so a request did go out" + ); + + assert_eq!(clean.bloom.reason, Some(FailKind::BloomMiss)); + assert_eq!( + claimed.discovery.reason, + Some(FailKind::BloomUnconfirmed), + "a lookup issued on a filter claim and left unanswered is its own finding" + ); + + // The defect this guards: the claimed run must not land on any reason a + // run that never issued a request can also produce. `no_response` was + // exactly such a reason — the bloom stage reaches it too — so reporting + // it here told the operator nothing about which case they were in. + for shared in [ + FailKind::BloomMiss, + FailKind::NoResponse, + FailKind::BackoffSuppressed, + FailKind::NoTreePeers, + ] { + assert_ne!( + claimed.discovery.reason, + Some(shared), + "{} cannot distinguish a claimed lookup from one never issued", + shared.name() + ); + } + + // The verdict is the answer and the answer was already right: absent + // either way. Only the reason changes. + assert_eq!(clean.overall, Overall::Failed); + assert_eq!( + clean.overall, claimed.overall, + "the key is absent on both paths; the verdict must not move" + ); +} + +#[test] +fn cancelling_mid_discovery_still_names_the_filter_claim() { + // `expire_running_stage` writes the reason for a stage that never got to + // settle. It must give the same finding the budget path would. + let mut pre = preflight(); + pre.coords_cached = false; + let mut probe = Probe::new(T0, budgets(), pre); + + let mut o = obs(T0); + o.coords_cached = false; + probe.step(&o); + + let mut o = obs(T0 + 1_000); + o.coords_cached = false; + o.lookup_pending = true; + o.lookup_outcome = Some(LookupOutcomeKind::Sent); + probe.step(&o); + assert_eq!(probe.snapshot().discovery.verdict, StageVerdict::Running); + + probe.cancel(T0 + 2_000); + assert_eq!( + probe.snapshot().discovery.reason, + Some(FailKind::BloomUnconfirmed) + ); +} + // ---- ownership ---------------------------------------------------------- #[test]