From 390acf6d4e1d3f2976964b1ec098faa2fb0b4aa0 Mon Sep 17 00:00:00 2001 From: Johnathan Corgan Date: Wed, 30 Sep 2026 17:46:32 +0000 Subject: [PATCH] Test that a gateway NAT rebuild clears its pending mark, and log retry failures once Nothing CI runs observed the pending mark being cleared on success: only the ignored kernel test reached that line, so a gateway that never cleared it would rebuild its whole table and log every ten seconds without a test going red. The mark is now set and cleared in track_rebuild, which takes the rebuild as a closure, and unprivileged tests drive it with a failing and a succeeding stand-in to check that a failure leaves the retry pending and a success leaves retry_pending nothing to do. The coverage note above the tests says what remains only in the ignored test. A failure that persists, such as the kernel refusing the batch while a module or capability is missing, warned on every retry, six lines a minute for the life of the process. The retry now warns when its failure changes, logs repeats at debug level, and reports recovery once, whether the retry applied the rules or a later mapping change did, following the conntrack read log's pattern. rebuild_desired gets a doc comment. --- src/bin/fips-gateway.rs | 31 +++++++-- src/gateway/nat.rs | 143 +++++++++++++++++++++++++++++++++++++++- 2 files changed, 168 insertions(+), 6 deletions(-) diff --git a/src/bin/fips-gateway.rs b/src/bin/fips-gateway.rs index 60173841..4fa248c7 100644 --- a/src/bin/fips-gateway.rs +++ b/src/bin/fips-gateway.rs @@ -107,6 +107,30 @@ fn report_unreadable_conntrack( } } +/// Log a pending NAT rebuild retry once per change of outcome. +/// +/// A recovery is reported whether the retry applied the rules itself or a +/// mapping change applied them in between and left nothing pending. +#[cfg(target_os = "linux")] +fn report_nat_retry(log: &mut nat::RetryLog, result: &Result) { + match (log.observe(result.as_ref().err()), result) { + (nat::RetryReport::Failed, Err(e)) => { + warn!(error = %e, "Failed to retry pending NAT rules") + } + (nat::RetryReport::Repeated, Err(e)) => { + debug!(error = %e, "Pending NAT rules still failing to apply") + } + (nat::RetryReport::Recovered, Ok(true)) => { + info!("Applied pending NAT rules; retries recovered") + } + (nat::RetryReport::Recovered, _) => { + info!("Pending NAT rules were applied by a later update; retries recovered") + } + (nat::RetryReport::Clean, Ok(true)) => info!("Applied pending NAT rules"), + _ => {} + } +} + /// Check once at startup which conntrack source the tick will read, and say so. /// /// Without this, an operator on a kernel with no readable source learns that @@ -547,14 +571,11 @@ async fn main() { let mut exit_code = 0; let mut nat_retry = tokio::time::interval(std::time::Duration::from_secs(10)); nat_retry.set_missed_tick_behavior(tokio::time::MissedTickBehavior::Skip); + let mut nat_retry_log = nat::RetryLog::default(); loop { tokio::select! { _ = nat_retry.tick() => { - match nat_mgr.retry_pending() { - Ok(true) => info!("Applied pending NAT rules"), - Ok(false) => {}, - Err(e) => warn!(error = %e, "Failed to retry pending NAT rules"), - } + report_nat_retry(&mut nat_retry_log, &nat_mgr.retry_pending()); } Some(event) = event_rx.recv() => { match event { diff --git a/src/gateway/nat.rs b/src/gateway/nat.rs index e7073c27..72de3a89 100644 --- a/src/gateway/nat.rs +++ b/src/gateway/nat.rs @@ -519,14 +519,80 @@ impl NatManager { (result, elapsed_us) } + /// Rebuild the desired state, leaving it marked pending unless the kernel + /// accepts it. fn rebuild_desired(&mut self) -> Result<(), NatError> { + self.track_rebuild(Self::rebuild) + } + + /// Run `apply` with the desired state marked pending, and clear the mark + /// only if it succeeds. + /// + /// Split from `rebuild_desired` so a test can drive both outcomes without + /// a netlink socket. + fn track_rebuild( + &mut self, + apply: impl FnOnce(&Self) -> Result<(), NatError>, + ) -> Result<(), NatError> { self.rebuild_pending = true; - self.rebuild()?; + apply(self)?; self.rebuild_pending = false; Ok(()) } } +/// How a pending-rebuild retry compares with the retry before it. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub enum RetryReport { + /// A failure that differs from the previous retry's outcome, or the first. + Failed, + /// The same failure as the previous retry. + Repeated, + /// The first success after a failed retry. + Recovered, + /// A success with no failed retry before it. + Clean, +} + +/// Remembers the last failed retry of a pending rebuild. +/// +/// A failure that does not clear on its own, for example the kernel refusing +/// the batch while a module or capability is missing, fails every retry the +/// same way, and a per-retry warning would repeat for the life of the +/// process. Warning on a change of outcome, and reporting the recovery once, +/// keeps the log readable. A retry that finds nothing pending after a failure +/// counts as recovery, since a mapping change rebuilt the table in between. +#[derive(Debug, Default)] +pub struct RetryLog { + last_failure: Option, +} + +impl RetryLog { + /// Record a retry outcome and say how it compares with the last one. + /// + /// `None` is a success, whether or not anything was pending; `Some` is + /// the retry's error. Two failures are the same when their messages are. + pub fn observe(&mut self, failure: Option<&NatError>) -> RetryReport { + match (failure.map(ToString::to_string), self.last_failure.take()) { + (Some(now), Some(before)) => { + let report = if now == before { + RetryReport::Repeated + } else { + RetryReport::Failed + }; + self.last_failure = Some(now); + report + } + (Some(now), None) => { + self.last_failure = Some(now); + RetryReport::Failed + } + (None, Some(_)) => RetryReport::Recovered, + (None, None) => RetryReport::Clean, + } + } +} + /// Largest batch, in bytes, that the kernel can admit in one send. fn admissible_limit() -> u64 { 2 * MAX_SNDBUF as u64 - SNDBUF_OVERHEAD @@ -877,6 +943,13 @@ fn send_batch(bytes: &[u8]) -> Result<(), NatError> { // `SO_SNDBUF` fallback after `SO_SNDBUFFORCE` returns `EPERM` needs a process // without CAP_NET_ADMIN, and the gateway suite's container is privileged, so // nothing runs that either. The gateway suite covers only the success path. +// +// The pending-rebuild flag is covered here on both sides through +// `track_rebuild`, with a stand-in for the rebuild: a failure leaves it set and +// `retry_pending` still retries, and a success clears it so `retry_pending` +// finds nothing to do. What stays only in the ignored kernel test, which no +// suite runs, is `retry_pending` itself applying a pending rebuild and +// returning `Ok(true)`, and a kernel rejection leaving the old table in place. #[cfg(test)] mod tests { use super::*; @@ -927,6 +1000,74 @@ mod tests { ); } + #[test] + fn failed_tracked_rebuild_stays_pending_and_retry_still_rebuilds() { + let mut mgr = manager_with_mappings(1); + let refused = || NatError::Nftables("refused".into()); + + assert!(mgr.track_rebuild(|_| Err(refused())).is_err()); + assert!(mgr.rebuild_pending, "a failed rebuild must stay pending"); + + // With encoding made to fail, a retry that is still pending attempts + // the rebuild, and fails, instead of reporting nothing to do. + mgr.pre_chain = Chain::new(&mgr.table); + assert!(mgr.retry_pending().is_err()); + assert!(mgr.rebuild_pending); + } + + #[test] + fn successful_tracked_rebuild_clears_pending_and_retry_does_nothing() { + let mut mgr = manager_with_mappings(1); + assert!( + mgr.track_rebuild(|_| Err(NatError::Nftables("refused".into()))) + .is_err() + ); + assert!(mgr.rebuild_pending); + + let mut applied = 0; + mgr.track_rebuild(|m| { + assert!(m.rebuild_pending, "the rebuild runs with the mark set"); + applied += 1; + Ok(()) + }) + .unwrap(); + assert_eq!(applied, 1); + assert!( + !mgr.rebuild_pending, + "a successful rebuild must clear pending" + ); + + // Encoding would fail, so `Ok(false)` shows the retry did not rebuild. + mgr.pre_chain = Chain::new(&mgr.table); + assert!(!mgr.retry_pending().unwrap()); + } + + #[test] + fn retry_log_warns_on_a_new_failure_and_reports_recovery_once() { + let kernel = |errno| NatError::Kernel { + errno: Errno(errno), + seq: 3, + }; + let mut log = RetryLog::default(); + + assert_eq!(log.observe(None), RetryReport::Clean); + assert_eq!(log.observe(Some(&kernel(22))), RetryReport::Failed); + assert_eq!(log.observe(Some(&kernel(22))), RetryReport::Repeated); + assert_eq!(log.observe(Some(&kernel(22))), RetryReport::Repeated); + assert_eq!( + log.observe(Some(&kernel(1))), + RetryReport::Failed, + "a different failure is a different outcome and is worth a line" + ); + assert_eq!(log.observe(None), RetryReport::Recovered); + assert_eq!(log.observe(None), RetryReport::Clean); + assert_eq!( + log.observe(Some(&kernel(1))), + RetryReport::Failed, + "a failure after recovery warns again" + ); + } + #[test] fn failed_port_forward_rebuild_remains_pending() { let mut mgr = manager_with_mappings(1);