transaction cleanup

CHANGELOG.md

@@ -5,6 +5,15 @@
   - BLAKE3 uses its WASM SIMD implementation on wasm32. Adds 14KB to the `.wasm` and requires WASM SIMD support, which browsers have had since Safari 16.4.
 
 - veilid-core:
+  - Safety routes are allocated, tested, and released per sequence ordering, and the hops of a route that died are kept out of new allocations for ten minutes.
+  - A lost loopback no longer schedules another test of its own route, and a multi-hop loopback failure no longer blames the first hop's transport.
+  - Per-ordering loopback tallies, a `route test summary` log line for any minute with a loopback failure or a release, and the `route diag` and `route reallocate` debug commands.
+  - `route allocate` accepts node ids to avoid as hops.
+  - A refused connect is no longer counted as evidence against a transport.
+  - Last flows are kept per remote address, answers return over the flow their question arrived on, and a lost question over a flow we did not dial blames nobody.
+  - Degraded detection counts fresh failures of Reliable peers only, excludes our own relay, and clears its evidence on recovery.
+  - App call results are logged truncated.
+  - A DHT transaction record no longer fails its stage consensus when as many node transactions went unanswered as answered.
   - **Security** B01T direct-bootstrap requests are answered from the last successful bootstrap set held by the routing domain, which is persisted across restarts. The handler no longer resolves DNS, so an unauthenticated packet can no longer cause non-veilid traffic or block a worker on a slow resolver. Thanks to quikchaos for reporting this issue!
   - Bootstrap records are cached verbatim for every record version received, so a node serves what it was told rather than only what it selected for its own bootstrap. A saved routing table that predates the cache is discarded on load and the node bootstraps again, since nothing else ever fetches records: without this a node that restarted with a warm routing table never bootstrapped, held no records, and refused B01T on every protocol.
   - New `network.routing_table.bootstrap_records` config: whole bootstrap records, verbatim, as `veilid-server --dump-txt-record` prints them. They are served to direct bootstrap requests with no lookup and can be used to join the network without resolving `bootstrap` at all, so the first bootstrap server on a network can serve records before there is anything to look up. Empty by default.
@@ -12,6 +21,14 @@
   - Bootstrap hostname resolution runs on the blocking pool instead of the executor.
   - Android below API 29 has no system TXT resolver, so a bootstrap hostname is contacted directly on port 5150 over UDP or TCP for a B01T exchange instead. Startup fails on such a device when neither protocol is enabled, since the hostname could never be reached.
   - Stats collection, aggregation, and analysis for all subsystems. Robot-generated python script for reviewing the effect of optimizations.
+  - DHT transaction quality counters under the `stats` feature: per-command fanout outcomes, subkey confirmation coverage at End and Commit, node-set attrition, the cost of each mitigation, and TryAgain reasons; `stats reset` zeroes them.
+  - A DHT transaction ends only at nodes that answered every set, re-sending a node the sets it is missing first, and set answers that arrive after the early consensus exit are recorded instead of dropped.
+  - A DHT transaction commit held by fewer than the required nodes returns TryAgain instead of Ok.
+  - A set that reaches a storage node after End is refused without ending that node's transaction.
+  - The set retry pass in DHT transactions is gone; it re-sent 4 of 6391 set RPCs in a stress run and none once late answers were collected.
+  - A bootstrap name whose TXT lookup returns nothing within ten seconds is direct-bootstrapped over every enabled protocol at once, so a node behind a phone tether whose DNS relay answers A/AAAA but not TXT still joins the network.
+  - DHT transaction keepalives are sent only when no command answer has refreshed the node's lease since the last deadline.
+  - A DHT transaction command returns at consensus instead of waiting up to half a second for stragglers, which now settle in the background.
   - Fix OnlineDetector spurious flap.
   - Properly drop TCP connections when offline condition is detected so they can be recreated in the event of NAT state loss, as is common on cellular.
   - Fix UDP stalls on cellular/CLAT464.
@@ -59,6 +76,9 @@
   - Completely remove 'rust-android-gradle' because it is failing to keep up with the rest of the ecosystem (AGP, Kotlin, etc)
   - Fix multiple-attach idempotency
 
+- veilid-cli:
+  - The interactive console no longer exits or floods `thingbuf receiver has closed` when a log burst overruns the line editor.
+
 - veilid-python:
   - More tests
 

dev-setup/_flutter_install.sh

@@ -6,7 +6,17 @@
 FLUTTER_SDK_DIR="${FLUTTER_SDK_DIR:-$HOME/.local/share/veilid-flutter}"
 
 # flutter --version -> "Flutter 3.47.1 • channel stable • ..."; empty when flutter isn't installed.
-flutter_ver() { command -v flutter >/dev/null 2>&1 && flutter --version 2>/dev/null | head -1; }
+# The tool's first run in a fresh container prints only its spinner and update banner and no
+# version line, so ask twice
+flutter_ver() {
+    command -v flutter >/dev/null 2>&1 || return 0
+    local v
+    for _ in 1 2; do
+        v="$(flutter --version 2>/dev/null | grep -m1 '^Flutter ')"
+        [ -n "$v" ] && break
+    done
+    echo "$v"
+}
 
 # Put the flutter bin on this session's PATH + persist it to the user's shell rc (idempotent).
 _flutter_persist_path() {

veilid-cli/src/interactive_ui.rs

@@ -360,6 +360,24 @@ pub struct InteractiveUISender {
     connection_state_sender: flume::Sender<ConnectionState>,
 }
 
+impl InteractiveUISender {
+    // console writer: a full buffer drops the line, a gone readline stops all writes
+    fn write_console_line(&self, line: &str) {
+        use std::io::Write;
+
+        let Some(mut stdout) = self.inner.lock().stdout.clone() else {
+            return;
+        };
+        match writeln!(stdout, "{}", line) {
+            Ok(()) => {}
+            Err(e) if e.kind() == std::io::ErrorKind::WouldBlock => {}
+            Err(_) => {
+                self.inner.lock().stdout = None;
+            }
+        }
+    }
+}
+
 impl UISender for InteractiveUISender {
     fn clone_uisender(&self) -> Box<dyn UISender> {
         Box::new(InteractiveUISender {
@@ -422,28 +440,15 @@ impl UISender for InteractiveUISender {
     }
 
     fn add_node_event(&self, _log_color: Level, event: &str) {
-        use std::io::Write;
-
-        let Some(mut stdout) = self.inner.lock().stdout.clone() else {
-            return;
-        };
-        if let Err(e) = writeln!(stdout, "{}", event) {
-            self.inner.lock().error = Some(e.to_string());
-        }
+        self.write_console_line(event);
     }
     fn add_log_event(&self, log_color: Level, event: &str) {
-        use std::io::Write;
-
-        let (enable_color, mut stdout) = {
+        let enable_color = {
             let inner = self.inner.lock();
-            if !inner.log_enabled {
+            if !inner.log_enabled || inner.stdout.is_none() {
                 return;
             }
-            let Some(stdout) = inner.stdout.clone() else {
-                return;
-            };
-
-            (inner.enable_color, stdout)
+            inner.enable_color
         };
 
         let log_line = format!(
@@ -459,10 +464,7 @@ impl UISender for InteractiveUISender {
                 Level::Debug => style(log_line).green().bright().to_string(),
                 Level::Trace => style(log_line).blue().bright().to_string(),
             };
-            if let Err(e) = writeln!(stdout, "{}", log_line) {
-                eprintln!("Error: {:?}", e);
-                self.inner.lock().done.take();
-            }
+            self.write_console_line(&log_line);
         } else {
             println!("{}", log_line);
         }

veilid-core/public-api.txt

@@ -128,7 +128,9 @@ pub veilid_core::Sequencing::EnsureOrdered = 2
 pub veilid_core::Sequencing::PreferOrdered = 1
 pub veilid_core::Sequencing::PreferUnordered = 0
 impl veilid_core::Sequencing
+pub fn veilid_core::Sequencing::for_route_orderings(&self, veilid_core::SequenceOrderingSet) -> veilid_core::Sequencing
 pub fn veilid_core::Sequencing::matches_ordering(&self, veilid_core::SequenceOrdering) -> bool
+pub fn veilid_core::Sequencing::preferred_ordering(&self) -> veilid_core::SequenceOrdering
 impl core::fmt::Display for veilid_core::Sequencing
 pub fn veilid_core::Sequencing::fmt(&self, &mut core::fmt::Formatter<'_>) -> core::fmt::Result
 impl core::str::traits::FromStr for veilid_core::Sequencing

veilid-core/smoketest/Cargo.lock

@@ -551,9 +551,9 @@ dependencies = [
 
 [[package]]
 name = "cc"
-version = "1.4.5"
+version = "1.4.6"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "005ec2760ca554fae18df7a11195552ec576cd665632a881bc011d5bb2fd4d80"
+checksum = "a3eb0f42d6c360dc3f8a821f6bf2fdea7f72bfd36b3076eb0e6d1e9e0752fff4"
 dependencies = [
  "find-msvc-tools",
  "shlex",

veilid-core/src/component.rs

@@ -71,6 +71,10 @@ pub(crate) trait VeilidComponent:
 {
     fn name(&self) -> &'static str;
     fn log_facilities(&self) -> VeilidComponentLogFacilities;
+    /// Zero the component's cumulative stats counters, if it keeps any.
+    #[cfg(feature = "stats")]
+    fn reset_stats(&self) {}
+
     /// A JSON-serializable stats snapshot, or None if the component has no stats.
     #[cfg(feature = "stats")]
     fn stats(&self) -> Option<Box<dyn VeilidComponentStats>> {
@@ -419,6 +423,14 @@ impl VeilidComponentRegistry {
         serde_json::Value::Object(map)
     }
 
+    // Zero every component's cumulative counters; the registry lock is dropped first
+    #[cfg(feature = "stats")]
+    pub(crate) fn reset_component_stats(&self) {
+        for component in self.get_init_order() {
+            component.reset_stats();
+        }
+    }
+
     //////////////////////////////////////////////////////////////
 
     pub fn lookup<'a, T: VeilidComponent + Send + Sync + 'static>(
@@ -527,6 +539,18 @@ macro_rules! impl_veilid_component {
             }
         );
     };
+    ($component_name:ty, stats, reset) => {
+        impl_veilid_component!(@inner $component_name,
+            #[cfg(feature = "stats")]
+            fn stats(&self) -> Option<Box<dyn VeilidComponentStats>> {
+                <$component_name>::stats_impl(self)
+            }
+            #[cfg(feature = "stats")]
+            fn reset_stats(&self) {
+                <$component_name>::reset_stats_impl(self)
+            }
+        );
+    };
 }
 
 pub(crate) use impl_veilid_component;

veilid-core/src/logging/api_log_queue.rs

@@ -20,7 +20,6 @@
 
 use super::*;
 use core::fmt::Write as _;
-use core::sync::atomic::{AtomicU64, Ordering};
 
 /// Queue depth. Roughly a second of a bad storm; past this the drop counter takes over.
 const QUEUE_CAPACITY: usize = 4096;

veilid-core/src/logging/log_throttle.rs

@@ -9,7 +9,6 @@
 //! Used through the `throttle:` option on `veilid_log!` rather than directly.
 
 use super::*;
-use core::sync::atomic::{AtomicU64, Ordering};
 
 /// Per-call-site emission gate: lets one event through per interval and counts what it drops.
 ///

veilid-core/src/logging/macros.rs

@@ -126,6 +126,15 @@ macro_rules! veilid_log_event {
         $($k).+ = $($fields)*,
         concat!($prefix,""))
     };
+    // veilid_log!(self, prefix:"", Level::XXX, target: "facility", msg: "message", fields: field=value, ?other_field)
+    // Sinks that render only the message (journald) show a blank line for a field-only event
+    ($self_expr:expr, prefix: $prefix:literal, level: $lvl:expr, target: $target:expr, msg: $msg:literal, fields: $($k:ident).+ = $($fields:tt)*) => {event!(
+        target: $target,
+        $lvl,
+        __VEILID_LOG_KEY = $self_expr.log_key(),
+        $($k).+ = $($fields)*,
+        concat!($prefix,$msg))
+    };
 }
 pub(crate) use veilid_log_event;
 
@@ -186,6 +195,8 @@ macro_rules! veilid_log {
     ($self_ident:ident error, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident level: $crate::Level::ERROR, fields: $($k).+ = $($fields)*)};
     // veilid_log!(self error target: "facility", fields: field=value, ?other_field)
     ($self_ident:ident error target: $target:expr, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident, prefix: "", level: $crate::Level::ERROR, target: $target, fields: $($k).+ = $($fields)*)};
+    // veilid_log!(self error target: "facility", msg: "message", fields: field=value, ?other_field)
+    ($self_ident:ident error target: $target:expr, msg: $msg:literal, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident, prefix: "", level: $crate::Level::ERROR, target: $target, msg: $msg, fields: $($k).+ = $($fields)*)};
 
     // WARN //////////////////////////////////////////////////////////////////////////
     // veilid_log!(self warn throttle: 1000, "data: {}", data)
@@ -204,6 +215,8 @@ macro_rules! veilid_log {
     ($self_ident:ident warn, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident, prefix: "", level: $crate::Level::WARN, fields: $($k).+ = $($fields)*)};
     // veilid_log!(self warn target: "facility", fields: field=value, ?other_field)
     ($self_ident:ident warn target: $target:expr, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident, prefix: "", level: $crate::Level::WARN, target: $target, fields: $($k).+ = $($fields)*)};
+    // veilid_log!(self warn target: "facility", msg: "message", fields: field=value, ?other_field)
+    ($self_ident:ident warn target: $target:expr, msg: $msg:literal, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident, prefix: "", level: $crate::Level::WARN, target: $target, msg: $msg, fields: $($k).+ = $($fields)*)};
 
     // INFO //////////////////////////////////////////////////////////////////////////
     // veilid_log!(self info throttle: 1000, "data: {}", data)
@@ -222,6 +235,8 @@ macro_rules! veilid_log {
     ($self_ident:ident info, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident, prefix: "", level: $crate::Level::INFO, fields: $($k).+ = $($fields)*)};
     // veilid_log!(self info target: "facility", fields: field=value, ?other_field)
     ($self_ident:ident info target: $target:expr, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident, prefix: "", level: $crate::Level::INFO, target: $target, fields: $($k).+ = $($fields)*)};
+    // veilid_log!(self info target: "facility", msg: "message", fields: field=value, ?other_field)
+    ($self_ident:ident info target: $target:expr, msg: $msg:literal, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident, prefix: "", level: $crate::Level::INFO, target: $target, msg: $msg, fields: $($k).+ = $($fields)*)};
 
     // DEBUG //////////////////////////////////////////////////////////////////////////
     // veilid_log!(self debug throttle: 1000, "data: {}", data)
@@ -240,6 +255,8 @@ macro_rules! veilid_log {
     ($self_ident:ident debug, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident, prefix: "", level: $crate::Level::DEBUG, fields: $($k).+ = $($fields)*)};
     // veilid_log!(self debug target: "facility" fields: field=value, ?other_field)
     ($self_ident:ident debug target: $target:expr, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident, prefix: "", level: $crate::Level::DEBUG, target: $target, fields: $($k).+ = $($fields)*)};
+    // veilid_log!(self debug target: "facility", msg: "message", fields: field=value, ?other_field)
+    ($self_ident:ident debug target: $target:expr, msg: $msg:literal, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident, prefix: "", level: $crate::Level::DEBUG, target: $target, msg: $msg, fields: $($k).+ = $($fields)*)};
 
     // TRACE //////////////////////////////////////////////////////////////////////////
     // veilid_log!(self trace throttle: 1000, "data: {}", data)
@@ -258,6 +275,8 @@ macro_rules! veilid_log {
     ($self_ident:ident trace, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident, prefix: "", level: $crate::Level::TRACE, fields: $($k).+ = $($fields)*)};
     // veilid_log!(self trace target: "facility", fields: field=value, ?other_field)
     ($self_ident:ident trace target: $target:expr, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident, prefix: "", level: $crate::Level::TRACE, target: $target, fields: $($k).+ = $($fields)*)};
+    // veilid_log!(self trace target: "facility", msg: "message", fields: field=value, ?other_field)
+    ($self_ident:ident trace target: $target:expr, msg: $msg:literal, fields: $($k:ident).+ = $($fields:tt)*) => {veilid_log_event!($self_ident, prefix: "", level: $crate::Level::TRACE, target: $target, msg: $msg, fields: $($k).+ = $($fields)*)};
 
     // DEBUGWARN //////////////////////////////////////////////////////////////////////////
     // veilid_log!(self debugwarn throttle: 1000, "data: {}", data)

veilid-core/src/logging/tests_logging/test_log_throttle.rs

@@ -1,5 +1,4 @@
 use super::*;
-use core::sync::atomic::AtomicUsize;
 
 impl_veilid_log_facility!("test");
 

veilid-core/src/network_manager/bootstrap/mod.rs

@@ -10,6 +10,8 @@ impl_veilid_log_facility!("net");
 
 /// Port a bootstrap host answers B01T on when a TXT name has to be reached directly
 pub const BOOTSTRAP_DIRECT_PORT: u16 = 5150;
+/// How long a bootstrap name's TXT lookups may take before direct bootstrap is tried
+pub const BOOTSTRAP_TXT_TIMEOUT_MS: u32 = 10_000;
 
 /// Ceiling on cached record strings. Far above any real bootstrap's output, and keeps a hostile
 /// bootstrap from inflating the B01T response of every node that contacted it.

veilid-core/src/network_manager/connection_handle.rs

@@ -1,5 +1,4 @@
 use super::*;
-use std::sync::atomic::{AtomicBool, Ordering};
 
 #[derive(Clone, Debug)]
 pub struct ConnectionHandle {

veilid-core/src/network_manager/network/native/low_level_protocol_tcp.rs

@@ -1,5 +1,4 @@
 use super::*;
-use std::sync::atomic::{AtomicUsize, Ordering};
 use stop_token::future::FutureExt;
 
 const LISTENER_RESTART_AFTER_CONSECUTIVE_ERRORS: usize = 16;

veilid-core/src/network_manager/network/native/mod.rs

@@ -326,13 +326,14 @@ impl PlatformNetwork for NativeNetwork {
             }
             .await;
 
-            if let Ok(nr) = &send_result {
+            if let Some(outcome) = send_result
+                .as_ref()
+                .ok()
+                .and_then(TransportSendOutcome::from_network_result)
+            {
                 self.network_manager()
                     .transport_stats()
-                    .record_unbound_send(
-                        &stats_dial_info,
-                        TransportSendOutcome::from_network_result(nr),
-                    );
+                    .record_unbound_send(&stats_dial_info, outcome);
             }
             let nr = send_result?;
             if !matches!(nr, NetworkResult::Value(_)) {
@@ -398,10 +399,12 @@ impl PlatformNetwork for NativeNetwork {
                             .send_message(data, peer_socket_addr, "unbound_recv")
                             .await
                             .wrap_err("send message failure")?;
-                        network_manager.transport_stats().record_unbound_send(
-                            &dial_info,
-                            TransportSendOutcome::from_network_result(&send_res),
-                        );
+                        if let Some(outcome) = TransportSendOutcome::from_network_result(&send_res)
+                        {
+                            network_manager
+                                .transport_stats()
+                                .record_unbound_send(&dial_info, outcome);
+                        }
                         network_result_try!(send_res);
                         network_manager.stats_packet_sent(ip_addr, ByteCount::new(data_len as u64));
 
@@ -468,19 +471,24 @@ impl PlatformNetwork for NativeNetwork {
                         let pnc = match connect_res {
                             NetworkResult::Value(pnc) => pnc,
                             nr => {
-                                network_manager.transport_stats().record_unbound_send(
-                                    &stats_dial_info,
-                                    TransportSendOutcome::from_network_result(&nr),
-                                );
+                                if let Some(outcome) =
+                                    TransportSendOutcome::from_network_result(&nr)
+                                {
+                                    network_manager
+                                        .transport_stats()
+                                        .record_unbound_send(&stats_dial_info, outcome);
+                                }
                                 // PANIC-CENSUS: provably-dead the non-Value arm carries no value to map
                                 return Ok(nr.map(|_| unreachable!()));
                             }
                         };
                         let send_res = pnc.send(data).await.wrap_err("send failure")?;
-                        network_manager.transport_stats().record_unbound_send(
-                            &stats_dial_info,
-                            TransportSendOutcome::from_network_result(&send_res),
-                        );
+                        if let Some(outcome) = TransportSendOutcome::from_network_result(&send_res)
+                        {
+                            network_manager
+                                .transport_stats()
+                                .record_unbound_send(&stats_dial_info, outcome);
+                        }
                         network_result_try!(send_res);
                         network_manager.stats_packet_sent(ip_addr, ByteCount::new(data_len as u64));
 

veilid-core/src/network_manager/network/wasm/mod.rs

@@ -261,13 +261,14 @@ impl PlatformNetwork for WasmNetwork {
             }
             .await;
 
-            if let Ok(nr) = &send_result {
+            if let Some(outcome) = send_result
+                .as_ref()
+                .ok()
+                .and_then(TransportSendOutcome::from_network_result)
+            {
                 self.network_manager()
                     .transport_stats()
-                    .record_unbound_send(
-                        &stats_dial_info,
-                        TransportSendOutcome::from_network_result(nr),
-                    );
+                    .record_unbound_send(&stats_dial_info, outcome);
             }
             let nr = send_result?;
             if !matches!(nr, NetworkResult::Value(_)) {
@@ -350,19 +351,24 @@ impl PlatformNetwork for WasmNetwork {
                         let pnc = match connect_res {
                             NetworkResult::Value(pnc) => pnc,
                             nr => {
-                                network_manager.transport_stats().record_unbound_send(
-                                    &stats_dial_info,
-                                    TransportSendOutcome::from_network_result(&nr),
-                                );
+                                if let Some(outcome) =
+                                    TransportSendOutcome::from_network_result(&nr)
+                                {
+                                    network_manager
+                                        .transport_stats()
+                                        .record_unbound_send(&stats_dial_info, outcome);
+                                }
                                 // PANIC-CENSUS: provably-dead the non-Value arm carries no value to map
                                 return Ok(nr.map(|_| unreachable!()));
                             }
                         };
                         let send_res = pnc.send(data).await.wrap_err("send failure")?;
-                        network_manager.transport_stats().record_unbound_send(
-                            &stats_dial_info,
-                            TransportSendOutcome::from_network_result(&send_res),
-                        );
+                        if let Some(outcome) = TransportSendOutcome::from_network_result(&send_res)
+                        {
+                            network_manager
+                                .transport_stats()
+                                .record_unbound_send(&stats_dial_info, outcome);
+                        }
                         network_result_try!(send_res);
                         network_manager.stats_packet_sent(ip_addr, ByteCount::new(data_len as u64));
 

veilid-core/src/network_manager/network_connection.rs

@@ -1,6 +1,5 @@
 use super::*;
 use futures_util::{FutureExt, StreamExt};
-use std::sync::atomic::{AtomicBool, Ordering};
 use std::{io, sync::Arc};
 use stop_token::prelude::*;
 
@@ -577,10 +576,10 @@ impl NetworkConnection {
             // latter, and matching only on `Err` swallowed it
             match protocol_connection.close().await {
                 Err(e) => {
-                    veilid_log!(registry debug throttle: PROTOCOL_LOG_THROTTLE_MS, "Protocol connection close error: {}", e);
+                    veilid_log!(registry debug throttle: PROTOCOL_LOG_THROTTLE_MS, "Protocol connection close error: {} flow={:#}", e, flow);
                 }
                 Ok(nres) if !matches!(nres, NetworkResult::Value(_)) => {
-                    veilid_log!(registry debug throttle: PROTOCOL_LOG_THROTTLE_MS, "Protocol connection close incomplete: {}", nres);
+                    veilid_log!(registry debug throttle: PROTOCOL_LOG_THROTTLE_MS, "Protocol connection close incomplete: {} flow={:#}", nres, flow);
                 }
                 Ok(_) => {}
             }

veilid-core/src/network_manager/online_detector.rs

@@ -106,7 +106,7 @@ pub(crate) fn effective_online_state(
 }
 
 /// Events that drive the online/offline state machine.
-enum OnlineEvent {
+pub(crate) enum OnlineEvent {
     /// Received something from outside.
     Success,
     /// Failures for previously-live nodes on one framing type. `fresh_node_ids` is the
@@ -128,17 +128,17 @@ enum OnlineEvent {
 
 /// Per-routing-domain online/offline tracking.
 #[derive(Debug)]
-struct OnlineDetectionPerDomain {
+pub(crate) struct OnlineDetectionPerDomain {
     /// Previously-live nodes that failed on each framing type since the last success.
     pending_failures: BTreeMap<FramingType, BTreeSet<NodeId>>,
     /// The same breadth over a time window, which an interleaved success cannot erase
-    windowed_failures: BTreeMap<FramingType, BTreeMap<NodeId, Timestamp>>,
+    pub(crate) windowed_failures: BTreeMap<FramingType, BTreeMap<NodeId, Timestamp>>,
     /// Last time the windowed breadth crossed threshold on every enabled framing type
-    last_degraded_evidence_ts: Option<Timestamp>,
+    pub(crate) last_degraded_evidence_ts: Option<Timestamp>,
     /// Last completed round trip; exiting Degraded requires one after the evidence
-    last_success_ts: Option<Timestamp>,
+    pub(crate) last_success_ts: Option<Timestamp>,
     /// Last committed three-state answer, updated on events and lazily on reads
-    effective_state: OnlineState,
+    pub(crate) effective_state: OnlineState,
     /// Consecutive Degraded re-entries within `DEGRADED_REENTRY_SECS`; escalates the exit window
     degraded_reentries: u32,
     /// When Degraded last ended, for the rapid-re-entry test
@@ -146,7 +146,7 @@ struct OnlineDetectionPerDomain {
     /// When we last switched online/offline.
     last_transition_ts: Timestamp,
     /// Current state.
-    online_state: OnlineState,
+    pub(crate) online_state: OnlineState,
     /// Flap detector over online_state.
     flap_detector: FlapDetector<OnlineState>,
     /// Start of the current offline period, if currently offline.
@@ -201,6 +201,17 @@ impl Default for OnlineDetectionPerDomain {
     }
 }
 
+/// Which peers' fresh failures may arm the degraded window
+#[derive(Copy, Clone, Debug, PartialEq, Eq)]
+pub enum DegradedBreadthStrategy {
+    /// Any responsive peer that answered recently and is not already judged failing; the
+    /// pre-2026-09 behavior, kept selectable for comparison runs
+    #[expect(dead_code)]
+    Responsive,
+    /// Only peers in the Reliable state: the ones whose loss is news rather than habit
+    ReliableOnly,
+}
+
 /// Detects if our node is online or offline.
 ///
 /// To determine if network errors are 'our fault' or 'the other side's fault', we need to
@@ -208,6 +219,8 @@ impl Default for OnlineDetectionPerDomain {
 /// changing its state.
 pub struct OnlineDetector {
     registry: VeilidComponentRegistry,
+    /// Which peers' failures count toward degraded breadth
+    breadth_strategy: DegradedBreadthStrategy,
     inner: Mutex<BTreeMap<RoutingDomain, OnlineDetectionPerDomain>>,
     /// Framing types the network uses; only these gate offline detection.
     enabled_framing_types: Mutex<FramingTypeSet>,
@@ -247,6 +260,7 @@ impl OnlineDetector {
     pub fn new(registry: VeilidComponentRegistry) -> Self {
         Self {
             registry,
+            breadth_strategy: DegradedBreadthStrategy::ReliableOnly,
             inner: Mutex::new(BTreeMap::new()),
             // Require both classes until the network reports its protocol config.
             enabled_framing_types: Mutex::new(FramingTypeSet::all()),
@@ -296,10 +310,25 @@ impl OnlineDetector {
         node_ids: impl IntoIterator<Item = NodeId>,
         sent_ts: Timestamp,
         transport: TransportType,
+        remote: Option<SocketAddress>,
     ) {
         if !Self::uses_ping_detection(routing_domain) {
             return;
         }
+        // A send that went through our own relay failed on the relay's side of the relay,
+        // not on our path to it; our connection to the relay is protected and kept alive
+        let via_own_relay = remote.is_some_and(|remote| {
+            self.routing_table()
+                .relays(routing_domain)
+                .iter()
+                .filter_map(|r| r.relay_node.unfiltered().get_peer_info(routing_domain))
+                .any(|pi| {
+                    pi.node_info()
+                        .dial_info_detail_list()
+                        .iter()
+                        .any(|did| did.dial_info.socket_address() == remote)
+                })
+        });
         // Only currently-responsive nodes count. A probe timing out to a node that is
         // Initial/Missing/Dead/Punished is evidence about that node, not about us: a stale
         // routing table loads entries as Initial while their persisted answer history
@@ -320,8 +349,14 @@ impl OnlineDetector {
                 continue;
             };
             let (responsive, fresh) = nr.operate(|e| {
-                let responsive = e.state(cur_ts).is_responsive();
-                let fresh = responsive
+                let state = e.state(cur_ts);
+                let responsive = state.is_responsive();
+                let eligible = match self.breadth_strategy {
+                    DegradedBreadthStrategy::Responsive => responsive,
+                    DegradedBreadthStrategy::ReliableOnly => state == BucketEntryState::Reliable,
+                };
+                let fresh = eligible
+                    && !via_own_relay
                     && e.per_sequence_ordering_stats().get(&so).is_some_and(|s| {
                         s.recent_lost_questions
                             < crate::routing_table::TRANSPORT_FAILING_LOST_QUESTIONS
@@ -546,7 +581,7 @@ impl OnlineDetector {
 
     /// Recompute and commit the effective three-state answer; returns a
     /// transition for the caller to log outside the lock.
-    fn commit_effective(
+    pub(crate) fn commit_effective(
         pd: &mut OnlineDetectionPerDomain,
         local_stall_ts: Option<Timestamp>,
         now: Timestamp,
@@ -566,7 +601,13 @@ impl OnlineDetector {
         }
         // Decided on entry, held for the whole degraded period
         match (old_state, new_state) {
-            (OnlineState::Degraded, _) => pd.degraded_recovered_ts = Some(now),
+            (OnlineState::Degraded, _) => {
+                pd.degraded_recovered_ts = Some(now);
+                // The window outlives the clean period; without this one more failure
+                // re-crosses the threshold on the old entries
+                pd.windowed_failures.clear();
+                pd.last_degraded_evidence_ts = None;
+            }
             (_, OnlineState::Degraded) => {
                 let rapid = pd.degraded_recovered_ts.is_some_and(|ts| {
                     now.duration_since(ts) <= TimestampDuration::new_secs(DEGRADED_REENTRY_SECS)
@@ -750,6 +791,11 @@ impl OnlineDetector {
             self.network_manager()
                 .transport_stats()
                 .reset_routing_domain(routing_domain, "sustained offline ended");
+            if routing_domain == RoutingDomain::PublicInternet {
+                self.routing_table()
+                    .route_spec_store()
+                    .clear_dead_route_hops();
+            }
         }
         if let Some(penalty) = opt_flap_penalty {
             veilid_log!(self debugwarn "{:?} online state FLAPPING (penalty={:.1})", routing_domain, penalty);
@@ -768,7 +814,7 @@ impl OnlineDetector {
     }
 
     /// Handle an event while online.
-    fn process_online_event(
+    pub(crate) fn process_online_event(
         pd: &mut OnlineDetectionPerDomain,
         event: &OnlineEvent,
         enabled_framing_types: FramingTypeSet,

veilid-core/src/network_manager/send_data.rs

@@ -93,6 +93,35 @@ impl NetworkManager {
         node_ref: FilteredNodeRef,
         data: Bytes,
     ) -> EyreResult<SendDataResult> {
+        // An answer goes back over the flow its question arrived on; only if that flow is
+        // gone does it fall through to the contact method
+        if let Some(flow) = node_ref.reply_flow() {
+            let net = self.net();
+            match pin_future!(net.send_data_to_existing_flow(flow, data.clone())).await? {
+                NetworkAttempt::Performed(NetworkResult::Value(unique_flow)) => {
+                    self.set_last_flow_from_send(
+                        node_ref.unfiltered(),
+                        unique_flow.flow,
+                        Timestamp::now(),
+                    );
+                    return Ok(SendDataResult::new(
+                        NodeContactMethodResult::Resolved(ContactMethod::Existing),
+                        NetworkResult::value(unique_flow),
+                    ));
+                }
+                NetworkAttempt::Performed(NetworkResult::Timeout) => {
+                    node_ref.clear_last_flow(flow);
+                    return Ok(SendDataResult::new(
+                        NodeContactMethodResult::Resolved(ContactMethod::Existing),
+                        NetworkResult::timeout(),
+                    ));
+                }
+                _ => {
+                    node_ref.clear_last_flow(flow);
+                }
+            }
+        }
+
         let mut ncm_result =
             self.get_node_contact_method(node_ref.clone(), ContactMethodIntent::Send)?;
 
@@ -106,14 +135,16 @@ impl NetworkManager {
             .await?;
 
             // Outbound health only; says nothing about peers reaching us
-            if let (Some(routing_domain), Some(transport)) =
-                (node_ref.best_routing_domain(), sdr.opt_transport_type())
-            {
+            if let (Some(routing_domain), Some(transport), Some(outcome)) = (
+                node_ref.best_routing_domain(),
+                sdr.opt_transport_type(),
+                TransportSendOutcome::from_send_data_result(&sdr),
+            ) {
                 self.transport_stats().record_send(
                     routing_domain,
                     transport,
                     node_ref.best_node_id(),
-                    TransportSendOutcome::from(&sdr),
+                    outcome,
                 );
             }
 
@@ -199,14 +230,16 @@ impl NetworkManager {
         // so a relay whose downstream flows were all dead read as idle rather than broken. Safe to
         // feed from here: suppression needs failures across several distinct peers, so one dead
         // destination indicts the peer rather than the transport.
-        if let (Some(routing_domain), Some(transport)) =
-            (destination_node_ref.best_routing_domain(), opt_transport)
-        {
+        if let (Some(routing_domain), Some(transport), Some(outcome)) = (
+            destination_node_ref.best_routing_domain(),
+            opt_transport,
+            TransportSendOutcome::from_network_result(&nres),
+        ) {
             self.transport_stats().record_send(
                 routing_domain,
                 transport,
                 destination_node_ref.best_node_id(),
-                TransportSendOutcome::from_network_result(&nres),
+                outcome,
             );
         }
 
@@ -588,13 +621,16 @@ impl NetworkManager {
         dial_info: DialInfo,
         data: Bytes,
     ) -> EyreResult<NetworkResult<UniqueFlow>> {
-        // Reuse only the existing flow whose remote address matches the target dial info
+        // Reuse only the existing flow whose remote is the target dial info; a flow that
+        // arrived through a relay has the relay's remote and must not carry a direct send
         let filtered_node_ref =
             node_ref.custom_filtered(NodeRefFilter::from(dial_info.make_filter()));
 
-        let opt_last_flow = filtered_node_ref.last_flow().filter(|flow| {
-            !self.transport_deprioritized(&filtered_node_ref, flow.transport_type())
-        });
+        let opt_last_flow = filtered_node_ref
+            .last_flow_to(dial_info.socket_address())
+            .filter(|flow| {
+                !self.transport_deprioritized(&filtered_node_ref, flow.transport_type())
+            });
 
         let data = if let Some(flow) = opt_last_flow {
             veilid_log!(self debug target:"contact_method",

veilid-core/src/network_manager/tests_network_manager/test_online_detector.rs

@@ -155,7 +155,59 @@ pub fn test_escalated_window_closes_the_gap() {
     );
 }
 
+fn node(n: u8) -> NodeId {
+    let mut b = [0u8; 32];
+    b[0] = n;
+    NodeId::new(CRYPTO_KIND_VLD0, BareNodeId::new(&b))
+}
+
+fn broad_failure(ft: FramingType, first: u8, count: u8, sent_ts: Timestamp) -> OnlineEvent {
+    let ids: Vec<NodeId> = (first..first + count).map(node).collect();
+    OnlineEvent::Failure {
+        live_node_ids: ids.clone(),
+        fresh_node_ids: ids,
+        responsive_count: 0,
+        sent_ts,
+        framing_type: ft,
+    }
+}
+
+pub fn test_recovery_clears_evidence_window() {
+    // A recovered domain must not re-degrade on a single failure: the evidence window
+    // (10s) outlives the clean period (5s), so the old entries have to go with the episode
+    let mut pd = OnlineDetectionPerDomain::default();
+    let framing = FramingTypeSet::all();
+    let threshold = OFFLINE_DETECTION_FAILURE_THRESHOLD_CONNECTION as u8;
+
+    // Enough fresh failures on every framing type: degraded
+    for ft in framing {
+        let ev = broad_failure(ft, 1, threshold, ts(10));
+        // Offline needs the same breadth sustained; here only the degraded overlay matters
+        let _ = OnlineDetector::process_online_event(&mut pd, &ev, framing, ts(10));
+    }
+    assert_eq!(pd.last_degraded_evidence_ts, Some(ts(10)));
+    assert!(OnlineDetector::commit_effective(&mut pd, None, ts(10)).is_some());
+    assert_eq!(pd.effective_state, OnlineState::Degraded);
+
+    // A round trip after the evidence plus the clean period: recovered, window gone
+    pd.last_success_ts = Some(ts(12));
+    let transition = OnlineDetector::commit_effective(&mut pd, None, ts(16));
+    assert_eq!(transition.map(|t| t.1), Some(OnlineState::Online));
+    assert!(pd.windowed_failures.values().all(BTreeMap::is_empty));
+    assert_eq!(pd.last_degraded_evidence_ts, None);
+
+    // One more failure per framing type is not breadth
+    for ft in framing {
+        let ev = broad_failure(ft, 100, 1, ts(17));
+        let _ = OnlineDetector::process_online_event(&mut pd, &ev, framing, ts(17));
+    }
+    assert_eq!(pd.last_degraded_evidence_ts, None);
+    assert!(OnlineDetector::commit_effective(&mut pd, None, ts(17)).is_none());
+    assert_eq!(pd.effective_state, OnlineState::Online);
+}
+
 pub fn test_all() {
+    test_recovery_clears_evidence_window();
     test_no_evidence_is_online();
     test_offline_dominates();
     test_fresh_evidence_degrades();

veilid-core/src/network_manager/tests_network_manager/test_transport_stats.rs

@@ -204,7 +204,43 @@ pub fn test_unbound_sends_count_toward_diversity() {
     assert_eq!(w.verdict(now()), TransportVerdict::Unknown);
 }
 
+pub fn test_refused_connect_is_not_evidence() {
+    info!("--- test_refused_connect_is_not_evidence ---");
+
+    // A refused connect made the round trip, so it says nothing against the transport
+    #[cfg(unix)]
+    {
+        let refused: NetworkResult<()> =
+            NetworkResult::NoConnection(std::io::Error::from_raw_os_error(libc::ECONNREFUSED));
+        assert_eq!(TransportSendOutcome::from_network_result(&refused), None);
+
+        // No route to the network is exactly the broken local path suppression is for
+        let unreachable: NetworkResult<()> =
+            NetworkResult::NoConnection(std::io::Error::from_raw_os_error(libc::ENETUNREACH));
+        assert_eq!(
+            TransportSendOutcome::from_network_result(&unreachable),
+            Some(TransportSendOutcome::FailedToSend)
+        );
+    }
+
+    // The wasm shape: refused by kind with no os error stays evidence
+    let kind_only: NetworkResult<()> =
+        NetworkResult::NoConnection(std::io::Error::from(std::io::ErrorKind::ConnectionRefused));
+    assert_eq!(
+        TransportSendOutcome::from_network_result(&kind_only),
+        Some(TransportSendOutcome::FailedToSend)
+    );
+
+    // The debug `transport disable` driver must keep latching
+    let disabled: NetworkResult<()> = NetworkResult::no_connection_other("transport disabled");
+    assert_eq!(
+        TransportSendOutcome::from_network_result(&disabled),
+        Some(TransportSendOutcome::FailedToSend)
+    );
+}
+
 pub fn test_all() {
+    test_refused_connect_is_not_evidence();
     test_verdict_needs_min_samples();
     test_verdict_any_success_is_healthy();
     test_window_keeps_min_samples_when_quiet();

veilid-core/src/network_manager/transport_stats.rs

@@ -73,17 +73,18 @@ impl TransportSendOutcome {
         matches!(self, TransportSendOutcome::Sent)
     }
 
-    pub(crate) fn from_network_result<T>(nr: &NetworkResult<T>) -> Self {
+    /// What a send result says about the transport; None when it says nothing
+    pub(crate) fn from_network_result<T>(nr: &NetworkResult<T>) -> Option<Self> {
         match nr {
-            NetworkResult::Value(_) => TransportSendOutcome::Sent,
-            NetworkResult::Timeout => TransportSendOutcome::Timeout,
-            _ => TransportSendOutcome::FailedToSend,
+            NetworkResult::Value(_) => Some(TransportSendOutcome::Sent),
+            NetworkResult::Timeout => Some(TransportSendOutcome::Timeout),
+            // Refused proves the path works; it is no evidence against the transport
+            NetworkResult::NoConnection(e) if is_connection_refused(e) => None,
+            _ => Some(TransportSendOutcome::FailedToSend),
         }
     }
-}
 
-impl From<&SendDataResult> for TransportSendOutcome {
-    fn from(sdr: &SendDataResult) -> Self {
+    pub(crate) fn from_send_data_result(sdr: &SendDataResult) -> Option<Self> {
         Self::from_network_result(sdr.network_result())
     }
 }

veilid-core/src/network_manager/types/dial_info_filter.rs

@@ -100,19 +100,22 @@ impl DialInfoFilter {
     pub fn is_dead(&self) -> bool {
         self.protocol_type_set.is_empty() || self.address_type_set.is_empty()
     }
+    /// Only the protocols that carry this ordering
+    pub fn ensure_ordering(ordering: SequenceOrdering) -> DialInfoFilter {
+        DialInfoFilter::all()
+            .with_protocol_type_set(ProtocolType::all_sequence_ordering_set(ordering))
+    }
+
+    /// The ordering to prefer and the filter with any ensure requirement applied. A preference
+    /// leaves the filter open; only ordered has an ensure variant until the wire gains one for
+    /// unordered, so callers that must have datagrams pair PreferUnordered with `ensure_ordering`.
     pub fn apply_sequencing(self, sequencing: Sequencing) -> (SequenceOrdering, DialInfoFilter) {
-        // Get first filtered dialinfo
-        match sequencing {
-            Sequencing::PreferUnordered => (SequenceOrdering::Unordered, self),
-            Sequencing::PreferOrdered => (SequenceOrdering::Ordered, self),
-            Sequencing::EnsureOrdered => (
-                SequenceOrdering::Ordered,
-                self.filtered(
-                    DialInfoFilter::all().with_protocol_type_set(ProtocolType::all_ordered_set()),
-                ),
-            ),
-        }
-        // return ordered sort and filter with ensure applied
+        let ordering = sequencing.preferred_ordering();
+        let filter = match sequencing {
+            Sequencing::PreferUnordered | Sequencing::PreferOrdered => self,
+            Sequencing::EnsureOrdered => self.filtered(DialInfoFilter::ensure_ordering(ordering)),
+        };
+        (ordering, filter)
     }
     pub fn is_ordered_only(&self) -> bool {
         for pt in self.protocol_type_set {

veilid-core/src/network_manager/types/protocol_type.rs

@@ -47,17 +47,6 @@ static PROTOCOL_TYPE_ORDERING: LazyLock<BTreeMap<(Sequencing, ProtocolType), usi
         out
     });
 
-static PROTOCOL_TYPE_ALL_ORDERED_SET: LazyLock<ProtocolTypeSet> = LazyLock::new(|| {
-    let mut out = ProtocolTypeSet::new();
-
-    out.insert(ProtocolType::TCP);
-    out.insert(ProtocolType::WS);
-    #[cfg(feature = "enable-protocol-wss")]
-    out.insert(ProtocolType::WSS);
-
-    out
-});
-
 static PROTOCOL_TYPE_ALL_CONNECTION_SET: LazyLock<ProtocolTypeSet> = LazyLock::new(|| {
     let mut out = ProtocolTypeSet::new();
 
@@ -121,10 +110,6 @@ impl ProtocolType {
             .get(&(sequencing, *self))
             .unwrap_or_log()
     }
-    pub fn all_ordered_set() -> ProtocolTypeSet {
-        *PROTOCOL_TYPE_ALL_ORDERED_SET
-    }
-
     pub fn all_connection_set() -> ProtocolTypeSet {
         *PROTOCOL_TYPE_ALL_CONNECTION_SET
     }

veilid-core/src/routing_table/bucket.rs

@@ -1,5 +1,4 @@
 use super::*;
-use core::sync::atomic::Ordering;
 
 impl_veilid_log_facility!("rtab");
 

veilid-core/src/routing_table/bucket_entry/mod.rs

@@ -2,9 +2,7 @@ mod state;
 mod state_reason;
 
 use super::*;
-#[cfg(feature = "tracking")]
-use core::sync::atomic::AtomicUsize;
-use core::sync::atomic::{AtomicU32, Ordering};
+use core::sync::atomic::AtomicU32;
 use hashlink::LruCache;
 
 pub(crate) use state::*;
@@ -22,14 +20,20 @@ pub(crate) const CONNECTIONLESS_TIMEOUT: TimestampDuration = TimestampDuration::
 #[derive(Debug, Clone, Eq, PartialEq, PartialOrd, Ord, Hash, Serialize, Deserialize)]
 pub(crate) struct LastFlowKey {
     pub transport: TransportType,
+    /// A node can be reached over several remotes per transport (its own address, its relay,
+    /// our relay); keying on the remote keeps a relayed flow from overwriting a direct one
+    pub remote: SocketAddress,
 }
 
 impl fmt::Display for LastFlowKey {
     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
-        write!(f, "{}", f.to_string(self.transport))
+        write!(f, "{}@{}", f.to_string(self.transport), self.remote)
     }
 }
 
+/// Live flows kept per transport type for one node
+const LAST_FLOWS_PER_TRANSPORT: usize = 4;
+
 #[derive(Debug, Clone, Eq, PartialEq, PartialOrd, Ord, Hash, Serialize, Deserialize)]
 pub(crate) struct LastSenderInfoKey {
     pub routing_domain: RoutingDomain,
@@ -153,7 +157,7 @@ pub(crate) struct BucketEntryInner {
     updated_since_last_network_change: bool,
     /// The last flows used to contact this node, per protocol type
     #[serde(skip)]
-    last_flows: BTreeMap<LastFlowKey, LastFlowEntry>,
+    pub(super) last_flows: BTreeMap<LastFlowKey, LastFlowEntry>,
     /// Last seen senderinfo per protocol/address type
     #[serde(skip)]
     last_sender_info: HashMap<LastSenderInfoKey, SenderInfo>,
@@ -824,16 +828,18 @@ impl BucketEntryInner {
     fn flow_to_key(&self, last_flow: Flow) -> LastFlowKey {
         LastFlowKey {
             transport: last_flow.transport_type(),
+            remote: *last_flow.remote_address(),
         }
     }
 
-    // Stores a flow in this entry's table of last flows
+    // Stores a flow in this entry's table of last flows, keeping the newest few per transport
     pub(super) fn set_last_flow(&mut self, last_flow: Flow, timestamp: Timestamp) {
         if self.punishment.is_some() {
             // Don't record connection if this entry is currently punished
             return;
         }
         let key = self.flow_to_key(last_flow);
+        let transport = key.transport;
         self.last_flows.insert(
             key,
             LastFlowEntry {
@@ -841,6 +847,20 @@ impl BucketEntryInner {
                 timestamp,
             },
         );
+        loop {
+            let same_transport = self
+                .last_flows
+                .iter()
+                .filter(|(k, _)| k.transport == transport)
+                .map(|(k, e)| (e.timestamp, k.clone()));
+            let Some((_, oldest)) = same_transport.clone().min() else {
+                break;
+            };
+            if same_transport.count() <= LAST_FLOWS_PER_TRANSPORT {
+                break;
+            }
+            self.last_flows.remove(&oldest);
+        }
     }
 
     // Removes a flow in this entry's table of last flows

veilid-core/src/routing_table/mod.rs

@@ -160,7 +160,7 @@ pub(crate) struct RoutingTable {
     /// Buckets to kick on our next kick task
     kick_queue: Mutex<BTreeSet<BucketIndex>>,
     /// Set when peerinfo changed on either side; the cm viability task fires only when set
-    cm_viability_dirty: core::sync::atomic::AtomicBool,
+    cm_viability_dirty: AtomicBool,
     /// Last route-test enqueue time per route, so a struggling route is not
     /// re-tested continuously on lossy networks
     route_test_cooldown: Mutex<BTreeMap<RouteId, Timestamp>>,
@@ -238,7 +238,7 @@ impl RoutingTable {
             public_keys: Default::default(),
             secret_keys: Default::default(),
             kick_queue: Default::default(),
-            cm_viability_dirty: core::sync::atomic::AtomicBool::new(true),
+            cm_viability_dirty: AtomicBool::new(true),
             route_test_cooldown: Default::default(),
             deferred_route_tests: Default::default(),
             #[cfg(feature = "stats")]
@@ -1634,14 +1634,12 @@ impl RoutingTable {
     /// Signal that some peerinfo changed (ours or theirs) so contact-method
     /// viability gets recomputed; the task's basis check skips unchanged entries
     pub(crate) fn mark_cm_viability_dirty(&self) {
-        self.cm_viability_dirty
-            .store(true, core::sync::atomic::Ordering::Release);
+        self.cm_viability_dirty.store(true, Ordering::Release);
     }
 
     /// Take the viability dirty flag; changes that land during a recompute re-set it
     pub(crate) fn take_cm_viability_dirty(&self) -> bool {
-        self.cm_viability_dirty
-            .swap(false, core::sync::atomic::Ordering::AcqRel)
+        self.cm_viability_dirty.swap(false, Ordering::AcqRel)
     }
 
     /// Called whenever a routing table entry is:

veilid-core/src/routing_table/node_ref/filtered_node_ref.rs

@@ -7,6 +7,8 @@ pub(crate) struct FilteredNodeRef {
     entry: Arc<BucketEntry>,
     filter: NodeRefFilter,
     sequencing: Sequencing,
+    /// The inbound flow an answer must go back over, when this ref addresses a questioner
+    reply_flow: Option<Flow>,
     #[cfg(feature = "tracking")]
     track_id: usize,
 }
@@ -30,6 +32,7 @@ impl FilteredNodeRef {
             entry,
             filter,
             sequencing,
+            reply_flow: None,
             #[cfg(feature = "tracking")]
             track_id,
         }
@@ -39,6 +42,17 @@ impl FilteredNodeRef {
         NodeRef::new(self.registry(), self.entry.clone())
     }
 
+    /// Pin the flow an answer goes back over
+    pub fn with_reply_flow(&self, flow: Flow) -> FilteredNodeRef {
+        let mut out = self.clone();
+        out.reply_flow = Some(flow);
+        out
+    }
+
+    pub fn reply_flow(&self) -> Option<Flow> {
+        self.reply_flow
+    }
+
     pub fn merge_filter_clone(&self, filter: NodeRefFilter) -> FilteredNodeRef {
         let mut out = self.clone();
         out.merge_filter(filter);
@@ -46,25 +60,20 @@ impl FilteredNodeRef {
     }
 
     pub fn with_sequencing(&self, sequencing: Sequencing) -> FilteredNodeRef {
-        FilteredNodeRef::new(
-            self.registry.clone(),
-            self.entry.clone(),
-            self.filter(),
-            sequencing,
-        )
+        let mut out = self.clone();
+        out.sequencing = sequencing;
+        out
     }
 
     pub fn with_routing_domain<R: Into<RoutingDomainSet>>(
         &self,
         routing_domain_set: R,
     ) -> FilteredNodeRef {
-        FilteredNodeRef::new(
-            self.registry.clone(),
-            self.entry.clone(),
-            self.filter()
-                .with_routing_domain_set(routing_domain_set.into()),
-            self.sequencing(),
-        )
+        let mut out = self.clone();
+        out.filter = self
+            .filter()
+            .with_routing_domain_set(routing_domain_set.into());
+        out
     }
 
     /// Make a noderef that meets the sequencing requirements, but is not
@@ -213,6 +222,7 @@ impl Clone for FilteredNodeRef {
             entry: self.entry.clone(),
             filter: self.filter,
             sequencing: self.sequencing,
+            reply_flow: self.reply_flow,
             #[cfg(feature = "tracking")]
             track_id: self.entry.track(),
         }

veilid-core/src/routing_table/node_ref/traits.rs

@@ -218,27 +218,19 @@ pub(crate) trait NodeRefCommonTrait:
         })
     }
 
-    /// Get the most recent 'last connection' flow whose remote matches the given address.
-    /// Prefers an exact (IP, port) match. Falls back to any flow with the same remote IP,
-    /// which covers incoming connections from a peer (ephemeral source port) where exact
-    /// port match would miss. Relay-mediated flows have a different remote IP and don't match.
-    #[expect(dead_code)]
+    /// The most recent live flow whose remote is exactly the given address. Veilid nodes bind
+    /// their outbound source port, so one connection exists between two nodes and its remote
+    /// is the dial info; a flow relayed in from elsewhere has a different remote and never matches.
     fn last_flow_to(&self, remote: SocketAddress) -> Option<Flow> {
         self.operate(|e| {
             let routing_table = self.routing_table();
             let sequencing = self.sequencing();
             let filter = self.filter();
             let (_ordering, filter) = filter.apply_sequencing(sequencing);
-            let mut last_flows = e.last_flows(&routing_table, true, filter);
-            last_flows.retain(|(flow, _)| flow.remote_address().address() == remote.address());
-            // Prefer exact port match
-            if let Some(exact) = last_flows
-                .iter()
+            e.last_flows(&routing_table, true, filter)
+                .into_iter()
                 .find(|(flow, _)| flow.remote_address() == &remote)
-            {
-                return Some(exact.0);
-            }
-            last_flows.first().map(|x| x.0)
+                .map(|x| x.0)
         })
     }
 

veilid-core/src/routing_table/route_spec_store/mod.rs

@@ -46,6 +46,23 @@ const ROUTE_MIN_IDLE_TIME_MS: u32 = 30_000;
 const ROUTE_LOST_DESTINATIONS_INVALIDATE_THRESHOLD: usize = 5;
 /// Number of consecutive send failures before invalidating compiled route cache for a safety route
 const ROUTE_SEND_FAILURES_INVALIDATE_THRESHOLD: usize = 1;
+/// Consecutive loopback failures that kill an ordering. Datagram legs compound across hops, so
+/// unordered routes get more slack. Provisional until the 2026-09-12 ambient-rate runs settle them.
+const ROUTE_LOOPBACK_FAILURES_INVALIDATE_THRESHOLD_ORDERED: usize = 3;
+const ROUTE_LOOPBACK_FAILURES_INVALIDATE_THRESHOLD_UNORDERED: usize = 5;
+
+/// How long the hops of a route that died on an ordering stay out of new routes for that ordering
+const ROUTE_DEAD_HOP_AVOID_SECS: u32 = 600;
+
+/// Loopback failure threshold for one ordering
+pub(super) fn loopback_failure_threshold(ordering: SequenceOrdering) -> usize {
+    match ordering {
+        SequenceOrdering::Ordered => ROUTE_LOOPBACK_FAILURES_INVALIDATE_THRESHOLD_ORDERED,
+        SequenceOrdering::Unordered => ROUTE_LOOPBACK_FAILURES_INVALIDATE_THRESHOLD_UNORDERED,
+    }
+}
+/// How often the per-ordering loopback tallies are logged
+const ROUTE_TEST_SUMMARY_INTERVAL: TimestampDuration = TimestampDuration::new_secs(60);
 /// The size of the compiled route cache
 const COMPILED_ROUTE_CACHE_SIZE: usize = 1024;
 
@@ -79,6 +96,10 @@ pub(crate) struct RouteSpecStore {
     route_selection_counter: AtomicUsize,
     /// Round-robin counter for distributing route-test destination selection
     test_destination_rotation_counter: AtomicUsize,
+    /// Per-ordering loopback tallies for the periodic summary line
+    route_test_summary: Mutex<RouteTestSummary>,
+    /// Hops of routes that died on an ordering, kept out of that ordering's allocations for a while
+    dead_route_hops: Mutex<BTreeMap<SequenceOrdering, HashMap<NodeId, Timestamp>>>,
 }
 
 impl_veilid_component_accessors!(RouteSpecStore);
@@ -103,6 +124,8 @@ impl RouteSpecStore {
             default_route_hop_count_unsafe,
             route_selection_counter: AtomicUsize::new(0),
             test_destination_rotation_counter: AtomicUsize::new(0),
+            route_test_summary: Mutex::new(RouteTestSummary::default()),
+            dead_route_hops: Mutex::new(BTreeMap::new()),
         }
     }
 

veilid-core/src/routing_table/route_spec_store/route_allocate.rs

@@ -105,7 +105,28 @@ impl RouteSpecStore {
             .await
     }
 
+    /// Allocate, preferring hops that have not recently killed a route on this ordering. After
+    /// an outage every hop is on that list, so when avoidance leaves no route it is dropped.
     pub async fn allocate_route_inner(
+        &self,
+        lock: &AsyncMutexGuard<'_, ()>,
+        params: AllocateRouteParams,
+    ) -> VeilidAPIResult<RouteIdAndKeys> {
+        let dead_hops = self.dead_route_hops_to_avoid(params.sequencing.preferred_ordering());
+        if !dead_hops.is_empty() {
+            let mut avoiding = params.clone();
+            avoiding.avoid_nodes.extend(dead_hops);
+            match self.allocate_route_unavoided(lock, avoiding).await {
+                Err(VeilidAPIError::TryAgain { .. }) => {
+                    veilid_log!(self debug "dead-hop avoidance left no route; allocating without it");
+                }
+                other => return other,
+            }
+        }
+        self.allocate_route_unavoided(lock, params).await
+    }
+
+    async fn allocate_route_unavoided(
         &self,
         _lock: &AsyncMutexGuard<'_, ()>,
         mut params: AllocateRouteParams,
@@ -417,6 +438,7 @@ impl RouteSpecStore {
                 return false;
             };
             veilid_log!(self debug "releasing allocated route {}: keys={}", id, rssd.get_route_set_keys());
+            self.record_route_release_summary(rssd.get_orderings());
 
             // Remove from hop cache
             let id_clone = id.clone();
@@ -528,6 +550,17 @@ impl RouteSpecStore {
                     return false;
                 }
 
+                // A hop must carry the route's ordering on that ordering's own protocols
+                let ordering_filter =
+                    DialInfoFilter::ensure_ordering(sequencing.preferred_ordering());
+                if !their_ni
+                    .dial_info_detail_list()
+                    .iter()
+                    .any(|did| did.matches_filter(&ordering_filter))
+                {
+                    return false;
+                }
+
                 // Exclude nodes that have don't advertise route capability
                 if !their_ni.has_capability(VEILID_CAPABILITY_ROUTE) {
                     return false;
@@ -833,93 +866,46 @@ impl RouteSpecStore {
                 }
             }
 
-            // Ensure this route is viable by checking that each node can contact the next one
-            let mut orderings = SequenceOrderingSet::all();
-            if params.directions.contains(Direction::Out) {
-                let mut previous_node = published_peer_info.clone();
-                let mut reachable = true;
-                for n in permutation {
-                    let current_node = nodes_pi.get(*n).cloned().unwrap_or_log();
-                    let cm = routing_table.get_best_contact_method(
+            // Ensure this route is viable: every hop pair must carry the route's one ordering,
+            // proven on that ordering's protocols alone since a preference would accept any
+            let ordering = params.sequencing.preferred_ordering();
+            let probe_sequencing = ordering.strict_sequencing();
+            let probe_filter = DialInfoFilter::ensure_ordering(ordering);
+            let hop_pair_viable = |peer_a: &Arc<PeerInfo>, peer_b: &Arc<PeerInfo>| {
+                routing_table
+                    .get_best_contact_method(
                         RoutingDomain::PublicInternet,
                         ContactMethodRequest {
-                            peer_a: previous_node.clone(),
+                            peer_a: peer_a.clone(),
                             peer_a_published: true,
-                            peer_b: current_node.clone(),
-                            dial_info_filter: DialInfoFilter::all(),
-                            sequencing: params.sequencing,
+                            peer_b: peer_b.clone(),
+                            dial_info_filter: probe_filter,
+                            sequencing: probe_sequencing,
                         },
-                    );
-                    if cm.is_none() {
-                        reachable = false;
-                        break;
+                    )
+                    .is_some()
+            };
+            if params.directions.contains(Direction::Out) {
+                let mut previous_node = published_peer_info.clone();
+                for n in permutation {
+                    let current_node = nodes_pi.get(*n).cloned().unwrap_or_log();
+                    if !hop_pair_viable(&previous_node, &current_node) {
+                        return None;
                     }
-
-                    // Check if we can do each ordering strictly
-                    for ordering in orderings {
-                        let cm = routing_table.get_best_contact_method(
-                            RoutingDomain::PublicInternet,
-                            ContactMethodRequest {
-                                peer_a: previous_node.clone(),
-                                peer_a_published: true,
-                                peer_b: current_node.clone(),
-                                dial_info_filter: DialInfoFilter::all(),
-                                sequencing: ordering.strict_sequencing(),
-                            },
-                        );
-                        if cm.is_none() {
-                            orderings.remove(ordering);
-                        }
-                    }
-
                     previous_node = current_node;
                 }
-                if !reachable {
-                    return None;
-                }
             }
             if params.directions.contains(Direction::In) {
                 let mut next_node = published_peer_info.clone();
-                let mut reachable = true;
                 for n in permutation.iter().rev() {
                     let current_node = nodes_pi.get(*n).cloned().unwrap_or_log();
-                    let cm = routing_table.get_best_contact_method(
-                        RoutingDomain::PublicInternet,
-                        ContactMethodRequest {
-                            peer_a: next_node.clone(),
-                            peer_a_published: true,
-                            peer_b: current_node.clone(),
-                            dial_info_filter: DialInfoFilter::all(),
-                            sequencing: params.sequencing,
-                        },
-                    );
-                    if cm.is_none() {
-                        reachable = false;
-                        break;
-                    }
-
-                    // Check if we can do each ordering strictly
-                    for ordering in orderings {
-                        let cm = routing_table.get_best_contact_method(
-                            RoutingDomain::PublicInternet,
-                            ContactMethodRequest {
-                                peer_a: next_node.clone(),
-                                peer_a_published: true,
-                                peer_b: current_node.clone(),
-                                dial_info_filter: DialInfoFilter::all(),
-                                sequencing: ordering.strict_sequencing(),
-                            },
-                        );
-                        if cm.is_none() {
-                            orderings.remove(ordering);
-                        }
+                    if !hop_pair_viable(&next_node, &current_node) {
+                        return None;
                     }
                     next_node = current_node;
                 }
-                if !reachable {
-                    return None;
-                }
             }
+            let orderings = SequenceOrderingSet::only(ordering);
 
             // Apply relay-capable preference per policy. Tier 0 (AllHops) excludes
             // SignalReverse/SignalHolePunch-only first hops and biases the whole

veilid-core/src/routing_table/route_spec_store/route_compile.rs

@@ -38,6 +38,8 @@ pub struct CompiledRoute {
     pub first_hop: FilteredNodeRef,
     /// Whether this compiled route was built with optimized hop encoding (NodeId only vs full PeerInfo)
     pub optimized: bool,
+    /// Sequencing the routed operation is sent with: the request's, narrowed to what the safety route carries
+    pub sequencing: Sequencing,
 }
 
 /// The state of a cache lookup for a compiled route
@@ -64,6 +66,8 @@ struct RouteCompileContext {
     optimize: bool,
     /// Whether or not the private route was allocated
     pr_allocated: bool,
+    /// Sequencing narrowed to what the safety route carries
+    sequencing: Sequencing,
 }
 
 impl RouteSpecStore {
@@ -86,7 +90,10 @@ impl RouteSpecStore {
         let first_hop = safety_arce.hop_node_ref(0).unwrap_or_log();
 
         // Ensure sequencing requirement is set on first hop
-        let mut first_hop = first_hop.sequencing_filtered(safety_spec.sequencing);
+        let sequencing = safety_spec
+            .sequencing
+            .for_route_orderings(safety_arce.orderings());
+        let mut first_hop = first_hop.sequencing_filtered(sequencing);
 
         // Enforce the routing domain
         first_hop
@@ -103,6 +110,7 @@ impl RouteSpecStore {
             hop_node_refs,
             optimize,
             pr_allocated,
+            sequencing,
         })
     }
 
@@ -272,6 +280,7 @@ impl RouteSpecStore {
             first_hop: ctx.first_hop,
             optimized: ctx.optimize,
             pr_allocated: ctx.pr_allocated,
+            sequencing: ctx.sequencing,
         }))
     }
 
@@ -373,6 +382,7 @@ impl RouteSpecStore {
                     first_hop,
                     optimized: true, // Stubs are always considered optimized
                     pr_allocated: opt_private_route_id.is_some(),
+                    sequencing: *sequencing,
                 });
 
                 // Cache the compiled route stub

veilid-core/src/routing_table/route_spec_store/route_select.rs

@@ -1,25 +1,44 @@
 use super::*;
 
+/// Safety route request for one send: the safety spec plus what the destination rules out
 #[derive(Clone, Debug)]
 pub struct RouteSelectParams {
+    /// Crypto kind the route's keys must include
     pub crypto_kind: CryptoKind,
+    /// Allocated route to use as-is when it still fits this request
     pub preferred_route: Option<AllocatedRouteSetId>,
+    /// Requested safety route length
     pub hop_count: usize,
+    /// Stability the route should meet; routes that meet it rank first
     pub stability: Stability,
+    /// Requested sequencing; its preferred ordering picks the route pool
     pub sequencing: Sequencing,
+    /// Directions the route must support
     pub directions: DirectionSet,
+    /// Nodes that must not appear as hops
     pub avoid_nodes: Vec<NodeId>,
+    /// Destination is a private route; an unsafe one doubles a short hop count
     pub is_destination_safe: bool,
 }
 
+/// Match for one allocated route in the pool
 #[derive(Clone, Debug)]
 struct FirstAvailableRouteParams {
+    /// Crypto kind the route's keys must include
     pub crypto_kind: CryptoKind,
+    /// Fewest hops accepted
     pub min_hop_count: usize,
+    /// Most hops accepted
     pub max_hop_count: usize,
+    /// Stability the route should meet; routes that meet it rank first
     pub stability: Stability,
+    /// Requested sequencing, matched against the route's live orderings
     pub sequencing: Sequencing,
+    /// The one ordering the route must carry
+    pub ordering: SequenceOrdering,
+    /// Directions the route must support
     pub directions: DirectionSet,
+    /// Nodes that must not appear as hops
     pub avoid_nodes: Vec<NodeId>,
 }
 
@@ -93,6 +112,7 @@ impl RouteSpecStore {
             max_hop_count: params.hop_count,
             stability: params.stability,
             sequencing: params.sequencing,
+            ordering: params.sequencing.preferred_ordering(),
             directions: params.directions,
             avoid_nodes: params.avoid_nodes,
         };
@@ -129,7 +149,7 @@ impl RouteSpecStore {
 
             // Select a safety route from the pool or make one if we don't have one that matches
             // Try this outside of the allocate lock to see if we can do this lock-free first
-            if let Some(sr_route_id_and_public_keys) = Self::first_available_route_inner(
+            if let Some(sr_route_id_and_public_keys) = Self::first_available_route_preferring(
                 &cache,
                 &first_available_route_params,
                 &self.route_selection_counter,
@@ -167,7 +187,7 @@ impl RouteSpecStore {
                 // Must re-check first available route to avoid race condition due to await
                 // Because during the time we didn't hold the allocate lock, the first available route may have been allocated
                 let cache = self.cache.read();
-                if let Some(sr_route_id_and_public_keys) = Self::first_available_route_inner(
+                if let Some(sr_route_id_and_public_keys) = Self::first_available_route_preferring(
                     &cache,
                     &first_available_route_params,
                     &self.route_selection_counter,
@@ -200,9 +220,23 @@ impl RouteSpecStore {
             avoid_nodes: first_available_route_params.avoid_nodes,
             automatic: true,
         };
-        let allocated = self
-            .allocate_route_inner(&allocate_route_lock_guard, params)
+        let mut allocated = self
+            .allocate_route_inner(&allocate_route_lock_guard, params.clone())
             .await;
+        // A preference for datagrams falls back to an ordered route when no datagram route can be built
+        if matches!(allocated, Err(VeilidAPIError::TryAgain { .. }))
+            && params.sequencing == Sequencing::PreferUnordered
+        {
+            allocated = self
+                .allocate_route_inner(
+                    &allocate_route_lock_guard,
+                    AllocateRouteParams {
+                        sequencing: Sequencing::PreferOrdered,
+                        ..params
+                    },
+                )
+                .await;
+        }
         #[cfg(feature = "instrument")]
         {
             let span = tracing::Span::current();
@@ -214,6 +248,28 @@ impl RouteSpecStore {
         allocated
     }
 
+    /// First available route carrying the preferred ordering; a preference for datagrams
+    /// falls back to an ordered route, a requirement for ordered never does
+    fn first_available_route_preferring(
+        cache: &RouteSpecStoreCache,
+        params: &FirstAvailableRouteParams,
+        route_selection_counter: &AtomicUsize,
+    ) -> Option<RouteIdAndKeys> {
+        if let Some(found) =
+            Self::first_available_route_inner(cache, params, route_selection_counter)
+        {
+            return Some(found);
+        }
+        if params.sequencing != Sequencing::PreferUnordered {
+            return None;
+        }
+        let fallback = FirstAvailableRouteParams {
+            ordering: SequenceOrdering::Ordered,
+            ..params.clone()
+        };
+        Self::first_available_route_inner(cache, &fallback, route_selection_counter)
+    }
+
     /// Find first matching unpublished route that fits into the selection criteria
     /// Don't pick any routes that have failed and haven't been tested yet
     /// Round-robins among top-tier routes to distribute load across safety routes
@@ -233,7 +289,8 @@ impl RouteSpecStore {
         // Get all valid routes, allow routes that need testing
         // but definitely prefer routes that have been recently tested
         for (id, arce) in cache.iter_allocated_routes() {
-            if arce.is_live_sequencing_match(params.sequencing)
+            if arce.orderings() == SequenceOrderingSet::only(params.ordering)
+                && arce.is_live_sequencing_match(params.sequencing)
                 && arce.hop_count() >= params.min_hop_count
                 && arce.hop_count() <= params.max_hop_count
                 && arce.directions().is_superset(params.directions)

veilid-core/src/routing_table/route_spec_store/route_stats.rs

@@ -34,6 +34,14 @@ pub struct RouteOrderingStats {
     pub failed_to_send: usize,
     /// Consecutive loopback failures deferred under blame suppression
     pub deferred_loopback_failures: usize,
+    /// Loopback passes this session
+    pub loopback_pass: u64,
+    /// Loopback failures this session
+    pub loopback_fail: u64,
+    /// Current run of loopback failures
+    pub consecutive_loopback_failures: usize,
+    /// Longest run of loopback failures this session
+    pub max_consecutive_loopback_failures: usize,
     /// Per-destination lost question tracking: destination pubkey -> lost count
     pub lost_question_destinations: HashMap<PublicKey, usize>,
     /// When this ordering was last known valid (loopback pass / rcvd traffic)
@@ -53,9 +61,12 @@ pub struct RouteOrderingStats {
 }
 
 impl RouteOrderingStats {
-    /// Disposition of this single ordering (route-level Locked handled by caller).
-    pub fn disposition(&self) -> RouteStatsDisposition {
-        if self.failed_to_send >= ROUTE_SEND_FAILURES_INVALIDATE_THRESHOLD {
+    /// Disposition of this single ordering; `loopback_threshold` is the run of loopback
+    /// failures that kills it (route-level Locked handled by caller).
+    pub fn disposition(&self, loopback_threshold: usize) -> RouteStatsDisposition {
+        if self.failed_to_send >= ROUTE_SEND_FAILURES_INVALIDATE_THRESHOLD
+            || self.consecutive_loopback_failures >= loopback_threshold
+        {
             RouteStatsDisposition::InvalidSendFailure
         } else if self.lost_question_destinations.len()
             >= ROUTE_LOST_DESTINATIONS_INVALIDATE_THRESHOLD
@@ -68,7 +79,10 @@ impl RouteOrderingStats {
 
     /// Does this ordering need (re)testing?
     pub fn needs_testing(&self, cur_ts: Timestamp) -> bool {
-        if !self.lost_question_destinations.is_empty() || self.failed_to_send > 0 {
+        if !self.lost_question_destinations.is_empty()
+            || self.failed_to_send > 0
+            || self.consecutive_loopback_failures > 0
+        {
             return true;
         }
         if let Some(last_tested_ts) = self.last_known_valid_ts {
@@ -80,6 +94,30 @@ impl RouteOrderingStats {
     }
 }
 
+/// Loopback tally for one ordering after a result: on a pass, `streak` is the run of failures
+/// the pass ended; on a failure, the current run
+#[derive(Copy, Clone, Debug, Default, PartialEq, Eq)]
+pub struct RouteLoopbackTally {
+    pub streak: usize,
+    pub pass: u64,
+    pub fail: u64,
+}
+
+/// Loopback and release tallies for one ordering since the last summary line
+#[derive(Clone, Copy, Debug, Default)]
+pub struct RouteTestSummaryEntry {
+    pub pass: u64,
+    pub fail: u64,
+    pub releases: u64,
+}
+
+/// Per-ordering route test tallies, logged and reset on an interval
+#[derive(Debug, Default)]
+pub struct RouteTestSummary {
+    pub by_ordering: BTreeMap<SequenceOrdering, RouteTestSummaryEntry>,
+    pub last_log_ts: Option<Timestamp>,
+}
+
 #[derive(Clone, Debug)]
 pub struct RouteStats {
     /// Timestamp of when the route was created
@@ -135,7 +173,7 @@ impl fmt::Display for RouteStats {
         for (ordering, os) in self.per_ordering.iter() {
             writeln!(
                 f,
-                "  [{}] valid={} sent={} rq={} ra={} lost-dests/failed={}/{} answer={}",
+                "  [{}] valid={} sent={} rq={} ra={} lost-dests/failed={}/{} loopback={}/{} streak={} max={} answer={}",
                 ordering,
                 f.to_string_opt(os.last_known_valid_ts),
                 f.to_string_opt(os.last_sent_ts),
@@ -143,6 +181,10 @@ impl fmt::Display for RouteStats {
                 f.to_string_opt(os.last_rcvd_answer_ts),
                 os.lost_question_destinations.len(),
                 os.failed_to_send,
+                os.loopback_pass,
+                os.loopback_fail,
+                os.consecutive_loopback_failures,
+                os.max_consecutive_loopback_failures,
                 f.to_string(&os.answer),
             )?;
         }
@@ -238,7 +280,7 @@ impl RouteStats {
         // No entry => untested, treated as Valid (optimistic; not dead).
         self.per_ordering
             .get(&ordering)
-            .map(|o| o.disposition())
+            .map(|o| o.disposition(loopback_failure_threshold(ordering)))
             .unwrap_or(RouteStatsDisposition::Valid)
     }
 
@@ -253,11 +295,25 @@ impl RouteStats {
         !orderings.is_empty() && orderings.iter().all(|o| self.is_dead_for_ordering(o))
     }
 
+    /// Dead on every ordering by evidence that spans the route (a loopback run, or lost questions
+    /// to several destinations); a bare send failure names the first hop, which its own liveness
+    /// covers, and says nothing about the others
+    pub fn death_blames_hops_for(&self, orderings: SequenceOrderingSet) -> bool {
+        !orderings.is_empty()
+            && orderings.iter().all(|o| {
+                self.per_ordering.get(&o).is_some_and(|s| {
+                    s.consecutive_loopback_failures >= loopback_failure_threshold(o)
+                        || s.lost_question_destinations.len()
+                            >= ROUTE_LOST_DESTINATIONS_INVALIDATE_THRESHOLD
+                })
+            })
+    }
+
     /// Disposition aggregated over all orderings (any ordering Valid => Valid).
     pub fn aggregate_disposition(&self) -> RouteStatsDisposition {
         let mut worst = RouteStatsDisposition::Valid;
-        for o in self.per_ordering.values() {
-            match o.disposition() {
+        for (ordering, o) in self.per_ordering.iter() {
+            match o.disposition(loopback_failure_threshold(*ordering)) {
                 RouteStatsDisposition::Valid => return RouteStatsDisposition::Valid,
                 d => worst = d,
             }
@@ -326,23 +382,38 @@ impl RouteStats {
     }
 
     /// Record a loopback route test result for an ordering. A pass marks the
-    /// ordering valid and clears its failures; a fail counts as a send failure
-    /// for that ordering, so repeated loopback failures drive the ordering (and
-    /// eventually the route) to dead.
+    /// ordering valid and clears its failures; failures count consecutively and a run of
+    /// them (per-ordering threshold) kills the ordering. Returns the tally after the result.
     pub fn record_loopback_result(
         &mut self,
         ordering: SequenceOrdering,
         ok: bool,
         cur_ts: Timestamp,
-    ) {
+    ) -> RouteLoopbackTally {
         let os = self.ordering_mut(ordering);
         os.deferred_loopback_failures = 0;
+        let ended_streak = os.consecutive_loopback_failures;
         if ok {
             os.last_known_valid_ts = Some(cur_ts);
             os.failed_to_send = 0;
             os.lost_question_destinations.clear();
+            os.loopback_pass += 1;
+            os.consecutive_loopback_failures = 0;
         } else {
-            os.failed_to_send += 1;
+            os.loopback_fail += 1;
+            os.consecutive_loopback_failures += 1;
+            os.max_consecutive_loopback_failures = os
+                .max_consecutive_loopback_failures
+                .max(os.consecutive_loopback_failures);
+        }
+        RouteLoopbackTally {
+            streak: if ok {
+                ended_streak
+            } else {
+                os.consecutive_loopback_failures
+            },
+            pass: os.loopback_pass,
+            fail: os.loopback_fail,
         }
     }
 
@@ -487,6 +558,9 @@ impl RouteSpecStore {
             {
                 veilid_log!(self debug "Marking dead route for release: {}", key);
                 arce.mark_for_release();
+                if arce.with_stats(|s| s.death_blames_hops_for(arce.orderings())) {
+                    self.avoid_dead_route_hops(arce.orderings(), &arce.hop_node_refs());
+                }
                 // Nothing holds it right now -> release immediately
                 (!arce.is_locked()).then_some(rid)
             } else {
@@ -498,6 +572,96 @@ impl RouteSpecStore {
         }
     }
 
+    /// Keep a dead route's hops out of its orderings' allocations for a while, otherwise the
+    /// pool refills with the same dead hop pair
+    fn avoid_dead_route_hops(&self, orderings: SequenceOrderingSet, hops: &[NodeRef]) {
+        let cur_ts = Timestamp::now();
+        let mut dead_route_hops = self.dead_route_hops.lock();
+        for ordering in orderings {
+            let avoided = dead_route_hops.entry(ordering).or_default();
+            for hop in hops {
+                avoided.insert(hop.best_node_id(), cur_ts);
+            }
+        }
+    }
+
+    /// Hops to avoid when allocating a route for this ordering; expired entries are dropped
+    pub(super) fn dead_route_hops_to_avoid(&self, ordering: SequenceOrdering) -> Vec<NodeId> {
+        let cur_ts = Timestamp::now();
+        let avoid_for = TimestampDuration::new_secs(ROUTE_DEAD_HOP_AVOID_SECS);
+        let mut dead_route_hops = self.dead_route_hops.lock();
+        let Some(avoided) = dead_route_hops.get_mut(&ordering) else {
+            return Vec::new();
+        };
+        avoided.retain(|_, ts| cur_ts.duration_since(*ts) < avoid_for);
+        avoided.keys().cloned().collect()
+    }
+
+    /// Forget dead hops; routes that died during our own outage say nothing about their hops
+    pub(crate) fn clear_dead_route_hops(&self) {
+        self.dead_route_hops.lock().clear();
+    }
+
+    /// Tally a loopback outcome for the periodic summary
+    pub fn record_route_test_summary(&self, ordering: SequenceOrdering, ok: bool) {
+        let mut summary = self.route_test_summary.lock();
+        let entry = summary.by_ordering.entry(ordering).or_default();
+        if ok {
+            entry.pass += 1;
+        } else {
+            entry.fail += 1;
+        }
+    }
+
+    /// Tally a route release under each ordering it carried
+    pub fn record_route_release_summary(&self, orderings: SequenceOrderingSet) {
+        let mut summary = self.route_test_summary.lock();
+        for ordering in orderings {
+            summary.by_ordering.entry(ordering).or_default().releases += 1;
+        }
+    }
+
+    /// Log the per-ordering loopback tallies for an interval that saw a failure or a release, then reset them
+    pub fn log_route_test_summary(&self, cur_ts: Timestamp) {
+        let taken = {
+            let mut summary = self.route_test_summary.lock();
+            if summary
+                .last_log_ts
+                .is_some_and(|ts| cur_ts.duration_since(ts) < ROUTE_TEST_SUMMARY_INTERVAL)
+            {
+                return;
+            }
+            summary.last_log_ts = Some(cur_ts);
+            mem::take(&mut summary.by_ordering)
+        };
+        // A clean interval stays quiet
+        if taken.values().all(|e| e.fail == 0 && e.releases == 0) {
+            return;
+        }
+        let mut route_counts = BTreeMap::<SequenceOrdering, usize>::new();
+        self.list_allocated_routes(|_k, v| {
+            for ordering in v.orderings() {
+                *route_counts.entry(ordering).or_default() += 1;
+            }
+            Option::<()>::None
+        });
+        let parts = SequenceOrderingSet::all()
+            .iter()
+            .map(|ordering| {
+                let entry = taken.get(&ordering).copied().unwrap_or_default();
+                format!(
+                    "{:#} pass/fail={}/{} (routes {}, releases {})",
+                    ordering,
+                    entry.pass,
+                    entry.fail,
+                    route_counts.get(&ordering).copied().unwrap_or(0),
+                    entry.releases
+                )
+            })
+            .collect::<Vec<_>>();
+        veilid_log!(self debug target: "rtab::route", "route test summary: {}", parts.join(" "));
+    }
+
     /// Modify the route statistics for remote routes
     /// Changes made to the route stats may invalidate the route in the compiled route cache
     pub fn update_remote_route_stats<F>(&self, cur_ts: Timestamp, key: &PublicKey, f: F)

veilid-core/src/routing_table/route_spec_store/route_test.rs

@@ -328,10 +328,9 @@ impl RouteSpecStore {
 
         let healthy = loopback_ok && (any_direct_ok || direct_count == 0);
         if !healthy {
-            if let Some(probe_transport) = probe_transport {
-                for hop in hops {
-                    hop.report_failed_route_test(probe_transport);
-                }
+            // A multi-hop failure cannot isolate a hop; only a single hop's legs are ours
+            if let (Some(probe_transport), [hop]) = (probe_transport, hops.as_slice()) {
+                hop.report_failed_route_test(probe_transport);
             }
             return Ok(Some(false));
         }

veilid-core/src/routing_table/routing_domains/public_internet/controller/bootstrap.rs

@@ -45,7 +45,7 @@ impl PublicInternetRoutingDomainController {
             } else if Resolver::supports_txt() {
                 bootstrap_txt_names.push(bootstrap);
             } else {
-                // No TXT resolver here, so the bootstrap host answers B01T directly instead
+                // No TXT resolver here, so the bootstrap host is asked directly instead
                 for url in self.direct_bootstrap_urls(&bootstrap) {
                     match dial_info_converter.try_vec_from_url(&url).await {
                         Ok(bootstrap_di_vec) => bootstrap_dialinfos.extend(bootstrap_di_vec),
@@ -79,11 +79,22 @@ impl PublicInternetRoutingDomainController {
             }));
         }
         for bstn in bootstrap_txt_names {
-            // TXT bootstrap
+            // TXT bootstrap, then the host directly if the resolver gave nothing in
+            // time: a tethered phone's DNS relay answers A/AAAA but not TXT
             unord.push(pin_dyn_future!(async {
                 let bstn = bstn;
                 veilid_log!(self debug "TXT bootstrap with: {}", bstn);
-                pin_future!(network_manager.txt_bootstrap(bstn)).await
+                let txt_timeout = TimestampDuration::new_ms(BOOTSTRAP_TXT_TIMEOUT_MS.into());
+                match pin_future!(network_manager.txt_bootstrap(bstn.clone()))
+                    .timeout_duration(txt_timeout)
+                    .await
+                {
+                    Ok(Ok(peers)) if !peers.peers.is_empty() => Ok(peers),
+                    _ => {
+                        veilid_log!(self debug "TXT bootstrap gave nothing, trying direct bootstrap on: {}", bstn);
+                        self.direct_bootstrap_by_name(&bstn).await
+                    }
+                }
             }));
         }
 
@@ -213,6 +224,46 @@ impl PublicInternetRoutingDomainController {
         Ok(())
     }
 
+    /// Direct bootstrap from every address a bootstrap name resolves to, every
+    /// protocol at once, results merged
+    async fn direct_bootstrap_by_name(&self, hostname: &str) -> EyreResult<BootstrapPeers> {
+        let dial_info_converter = BootstrapDialInfoConverter::default();
+        let mut unord = FuturesUnordered::new();
+        for url in self.direct_bootstrap_urls(hostname) {
+            match dial_info_converter.try_vec_from_url(&url).await {
+                Ok(dial_infos) => {
+                    for dial_info in dial_infos {
+                        let registry = self.registry();
+                        unord.push(async move {
+                            let network_manager = registry.network_manager();
+                            let res =
+                                pin_future!(network_manager.direct_bootstrap(dial_info.clone()))
+                                    .await;
+                            (dial_info, res)
+                        });
+                    }
+                }
+                Err(e) => {
+                    veilid_log!(self debug "Could not resolve direct bootstrap {}: {}", url, e);
+                }
+            }
+        }
+        let mut out = BootstrapPeers::default();
+        while let Some((dial_info, res)) = unord.next().await {
+            match res {
+                Ok(peers) => {
+                    out.peers.extend(peers.peers);
+                    out.records.extend(peers.records);
+                    out.record_strings.extend(peers.record_strings);
+                }
+                Err(e) => {
+                    veilid_log!(self debug "Direct bootstrap {} failed: {}", dial_info, e);
+                }
+            }
+        }
+        Ok(out)
+    }
+
     /// Direct bootstrap urls for a TXT bootstrap name, one per enabled outbound protocol
     fn direct_bootstrap_urls(&self, hostname: &str) -> Vec<String> {
         let protocol = &self.config().network.protocol;

veilid-core/src/routing_table/routing_domains/public_internet/controller/private_route_management.rs

@@ -10,6 +10,13 @@ const MINIMUM_BACKGROUND_SAFETY_ROUTE_COUNT: usize = 2;
 /// or a recent route test has already bumped `last_known_valid_ts` within the same window.
 const SR_LOOPBACK_KEEPALIVE_INTERVAL: TimestampDuration = TimestampDuration::new_secs(10);
 
+/// The one ordering a pool route carries; None for legacy routes that carried both
+fn single_ordering(orderings: SequenceOrderingSet) -> Option<SequenceOrdering> {
+    (orderings.len() == 1)
+        .then(|| orderings.iter().next())
+        .flatten()
+}
+
 impl PublicInternetRoutingDomainController {
     /// Fastest routes sort
     fn route_sort_latency_fn(
@@ -45,7 +52,9 @@ impl PublicInternetRoutingDomainController {
 
         rss.list_allocated_routes(|_k, v| {
             let is_known_valid = v.with_stats(|stats| stats.last_known_valid_ts().is_some());
-            if is_known_valid && v.is_automatic() {
+            // Ordered routes gate readiness; unordered ones are best effort
+            let is_ordered = single_ordering(v.orderings()) == Some(SequenceOrdering::Ordered);
+            if is_known_valid && v.is_automatic() && is_ordered {
                 if v.hop_count() == rss.get_default_route_hop_count_safe() {
                     safe_route_count += 1;
                 } else if v.hop_count() == rss.get_default_route_hop_count_unsafe() {
@@ -82,8 +91,9 @@ impl PublicInternetRoutingDomainController {
         let default_route_hop_count_unsafe = rss.get_default_route_hop_count_unsafe();
 
         let mut must_test_routes = Vec::<AllocatedRouteSetId>::new();
-        let mut automatic_safe_routes = Vec::<(AllocatedRouteSetId, u64)>::new();
-        let mut automatic_unsafe_routes = Vec::<(AllocatedRouteSetId, u64)>::new();
+        // Pool routes by (hop count, ordering) cell, with latency for the speed sort
+        let mut pool =
+            BTreeMap::<(usize, SequenceOrdering), Vec<(AllocatedRouteSetId, u64)>>::new();
         let mut expired_routes = Vec::<AllocatedRouteSetId>::new();
         rss.list_allocated_routes(|k, v| {
             // A route a test confirmed dead is marked for release; release it once its refcount
@@ -96,6 +106,12 @@ impl PublicInternetRoutingDomainController {
                 return Option::<()>::None;
             }
             let route_orderings = v.orderings();
+            // Pool routes carry one ordering each; a legacy route that carried both makes way
+            let opt_ordering = single_ordering(route_orderings);
+            if v.is_automatic() && opt_ordering.is_none() {
+                expired_routes.push(k.clone());
+                return Option::<()>::None;
+            }
             v.with_stats(|stats| {
                 // Ignore routes that don't need or want testing
                 if !stats.needs_testing(route_orderings, cur_ts) {
@@ -106,13 +122,16 @@ impl PublicInternetRoutingDomainController {
                 if v.is_published() || stats.last_known_valid_ts().is_none() {
                     must_test_routes.push(k.clone());
                 }
-                // If this is of default safe route hop length, include it in routes to keep alive
-                else if v.is_automatic() && v.hop_count() == default_route_hop_count_safe {
-                    automatic_safe_routes.push((k.clone(), stats.latency.average.as_u64()));
-                }
-                // If this is a default unsafe route hop length, include it in routes to keep alive
-                else if v.is_automatic() && v.hop_count() == default_route_hop_count_unsafe {
-                    automatic_unsafe_routes.push((k.clone(), stats.latency.average.as_u64()));
+                // Pool routes of a default length are kept alive per cell
+                else if v.is_automatic()
+                    && (v.hop_count() == default_route_hop_count_safe
+                        || v.hop_count() == default_route_hop_count_unsafe)
+                {
+                    if let Some(ordering) = opt_ordering {
+                        pool.entry((v.hop_count(), ordering))
+                            .or_default()
+                            .push((k.clone(), stats.latency.average.as_u64()));
+                    }
                 }
                 // Else tear down only automatic (pool-managed) routes; manual routes are caller-owned
                 else if v.is_automatic() {
@@ -122,33 +141,15 @@ impl PublicInternetRoutingDomainController {
             })
         });
 
-        // Sort automatic routes by speed if we know the speed
-        automatic_safe_routes.sort_unstable_by(Self::route_sort_latency_fn);
-        automatic_unsafe_routes.sort_unstable_by(Self::route_sort_latency_fn);
-
-        // Save up to N unpublished routes and test them
-        let background_safety_route_count = DESIRED_BACKGROUND_SAFETY_ROUTE_COUNT;
-
-        let safe_routes_to_keep =
-            usize::min(background_safety_route_count, automatic_safe_routes.len());
-        for automatic_safe_route in automatic_safe_routes.iter().take(safe_routes_to_keep) {
-            must_test_routes.push(automatic_safe_route.0.clone());
-        }
-        let unsafe_routes_to_keep =
-            usize::min(background_safety_route_count, automatic_unsafe_routes.len());
-        for automatic_unsafe_route in automatic_unsafe_routes.iter().take(unsafe_routes_to_keep) {
-            must_test_routes.push(automatic_unsafe_route.0.clone());
-        }
-
-        // Kill off all but N unpublished routes rather than testing them
-        if automatic_safe_routes.len() > safe_routes_to_keep {
-            for x in &automatic_safe_routes[safe_routes_to_keep..] {
-                expired_routes.push(x.0.clone());
+        // Per cell: keep and test the fastest N, kill off the rest rather than testing them
+        for routes in pool.values_mut() {
+            routes.sort_unstable_by(Self::route_sort_latency_fn);
+            let keep = usize::min(DESIRED_BACKGROUND_SAFETY_ROUTE_COUNT, routes.len());
+            for route in routes.iter().take(keep) {
+                must_test_routes.push(route.0.clone());
             }
-        }
-        if automatic_unsafe_routes.len() > unsafe_routes_to_keep {
-            for x in &automatic_unsafe_routes[unsafe_routes_to_keep..] {
-                expired_routes.push(x.0.clone());
+            for route in routes.iter().skip(keep) {
+                expired_routes.push(route.0.clone());
             }
         }
 
@@ -204,6 +205,49 @@ impl PublicInternetRoutingDomainController {
         out
     }
 
+    /// Release the automatic unpublished routes and run the management routine now so the
+    /// pool refills without waiting for its tick. Returns (released, allocated).
+    #[cfg(feature = "debug-api")]
+    pub(crate) async fn reallocate_safety_routes(&self) -> EyreResult<(usize, usize)> {
+        let routing_table = self.routing_table();
+        let rss = routing_table.route_spec_store();
+        let pool = rss.list_allocated_routes(|k, v| {
+            (v.is_automatic() && !v.is_published()).then(|| k.clone())
+        });
+        let released = pool.len();
+        for id in pool {
+            rss.release_route(id.into());
+        }
+        // A tick already in flight is skipped by try_tick_now; retry until one of ours starts.
+        // The routine runs detached, so wait for the pool count to settle rather than for it.
+        for _ in 0..20 {
+            if self.private_route_management_task.try_tick_now().await? {
+                break;
+            }
+            sleep(100).await;
+        }
+        let pool_size = || {
+            rss.list_allocated_routes(|_k, v| (v.is_automatic() && !v.is_published()).then_some(()))
+                .len()
+        };
+        let mut allocated = pool_size();
+        let mut settled = 0;
+        for _ in 0..100 {
+            sleep(100).await;
+            let now = pool_size();
+            settled = if now == allocated && now > 0 {
+                settled + 1
+            } else {
+                0
+            };
+            allocated = now;
+            if settled >= 5 {
+                break;
+            }
+        }
+        Ok((released, allocated))
+    }
+
     /// Keep private routes assigned and accessible
     #[cfg_attr(
         feature = "instrument",
@@ -257,47 +301,40 @@ impl PublicInternetRoutingDomainController {
                 .await;
         }
 
-        // Ensure we have a minimum of N allocated local, unpublished routes with the default number of hops
-        // and all our supported crypto kinds. Also allocate some routes of twice the default length for
-        // safety routes to direct nodes.
+        // Ensure we have a minimum of N allocated local, unpublished routes per (hop count, ordering)
+        // cell, with all our supported crypto kinds: the default length for safe destinations and
+        // twice that for direct ones, each for ordered and for unordered traffic.
         let default_route_hop_count_safe = rss.get_default_route_hop_count_safe();
         let default_route_hop_count_unsafe = rss.get_default_route_hop_count_unsafe();
 
-        let mut local_safety_route_count_safe = 0usize;
-        let mut local_safety_route_count_unsafe = 0usize;
-
+        let mut pool_counts = BTreeMap::<(usize, SequenceOrdering), usize>::new();
         rss.list_allocated_routes(|_k, v| {
             if !v.is_published() && v.is_automatic() {
-                if v.hop_count() == default_route_hop_count_safe {
-                    local_safety_route_count_safe += 1;
-                } else if v.hop_count() == default_route_hop_count_unsafe {
-                    local_safety_route_count_unsafe += 1;
+                if let Some(ordering) = single_ordering(v.orderings()) {
+                    *pool_counts.entry((v.hop_count(), ordering)).or_default() += 1;
                 }
             }
             Option::<()>::None
         });
 
-        let background_safety_route_count = DESIRED_BACKGROUND_SAFETY_ROUTE_COUNT;
-
-        // Newly allocated routes, separated by type for interleaving
-        let mut newly_safe_routes = Vec::new();
-        let mut newly_unsafe_routes = Vec::new();
-
-        // Allocate more routes if needed
-        for (route_count, hop_count, is_safe) in [
-            (
-                local_safety_route_count_safe,
-                default_route_hop_count_safe,
-                true,
-            ),
-            (
-                local_safety_route_count_unsafe,
-                default_route_hop_count_unsafe,
-                false,
-            ),
-        ] {
-            if route_count < background_safety_route_count {
-                let routes_to_allocate = background_safety_route_count - route_count;
+        // Ordered cells first (they gate readiness), safe and unsafe lengths interleaved so the
+        // first batch of parallel tests covers both lengths
+        let mut newly_allocated_routes = Vec::new();
+        for ordering in [SequenceOrdering::Ordered, SequenceOrdering::Unordered] {
+            let mut newly_safe_routes = Vec::new();
+            let mut newly_unsafe_routes = Vec::new();
+            for (hop_count, is_safe) in [
+                (default_route_hop_count_safe, true),
+                (default_route_hop_count_unsafe, false),
+            ] {
+                let route_count = pool_counts
+                    .get(&(hop_count, ordering))
+                    .copied()
+                    .unwrap_or(0);
+                if route_count >= DESIRED_BACKGROUND_SAFETY_ROUTE_COUNT {
+                    continue;
+                }
+                let routes_to_allocate = DESIRED_BACKGROUND_SAFETY_ROUTE_COUNT - route_count;
 
                 // Parameters here must be the most inclusive route allocation spec
                 // These will be used by test_remote_route as well
@@ -305,7 +342,7 @@ impl PublicInternetRoutingDomainController {
                     crypto_kinds: VALID_CRYPTO_KINDS.to_vec(),
                     hop_count,
                     stability: Stability::Reliable,
-                    sequencing: Sequencing::PreferOrdered,
+                    sequencing: ordering.minimum_sequencing(),
                     directions: DirectionSet::all(),
                     avoid_nodes: Vec::new(),
                     automatic: true,
@@ -313,7 +350,8 @@ impl PublicInternetRoutingDomainController {
                 for _n in 0..routes_to_allocate {
                     match rss.allocate_route(params.clone()).await {
                         Err(VeilidAPIError::TryAgain { message }) => {
-                            veilid_log!(self debug "Route allocation unavailable: {}", message);
+                            veilid_log!(self debug "Route allocation unavailable ({:#} {} hops): {}", ordering, hop_count, message);
+                            break;
                         }
                         Err(e) => return Err(e.into()),
                         Ok(v) => {
@@ -326,28 +364,21 @@ impl PublicInternetRoutingDomainController {
                     }
                 }
             }
-        }
-
-        // Interleave safe and unsafe routes so the first batch of parallel tests
-        // includes both types. This ensures safety_routes_ready() sees both safe=1+
-        // and unsafe=1+ after the first batch completes, rather than having to wait
-        // for all safe routes to finish before any unsafe routes start.
-        let mut newly_allocated_routes = Vec::new();
-        let max_len = newly_safe_routes.len().max(newly_unsafe_routes.len());
-        for i in 0..max_len {
-            if let Some(r) = newly_safe_routes.get(i) {
-                newly_allocated_routes.push(r.clone());
-            }
-            if let Some(r) = newly_unsafe_routes.get(i) {
-                newly_allocated_routes.push(r.clone());
+            let max_len = newly_safe_routes.len().max(newly_unsafe_routes.len());
+            for i in 0..max_len {
+                if let Some(r) = newly_safe_routes.get(i) {
+                    newly_allocated_routes.push(r.clone());
+                }
+                if let Some(r) = newly_unsafe_routes.get(i) {
+                    newly_allocated_routes.push(r.clone());
+                }
             }
         }
 
         // Enqueue tests for newly allocated routes
         if !newly_allocated_routes.is_empty() {
             #[cfg(feature = "verbose-tracing")]
-            veilid_log!(self debug "Enqueuing {} newly allocated route tests ({} safe, {} unsafe)",
-                newly_allocated_routes.len(), newly_safe_routes.len(), newly_unsafe_routes.len());
+            veilid_log!(self debug "Enqueuing {} newly allocated route tests", newly_allocated_routes.len());
             routing_table
                 .enqueue_route_tests(
                     cur_ts,
@@ -383,6 +414,8 @@ impl PublicInternetRoutingDomainController {
                 .await;
         }
 
+        rss.log_route_test_summary(cur_ts);
+
         // Send update (also may send updates for released routes done by other parts of the program)
         rss.send_route_update();
 

veilid-core/src/routing_table/tasks/mod.rs

@@ -84,10 +84,7 @@ impl RoutingTable {
         self.rolling_answers_task.tick().await?;
 
         // Recompute contact-method viability when peerinfo changed on either side
-        if self
-            .cm_viability_dirty
-            .load(core::sync::atomic::Ordering::Acquire)
-        {
+        if self.cm_viability_dirty.load(Ordering::Acquire) {
             self.update_cm_viability_task.tick().await?;
         }
 

veilid-core/src/routing_table/tasks/ping_validator.rs

@@ -756,7 +756,7 @@ impl RoutingTable {
     /// Completion callback for a per-ordering route loopback ping. On Sent we record a
     /// per-ordering pass on the route (drives last_known_valid_ts / clears failures). On Failed
     /// we record a per-ordering failure on the route (drives the ordering, and eventually the
-    /// route, to dead) and attribute failure to the transport actually used at the first hop.
+    /// route, to dead); a single-hop route also charges that hop on the transport we used.
     /// NotSent is treated as a non-network failure and left for next cycle.
     fn make_loopback_probe_callback(
         route_id: RouteId,
@@ -776,10 +776,15 @@ impl RoutingTable {
                         veilid_log!(registry debug target: "rtab::stats", "Route loopback rtt: route={:#} ord={:#} rtt={:#} hops={}", route_key, ordering, status_answer.answer.answer_context.latency, hops.len());
 
                         let cur_ts = Timestamp::now();
+                        let mut tally = RouteLoopbackTally::default();
                         rss.update_allocated_route_stats(cur_ts, &route_key, |s| {
-                            s.record_loopback_result(ordering, true, cur_ts);
+                            tally = s.record_loopback_result(ordering, true, cur_ts);
                             Ok(())
                         });
+                        rss.record_route_test_summary(ordering, true);
+                        if tally.streak > 0 {
+                            veilid_log!(registry debug "Route loopback recovered: {:#} ord={:#} after {} failures pass/fail={}/{}", route_id, ordering, tally.streak, tally.pass, tally.fail);
+                        }
                         return Vec::new();
                     }
                     Ok(StatusResult::Failed(sdr)) => sdr,
@@ -830,20 +835,29 @@ impl RoutingTable {
                 // Record a per-ordering failure on the route so repeated loopback failures
                 // drive this ordering (and eventually the route) to dead and release.
                 let cur_ts = Timestamp::now();
+                let mut tally = RouteLoopbackTally::default();
                 rss.update_allocated_route_stats(cur_ts, &route_key, |s| {
-                    s.record_loopback_result(ordering, false, cur_ts);
+                    tally = s.record_loopback_result(ordering, false, cur_ts);
                     Ok(())
                 });
+                rss.record_route_test_summary(ordering, false);
                 // If this failure leaves the route dead for all orderings, mark it for release
                 // now (sticky) so it gets released once its refcount drains.
                 rss.mark_allocated_route_for_release_if_dead(&route_key);
 
+                let hop_ids = hops
+                    .iter()
+                    .map(|h| h.to_string())
+                    .collect::<Vec<_>>()
+                    .join(",");
                 let Some(transport) = opt_transport else {
-                    veilid_log!(registry debug "Route loopback FAILED with no transport recorded: {:#} ({:#})", route_id, ordering);
+                    veilid_log!(registry debug "Route loopback FAILED with no transport recorded: {:#} ord={:#} fails={} pass/fail={}/{} hops=[{}]", route_id, ordering, tally.streak, tally.pass, tally.fail, hop_ids);
                     return Vec::new();
                 };
-                veilid_log!(registry debug "Route loopback FAILED: {:#} ({:#} via {:#})", route_id, ordering, transport);
-                for hop in &hops {
+                // first_hop is only our leg's transport; the ordering is what the hops forward with
+                veilid_log!(registry debug "Route loopback FAILED: {:#} ord={:#} first_hop={:#} fails={} pass/fail={}/{} hops=[{}]", route_id, ordering, transport, tally.streak, tally.pass, tally.fail, hop_ids);
+                // A multi-hop failure cannot isolate a hop; only a single hop's legs are ours
+                if let [hop] = hops.as_slice() {
                     hop.report_failed_route_test(transport);
                 }
 

veilid-core/src/routing_table/tests_routing_table/mod.rs

@@ -3,6 +3,7 @@ pub mod test_bucket_entry_state;
 pub mod test_network_estimator;
 pub mod test_nodes_needed;
 pub mod test_persisted_reset;
+pub mod test_route_stats;
 pub mod test_routing_metrics;
 pub mod test_serialize_routing_table;
 pub mod test_signed_node_info;
@@ -12,6 +13,7 @@ pub use mocks::*;
 use super::*;
 
 pub async fn test_all() {
+    test_route_stats::test_all();
     test_serialize_routing_table::test_kick_preserves_best_node_id().await;
     test_serialize_routing_table::test_load_rejects_entries_without_node_ids().await;
     test_serialize_routing_table::test_replace_node_ids_rejects_without_valid_id().await;

veilid-core/src/routing_table/tests_routing_table/test_route_stats.rs

@@ -0,0 +1,125 @@
+use crate::routing_table::*;
+
+fn now() -> Timestamp {
+    Timestamp::new(1_000_000_000u64)
+}
+
+fn only(ordering: SequenceOrdering) -> SequenceOrderingSet {
+    SequenceOrderingSet::only(ordering)
+}
+
+pub fn test_loopback_failure_run_kills_ordering() {
+    info!("--- test_loopback_failure_run_kills_ordering ---");
+    let mut stats = RouteStats::new(now());
+    let threshold = loopback_failure_threshold(SequenceOrdering::Unordered);
+
+    for n in 1..threshold {
+        let tally = stats.record_loopback_result(SequenceOrdering::Unordered, false, now());
+        assert_eq!(tally.streak, n);
+        assert!(!stats.is_dead_for_ordering(SequenceOrdering::Unordered));
+        // A failing ordering wants a retest
+        assert!(stats.needs_testing(only(SequenceOrdering::Unordered), now()));
+    }
+    let tally = stats.record_loopback_result(SequenceOrdering::Unordered, false, now());
+    assert_eq!(tally.fail, threshold as u64);
+    assert!(stats.is_dead_for_ordering(SequenceOrdering::Unordered));
+    assert!(stats.is_dead_for(only(SequenceOrdering::Unordered)));
+
+    // The other ordering is untouched and never counted
+    assert!(!stats.is_dead_for_ordering(SequenceOrdering::Ordered));
+    assert!(!stats.is_dead_for(only(SequenceOrdering::Ordered)));
+}
+
+pub fn test_loopback_pass_resets_run() {
+    info!("--- test_loopback_pass_resets_run ---");
+    let mut stats = RouteStats::new(now());
+    let threshold = loopback_failure_threshold(SequenceOrdering::Ordered);
+
+    for _ in 1..threshold {
+        stats.record_loopback_result(SequenceOrdering::Ordered, false, now());
+    }
+    let tally = stats.record_loopback_result(SequenceOrdering::Ordered, true, now());
+    // The pass reports the run it ended
+    assert_eq!(tally.streak, threshold - 1);
+    assert_eq!(tally.pass, 1);
+    assert!(!stats.is_dead_for_ordering(SequenceOrdering::Ordered));
+    assert!(!stats.needs_testing(only(SequenceOrdering::Ordered), now()));
+
+    // A fresh run starts from zero
+    let tally = stats.record_loopback_result(SequenceOrdering::Ordered, false, now());
+    assert_eq!(tally.streak, 1);
+    assert!(!stats.is_dead_for_ordering(SequenceOrdering::Ordered));
+}
+
+pub fn test_send_does_not_clear_loopback_run() {
+    info!("--- test_send_does_not_clear_loopback_run ---");
+    let mut stats = RouteStats::new(now());
+    let threshold = loopback_failure_threshold(SequenceOrdering::Ordered);
+
+    for _ in 1..threshold {
+        stats.record_loopback_result(SequenceOrdering::Ordered, false, now());
+        // Sending over the route is not evidence it works
+        stats.record_sent(SequenceOrdering::Ordered, now(), ByteCount::new(100));
+    }
+    stats.record_loopback_result(SequenceOrdering::Ordered, false, now());
+    assert!(stats.is_dead_for_ordering(SequenceOrdering::Ordered));
+}
+
+pub fn test_send_failure_death_does_not_blame_hops() {
+    info!("--- test_send_failure_death_does_not_blame_hops ---");
+    let mut stats = RouteStats::new(now());
+    stats.record_send_failed(SequenceOrdering::Ordered);
+    assert!(stats.is_dead_for(only(SequenceOrdering::Ordered)));
+    assert!(!stats.death_blames_hops_for(only(SequenceOrdering::Ordered)));
+
+    let mut stats = RouteStats::new(now());
+    for _ in 0..loopback_failure_threshold(SequenceOrdering::Ordered) {
+        stats.record_loopback_result(SequenceOrdering::Ordered, false, now());
+    }
+    assert!(stats.death_blames_hops_for(only(SequenceOrdering::Ordered)));
+    assert!(!stats.death_blames_hops_for(only(SequenceOrdering::Unordered)));
+}
+
+pub fn test_sequencing_narrows_to_route_orderings() {
+    info!("--- test_sequencing_narrows_to_route_orderings ---");
+    let ordered = only(SequenceOrdering::Ordered);
+    let unordered = only(SequenceOrdering::Unordered);
+
+    assert_eq!(
+        Sequencing::PreferUnordered.for_route_orderings(ordered),
+        Sequencing::PreferOrdered
+    );
+    assert_eq!(
+        Sequencing::PreferUnordered.for_route_orderings(unordered),
+        Sequencing::PreferUnordered
+    );
+    assert_eq!(
+        Sequencing::PreferOrdered.for_route_orderings(unordered),
+        Sequencing::PreferOrdered
+    );
+    assert_eq!(
+        Sequencing::EnsureOrdered.for_route_orderings(unordered),
+        Sequencing::EnsureOrdered
+    );
+
+    assert_eq!(
+        Sequencing::PreferUnordered.preferred_ordering(),
+        SequenceOrdering::Unordered
+    );
+    assert_eq!(
+        Sequencing::PreferOrdered.preferred_ordering(),
+        SequenceOrdering::Ordered
+    );
+    assert_eq!(
+        Sequencing::EnsureOrdered.preferred_ordering(),
+        SequenceOrdering::Ordered
+    );
+}
+
+pub fn test_all() {
+    test_send_failure_death_does_not_blame_hops();
+    test_loopback_failure_run_kills_ordering();
+    test_loopback_pass_resets_run();
+    test_send_does_not_clear_loopback_run();
+    test_sequencing_narrows_to_route_orderings();
+}

veilid-core/src/rpc_processor/destination.rs

@@ -542,8 +542,8 @@ impl RPCProcessor {
                     }
                 };
 
-                // Get the filtered noderef of the sender
-                let sender_noderef = detail.sender_noderef.clone();
+                // Answers go back over the flow the question arrived on
+                let sender_noderef = detail.sender_noderef.with_reply_flow(detail.flow);
                 NetworkResult::value(Destination::direct(sender_noderef, None))
             }
             RespondTo::PrivateRoute(pr) => {

veilid-core/src/rpc_processor/mod.rs

@@ -170,9 +170,12 @@ pub(crate) struct RPCProcessor {
     reply_pool: FutureRaceCompletionPool,
     /// The context for the startup of the RPC processor
     startup_context: RPCProcessorStartupContext,
+    /// Answers that arrived after the caller stopped waiting, by answer kind
+    #[cfg(feature = "stats")]
+    answers_after_waiter_dropped: Mutex<BTreeMap<&'static str, u64>>,
 }
 
-impl_veilid_component!(RPCProcessor, stats);
+impl_veilid_component!(RPCProcessor, stats, reset);
 
 impl RPCProcessor {
     fn new_inner() -> RPCProcessorInner {
@@ -229,6 +232,8 @@ impl RPCProcessor {
             queue_size,
             concurrency,
             startup_context,
+            #[cfg(feature = "stats")]
+            answers_after_waiter_dropped: Mutex::new(BTreeMap::new()),
         }
     }
 
@@ -258,6 +263,9 @@ impl RPCProcessor {
             .with_facility(
                 VeilidComponentLogFacility::try_new_with_tags("fanout", ["#fanout"]).unwrap(),
             )
+            .with_facility(
+                VeilidComponentLogFacility::try_new_with_tags("rpc::route", ["#verbose"]).unwrap(),
+            )
     }
 
     #[expect(clippy::unused_async)]
@@ -625,6 +633,11 @@ impl RPCProcessor {
         let timeout = waitable_reply.context.timeout;
         let handle = waitable_reply.handle;
         let registry = self.registry();
+        // Dropped with this future, so the pool can tell a late answer from a wanted one
+        #[cfg(feature = "stats")]
+        let caller_alive = Arc::new(());
+        #[cfg(feature = "stats")]
+        let caller_weak = Arc::downgrade(&caller_alive);
         let rx = self
             .reply_pool
             .channel_spawn(async move {
@@ -676,6 +689,13 @@ impl RPCProcessor {
                     Ok(TimeoutOr::Value((rpcreader, latency))) => {
                         // Reply received
                         let recv_ts = Timestamp::now_non_decreasing();
+                        veilid_stats!(if caller_weak.upgrade().is_none() {
+                            *this
+                                .answers_after_waiter_dropped
+                                .lock()
+                                .entry(rpcreader.operation.kind().desc())
+                                .or_default() += 1;
+                        });
 
                         // Record answer received
                         this.record_answer_received(
@@ -784,7 +804,6 @@ impl RPCProcessor {
         };
 
         // Compile the safety route with the private route
-        let sequencing = safety_selection.get_sequencing();
         let params = CompileRouteParams {
             safety_selection,
             private_route: remote_private_route,
@@ -794,6 +813,8 @@ impl RPCProcessor {
             network_result_try!(rss.compile_route(&params).await.to_rpc_network_result()?);
         let sr_is_stub = compiled_route.compiled_safety_route.is_stub();
         let sr_pubkey = compiled_route.compiled_safety_route.public_key.clone();
+        // Hops forward with this; a route that carries no datagram path is used ordered
+        let sequencing = compiled_route.sequencing;
 
         // Encrypt routed operation
         // Xmsg + ENC(Xmsg, DH(PKapr, SKbsr))
@@ -1044,7 +1065,7 @@ impl RPCProcessor {
                                 _ => (None, None),
                             };
 
-                            veilid_log!(rpc_processor debug target: "rpc_message", fields:
+                            veilid_log!(rpc_processor debug target: "rpc_message", msg: "rpc send route", fields:
                                 dir = "send",
                                 kind = "route",
                                 route_op_id,
@@ -1086,7 +1107,7 @@ impl RPCProcessor {
                         _ => (None, None),
                     };
 
-                    veilid_log!(rpc_processor debug target: "rpc_message", fields:
+                    veilid_log!(rpc_processor debug target: "rpc_message", msg: "rpc send route", fields:
                         dir = "send",
                         kind = "route",
                         route_op_id,
@@ -1232,7 +1253,13 @@ impl RPCProcessor {
         // defines broad failures. Direct sends are the unambiguous local-connectivity
         // signal; route stats carry routed failures.
         if let (Some(rd), Some(transport), false) = (opt_rd, opt_transport, is_routed) {
-            online_detector.record_failure(rd, vec![node_ref.best_node_id()], send_ts, transport);
+            online_detector.record_failure(
+                rd,
+                vec![node_ref.best_node_id()],
+                send_ts,
+                transport,
+                None,
+            );
         }
         let suppress_degradation = opt_rd.is_some_and(|rd| online_detector.blame_suppressed(rd));
         let transport_suppressed =
@@ -1293,6 +1320,16 @@ impl RPCProcessor {
             context.node_ref.best_routing_domain()
         };
 
+        // A question sent over a flow we did not dial (one that arrived inbound, possibly
+        // through a relay) says nothing about the peer or about us: drop that flow so the
+        // next contact dials per the contact method, and charge nothing
+        if !context.is_routed() && !context.send_data_result.dialed_evidence() {
+            if let Some(unique_flow) = context.send_data_result.unique_flow() {
+                context.node_ref.clear_last_flow(unique_flow.flow);
+            }
+            return;
+        }
+
         let network_manager = self.network_manager();
         let online_detector = network_manager.online_detector();
         // Routed losses are excluded from offline detection; see record_send_failure
@@ -1304,6 +1341,10 @@ impl RPCProcessor {
                         vec![context.node_ref.best_node_id()],
                         context.send_ts,
                         transport,
+                        context
+                            .send_data_result
+                            .unique_flow()
+                            .map(|uf| *uf.flow.remote_address()),
                     );
                 }
             }
@@ -1362,14 +1403,19 @@ impl RPCProcessor {
             // Trigger an out-of-band route test so silently-degraded routes
             // get released without waiting for the next regular cycle. The safety
             // route ref is always allocated, so use its set id directly.
-            let route_id: RouteId = sr.route_set_id().clone().into();
-            let cur_ts = Timestamp::now();
-            let enqueued = self
-                .routing_table()
-                .enqueue_route_tests(cur_ts, vec![route_id.clone()], 0)
-                .await;
-            if enqueued > 0 {
-                veilid_log!(self debug "scheduling out-of-band route test for {} after %SR timeout", route_id);
+            // A lost loopback is already the test; retesting from it just loops
+            let is_own_loopback = matches!(&context.destination,
+                Destination::PrivateRoute { private_route, .. } if private_route.public_key == *sr.route_key());
+            if !is_own_loopback {
+                let route_id: RouteId = sr.route_set_id().clone().into();
+                let cur_ts = Timestamp::now();
+                let enqueued = self
+                    .routing_table()
+                    .enqueue_route_tests(cur_ts, vec![route_id.clone()], 0)
+                    .await;
+                if enqueued > 0 {
+                    veilid_log!(self debug "scheduling out-of-band route test for {} after %SR timeout", route_id);
+                }
             }
         }
         // If remote private route was used, record question lost there
@@ -1769,7 +1815,7 @@ impl RPCProcessor {
         let signer = signing_params.as_ref().map(|x| x.signer_keypair.key());
 
         // Log rpc send
-        veilid_log!(self debug target: "rpc_message", fields: dir = "send", kind = "question", op_id = op_id.as_u64(), desc = operation.kind().desc(), ?dest, ?signer );
+        veilid_log!(self debug target: "rpc_message", msg: "rpc send question", fields: dir = "send", kind = "question", op_id = op_id.as_u64(), desc = operation.kind().desc(), ?dest, ?signer );
 
         // Produce rendered operation
         let rendered = Box::pin(
@@ -1935,7 +1981,7 @@ impl RPCProcessor {
         let signer = signing_params.as_ref().map(|x| x.signer_keypair.key());
 
         // Log rpc send
-        veilid_log!(self debug target: "rpc_message", fields: dir = "send", kind = "statement", ?route_op_id, op_id = operation.op_id().as_u64(), desc = operation.kind().desc(), ?dest, ?signer);
+        veilid_log!(self debug target: "rpc_message", msg: "rpc send statement", fields: dir = "send", kind = "statement", ?route_op_id, op_id = operation.op_id().as_u64(), desc = operation.kind().desc(), ?dest, ?signer);
 
         // Produce rendered operation
         let RenderedOperation {
@@ -2067,7 +2113,7 @@ impl RPCProcessor {
         let signer = signing_params.as_ref().map(|x| x.signer_keypair.key());
 
         // Log rpc send
-        veilid_log!(self debug target: "rpc_message", fields: dir = "send", kind = "answer", op_id = operation.op_id().as_u64(), desc = operation.kind().desc(), ?dest, ?signer);
+        veilid_log!(self debug target: "rpc_message", msg: "rpc send answer", fields: dir = "send", kind = "answer", op_id = operation.op_id().as_u64(), desc = operation.kind().desc(), ?dest, ?signer);
 
         // Produce rendered operation
         let RenderedOperation {
@@ -2417,19 +2463,19 @@ impl RPCProcessor {
                 self.record_question_received(&msg);
 
                 // Log rpc receive
-                veilid_log!(self debug target: "rpc_message", fields: dir = "recv", kind = "question", ?route_op_id, op_id = msg.operation.op_id().as_u64(), desc, header = ?msg.header, operation = ?msg.operation, signer = ?signer);
+                veilid_log!(self debug target: "rpc_message", msg: "rpc recv question", fields: dir = "recv", kind = "question", ?route_op_id, op_id = msg.operation.op_id().as_u64(), desc, header = ?msg.header, operation = ?msg.operation, signer = ?signer);
             }
             RPCOperationKind::Statement(_) => {
                 self.record_statement_received(&msg);
 
                 // Log rpc receive
-                veilid_log!(self debug target: "rpc_message", fields: dir = "recv", kind = "statement", ?route_op_id, op_id = msg.operation.op_id().as_u64(), desc, header = ?msg.header, operation = ?msg.operation, signer = ?signer);
+                veilid_log!(self debug target: "rpc_message", msg: "rpc recv statement", fields: dir = "recv", kind = "statement", ?route_op_id, op_id = msg.operation.op_id().as_u64(), desc, header = ?msg.header, operation = ?msg.operation, signer = ?signer);
             }
             RPCOperationKind::Answer(_) => {
                 // Answer stats are processed in wait_for_reply
 
                 // Log rpc receive
-                veilid_log!(self debug target: "rpc_message", fields: dir = "recv", kind = "answer", ?route_op_id, op_id = msg.operation.op_id().as_u64(), desc, header = ?msg.header, operation = ?msg.operation, signer = ?signer);
+                veilid_log!(self debug target: "rpc_message", msg: "rpc recv answer", fields: dir = "recv", kind = "answer", ?route_op_id, op_id = msg.operation.op_id().as_u64(), desc, header = ?msg.header, operation = ?msg.operation, signer = ?signer);
             }
         };
 

veilid-core/src/rpc_processor/rpc_route.rs

@@ -24,9 +24,11 @@ impl RPCProcessor {
         };
 
         // Apply sequencing preference and require routing domain to remain the same (for now)
+        let sequencing = routed_operation.sequencing();
         let next_hop_nr = next_hop_nr
-            .sequencing_filtered(routed_operation.sequencing())
+            .sequencing_filtered(sequencing)
             .with_routing_domain(RoutingDomain::PublicInternet);
+        let trace_nr = next_hop_nr.clone();
 
         // Pass along the route
         let next_hop_route = RPCOperationRoute::new(
@@ -40,7 +42,7 @@ impl RPCProcessor {
             RPCStatement::new(RPCStatementDetail::Route(Box::new(next_hop_route)));
 
         // Send the next route statement
-        Box::pin(
+        let res = Box::pin(
             self.statement(
                 Destination::direct(next_hop_nr, None),
                 next_hop_route_stmt,
@@ -51,7 +53,9 @@ impl RPCProcessor {
                 veilid_log!(self debug "process_route_safety_route_hop rpc_route stmt: {:#}", dur);
             }),
         )
-        .await
+        .await;
+        self.trace_route_hop_forward("sr", route_op_id, &trace_nr, sequencing, &res);
+        res
     }
 
     #[cfg_attr(
@@ -76,9 +80,11 @@ impl RPCProcessor {
         };
 
         // Apply sequencing preference and require routing domain to be PublicInternet for now
+        let sequencing = routed_operation.sequencing();
         let next_hop_nr = next_hop_nr
-            .sequencing_filtered(routed_operation.sequencing())
+            .sequencing_filtered(sequencing)
             .with_routing_domain(RoutingDomain::PublicInternet);
+        let trace_nr = next_hop_nr.clone();
 
         // Pass along the route
         let next_hop_route = RPCOperationRoute::new(
@@ -92,7 +98,7 @@ impl RPCProcessor {
             RPCStatement::new(RPCStatementDetail::Route(Box::new(next_hop_route)));
 
         // Send the next route statement
-        Box::pin(
+        let res = Box::pin(
             self.statement(
                 Destination::direct(next_hop_nr, None),
                 next_hop_route_stmt,
@@ -103,7 +109,29 @@ impl RPCProcessor {
                 veilid_log!(self debug "process_route_private_route_hop rpc_route stmt: {:#}", dur);
             }),
         )
-        .await
+        .await;
+        self.trace_route_hop_forward("pr", route_op_id, &trace_nr, sequencing, &res);
+        res
+    }
+
+    /// One opt-in line per forwarded hop so a routed op can be followed across nodes
+    fn trace_route_hop_forward(
+        &self,
+        leg: &str,
+        route_op_id: OperationId,
+        next_hop_nr: &FilteredNodeRef,
+        sequencing: Sequencing,
+        res: &RPCNetworkResult<()>,
+    ) {
+        let outcome = match res {
+            Ok(nr) => format!("{:?}", nr),
+            Err(e) => format!("Err({})", e),
+        };
+        let flow = next_hop_nr
+            .last_flow()
+            .map(|f| format!("{:#}", f))
+            .unwrap_or_else(|| "none".to_owned());
+        veilid_log!(self debug target: "rpc::route", "route hop fwd {} op={:#} next={} seq={:#} -> {} flow={}", leg, route_op_id, next_hop_nr.best_node_id(), sequencing, outcome, flow);
     }
 
     /// Process a routed operation that came in over a safety route but no private route
@@ -149,6 +177,8 @@ impl RPCProcessor {
             }
         };
 
+        veilid_log!(self debug target: "rpc::route", "route op terminated op={:#} sr={} pr=stub", route_op_id, remote_sr_pubkey);
+
         // Pass message to RPC system
         self.enqueue_safety_routed_message(
             detail,
@@ -224,6 +254,8 @@ impl RPCProcessor {
             ));
         };
 
+        veilid_log!(self debug target: "rpc::route", "route op terminated op={:#} sr={} pr={}", route_op_id, remote_sr_pubkey, pr_pubkey);
+
         // Pass message to RPC system
         self.enqueue_private_routed_message(
             detail,

veilid-core/src/rpc_processor/stats.rs

@@ -2,10 +2,24 @@ use super::*;
 
 #[derive(Debug, Serialize)]
 pub(super) struct RPCProcessorStats {
+    /// Time a message waits for a worker
     worker_dequeue_latency: LatencyStats,
+    /// Time a worker spends on a message
     worker_process_latency: LatencyStats,
+    /// Messages waiting for a worker
     queue_depth: u32,
+    /// Processing count and latency per operation kind
     process_by_kind: Vec<RPCKindStats>,
+    /// Answers that landed after the caller stopped waiting, by kind, since `stats reset`
+    answers_after_waiter_dropped: Vec<RPCKindCount>,
+}
+
+#[derive(Debug, Serialize)]
+pub(super) struct RPCKindCount {
+    /// Operation kind name
+    kind: String,
+    /// Occurrences
+    count: u64,
 }
 
 #[derive(Debug, Serialize)]
@@ -16,6 +30,10 @@ pub(super) struct RPCKindStats {
 }
 
 impl RPCProcessor {
+    pub(super) fn reset_stats_impl(&self) {
+        self.answers_after_waiter_dropped.lock().clear();
+    }
+
     pub(super) fn stats_impl(&self) -> Option<Box<dyn VeilidComponentStats>> {
         let inner = self.inner.lock();
         Some(Box::new(RPCProcessorStats {
@@ -41,6 +59,15 @@ impl RPCProcessor {
                     latency: acc.latency_stats().unwrap_or_default(),
                 })
                 .collect(),
+            answers_after_waiter_dropped: self
+                .answers_after_waiter_dropped
+                .lock()
+                .iter()
+                .map(|(kind, count)| RPCKindCount {
+                    kind: (*kind).to_string(),
+                    count: *count,
+                })
+                .collect(),
         }))
     }
 }

veilid-core/src/stats_manager/mod.rs

@@ -171,9 +171,10 @@ impl StatsManager {
         }
     }
 
-    /// Start a fresh collection window.
+    /// Start a fresh collection window and zero the cumulative counters.
     #[cfg(feature = "debug-api")]
     pub(crate) fn reset(&self) {
+        self.registry().reset_component_stats();
         self.inner.lock().since_ts = Timestamp::now();
     }
 

veilid-core/src/storage_manager/constants.rs

@@ -1,5 +1,8 @@
 use super::*;
 
+/// How often End re-checks for in-flight Sets to settle
+pub(super) const END_QUIESCENCE_POLL_MS: u32 = 50;
+
 /// Frequency to flush record stores to disk
 pub const FLUSH_RECORD_STORES_INTERVAL_SECS: u32 = 1;
 /// Frequency to save metadata to disk

veilid-core/src/storage_manager/gated_operation.rs

@@ -12,8 +12,6 @@
 //! budget. The initial budget is sized so the byte gate cannot bind while
 //! the concurrency cap does; only a congestion-driven decrease makes it
 //! bind, so a healthy network sees no behavior change at all.
-#[cfg(feature = "stats")]
-use super::gated_operation_accounting::*;
 use super::transaction_command::OutboundTransactCommandResult;
 #[cfg(any(feature = "aimd-dht", feature = "stats"))]
 use super::transaction_command::TransactCommandDisposition;
@@ -146,7 +144,9 @@ fn transact_result_congested(result: &OutboundTransactCommandResult) -> bool {
         match pnr.disposition {
             TransactCommandDisposition::Valid => valid_total += 1,
             TransactCommandDisposition::Invalid => {}
-            TransactCommandDisposition::Skipped => skipped += 1,
+            TransactCommandDisposition::Skipped | TransactCommandDisposition::Pending => {
+                skipped += 1
+            }
         }
     }
     transact_counts_congested(

veilid-core/src/storage_manager/mod.rs

@@ -1,3 +1,11 @@
+// Count a TryAgain by reason, then bail with it
+macro_rules! tx_try_again {
+    ($self:expr, $reason:ident, $($arg:tt)*) => {{
+        veilid_stats!($self.transaction_quality().lock().try_again(TryAgainReason::$reason));
+        apibail_try_again!($($arg)*);
+    }};
+}
+
 mod close_record;
 mod constants;
 mod create_record;
@@ -6,8 +14,6 @@ mod debug;
 mod delete_record;
 mod flush_record;
 mod gated_operation;
-#[cfg(feature = "stats")]
-mod gated_operation_accounting;
 mod get_value;
 mod inspect_record;
 mod local_record_detail;
@@ -46,13 +52,10 @@ pub mod tests_storage_manager;
 use super::*;
 
 use hashlink::{LinkedHashMap, LruCache};
-use std::sync::atomic::{AtomicU64, AtomicUsize};
 
 use crate::network_manager::OnlineState;
 use constants::*;
 use gated_operation::*;
-#[cfg(feature = "stats")]
-use gated_operation_accounting::*;
 use inspect_record::{InspectFanoutStop, OutboundInspectValueResult};
 use local_record_detail::*;
 use offline_subkey_writes::*;
@@ -64,6 +67,8 @@ use rehydrate::*;
 use remote_record_detail::*;
 use routing_table::*;
 use rpc_processor::*;
+#[cfg(feature = "stats")]
+use stats::*;
 use stop_token::future::FutureExt as _;
 use storage_manager_locks::*;
 
@@ -218,6 +223,10 @@ pub(crate) struct StorageManager {
     // Per-kind gate wait/hold telemetry
     #[cfg(feature = "stats")]
     gate_accounting: Arc<Mutex<GatedOperationAccounting>>,
+    // Transaction quality counters, shared with the outbound transaction manager.
+    // A leaf lock: never held while taking any other lock.
+    #[cfg(feature = "stats")]
+    transaction_quality: Arc<Mutex<TransactionQualityAccounting>>,
 }
 
 impl fmt::Debug for StorageManager {
@@ -237,7 +246,7 @@ impl fmt::Debug for StorageManager {
     }
 }
 
-impl_veilid_component!(StorageManager, stats);
+impl_veilid_component!(StorageManager, stats, reset);
 
 impl StorageManager {
     pub fn new(registry: VeilidComponentRegistry) -> StorageManager {
@@ -257,6 +266,10 @@ impl StorageManager {
             (registry.config().network.dht.max_concurrent_operations as usize).max(1),
         ));
 
+        let outbound_transaction_manager = OutboundTransactionManager::new(registry.clone());
+        #[cfg(feature = "stats")]
+        let transaction_quality = outbound_transaction_manager.transaction_quality().clone();
+
         let this = StorageManager {
             inner: StatsMutex::new(
                 StorageManagerInner {
@@ -267,7 +280,7 @@ impl StorageManager {
                     offline_subkey_writes: Default::default(),
                     rehydration_requests: Default::default(),
                     flush_record_waiters: Default::default(),
-                    outbound_transaction_manager: OutboundTransactionManager::new(registry.clone()),
+                    outbound_transaction_manager,
                     metadata_db: Default::default(),
                     routing_domain_ready_subscription: None,
                     online_state_change_subscription: None,
@@ -327,6 +340,8 @@ impl StorageManager {
             gate_active: Arc::new(AtomicUsize::new(0)),
             #[cfg(feature = "stats")]
             gate_accounting: Arc::new(Mutex::new(GatedOperationAccounting::default())),
+            #[cfg(feature = "stats")]
+            transaction_quality,
         };
 
         this.setup_tasks();
@@ -334,6 +349,11 @@ impl StorageManager {
         this
     }
 
+    #[cfg(feature = "stats")]
+    fn transaction_quality(&self) -> &Arc<Mutex<TransactionQualityAccounting>> {
+        &self.transaction_quality
+    }
+
     pub(crate) fn local_limits_from_config(c: Arc<VeilidConfig>) -> RecordStoreLimits {
         RecordStoreLimits {
             subkey_cache_size: c.network.dht.local_subkey_cache_size as usize,

veilid-core/src/storage_manager/outbound_transaction_manager/mod.rs

@@ -56,6 +56,22 @@ pub(in crate::storage_manager) struct AddNodeTransactionParams {
     pub begin_seqs: Vec<ValueSeqNum>,
 }
 
+/// What End will do: End goes to the voters, the non-voters roll back, the
+/// completion pass re-sends missing subkeys, and a short plan waits or fails
+#[derive(Default)]
+pub(in crate::storage_manager) struct TransactEndPlan {
+    /// One End command per record, to its voters
+    pub end_params: Vec<Arc<OutboundTransactCommandParams>>,
+    /// One single-node Set per missing subkey
+    pub completion_params: Vec<Arc<OutboundTransactCommandParams>>,
+    /// Begin nodes that will not vote
+    pub non_voters: LocalNodeTransactionIdSet,
+    /// Set questions still in flight across Begin nodes
+    pub outstanding: usize,
+    /// Some record has fewer voters than required
+    pub short: bool,
+}
+
 #[derive(Debug, Clone)]
 struct LocalNodeTransactionMapping {
     transaction_handle: OutboundTransactionHandle,
@@ -81,6 +97,9 @@ pub(in crate::storage_manager) struct OutboundTransactionManager {
     opt_keepalive_processor: Option<Arc<OutboundTransactionKeepaliveProcessor>>,
     /// Runs a `TerminalDelivery` in the background
     opt_terminal_delivery_spawner: Option<Box<dyn Fn(terminal_delivery::TerminalDelivery) + Send>>,
+    /// Transaction quality counters, a leaf lock shared with the storage manager
+    #[cfg(feature = "stats")]
+    quality: Arc<Mutex<TransactionQualityAccounting>>,
 }
 
 impl fmt::Debug for OutboundTransactionManager {
@@ -136,9 +155,16 @@ impl OutboundTransactionManager {
             next_lnxid: 1_000_000_000u64,
             opt_keepalive_processor: None,
             opt_terminal_delivery_spawner: None,
+            #[cfg(feature = "stats")]
+            quality: Arc::new(Mutex::new(TransactionQualityAccounting::default())),
         }
     }
 
+    #[cfg(feature = "stats")]
+    pub fn transaction_quality(&self) -> &Arc<Mutex<TransactionQualityAccounting>> {
+        &self.quality
+    }
+
     pub fn init(&mut self) {
         let cur_ts = Timestamp::now();
         let routing_table = self.routing_table();
@@ -185,7 +211,7 @@ impl OutboundTransactionManager {
                 if self.next_txid == start_txid {
                     // This should basically never happen, but logic is here for completeness
                     veilid_log!(self debugwarn "no free transaction handles available, wrapped around to start_txid={}", start_txid);
-                    apibail_try_again!("no free transaction handles available");
+                    tx_try_again!(self, Handles, "no free transaction handles available");
                 }
                 // Iterate and try again with the next txid
             } else {
@@ -206,7 +232,11 @@ impl OutboundTransactionManager {
                 if self.next_lnxid == start_lnxid {
                     // This should basically never happen, but logic is here for completeness
                     veilid_log!(self debugwarn "no free local node transaction ids available, wrapped around to start_lnxid={}", start_lnxid);
-                    apibail_try_again!("no free local node transaction ids available");
+                    tx_try_again!(
+                        self,
+                        Handles,
+                        "no free local node transaction ids available"
+                    );
                 }
                 // Iterate and try again with the next lnxid
             } else {
@@ -294,6 +324,7 @@ impl OutboundTransactionManager {
         // Done here so that it happens in the OTM inside the StorageManager inner lock,
         // along with the rest of the node transaction addition, to reduce the risk of race conditions with the keepalive processor.
         if let Some(keepalive_processor) = &self.opt_keepalive_processor {
+            veilid_stats!(self.quality.lock().mitigations.keepalives_registered += 1);
             keepalive_processor.register(
                 OutboundTransactionKeepaliveParams {
                     lnxid,
@@ -605,6 +636,7 @@ impl OutboundTransactionManager {
                         "terminal delivery scheduled: {:?} xid={} node={} record={} stage={:?}",
                         command, node_transaction.rnxid(), node_transaction.node_ref(),
                         record_state.record_key().opaque(), node_transaction.stage());
+                    veilid_stats!(self.quality.lock().mitigations.terminal_delivery_scheduled += 1);
                     spawner(terminal_delivery::TerminalDelivery {
                         opaque_record_key: record_state.record_key().opaque(),
                         rnxid: node_transaction.rnxid().clone(),
@@ -742,6 +774,9 @@ impl OutboundTransactionManager {
         let required_strict_consensus_count =
             self.config().internal().network.dht.set_value_count as usize;
 
+        #[cfg(feature = "stats")]
+        let quality = self.quality.clone();
+
         // Add all node transaction ids
         // Each record must still be in Init state (no node_transactions yet) when being recorded
         for result in results {
@@ -775,12 +810,17 @@ impl OutboundTransactionManager {
                     record_state
                 );
 
-                apibail_try_again!("did not get consensus of transaction ids in begin (rec={}, count={}, required_consensus={})",
+                tx_try_again!(self, BeginConsensus, "did not get consensus of transaction ids in begin (rec={}, count={}, required_consensus={})",
                     opaque_record_key,
                     node_transaction_count,
                     required_strict_consensus_count
                 );
             }
+            veilid_stats!({
+                let mut q = quality.lock();
+                q.node_sets.records += 1;
+                q.node_sets.begin_nodes += node_transaction_count as u64;
+            });
 
             // Update record state with results
             record_state.update_descriptor(result.descriptor)?;
@@ -864,12 +904,19 @@ impl OutboundTransactionManager {
                     continue;
                 }
                 TransactCommandDisposition::Skipped => {
-                    // Node was not waited for due to early consensus exit, leave its stage unchanged
+                    // No answer within the wait, leave its stage unchanged
                     #[cfg(feature = "verbose-tracing")]
-                    veilid_log!(node_transaction debug target: "dht", "transact_command_result: lnxid={} rndid={} SKIPPED (no response/early exit) record={} stage={:?}",
+                    veilid_log!(node_transaction debug target: "dht", "transact_command_result: lnxid={} rndid={} SKIPPED (no response) record={} stage={:?}",
                         pnr.lnxid, pnr.rnxid, result.params.opaque_record_key, node_transaction.stage());
                     continue;
                 }
+                TransactCommandDisposition::Pending => {
+                    // Answer still on its way; the node stays non-quiescent until it lands
+                    if result.params.command == TransactCommand::Set {
+                        node_transaction.add_outstanding_set();
+                    }
+                    continue;
+                }
                 TransactCommandDisposition::Valid => {
                     // Refresh the per-node RTT from this successful response
                     if let Some(rtt) = pnr.opt_rtt {
@@ -951,6 +998,7 @@ impl OutboundTransactionManager {
 
             let safety_selection = record_state.safety_selection().clone();
             let nodes = record_state.get_transact_command_nodes(Some(record_rollback_ids), None)?;
+            veilid_stats!(self.quality.lock().node_sets.rollback_sent_nodes += nodes.len() as u64);
 
             out.push(Arc::new(OutboundTransactCommandParams {
                 opaque_record_key,
@@ -1000,11 +1048,12 @@ impl OutboundTransactionManager {
         Ok(())
     }
 
-    /// Prepare to end a transaction
-    pub fn prepare_transact_end_params(
+    /// Plan End: per record, which Begin nodes may vote, which need a completion
+    /// pass, and whether any record is short of voters
+    pub fn plan_transact_end(
         &self,
         transaction_handle: OutboundTransactionHandle,
-    ) -> VeilidAPIResult<Vec<Arc<OutboundTransactCommandParams>>> {
+    ) -> VeilidAPIResult<TransactEndPlan> {
         // Get transaction
         let outbound_transaction_state = self.get_transaction_state(transaction_handle)?;
 
@@ -1016,7 +1065,11 @@ impl OutboundTransactionManager {
         match stage {
             OutboundTransactionStage::Begin => {}
             OutboundTransactionStage::Failed => {
-                apibail_try_again!("transaction stage was Failed, wanted Begin; try again");
+                tx_try_again!(
+                    self,
+                    StageFailed,
+                    "transaction stage was Failed, wanted Begin; try again"
+                );
             }
             OutboundTransactionStage::End
             | OutboundTransactionStage::Rollback
@@ -1025,31 +1078,98 @@ impl OutboundTransactionManager {
             }
         }
 
-        let mut out = vec![];
-
-        let mut unregister_keepalive_lnxids = LocalNodeTransactionIdSet::new();
+        let mut plan = TransactEndPlan::default();
 
         for record_state in outbound_transaction_state.get_record_states() {
             let opaque_record_key = record_state.record_key().opaque();
             let safety_selection = record_state.safety_selection().clone();
-            let nodes = record_state.get_transact_command_nodes(None, None)?;
             let required_strict_consensus_count = record_state.required_strict_consensus_count();
+            let desired = record_state.desired_subkeys();
+            let selection = select_end_voters(
+                &record_state.end_candidates(),
+                &desired,
+                required_strict_consensus_count,
+            );
+            plan.outstanding += selection.outstanding as usize;
+            plan.short |= selection.short;
+            // Exactly the minimum cannot lose an End answer; a spare comes from a
+            // completion pass or from a Set still in flight, so wait for either
+            plan.short |= selection.voters.len() <= required_strict_consensus_count
+                && (!selection.completion.is_empty() || selection.outstanding > 0);
 
-            for node in &nodes {
-                unregister_keepalive_lnxids.insert(node.lnxid);
+            for (lnxid, missing) in &selection.completion {
+                let nodes = record_state.get_transact_command_nodes(
+                    Some(LocalNodeTransactionIdSet::from([*lnxid])),
+                    None,
+                )?;
+                for subkey in missing {
+                    let Some(value) = record_state.desired_subkey_value(*subkey) else {
+                        apibail_internal!("missing desired value for subkey {}", subkey);
+                    };
+                    plan.completion_params
+                        .push(Arc::new(OutboundTransactCommandParams {
+                            opaque_record_key: opaque_record_key.clone(),
+                            safety_selection: safety_selection.clone(),
+                            nodes: nodes.clone(),
+                            command: TransactCommand::Set,
+                            opt_seqs: None,
+                            opt_subkey: Some(*subkey),
+                            opt_value: Some(value),
+                            required_strict_consensus_count: 1,
+                            pre_authorized_valid_count: 0,
+                        }));
+                }
             }
 
-            out.push(Arc::new(OutboundTransactCommandParams {
-                opaque_record_key,
-                safety_selection,
-                nodes,
-                command: TransactCommand::End,
-                opt_seqs: None,
-                opt_subkey: None,
-                opt_value: None,
-                required_strict_consensus_count,
-                pre_authorized_valid_count: 0,
-            }));
+            let voters: LocalNodeTransactionIdSet = selection.voters.iter().copied().collect();
+            for (lnxid, nt) in record_state.get_node_transactions() {
+                if nt.stage() == OutboundTransactionStage::Begin && !voters.contains(lnxid) {
+                    plan.non_voters.insert(*lnxid);
+                }
+            }
+            let nodes = record_state.get_transact_command_nodes(Some(voters), None)?;
+
+            veilid_stats!({
+                let mut q = self.quality.lock();
+                q.node_sets.end_sent_nodes += nodes.len() as u64;
+                q.end_coverage.nodes_sent_end += nodes.len() as u64;
+            });
+
+            plan.end_params
+                .push(Arc::new(OutboundTransactCommandParams {
+                    opaque_record_key,
+                    safety_selection,
+                    nodes,
+                    command: TransactCommand::End,
+                    opt_seqs: None,
+                    opt_subkey: None,
+                    opt_value: None,
+                    required_strict_consensus_count,
+                    pre_authorized_valid_count: 0,
+                }));
+        }
+
+        Ok(plan)
+    }
+
+    /// Commit to an End plan: the non-voters leave the transaction and every
+    /// keepalive stops. A non-voter is marked Failed, not Rollback: Failed never
+    /// competes with the voters' stage, and the rollback guard rolls Failed nodes
+    /// back and drops them once End is recorded.
+    pub fn commit_end_plan(
+        &mut self,
+        transaction_handle: OutboundTransactionHandle,
+        non_voters: &LocalNodeTransactionIdSet,
+    ) -> VeilidAPIResult<()> {
+        let outbound_transaction_state = self.get_transaction_state_mut(transaction_handle)?;
+        let mut unregister_keepalive_lnxids = LocalNodeTransactionIdSet::new();
+        for record_state in outbound_transaction_state.get_record_states_mut() {
+            unregister_keepalive_lnxids.extend(record_state.get_node_transaction_ids());
+            for (lnxid, nt) in record_state.get_node_transactions_mut() {
+                if non_voters.contains(lnxid) {
+                    nt.set_stage(OutboundTransactionStage::Failed, None);
+                }
+            }
         }
 
         // Cancel all scheduled keepalives
@@ -1059,7 +1179,101 @@ impl OutboundTransactionManager {
             }
         }
 
-        Ok(out)
+        Ok(())
+    }
+
+    /// Record the completion pass: each result is one Set to one node
+    pub fn record_transact_completion_results(
+        &mut self,
+        transaction_handle: OutboundTransactionHandle,
+        results: Vec<OutboundTransactCommandResult>,
+    ) -> VeilidAPIResult<()> {
+        let opt_keepalive_processor = self.opt_keepalive_processor.clone();
+        let outbound_transaction_state = self.get_transaction_state_mut(transaction_handle)?;
+        for result in results {
+            let Some(record_state) =
+                outbound_transaction_state.get_record_state_mut(&result.params.opaque_record_key)
+            else {
+                apibail_internal!("missing record: {}", result.params.opaque_record_key);
+            };
+            let subkey = result.params.opt_subkey.unwrap_or_log();
+            let value = result.params.opt_value.clone().unwrap_or_log();
+            for pnr in result.per_node_results {
+                let Some(nt) = record_state.get_node_transaction_mut(pnr.lnxid) else {
+                    apibail_internal!("missing node transaction {}", pnr.lnxid);
+                };
+                match pnr.disposition {
+                    TransactCommandDisposition::Valid => {
+                        Self::refresh_keepalive(&opt_keepalive_processor, &pnr);
+                        nt.record_set_answer(subkey, &value, pnr)
+                    }
+                    TransactCommandDisposition::Invalid => {
+                        nt.set_stage(OutboundTransactionStage::Rollback, None);
+                    }
+                    // Not retried: a node that cannot complete does not vote
+                    TransactCommandDisposition::Skipped | TransactCommandDisposition::Pending => {
+                        nt.set_stage(OutboundTransactionStage::Failed, None);
+                    }
+                }
+            }
+        }
+        Ok(())
+    }
+
+    /// A command answer carries the node's new expiration; the keepalive train
+    /// then has nothing to do until that runs down
+    fn refresh_keepalive(
+        opt_keepalive_processor: &Option<Arc<OutboundTransactionKeepaliveProcessor>>,
+        pnr: &OutboundTransactCommandPerNodeResult,
+    ) {
+        if let (Some(kp), Some(expiration)) = (opt_keepalive_processor, pnr.opt_expiration) {
+            kp.refresh(pnr.lnxid, expiration, pnr.opt_rtt);
+        }
+    }
+
+    /// A Set answer collected after its command returned. The transaction may be
+    /// gone already; then there is nothing to record.
+    pub fn record_late_transact_set_result(
+        &mut self,
+        lnxid: LocalNodeTransactionId,
+        subkey: ValueSubkey,
+        value: &Arc<SignedValueData>,
+        opt_pnr: Option<OutboundTransactCommandPerNodeResult>,
+    ) {
+        #[cfg(feature = "stats")]
+        let quality = self.quality.clone();
+        let opt_keepalive_processor = self.opt_keepalive_processor.clone();
+        let Some(mapping) = self.local_node_transaction_mappings.get(&lnxid).cloned() else {
+            return;
+        };
+        let Some(record_state) =
+            self.get_transaction_record_state_mut_by_lnxid(mapping.transaction_handle, lnxid)
+        else {
+            return;
+        };
+        let Some(nt) = record_state.get_node_transaction_mut(lnxid) else {
+            return;
+        };
+        nt.finish_outstanding_set();
+        let Some(pnr) = opt_pnr else {
+            return;
+        };
+        match pnr.disposition {
+            TransactCommandDisposition::Valid => {
+                veilid_stats!(quality
+                    .lock()
+                    .record_collected(TransactionCommandKind::Set, LateAnswer::Valid));
+                Self::refresh_keepalive(&opt_keepalive_processor, &pnr);
+                nt.record_set_answer(subkey, value, pnr);
+            }
+            TransactCommandDisposition::Invalid => {
+                veilid_stats!(quality
+                    .lock()
+                    .record_collected(TransactionCommandKind::Set, LateAnswer::Invalid));
+                nt.set_stage(OutboundTransactionStage::Rollback, None);
+            }
+            TransactCommandDisposition::Skipped | TransactCommandDisposition::Pending => {}
+        }
     }
 
     /// Record end transaction
@@ -1068,6 +1282,9 @@ impl OutboundTransactionManager {
         transaction_handle: OutboundTransactionHandle,
         results: Vec<OutboundTransactCommandResult>,
     ) -> VeilidAPIResult<()> {
+        #[cfg(feature = "stats")]
+        let quality = self.quality.clone();
+
         // Get transaction
         let outbound_transaction_state = self.get_transaction_state_mut(transaction_handle)?;
 
@@ -1079,7 +1296,11 @@ impl OutboundTransactionManager {
         match stage {
             OutboundTransactionStage::Begin => {}
             OutboundTransactionStage::Failed => {
-                apibail_try_again!("transaction stage was Failed, wanted Begin; try again");
+                tx_try_again!(
+                    self,
+                    StageFailed,
+                    "transaction stage was Failed, wanted Begin; try again"
+                );
             }
             OutboundTransactionStage::End
             | OutboundTransactionStage::Rollback
@@ -1088,6 +1309,10 @@ impl OutboundTransactionManager {
             }
         }
 
+        veilid_stats!(
+            quality.lock().node_sets.end_valid_nodes += Self::count_valid_results(&results)
+        );
+
         // Record results
         Self::record_transact_command_results(
             outbound_transaction_state,
@@ -1102,9 +1327,35 @@ impl OutboundTransactionManager {
             ) as OutboundTransactionPerNodeResultHandler,
         )?;
 
+        veilid_stats!({
+            let mut q = quality.lock();
+            for record_state in outbound_transaction_state.get_record_states() {
+                let coverage = record_state.stage_subkey_coverage(OutboundTransactionStage::End);
+                q.record_end_coverage(coverage, record_state.required_strict_consensus_count());
+            }
+        });
+
         Ok(())
     }
 
+    #[cfg(feature = "stats")]
+    fn count_valid_results(results: &[OutboundTransactCommandResult]) -> u64 {
+        results
+            .iter()
+            .flat_map(|r| r.per_node_results.iter())
+            .filter(|pnr| pnr.disposition == TransactCommandDisposition::Valid)
+            .count() as u64
+    }
+
+    #[cfg(feature = "stats")]
+    fn count_invalid_results(results: &[OutboundTransactCommandResult]) -> u64 {
+        results
+            .iter()
+            .flat_map(|r| r.per_node_results.iter())
+            .filter(|pnr| pnr.disposition == TransactCommandDisposition::Invalid)
+            .count() as u64
+    }
+
     /// Prepare to commit a transaction
     pub fn prepare_transact_commit_params(
         &self,
@@ -1121,7 +1372,11 @@ impl OutboundTransactionManager {
         match stage {
             OutboundTransactionStage::End => {}
             OutboundTransactionStage::Failed => {
-                apibail_try_again!("transaction stage was Failed, wanted End; try again");
+                tx_try_again!(
+                    self,
+                    StageFailed,
+                    "transaction stage was Failed, wanted End; try again"
+                );
             }
             OutboundTransactionStage::Begin
             | OutboundTransactionStage::Rollback
@@ -1155,6 +1410,11 @@ impl OutboundTransactionManager {
                 pre_authorized_valid_count,
                 record_state.get_node_transactions_count());
             let required_strict_consensus_count = record_state.required_strict_consensus_count();
+            veilid_stats!({
+                let mut q = self.quality.lock();
+                q.node_sets.commit_sent_nodes += nodes.len() as u64;
+                q.commit_coverage.pre_authorized_nodes += pre_authorized_valid_count as u64;
+            });
 
             out.push(Arc::new(OutboundTransactCommandParams {
                 opaque_record_key,
@@ -1178,6 +1438,9 @@ impl OutboundTransactionManager {
         transaction_handle: OutboundTransactionHandle,
         results: Vec<OutboundTransactCommandResult>,
     ) -> VeilidAPIResult<()> {
+        #[cfg(feature = "stats")]
+        let quality = self.quality.clone();
+
         // Get transaction
         let outbound_transaction_state = self.get_transaction_state_mut(transaction_handle)?;
 
@@ -1189,7 +1452,11 @@ impl OutboundTransactionManager {
         match stage {
             OutboundTransactionStage::End => {}
             OutboundTransactionStage::Failed => {
-                apibail_try_again!("transaction stage was Failed, wanted End; try again");
+                tx_try_again!(
+                    self,
+                    StageFailed,
+                    "transaction stage was Failed, wanted End; try again"
+                );
             }
             OutboundTransactionStage::Begin
             | OutboundTransactionStage::Rollback
@@ -1198,6 +1465,12 @@ impl OutboundTransactionManager {
             }
         }
 
+        veilid_stats!({
+            let mut q = quality.lock();
+            q.node_sets.commit_valid_nodes += Self::count_valid_results(&results);
+            q.commit_coverage.commit_refusals += Self::count_invalid_results(&results);
+        });
+
         // For all node transactions where commit commands were not required,
         // transition them directly to the commit state.
         for record_state in outbound_transaction_state.get_record_states_mut() {
@@ -1223,6 +1496,35 @@ impl OutboundTransactionManager {
             ) as OutboundTransactionPerNodeResultHandler,
         )?;
 
+        // Below the per-subkey minimum the app retries instead of hearing Ok
+        let mut opt_short = None;
+        for record_state in outbound_transaction_state.get_record_states() {
+            let required = record_state.required_strict_consensus_count();
+            if let Some(coverage) = record_state
+                .stage_subkey_coverage(OutboundTransactionStage::Commit)
+                .filter(|c| *c < required)
+            {
+                veilid_stats!(
+                    quality
+                        .lock()
+                        .commit_coverage
+                        .records_below_required_coverage += 1
+                );
+                opt_short = Some((record_state.record_key().opaque(), coverage, required));
+                break;
+            }
+        }
+        if let Some((opaque_record_key, coverage, required)) = opt_short {
+            tx_try_again!(
+                self,
+                CommitConsensus,
+                "commit held by {} of {} required nodes for record {}",
+                coverage,
+                required,
+                opaque_record_key
+            );
+        }
+
         Ok(())
     }
 
@@ -1245,7 +1547,11 @@ impl OutboundTransactionManager {
         match stage {
             OutboundTransactionStage::Begin => {}
             OutboundTransactionStage::Failed => {
-                apibail_try_again!("transaction stage was Failed, wanted Begin; try again");
+                tx_try_again!(
+                    self,
+                    StageFailed,
+                    "transaction stage was Failed, wanted Begin; try again"
+                );
             }
             OutboundTransactionStage::End
             | OutboundTransactionStage::Rollback
@@ -1302,6 +1608,7 @@ impl OutboundTransactionManager {
         transaction_handle: OutboundTransactionHandle,
         result: OutboundTransactCommandResult,
     ) -> VeilidAPIResult<()> {
+        let opt_keepalive_processor = self.opt_keepalive_processor.clone();
         // Get transaction
         let outbound_transaction_state = self.get_transaction_state_mut(transaction_handle)?;
 
@@ -1313,7 +1620,11 @@ impl OutboundTransactionManager {
         match stage {
             OutboundTransactionStage::Begin => {}
             OutboundTransactionStage::Failed => {
-                apibail_try_again!("transaction stage was Failed, wanted Begin; try again");
+                tx_try_again!(
+                    self,
+                    StageFailed,
+                    "transaction stage was Failed, wanted Begin; try again"
+                );
             }
             OutboundTransactionStage::End
             | OutboundTransactionStage::Rollback
@@ -1344,6 +1655,8 @@ impl OutboundTransactionManager {
                 // Check if node id transactions reached consensus
 
                 node_transaction.update_expiration(pnr.opt_expiration);
+                node_transaction.confirm_subkey(subkey);
+                Self::refresh_keepalive(&opt_keepalive_processor, &pnr);
 
                 // Record subkey write
                 let opt_value = if let Some(newer_value) = pnr.opt_value {
@@ -1422,9 +1735,12 @@ impl OutboundTransactionManager {
                 record_state.record_key().opaque(), subkey, found_newer);
             record_state.updated_consensus_mut().record(subkey, None);
             record_state.current_consensus_mut().record(subkey, None);
-            apibail_try_again!(
+            let opaque_record_key = record_state.record_key().opaque();
+            tx_try_again!(
+                self,
+                SetConsensus,
                 "set did not reach consensus for subkey: {}:{}",
-                record_state.record_key().opaque(),
+                opaque_record_key,
                 subkey
             );
         }
@@ -1450,7 +1766,11 @@ impl OutboundTransactionManager {
         match stage {
             OutboundTransactionStage::Begin => {}
             OutboundTransactionStage::Failed => {
-                apibail_try_again!("transaction stage was Failed, wanted Begin; try again");
+                tx_try_again!(
+                    self,
+                    StageFailed,
+                    "transaction stage was Failed, wanted Begin; try again"
+                );
             }
             OutboundTransactionStage::End
             | OutboundTransactionStage::Rollback
@@ -1504,6 +1824,7 @@ impl OutboundTransactionManager {
         transaction_handle: OutboundTransactionHandle,
         result: OutboundTransactCommandResult,
     ) -> VeilidAPIResult<()> {
+        let opt_keepalive_processor = self.opt_keepalive_processor.clone();
         // Get transaction
         let outbound_transaction_state = self.get_transaction_state_mut(transaction_handle)?;
 
@@ -1515,7 +1836,11 @@ impl OutboundTransactionManager {
         match stage {
             OutboundTransactionStage::Begin => {}
             OutboundTransactionStage::Failed => {
-                apibail_try_again!("transaction stage was Failed, wanted Begin; try again");
+                tx_try_again!(
+                    self,
+                    StageFailed,
+                    "transaction stage was Failed, wanted Begin; try again"
+                );
             }
             OutboundTransactionStage::End
             | OutboundTransactionStage::Rollback
@@ -1540,6 +1865,7 @@ impl OutboundTransactionManager {
 
         let get_result_handler = Box::new(
             |node_transaction: &mut NodeTransaction, pnr: OutboundTransactCommandPerNodeResult| {
+                Self::refresh_keepalive(&opt_keepalive_processor, &pnr);
                 // Record subkey get for this node transaction
                 let opt_value = pnr.opt_value;
                 #[cfg(feature = "verbose-tracing")]
@@ -1672,7 +1998,11 @@ impl OutboundTransactionManager {
         match stage {
             OutboundTransactionStage::Begin => {}
             OutboundTransactionStage::Failed => {
-                apibail_try_again!("transaction stage was Failed, wanted Begin; try again");
+                tx_try_again!(
+                    self,
+                    StageFailed,
+                    "transaction stage was Failed, wanted Begin; try again"
+                );
             }
             OutboundTransactionStage::End
             | OutboundTransactionStage::Rollback

veilid-core/src/storage_manager/outbound_transaction_manager/node_transaction.rs

@@ -46,6 +46,12 @@ pub(super) struct NodeTransaction {
     /// Per-subkey seqs this node reported in its Begin answer
     #[serde(default)]
     begin_seqs: Vec<ValueSeqNum>,
+    /// Subkeys this node answered a Set for, whether it took the value or held a newer one
+    #[serde(default)]
+    confirmed_subkeys: BTreeSet<ValueSubkey>,
+    /// Set questions still in flight to this node; never survive a restart
+    #[serde(skip)]
+    outstanding_sets: u32,
 }
 
 impl VeilidComponentRegistryAccessor for NodeTransaction {
@@ -76,6 +82,8 @@ impl NodeTransaction {
             updated_values: Default::default(),
             opt_last_rtt: opt_initial_rtt,
             begin_seqs,
+            confirmed_subkeys: BTreeSet::new(),
+            outstanding_sets: 0,
         }
     }
 
@@ -174,6 +182,47 @@ impl NodeTransaction {
         self.opt_last_rtt = Some(rtt);
     }
 
+    pub(super) fn confirm_subkey(&mut self, subkey: ValueSubkey) {
+        self.confirmed_subkeys.insert(subkey);
+    }
+
+    pub fn confirmed_subkeys(&self) -> &BTreeSet<ValueSubkey> {
+        &self.confirmed_subkeys
+    }
+
+    pub fn outstanding_sets(&self) -> u32 {
+        self.outstanding_sets
+    }
+
+    pub(super) fn add_outstanding_set(&mut self) {
+        self.outstanding_sets += 1;
+    }
+
+    pub(super) fn finish_outstanding_set(&mut self) {
+        self.outstanding_sets = self.outstanding_sets.saturating_sub(1);
+    }
+
+    /// A Set answer settles this node's view of the subkey: the value landed, or the
+    /// node holds a newer one that the commit will keep
+    pub(super) fn record_set_answer(
+        &mut self,
+        subkey: ValueSubkey,
+        value: &Arc<SignedValueData>,
+        pnr: OutboundTransactCommandPerNodeResult,
+    ) {
+        self.update_expiration(pnr.opt_expiration);
+        if let Some(rtt) = pnr.opt_rtt {
+            self.record_rtt(rtt);
+        }
+        self.confirm_subkey(subkey);
+        if let Some(newer) = pnr.opt_value {
+            self.record_current_subkey_value(subkey, Some(newer));
+            self.record_updated_subkey_value(subkey, None);
+        } else {
+            self.record_updated_subkey_value(subkey, Some(value.clone()));
+        }
+    }
+
     pub fn commit_will_change_remote(&self) -> bool {
         for (subkey, updated_value) in self
             .updated_values

veilid-core/src/storage_manager/outbound_transaction_manager/outbound_transaction_keepalive_deadlines.rs

@@ -7,6 +7,9 @@ pub(super) struct OutboundTransactionKeepaliveState {
     pub opt_last_rtt: Option<TimestampDuration>,
     /// Most recent server-reported expiration; drives the next send time.
     pub opt_last_expiration: Option<Timestamp>,
+    /// A command answer refreshed the expiration since the last deadline was set,
+    /// so that deadline reschedules instead of sending
+    pub refreshed: bool,
     /// Server told us the inbound transaction is gone. Future fires should bail.
     pub dead: bool,
 }

veilid-core/src/storage_manager/outbound_transaction_manager/outbound_transaction_keepalive_processor.rs

@@ -47,11 +47,19 @@ enum ProcessorResult {
 /// Processor object with shared state for synchronous register/unregister
 /// and async keepalive processing
 pub(in crate::storage_manager) struct OutboundTransactionKeepaliveProcessor {
+    /// Registry for logging and component access
     registry: VeilidComponentRegistry,
+    /// Send deadlines by time
     deadlines: Arc<Mutex<OutboundTransactionKeepaliveDeadlines>>,
+    /// Train state by node transaction, so command answers can refresh it
+    states: Mutex<HashMap<LocalNodeTransactionId, Arc<Mutex<OutboundTransactionKeepaliveState>>>>,
+    /// Command channel into the processor loop
     sender: flume::Sender<OutboundTransactionKeepaliveCommand>,
+    /// Command channel out of the processor loop
     receiver: flume::Receiver<OutboundTransactionKeepaliveCommand>,
+    /// The processor loop task
     jh: Mutex<Option<MustJoinHandle<()>>>,
+    /// Stops the processor loop
     stop_source: Mutex<Option<StopSource>>,
 }
 
@@ -81,6 +89,7 @@ impl OutboundTransactionKeepaliveProcessor {
                 .saturating_mul(TRANSACTION_TIMEOUT_RPC_MULTIPLIER);
         let (sender, receiver) = flume::unbounded();
         Self {
+            states: Mutex::new(HashMap::new()),
             deadlines: Arc::new(Mutex::new(OutboundTransactionKeepaliveDeadlines::new(
                 registry.clone(),
                 ttl,
@@ -117,6 +126,7 @@ impl OutboundTransactionKeepaliveProcessor {
             ..Default::default()
         }));
 
+        self.states.lock().insert(params.lnxid, state.clone());
         let keepalive = OutboundTransactionKeepalive::new(params, state);
 
         #[cfg(feature = "verbose-tracing")]
@@ -139,9 +149,29 @@ impl OutboundTransactionKeepaliveProcessor {
         instrument(level = "trace", target = "stor", skip(self))
     )]
     pub fn unregister(&self, lnxid: LocalNodeTransactionId) {
+        self.states.lock().remove(&lnxid);
         self.deadlines.lock().cancel_deadline(lnxid);
     }
 
+    /// A command answer carried a fresh expiration: the next deadline reschedules
+    /// from it instead of sending a keepalive the node does not need
+    pub fn refresh(
+        &self,
+        lnxid: LocalNodeTransactionId,
+        expiration: Timestamp,
+        opt_rtt: Option<TimestampDuration>,
+    ) {
+        let Some(state) = self.states.lock().get(&lnxid).cloned() else {
+            return;
+        };
+        let mut st = state.lock();
+        st.opt_last_expiration = Some(expiration);
+        if let Some(rtt) = opt_rtt {
+            st.opt_last_rtt = Some(rtt);
+        }
+        st.refreshed = true;
+    }
+
     /// Spawn the background processor loop. Must be called before register.
     pub fn init(&self) {
         let rx = self.receiver.clone();
@@ -292,11 +322,28 @@ impl OutboundTransactionKeepaliveProcessor {
         unord: &mut FuturesUnordered<PinBoxFutureStatic<ProcessorResult>>,
         keepalive: OutboundTransactionKeepalive,
     ) {
-        if keepalive.state().lock().dead {
-            return;
-        }
-
         let send_ts = Timestamp::now();
+        {
+            let mut st = keepalive.state().lock();
+            if st.dead {
+                return;
+            }
+            // Refreshed by a command answer since this deadline was set: reschedule only
+            if st.refreshed {
+                st.refreshed = false;
+                drop(st);
+                veilid_stats!(
+                    registry
+                        .storage_manager()
+                        .transaction_quality()
+                        .lock()
+                        .mitigations
+                        .keepalives_skipped += 1
+                );
+                deadlines.lock().schedule_deadline(keepalive, send_ts);
+                return;
+            }
+        }
 
         // Enqueue the next deadline now, before the RPC is awaited.
         deadlines
@@ -318,6 +365,14 @@ impl OutboundTransactionKeepaliveProcessor {
 
         let fut = async move {
             let rpc_processor = registry.rpc_processor();
+            veilid_stats!(
+                registry
+                    .storage_manager()
+                    .transaction_quality()
+                    .lock()
+                    .mitigations
+                    .keepalive_gets_sent += 1
+            );
 
             let start_ts = Timestamp::now();
             let result = rpc_processor

veilid-core/src/storage_manager/outbound_transaction_manager/outbound_transaction_record_state.rs

@@ -29,11 +29,95 @@ pub(in crate::storage_manager) struct OutboundTransactionRecordStageConsensus {
 }
 
 /// Which node transaction ids at what stage
-type StageConsensusMap = HashMap<OutboundTransactionStage, BTreeSet<LocalNodeTransactionId>>;
+pub(in crate::storage_manager) type StageConsensusMap =
+    HashMap<OutboundTransactionStage, BTreeSet<LocalNodeTransactionId>>;
+
+/// The one stage at least `required` node transactions share. Failed marks a missing answer, not
+/// a stage a node reached, so it never competes; two live stages meeting the bar, or none, is Failed
+pub(in crate::storage_manager) fn record_consensus_stage(
+    stage_consensus_map: &StageConsensusMap,
+    required: usize,
+) -> OutboundTransactionStage {
+    let mut opt_best_stage = None;
+    for (st, stn) in stage_consensus_map.iter() {
+        if *st == OutboundTransactionStage::Failed || stn.len() < required {
+            continue;
+        }
+        if opt_best_stage.is_some() {
+            return OutboundTransactionStage::Failed;
+        }
+        opt_best_stage = Some(*st);
+    }
+    opt_best_stage.unwrap_or(OutboundTransactionStage::Failed)
+}
 
 /// Filter for get_transact_command_nodes
 type GetTransactCommandNodesFilter<'a> = Box<dyn Fn(&'a NodeTransaction) -> bool + 'a>;
 
+/// Minimum over desired subkeys of the number of nodes confirming it, or None
+/// when nothing was desired
+pub(in crate::storage_manager) fn min_subkey_coverage(
+    desired: &[ValueSubkey],
+    nodes: &[&BTreeSet<ValueSubkey>],
+) -> Option<usize> {
+    desired
+        .iter()
+        .map(|sk| nodes.iter().filter(|c| c.contains(sk)).count())
+        .min()
+}
+
+/// What one node looks like when End is being planned
+pub(in crate::storage_manager) struct EndCandidate {
+    /// Local node transaction id
+    pub lnxid: LocalNodeTransactionId,
+    /// Subkeys the node answered a Set for
+    pub confirmed: BTreeSet<ValueSubkey>,
+    /// Set questions still in flight to the node
+    pub outstanding_sets: u32,
+}
+
+/// Which Begin nodes may vote End, which need a completion pass, and whether the
+/// record is short of voters
+#[derive(Debug, Default, PartialEq, Eq)]
+pub(in crate::storage_manager) struct EndSelection {
+    /// Every desired subkey confirmed and nothing in flight
+    pub voters: Vec<LocalNodeTransactionId>,
+    /// Quiescent but missing subkeys, with what to re-send
+    pub completion: Vec<(LocalNodeTransactionId, Vec<ValueSubkey>)>,
+    /// Set questions still in flight across all candidates
+    pub outstanding: u32,
+    /// Fewer voters than required
+    pub short: bool,
+}
+
+/// A node votes End only when nothing can land at it afterwards; a node with an
+/// answer in flight is neither a voter nor a completion target until it settles
+pub(in crate::storage_manager) fn select_end_voters(
+    candidates: &[EndCandidate],
+    desired: &[ValueSubkey],
+    required: usize,
+) -> EndSelection {
+    let mut out = EndSelection::default();
+    for c in candidates {
+        out.outstanding += c.outstanding_sets;
+        if c.outstanding_sets > 0 {
+            continue;
+        }
+        let missing: Vec<ValueSubkey> = desired
+            .iter()
+            .copied()
+            .filter(|sk| !c.confirmed.contains(sk))
+            .collect();
+        if missing.is_empty() {
+            out.voters.push(c.lnxid);
+        } else {
+            out.completion.push((c.lnxid, missing));
+        }
+    }
+    out.short = out.voters.len() < required;
+    out
+}
+
 /// State per record
 #[derive(Clone, Debug, Serialize, Deserialize)]
 pub(in crate::storage_manager) struct OutboundTransactionRecordState {
@@ -144,30 +228,15 @@ impl OutboundTransactionRecordState {
         let stage_consensus_map = self.get_stage_consensus_map();
 
         // Find a singular consensus
-        let stage = {
-            let mut opt_best_stage = None;
-            for (st, stn) in stage_consensus_map.iter().map(|(st, stn)| (*st, stn)) {
-                if stn.len() >= self.record_params.required_strict_consensus_count {
-                    if opt_best_stage.is_none() {
-                        opt_best_stage = Some(st);
-                    } else {
-                        // Multiple stages met strict consensus (should not happen) — log and mark Failed.
-                        #[cfg(feature = "verbose-tracing")]
-                        veilid_log!(self debug target: "dht", "stage_consensus: ambiguous — multiple stages met threshold {} for record {}: {:?}",
-                            self.record_params.required_strict_consensus_count, self.record_params.record_key.opaque(), stage_consensus_map);
-                        opt_best_stage = Some(OutboundTransactionStage::Failed);
-                        break;
-                    }
-                }
-            }
-            // If no stage has met the strict consensus, this is also failed
-            #[cfg(feature = "verbose-tracing")]
-            if opt_best_stage.is_none() {
-                veilid_log!(self debug target: "dht", "stage_consensus: no stage reached required threshold={} for record {}: stage_map={:?}",
-                    self.record_params.required_strict_consensus_count, self.record_params.record_key.opaque(), stage_consensus_map);
-            }
-            opt_best_stage.unwrap_or(OutboundTransactionStage::Failed)
-        };
+        let stage = record_consensus_stage(
+            &stage_consensus_map,
+            self.record_params.required_strict_consensus_count,
+        );
+        #[cfg(feature = "verbose-tracing")]
+        if stage == OutboundTransactionStage::Failed {
+            veilid_log!(self debug target: "dht", "stage_consensus: no single live stage met threshold {} for record {}: stage_map={:?}",
+                self.record_params.required_strict_consensus_count, self.record_params.record_key.opaque(), stage_consensus_map);
+        }
 
         // If the consensus stage has some requred state at this point, validate it
         let stage = match stage {
@@ -632,6 +701,38 @@ impl OutboundTransactionRecordState {
         self.desired_subkeys.insert(subkey, value);
     }
 
+    pub fn desired_subkeys(&self) -> Vec<ValueSubkey> {
+        self.desired_subkeys.keys().copied().collect()
+    }
+
+    /// Begin-stage nodes as End candidates
+    pub fn end_candidates(&self) -> Vec<EndCandidate> {
+        self.node_transactions_by_id
+            .iter()
+            .filter(|(_, nt)| nt.stage() == OutboundTransactionStage::Begin)
+            .map(|(lnxid, nt)| EndCandidate {
+                lnxid: *lnxid,
+                confirmed: nt.confirmed_subkeys().clone(),
+                outstanding_sets: nt.outstanding_sets(),
+            })
+            .collect()
+    }
+
+    pub fn desired_subkey_value(&self, subkey: ValueSubkey) -> Option<Arc<SignedValueData>> {
+        self.desired_subkeys.get(&subkey).cloned()
+    }
+
+    /// Minimum over desired subkeys of the nodes at `stage` that confirmed it
+    pub fn stage_subkey_coverage(&self, stage: OutboundTransactionStage) -> Option<usize> {
+        let nodes: Vec<&BTreeSet<ValueSubkey>> = self
+            .node_transactions_by_id
+            .values()
+            .filter(|nt| nt.stage() == stage)
+            .map(|nt| nt.confirmed_subkeys())
+            .collect();
+        min_subkey_coverage(&self.desired_subkeys(), &nodes)
+    }
+
     pub fn current_consensus(&self) -> &OutboundTransactionConsensus {
         &self.current_consensus
     }

veilid-core/src/storage_manager/outbound_transaction_manager/terminal_delivery.rs

@@ -42,6 +42,14 @@ impl TerminalDelivery {
                 veilid_log!(registry debug target: "network_result",
                     "terminal delivery expired after {} attempts: {:?} xid={} node={} record={}",
                     attempts, self.command, self.rnxid, self.node_ref, self.opaque_record_key);
+                veilid_stats!(
+                    registry
+                        .storage_manager()
+                        .transaction_quality()
+                        .lock()
+                        .mitigations
+                        .terminal_delivery_expired += 1
+                );
                 return;
             }
 
@@ -71,6 +79,14 @@ impl TerminalDelivery {
                 veilid_log!(registry debug target: "network_result",
                     "terminal delivery complete (attempt {}): {:?} xid={} node={} record={}",
                     attempts, self.command, self.rnxid, self.node_ref, self.opaque_record_key);
+                veilid_stats!(
+                    registry
+                        .storage_manager()
+                        .transaction_quality()
+                        .lock()
+                        .mitigations
+                        .terminal_delivery_completed += 1
+                );
                 return;
             }
 

veilid-core/src/storage_manager/record_store/record_store_inner/inbound_transactions_interface.rs

@@ -310,6 +310,7 @@ where
                 .try_remove_transaction(transaction_id)
                 .inspect_err(veilid_log_err!(self));
             veilid_log!(self debug "{}","end snapshot mismatch");
+            veilid_stats!(self.transaction_quality_inbound(|i| i.end_snapshot_mismatch += 1));
             return Ok(InboundTransactCommandResult::InvalidTransaction);
         }
 
@@ -362,6 +363,7 @@ where
                     .remove_transaction(transaction_id)
                     .unwrap_or_else(veilid_log_err!(self));
                 veilid_log!(self debug "{}","bad lock state");
+                veilid_stats!(self.transaction_quality_inbound(|i| i.commit_bad_lock_state += 1));
                 return Ok(InboundTransactCommandResult::InvalidTransaction);
             }
 
@@ -550,11 +552,12 @@ where
             return Ok(InboundTransactCommandResult::InvalidTransaction);
         };
 
+        // A Set landing after End is refused but does not end the transaction: the
+        // writer only counts a node that answered every Set before voting, so this
+        // one is a straggler whose Commit or Rollback is still on its way
         if active_transaction_list.is_locked_by(transaction_id) {
-            self.inbound_transactions
-                .remove_transaction(transaction_id)
-                .unwrap_or_else(veilid_log_err!(self));
             veilid_log!(self debug "{}","set after end");
+            veilid_stats!(self.transaction_quality_inbound(|i| i.set_after_end += 1));
             return Ok(InboundTransactCommandResult::InvalidTransaction);
         }
 

veilid-core/src/storage_manager/record_store/record_store_inner/mod.rs

@@ -57,6 +57,17 @@ where
     }
 }
 
+#[cfg(feature = "stats")]
+impl<D> RecordStoreInner<D>
+where
+    D: RecordDetail,
+{
+    fn transaction_quality_inbound(&self, f: impl FnOnce(&mut InboundStats)) {
+        let storage_manager = self.registry().storage_manager();
+        f(&mut storage_manager.transaction_quality().lock().inbound);
+    }
+}
+
 impl<D> fmt::Debug for RecordStoreInner<D>
 where
     D: RecordDetail,

veilid-core/src/storage_manager/stats/gated_operation_accounting.rs

@@ -1,7 +1,6 @@
 //! Rolling accounting for the DHT operation gate: per-kind wait/hold
 //! latencies and, with `aimd-dht`, per-direction AIMD decision tallies.
-//! Compiled only with `stats`; the serializable snapshot lives in `stats.rs`.
-use super::gated_operation::GatedOperationKind;
+//! The serializable snapshot lives in `mod.rs`.
 use super::*;
 
 /// Per-kind rolling wait/hold accounting
@@ -17,7 +16,7 @@ struct GatedKindAccounting {
 
 /// One kind's gate telemetry, read by the storage manager stats snapshot
 #[derive(Clone)]
-pub(super) struct GatedKindSnapshot {
+pub(in crate::storage_manager) struct GatedKindSnapshot {
     pub kind: &'static str,
     pub count: u64,
     pub retryable: u64,
@@ -28,7 +27,7 @@ pub(super) struct GatedKindSnapshot {
 /// Gate wait (admission delay) and hold (round-trip proxy) latencies plus a
 /// completion count, per operation kind
 #[derive(Debug, Default)]
-pub(super) struct GatedOperationAccounting {
+pub(in crate::storage_manager) struct GatedOperationAccounting {
     set: GatedKindAccounting,
     get: GatedKindAccounting,
     transact_set: GatedKindAccounting,
@@ -44,20 +43,28 @@ impl GatedOperationAccounting {
             GatedOperationKind::TransactGet => &mut self.transact_get,
         }
     }
-    pub(super) fn record_wait(&mut self, kind: GatedOperationKind, wait: TimestampDuration) {
+    pub(in crate::storage_manager) fn record_wait(
+        &mut self,
+        kind: GatedOperationKind,
+        wait: TimestampDuration,
+    ) {
         self.kind_mut(kind)
             .gate_wait_accounting
             .record_latency(wait);
     }
-    pub(super) fn record_completion(&mut self, kind: GatedOperationKind, held: TimestampDuration) {
+    pub(in crate::storage_manager) fn record_completion(
+        &mut self,
+        kind: GatedOperationKind,
+        held: TimestampDuration,
+    ) {
         let k = self.kind_mut(kind);
         k.count += 1;
         k.held_accounting.record_latency(held);
     }
-    pub(super) fn record_retryable(&mut self, kind: GatedOperationKind) {
+    pub(in crate::storage_manager) fn record_retryable(&mut self, kind: GatedOperationKind) {
         self.kind_mut(kind).retryable += 1;
     }
-    pub(super) fn per_kind(&self) -> [GatedKindSnapshot; 4] {
+    pub(in crate::storage_manager) fn per_kind(&self) -> [GatedKindSnapshot; 4] {
         let snap = |kind, k: &GatedKindAccounting| GatedKindSnapshot {
             kind,
             count: k.count,
@@ -77,7 +84,7 @@ impl GatedOperationAccounting {
 /// Cumulative AIMD decision tallies for one direction
 #[cfg(feature = "aimd-dht")]
 #[derive(Debug, Default)]
-pub(super) struct AimdAccounting {
+pub(in crate::storage_manager) struct AimdAccounting {
     holds: u64,
     lowers: u64,
     clamps: u64,
@@ -89,7 +96,7 @@ pub(super) struct AimdAccounting {
 
 #[cfg(feature = "aimd-dht")]
 impl AimdAccounting {
-    pub(super) fn record(&mut self, step: &AimdStepResult) {
+    pub(in crate::storage_manager) fn record(&mut self, step: &AimdStepResult) {
         match step.decision {
             AimdDecision::Hold => self.holds += 1,
             AimdDecision::Lower(_) => self.lowers += 1,
@@ -100,7 +107,7 @@ impl AimdAccounting {
         self.congested += step.congested;
         self.demand_events += step.demand_events;
     }
-    pub(super) fn counters(&self, limit: u64) -> AimdCounters {
+    pub(in crate::storage_manager) fn counters(&self, limit: u64) -> AimdCounters {
         AimdCounters {
             limit,
             holds: self.holds,
@@ -117,7 +124,7 @@ impl AimdAccounting {
 /// One direction's AIMD telemetry, read by the storage manager stats snapshot
 #[cfg(feature = "aimd-dht")]
 #[derive(Clone, Copy)]
-pub(super) struct AimdCounters {
+pub(in crate::storage_manager) struct AimdCounters {
     pub limit: u64,
     pub holds: u64,
     pub lowers: u64,

veilid-core/src/storage_manager/stats/mod.rs

@@ -1,5 +1,13 @@
+//! Storage manager stats: the serializable snapshot plus the accounting the
+//! record sites feed. Compiled only with `stats`.
+mod gated_operation_accounting;
+mod transaction_quality_accounting;
+
 use super::*;
 
+pub(in crate::storage_manager) use gated_operation_accounting::*;
+pub(in crate::storage_manager) use transaction_quality_accounting::*;
+
 #[derive(Debug, Serialize)]
 pub(super) struct StorageManagerStats {
     online: bool,
@@ -11,10 +19,30 @@ pub(super) struct StorageManagerStats {
     transactions: TransactionStats,
     gated_operations: Vec<GatedOperationKindStats>,
     locks: Vec<LockStatsEntry>,
+    transaction_quality: TransactionQualityStats,
     #[cfg(feature = "aimd-dht")]
     aimd: AimdStats,
 }
 
+/// Transaction quality counters since the last `stats reset`
+#[derive(Debug, Serialize)]
+struct TransactionQualityStats {
+    /// Per command kind
+    commands: Vec<CommandStats>,
+    /// Coverage at End
+    end_coverage: EndCoverageStats,
+    /// Coverage at Commit
+    commit_coverage: CommitCoverageStats,
+    /// Node-set attrition
+    node_sets: NodeSetStats,
+    /// Mitigation costs and outcomes
+    mitigations: MitigationStats,
+    /// End wait window
+    end_wait_duration: LatencyStats,
+    /// Storage-node side refusals
+    inbound: InboundStats,
+}
+
 #[derive(Debug, Serialize)]
 struct LockStatsEntry {
     name: String,
@@ -75,6 +103,10 @@ impl From<AimdCounters> for AimdDirectionStats {
 }
 
 impl StorageManager {
+    pub(super) fn reset_stats_impl(&self) {
+        *self.transaction_quality.lock() = TransactionQualityAccounting::default();
+    }
+
     pub(super) fn stats_impl(&self) -> Option<Box<dyn VeilidComponentStats>> {
         let (
             opened_records,
@@ -121,6 +153,19 @@ impl StorageManager {
             held: lock.held,
         }];
 
+        let transaction_quality = {
+            let q = self.transaction_quality.lock();
+            TransactionQualityStats {
+                commands: q.commands().to_vec(),
+                end_coverage: q.end_coverage.clone(),
+                commit_coverage: q.commit_coverage.clone(),
+                node_sets: q.node_sets.clone(),
+                mitigations: q.mitigations.clone(),
+                end_wait_duration: q.end_wait_duration(),
+                inbound: q.inbound.clone(),
+            }
+        };
+
         Some(Box::new(StorageManagerStats {
             online: self.is_online.load(Ordering::Acquire),
             gated_operations_active: self.gate_active.load(Ordering::Acquire) as u32,
@@ -131,6 +176,7 @@ impl StorageManager {
             transactions,
             gated_operations,
             locks,
+            transaction_quality,
             #[cfg(feature = "aimd-dht")]
             aimd: AimdStats {
                 upload: self.upload_budget.aimd_counters().into(),

veilid-core/src/storage_manager/stats/transaction_quality_accounting.rs

@@ -0,0 +1,391 @@
+//! Cumulative transaction-quality counters: per-command fanout outcomes, subkey
+//! confirmation coverage at End and Commit, node-set attrition, and the cost of
+//! every mitigation (retry pass, keepalives, terminal delivery, TryAgain).
+//! The serializable snapshot lives in `mod.rs`.
+//! Counters accumulate until `stats reset`; benchmarks report deltas.
+use super::*;
+
+/// Outbound transaction command kinds, Begin included
+#[derive(Debug, Clone, Copy, PartialEq, Eq)]
+pub(in crate::storage_manager) enum TransactionCommandKind {
+    Begin,
+    Set,
+    End,
+    Commit,
+    Rollback,
+    Get,
+}
+
+impl TransactionCommandKind {
+    pub fn name(self) -> &'static str {
+        match self {
+            Self::Begin => "begin",
+            Self::Set => "set",
+            Self::End => "end",
+            Self::Commit => "commit",
+            Self::Rollback => "rollback",
+            Self::Get => "get",
+        }
+    }
+}
+
+impl From<TransactCommand> for TransactionCommandKind {
+    fn from(c: TransactCommand) -> Self {
+        match c {
+            TransactCommand::End => Self::End,
+            TransactCommand::Commit => Self::Commit,
+            TransactCommand::Rollback => Self::Rollback,
+            TransactCommand::Get => Self::Get,
+            TransactCommand::Set => Self::Set,
+        }
+    }
+}
+
+/// Why a transaction call returned TryAgain
+#[derive(Debug, Clone, Copy, PartialEq, Eq)]
+pub(in crate::storage_manager) enum TryAgainReason {
+    BeginContended,
+    NotOnline,
+    OfflineWrites,
+    BeginConsensus,
+    SetConsensus,
+    StageFailed,
+    InTransaction,
+    Handles,
+    BackgroundDeferred,
+    EndIncomplete,
+    CommitConsensus,
+    Other,
+}
+
+/// What one outbound command's fanout did, recorded when it returns
+#[derive(Debug, Default)]
+pub(in crate::storage_manager) struct CommandOutcome {
+    /// Per-node RPCs sent
+    pub rpcs_sent: u64,
+    /// Answers with the transaction still valid
+    pub answered_valid: u64,
+    /// Answers with the transaction no longer valid
+    pub answered_invalid: u64,
+    /// Per-node timeouts inside the wait
+    pub no_response: u64,
+    /// Nodes still in flight when the command returned
+    pub abandoned_in_flight: u64,
+    /// The command returned with nodes still in flight
+    pub post_consensus_window_expired: bool,
+    /// Valid answers came up short of required
+    pub short_of_required: bool,
+    /// Wall time from issue to return
+    pub duration: TimestampDuration,
+}
+
+/// Late Set answers that were recorded into node state instead of dropped
+#[derive(Debug, Clone, Copy, PartialEq, Eq)]
+pub(in crate::storage_manager) enum LateAnswer {
+    Valid,
+    Invalid,
+}
+
+/// Per command kind accumulator
+#[derive(Debug, Default)]
+struct CommandAccounting {
+    /// Commands issued
+    commands: u64,
+    /// Per-node RPCs sent
+    rpcs_sent: u64,
+    /// Answers with the transaction still valid
+    answered_valid: u64,
+    /// Answers with the transaction no longer valid
+    answered_invalid: u64,
+    /// Per-node timeouts inside the wait
+    no_response: u64,
+    /// Nodes still in flight when a command returned
+    abandoned_in_flight: u64,
+    /// Commands that returned with nodes still in flight
+    post_consensus_window_expired: u64,
+    /// Commands whose valid answers came up short of required
+    short_of_required: u64,
+    /// Answers that landed after the command returned and were still recorded
+    collected_after_early_exit: u64,
+    /// Rolling command wall times
+    duration: LatencyStatsAccounting,
+}
+
+/// One kind's command telemetry, read by the storage manager stats snapshot
+#[derive(Debug, Clone, Serialize)]
+pub(in crate::storage_manager) struct CommandStats {
+    /// Command kind name
+    pub kind: &'static str,
+    /// Commands issued
+    pub commands: u64,
+    /// Per-node RPCs sent
+    pub rpcs_sent: u64,
+    /// Answers with the transaction still valid
+    pub answered_valid: u64,
+    /// Answers with the transaction no longer valid
+    pub answered_invalid: u64,
+    /// Per-node timeouts inside the wait
+    pub no_response: u64,
+    /// Nodes still in flight when a command returned
+    pub abandoned_in_flight: u64,
+    /// Commands that returned with nodes still in flight
+    pub post_consensus_window_expired: u64,
+    /// Commands whose valid answers came up short of required
+    pub short_of_required: u64,
+    /// Answers that landed after the command returned and were still recorded
+    pub collected_after_early_exit: u64,
+    /// Command wall time window
+    pub duration: LatencyStats,
+}
+
+/// Subkey confirmation coverage measured when End is sent and answered
+#[derive(Debug, Default, Clone, Serialize)]
+pub(in crate::storage_manager) struct EndCoverageStats {
+    /// Nodes sent End
+    pub nodes_sent_end: u64,
+    /// Nodes sent End with a desired subkey unconfirmed
+    pub nodes_sent_end_incomplete: u64,
+    /// Unconfirmed desired subkeys summed over those nodes
+    pub missing_subkey_confirmations: u64,
+    /// Records with a desired subkey confirmed by fewer End voters than required
+    pub records_below_required_coverage: u64,
+    /// Records whose minimum coverage was measured
+    pub coverage_records: u64,
+    /// Sum of per-record minimum coverage
+    pub coverage_sum: u64,
+    /// Lowest per-record minimum coverage seen
+    pub coverage_min: u64,
+}
+
+/// Subkey coverage over Commit-stage nodes, measured when Commit results land
+#[derive(Debug, Default, Clone, Serialize)]
+pub(in crate::storage_manager) struct CommitCoverageStats {
+    /// Records with a desired subkey held by fewer committed nodes than required
+    pub records_below_required_coverage: u64,
+    /// Commits that returned Ok while below required, which the commit gate makes impossible
+    pub commits_ok_below_required: u64,
+    /// Commit answers of InvalidTransaction
+    pub commit_refusals: u64,
+    /// Nodes promoted to Commit without an RPC
+    pub pre_authorized_nodes: u64,
+}
+
+/// Node-set attrition per record, summed so ratios are sum/sum
+#[derive(Debug, Default, Clone, Serialize)]
+pub(in crate::storage_manager) struct NodeSetStats {
+    /// Records that reached Begin consensus
+    pub records: u64,
+    /// Node transactions accepted at Begin
+    pub begin_nodes: u64,
+    /// Nodes sent End
+    pub end_sent_nodes: u64,
+    /// Nodes that answered End as still valid
+    pub end_valid_nodes: u64,
+    /// Nodes sent Commit
+    pub commit_sent_nodes: u64,
+    /// Nodes that answered Commit as still valid
+    pub commit_valid_nodes: u64,
+    /// Nodes sent Rollback
+    pub rollback_sent_nodes: u64,
+}
+
+/// TryAgain returns by reason
+#[derive(Debug, Default, Clone, Serialize)]
+pub(in crate::storage_manager) struct TryAgainStats {
+    /// Begin found the records locked
+    pub begin_contended: u64,
+    /// The DHT was offline
+    pub not_online: u64,
+    /// A record had pending offline writes
+    pub offline_writes: u64,
+    /// Begin fell short of consensus
+    pub begin_consensus: u64,
+    /// A Set fell short of consensus
+    pub set_consensus: u64,
+    /// The transaction stage was Failed
+    pub stage_failed: u64,
+    /// A record was already in a transaction
+    pub in_transaction: u64,
+    /// No free handle or node transaction id
+    pub handles: u64,
+    /// A background transaction yielded to foreground activity
+    pub background_deferred: u64,
+    /// End found fewer complete nodes than required
+    pub end_incomplete: u64,
+    /// Commit fell short of the per-subkey minimum
+    pub commit_consensus: u64,
+    /// Any other reason
+    pub other: u64,
+}
+
+/// Cost of each mitigation, plus transaction outcomes
+#[derive(Debug, Default, Clone, Serialize)]
+pub(in crate::storage_manager) struct MitigationStats {
+    /// Targeted Set re-sends before End
+    pub completion_pass_rpcs: u64,
+    /// End attempts that waited for in-flight Sets
+    pub end_waits: u64,
+    /// Keepalive trains registered
+    pub keepalives_registered: u64,
+    /// Keepalive Gets sent
+    pub keepalive_gets_sent: u64,
+    /// Keepalive deadlines that found the node already refreshed
+    pub keepalives_skipped: u64,
+    /// Terminal deliveries scheduled at drop
+    pub terminal_delivery_scheduled: u64,
+    /// Terminal deliveries answered
+    pub terminal_delivery_completed: u64,
+    /// Terminal deliveries that ran past the server-side expiration
+    pub terminal_delivery_expired: u64,
+    /// TryAgain returns by reason
+    pub try_again: TryAgainStats,
+    /// Transactions committed
+    pub transactions_committed: u64,
+    /// Transactions rolled back by the app
+    pub transactions_rolled_back: u64,
+    /// Transactions dropped by the rollback guard
+    pub transactions_failed: u64,
+}
+
+/// Storage-node side refusals, meaningful only on nodes that serve records
+#[derive(Debug, Default, Clone, Serialize)]
+pub(in crate::storage_manager) struct InboundStats {
+    /// Sets refused because the transaction had ended
+    pub set_after_end: u64,
+    /// Ends refused because the record changed since Begin
+    pub end_snapshot_mismatch: u64,
+    /// Commits refused because the transaction did not hold the lock
+    pub commit_bad_lock_state: u64,
+}
+
+#[derive(Debug, Default)]
+pub(in crate::storage_manager) struct TransactionQualityAccounting {
+    /// Begin commands
+    begin: CommandAccounting,
+    /// Set commands
+    set: CommandAccounting,
+    /// End commands
+    end: CommandAccounting,
+    /// Commit commands
+    commit: CommandAccounting,
+    /// Rollback commands
+    rollback: CommandAccounting,
+    /// Get commands
+    get: CommandAccounting,
+    /// Coverage at End
+    pub end_coverage: EndCoverageStats,
+    /// Coverage at Commit
+    pub commit_coverage: CommitCoverageStats,
+    /// Node-set attrition
+    pub node_sets: NodeSetStats,
+    /// Mitigation costs and outcomes
+    pub mitigations: MitigationStats,
+    /// Storage-node side refusals
+    pub inbound: InboundStats,
+    /// Rolling End wait durations
+    end_wait: LatencyStatsAccounting,
+}
+
+impl TransactionQualityAccounting {
+    pub fn record_end_wait(&mut self, wait: TimestampDuration) {
+        self.mitigations.end_waits += 1;
+        self.end_wait.record_latency(wait);
+    }
+
+    pub fn end_wait_duration(&self) -> LatencyStats {
+        self.end_wait.latency_stats().unwrap_or_default()
+    }
+
+    pub fn record_collected(&mut self, kind: TransactionCommandKind, answer: LateAnswer) {
+        let c = self.command_mut(kind);
+        c.collected_after_early_exit += 1;
+        match answer {
+            LateAnswer::Valid => c.answered_valid += 1,
+            LateAnswer::Invalid => c.answered_invalid += 1,
+        }
+    }
+
+    fn command_mut(&mut self, kind: TransactionCommandKind) -> &mut CommandAccounting {
+        match kind {
+            TransactionCommandKind::Begin => &mut self.begin,
+            TransactionCommandKind::Set => &mut self.set,
+            TransactionCommandKind::End => &mut self.end,
+            TransactionCommandKind::Commit => &mut self.commit,
+            TransactionCommandKind::Rollback => &mut self.rollback,
+            TransactionCommandKind::Get => &mut self.get,
+        }
+    }
+
+    pub fn record_command(&mut self, kind: TransactionCommandKind, outcome: CommandOutcome) {
+        let c = self.command_mut(kind);
+        c.commands += 1;
+        c.rpcs_sent += outcome.rpcs_sent;
+        c.answered_valid += outcome.answered_valid;
+        c.answered_invalid += outcome.answered_invalid;
+        c.no_response += outcome.no_response;
+        c.abandoned_in_flight += outcome.abandoned_in_flight;
+        c.post_consensus_window_expired += u64::from(outcome.post_consensus_window_expired);
+        c.short_of_required += u64::from(outcome.short_of_required);
+        c.duration.record_latency(outcome.duration);
+    }
+
+    /// One record's min-over-subkeys coverage at End; None when nothing was desired
+    pub fn record_end_coverage(&mut self, opt_min_coverage: Option<usize>, required: usize) {
+        let Some(min_coverage) = opt_min_coverage else {
+            return;
+        };
+        let ec = &mut self.end_coverage;
+        if min_coverage < required {
+            ec.records_below_required_coverage += 1;
+        }
+        let min_coverage = min_coverage as u64;
+        if ec.coverage_records == 0 || min_coverage < ec.coverage_min {
+            ec.coverage_min = min_coverage;
+        }
+        ec.coverage_records += 1;
+        ec.coverage_sum += min_coverage;
+    }
+
+    pub fn try_again(&mut self, reason: TryAgainReason) {
+        let ta = &mut self.mitigations.try_again;
+        let counter = match reason {
+            TryAgainReason::BeginContended => &mut ta.begin_contended,
+            TryAgainReason::NotOnline => &mut ta.not_online,
+            TryAgainReason::OfflineWrites => &mut ta.offline_writes,
+            TryAgainReason::BeginConsensus => &mut ta.begin_consensus,
+            TryAgainReason::SetConsensus => &mut ta.set_consensus,
+            TryAgainReason::StageFailed => &mut ta.stage_failed,
+            TryAgainReason::InTransaction => &mut ta.in_transaction,
+            TryAgainReason::Handles => &mut ta.handles,
+            TryAgainReason::BackgroundDeferred => &mut ta.background_deferred,
+            TryAgainReason::EndIncomplete => &mut ta.end_incomplete,
+            TryAgainReason::CommitConsensus => &mut ta.commit_consensus,
+            TryAgainReason::Other => &mut ta.other,
+        };
+        *counter += 1;
+    }
+
+    pub fn commands(&self) -> [CommandStats; 6] {
+        let snap = |kind: TransactionCommandKind, c: &CommandAccounting| CommandStats {
+            kind: kind.name(),
+            commands: c.commands,
+            rpcs_sent: c.rpcs_sent,
+            answered_valid: c.answered_valid,
+            answered_invalid: c.answered_invalid,
+            no_response: c.no_response,
+            abandoned_in_flight: c.abandoned_in_flight,
+            post_consensus_window_expired: c.post_consensus_window_expired,
+            short_of_required: c.short_of_required,
+            collected_after_early_exit: c.collected_after_early_exit,
+            duration: c.duration.latency_stats().unwrap_or_default(),
+        };
+        [
+            snap(TransactionCommandKind::Begin, &self.begin),
+            snap(TransactionCommandKind::Set, &self.set),
+            snap(TransactionCommandKind::End, &self.end),
+            snap(TransactionCommandKind::Commit, &self.commit),
+            snap(TransactionCommandKind::Rollback, &self.rollback),
+            snap(TransactionCommandKind::Get, &self.get),
+        ]
+    }
+}

veilid-core/src/storage_manager/tests_storage_manager/mod.rs

@@ -7,6 +7,8 @@ mod test_inbound_set_value_signature;
 mod test_inspect_fanout_done;
 mod test_min_seqnum;
 mod test_record_report_seqs;
+mod test_transaction_quality;
+mod test_transaction_stage_consensus;
 mod test_watch_fallback_backoff;
 mod test_watch_route_pinning;
 mod test_watch_subkey_filter;
@@ -19,6 +21,8 @@ pub async fn test_all() {
     test_inspect_fanout_done::test_all();
     test_min_seqnum::test_all().await;
     test_record_report_seqs::test_all();
+    test_transaction_quality::test_all();
+    test_transaction_stage_consensus::test_all();
     test_watch_fallback_backoff::test_all();
     test_watch_route_pinning::test_all().await;
     test_watch_subkey_filter::test_all().await;

veilid-core/src/storage_manager/tests_storage_manager/test_transaction_quality.rs

@@ -0,0 +1,127 @@
+//! Subkey confirmation coverage is per subkey over the nodes at a stage: a record
+//! is durable only if every desired subkey is confirmed by at least the required
+//! count, however many nodes voted. End goes only to nodes that are complete and
+//! have nothing in flight.
+
+use super::*;
+use crate::storage_manager::outbound_transaction_manager::{
+    min_subkey_coverage, select_end_voters, EndCandidate, LocalNodeTransactionId,
+};
+use std::collections::BTreeSet;
+
+const DESIRED: [ValueSubkey; 8] = [0, 1, 2, 3, 4, 5, 6, 7];
+
+fn confirmed(subkeys: &[ValueSubkey]) -> BTreeSet<ValueSubkey> {
+    subkeys.iter().copied().collect()
+}
+
+/// The five End voters of a 16x8 concurrent bulk store whose commit returned Ok
+/// with subkeys 2 and 5 held by only two of them
+fn torn_end_voters() -> Vec<BTreeSet<ValueSubkey>> {
+    vec![
+        confirmed(&[0, 1, 3, 4, 6, 7]),
+        confirmed(&[1, 2, 4, 5, 7]),
+        confirmed(&[0, 1, 3, 4, 6, 7]),
+        confirmed(&[0, 2, 3, 5, 6]),
+        confirmed(&[0, 1, 3, 4, 6, 7]),
+    ]
+}
+
+fn candidates(nodes: &[(u64, &[ValueSubkey], u32)]) -> Vec<EndCandidate> {
+    nodes
+        .iter()
+        .map(|(id, subkeys, outstanding)| EndCandidate {
+            lnxid: LocalNodeTransactionId::new(*id),
+            confirmed: confirmed(subkeys),
+            outstanding_sets: *outstanding,
+        })
+        .collect()
+}
+
+fn ids(list: &[u64]) -> Vec<LocalNodeTransactionId> {
+    list.iter()
+        .map(|id| LocalNodeTransactionId::new(*id))
+        .collect()
+}
+
+pub fn test_select_end_voters() {
+    info!("--- test_select_end_voters ---");
+    // The torn record's Begin set: nobody complete, so nobody votes yet and every
+    // quiescent node gets exactly its missing subkeys re-sent
+    let sel = select_end_voters(
+        &candidates(&[
+            (1, &[0, 1, 3, 4, 6, 7], 0),
+            (2, &[1, 2, 4, 5, 7], 0),
+            (3, &[0, 2, 3, 5, 6], 1),
+        ]),
+        &DESIRED,
+        2,
+    );
+    assert!(sel.voters.is_empty());
+    assert_eq!(
+        sel.completion,
+        vec![
+            (LocalNodeTransactionId::new(1), vec![2, 5]),
+            (LocalNodeTransactionId::new(2), vec![0, 3, 6]),
+        ]
+    );
+    assert_eq!(sel.outstanding, 1);
+    assert!(sel.short);
+
+    // Once confirmed, complete quiescent nodes vote; an in-flight one does not
+    let sel = select_end_voters(
+        &candidates(&[(1, &DESIRED, 0), (2, &DESIRED, 0), (3, &DESIRED, 1)]),
+        &DESIRED,
+        2,
+    );
+    assert_eq!(sel.voters, ids(&[1, 2]));
+    assert!(sel.completion.is_empty());
+    assert_eq!(sel.outstanding, 1);
+    assert!(!sel.short);
+
+    // A read-only transaction desires nothing, so every quiescent node votes
+    let sel = select_end_voters(&candidates(&[(1, &[], 0), (2, &[], 0)]), &[], 2);
+    assert_eq!(sel.voters, ids(&[1, 2]));
+    assert!(!sel.short);
+}
+
+pub fn test_min_subkey_coverage_is_per_subkey() {
+    info!("--- test_min_subkey_coverage_is_per_subkey ---");
+    let voters = torn_end_voters();
+    let nodes: Vec<&BTreeSet<ValueSubkey>> = voters.iter().collect();
+    // Five voters, none complete, and subkeys 2 and 5 reach only two of them
+    assert_eq!(min_subkey_coverage(&DESIRED, &nodes), Some(2));
+    assert_eq!(min_subkey_coverage(&[0, 1, 3, 4, 6, 7], &nodes), Some(4));
+
+    let full = vec![confirmed(&DESIRED); 5];
+    let nodes: Vec<&BTreeSet<ValueSubkey>> = full.iter().collect();
+    assert_eq!(min_subkey_coverage(&DESIRED, &nodes), Some(5));
+
+    // Nothing desired means nothing to cover
+    assert_eq!(min_subkey_coverage(&[], &nodes), None);
+    // Desired but no nodes means zero coverage
+    assert_eq!(min_subkey_coverage(&DESIRED, &[]), Some(0));
+}
+
+#[cfg(feature = "stats")]
+pub fn test_end_coverage_accounting() {
+    info!("--- test_end_coverage_accounting ---");
+    let mut q = TransactionQualityAccounting::default();
+    q.record_end_coverage(None, 5);
+    assert_eq!(q.end_coverage.coverage_records, 0);
+
+    q.record_end_coverage(Some(5), 5);
+    q.record_end_coverage(Some(2), 5);
+    q.record_end_coverage(Some(7), 5);
+    assert_eq!(q.end_coverage.records_below_required_coverage, 1);
+    assert_eq!(q.end_coverage.coverage_records, 3);
+    assert_eq!(q.end_coverage.coverage_sum, 14);
+    assert_eq!(q.end_coverage.coverage_min, 2);
+}
+
+pub fn test_all() {
+    test_select_end_voters();
+    test_min_subkey_coverage_is_per_subkey();
+    #[cfg(feature = "stats")]
+    test_end_coverage_accounting();
+}

veilid-core/src/storage_manager/tests_storage_manager/test_transaction_stage_consensus.rs

@@ -0,0 +1,53 @@
+//! A record's stage consensus is the one live stage enough node transactions share; a node
+//! that never answered is marked Failed for bookkeeping and must not outvote that stage.
+
+use super::*;
+use crate::storage_manager::outbound_transaction_manager::{
+    record_consensus_stage, LocalNodeTransactionId, OutboundTransactionStage,
+};
+use std::collections::{BTreeSet, HashMap};
+
+fn ids(range: std::ops::Range<u64>) -> BTreeSet<LocalNodeTransactionId> {
+    range.map(LocalNodeTransactionId::new).collect()
+}
+
+pub fn test_failed_nodes_do_not_outvote_a_live_stage() {
+    info!("--- test_failed_nodes_do_not_outvote_a_live_stage ---");
+    let mut map = HashMap::new();
+    map.insert(OutboundTransactionStage::End, ids(0..5));
+    map.insert(OutboundTransactionStage::Failed, ids(5..10));
+    assert_eq!(
+        record_consensus_stage(&map, 5),
+        OutboundTransactionStage::End
+    );
+
+    let mut map = HashMap::new();
+    map.insert(OutboundTransactionStage::Failed, ids(0..10));
+    assert_eq!(
+        record_consensus_stage(&map, 5),
+        OutboundTransactionStage::Failed
+    );
+}
+
+pub fn test_two_live_stages_or_too_few_is_failed() {
+    info!("--- test_two_live_stages_or_too_few_is_failed ---");
+    let mut map = HashMap::new();
+    map.insert(OutboundTransactionStage::End, ids(0..5));
+    map.insert(OutboundTransactionStage::Commit, ids(5..10));
+    assert_eq!(
+        record_consensus_stage(&map, 5),
+        OutboundTransactionStage::Failed
+    );
+
+    let mut map = HashMap::new();
+    map.insert(OutboundTransactionStage::End, ids(0..4));
+    assert_eq!(
+        record_consensus_stage(&map, 5),
+        OutboundTransactionStage::Failed
+    );
+}
+
+pub fn test_all() {
+    test_failed_nodes_do_not_outvote_a_live_stage();
+    test_two_live_stages_or_too_few_is_failed();
+}

veilid-core/src/storage_manager/transaction.rs

@@ -114,7 +114,7 @@ impl StorageManager {
                     Err(_) => {
                         veilid_log!(self debug target:"network_result", "transaction begin contended on records: [{}] (source=background)",
                             opaque_record_keys.iter().map(|x| x.to_string()).collect::<Vec<_>>().join(", "));
-                        apibail_try_again!("transaction begin contended");
+                        tx_try_again!(self, BeginContended, "transaction begin contended");
                     }
                 }
             }
@@ -143,7 +143,7 @@ impl StorageManager {
 
         // Early rejection if dht is not online
         if !self.dht_is_online() {
-            apibail_try_again!("dht is not online");
+            tx_try_again!(self, NotOnline, "dht is not online");
         }
 
         // Resolve config
@@ -170,7 +170,11 @@ impl StorageManager {
 
                 // Can't begin a transaction on a record with pending offline subkey writes
                 if inner.offline_subkey_writes.contains_key(&opaque_record_key) {
-                    apibail_try_again!("record has pending offline writes, try again later");
+                    tx_try_again!(
+                        self,
+                        OfflineWrites,
+                        "record has pending offline writes, try again later"
+                    );
                 }
 
                 let Some(opened_record) = inner.opened_records.get(&opaque_record_key) else {
@@ -380,7 +384,7 @@ impl StorageManager {
                     }
                     Some(OutboundTransactionKind::Foreground) => {
                         veilid_log!(self debug target:"network_result", "transaction begin contended on record {} (foreground holder)", opaque_record_key);
-                        apibail_try_again!("transaction begin contended");
+                        tx_try_again!(self, BeginContended, "transaction begin contended");
                     }
                     None => {}
                 }
@@ -445,7 +449,11 @@ impl StorageManager {
 
         // Yield to foreground transaction activity
         if !self.background_transactions_allowed() {
-            apibail_try_again!("background transaction deferred for foreground activity");
+            tx_try_again!(
+                self,
+                BackgroundDeferred,
+                "background transaction deferred for foreground activity"
+            );
         }
 
         let local_record_store = self.get_local_record_store()?;
@@ -456,7 +464,11 @@ impl StorageManager {
             .record_lock_table
             .try_peek_locks(membership.record_set.clone())
         else {
-            apibail_try_again!("background transaction set peek contended");
+            tx_try_again!(
+                self,
+                BackgroundDeferred,
+                "background transaction set peek contended"
+            );
         };
 
         // Safety selection for temporarily-opened members comes from the triggering record.
@@ -490,7 +502,9 @@ impl StorageManager {
                     .get_transaction_by_record(opaque)
                     .is_some()
                 {
-                    apibail_try_again!(
+                    tx_try_again!(
+                        self,
+                        InTransaction,
                         "background transaction member already in a transaction: {}",
                         opaque
                     );
@@ -752,7 +766,7 @@ impl StorageManager {
 
         // Early rejection if dht is not online
         if !self.dht_is_online() {
-            apibail_try_again!("dht is not online");
+            tx_try_again!(self, NotOnline, "dht is not online");
         }
 
         let (transaction_keys, transaction_kind) = {
@@ -825,6 +839,13 @@ impl StorageManager {
         )
         .await;
 
+        veilid_stats!(
+            self.transaction_quality
+                .lock()
+                .mitigations
+                .transactions_committed += 1
+        );
+
         Ok(())
     }
 
@@ -833,6 +854,14 @@ impl StorageManager {
     /// or a transaction can not be performed at this time, this will fail.
     /// Returns Err(VeilidAPIError::TryAgain) if the transaction could not be ended at this time
     /// Returns Err(_) if the transaction end failed and resulted in rollback or drop
+    /// End a transaction over a set of records.
+    ///
+    /// End goes only to nodes that answered every Set and have none in flight, so
+    /// nothing can land at a voter after its End. Nodes missing a confirmation get
+    /// one targeted completion pass first; in-flight Sets get a wait bounded by the
+    /// RPC timeout; a record still short of the required voters fails with TryAgain
+    /// rather than committing torn. Non-voters are marked Failed and the rollback
+    /// guard rolls them back once End is recorded.
     #[cfg_attr(
         feature = "instrument",
         instrument(level = "trace", target = "stor", skip(self, records_lock))
@@ -846,23 +875,74 @@ impl StorageManager {
             records_lock.clone(),
             transaction_handle,
             async move {
-                let command_params_list = {
-                    let mut inner = self.inner.lock();
-
-                    // Obtain the outbound transaction manager
-                    let otm = &mut inner.outbound_transaction_manager;
-
-                    // Prepare for rollback
-                    otm.prepare_transact_end_params(transaction_handle)
-                        .inspect_err(|e| {
-                            veilid_log!(self debug "error in prepare_transact_end_params: {}", e);
-                        })?
-                };
-
                 let rpc_timeout = TimestampDuration::new_ms(
                     self.config().internal().network.rpc.timeout_ms.into(),
                 );
 
+                // Vote only where nothing can land after End; see the doc comment
+                let wait_deadline = Timestamp::now().later(rpc_timeout);
+                #[cfg(feature = "stats")]
+                let mut opt_wait_start: Option<Timestamp> = None;
+                let (command_params_list, non_voters) = loop {
+                    let plan = self
+                        .inner
+                        .lock()
+                        .outbound_transaction_manager
+                        .plan_transact_end(transaction_handle)
+                        .inspect_err(|e| {
+                            veilid_log!(self debug "error in plan_transact_end: {}", e);
+                        })?;
+                    if !plan.short {
+                        veilid_stats!(if let Some(wait_start) = opt_wait_start {
+                            self.transaction_quality()
+                                .lock()
+                                .record_end_wait(Timestamp::now().duration_since(wait_start));
+                        });
+                        break (plan.end_params, plan.non_voters);
+                    }
+                    if !plan.completion_params.is_empty() {
+                        veilid_stats!(
+                            self.transaction_quality()
+                                .lock()
+                                .mitigations
+                                .completion_pass_rpcs += plan.completion_params.len() as u64
+                        );
+                        let mut unord = FuturesUnordered::new();
+                        for command_params in plan.completion_params {
+                            unord.push(self.outbound_transact_command(command_params));
+                        }
+                        let mut results = vec![];
+                        while let Some(res) = unord.next().await {
+                            results.push(res?);
+                        }
+                        self.inner
+                            .lock()
+                            .outbound_transaction_manager
+                            .record_transact_completion_results(transaction_handle, results)?;
+                        continue;
+                    }
+                    if plan.outstanding > 0 && Timestamp::now() < wait_deadline {
+                        #[cfg(feature = "stats")]
+                        {
+                            opt_wait_start.get_or_insert_with(Timestamp::now);
+                        }
+                        sleep(END_QUIESCENCE_POLL_MS).await;
+                        continue;
+                    }
+                    tx_try_again!(
+                        self,
+                        EndIncomplete,
+                        "fewer than required complete nodes to end transaction {}",
+                        transaction_handle
+                    );
+                };
+
+                // Non-voters leave now; the rollback guard rolls them back after End
+                self.inner
+                    .lock()
+                    .outbound_transaction_manager
+                    .commit_end_plan(transaction_handle, &non_voters)?;
+
                 // End transactions on all records.
                 let mut unord = FuturesUnordered::new();
                 for command_params in command_params_list {
@@ -1158,7 +1238,7 @@ impl StorageManager {
 
         // Early rejection if dht is not online
         if !self.dht_is_online() {
-            apibail_try_again!("dht is not online");
+            tx_try_again!(self, NotOnline, "dht is not online");
         }
 
         // Send all rollbacks to the network
@@ -1169,6 +1249,13 @@ impl StorageManager {
         self.drop_transaction_and_wait_locked(&records_lock, transaction_handle)
             .await;
 
+        veilid_stats!(
+            self.transaction_quality
+                .lock()
+                .mitigations
+                .transactions_rolled_back += 1
+        );
+
         Ok(())
     }
 
@@ -1279,7 +1366,7 @@ impl StorageManager {
 
         // Early rejection if dht is not online
         if !self.dht_is_online() {
-            apibail_try_again!("dht is not online");
+            tx_try_again!(self, NotOnline, "dht is not online");
         }
 
         let command_params = {
@@ -1353,7 +1440,9 @@ impl StorageManager {
                 let begin_network_seq = record_state.begin_network_seq(subkey)?;
                 if begin_network_seq.is_some() {
                     // Sequence number existed at begin time, so we should have gotten a value
-                    apibail_try_again!(
+                    tx_try_again!(
+                        self,
+                        Other,
                         "sequence number existed at transaction begin, but no value was returned"
                     );
                 }
@@ -1405,7 +1494,7 @@ impl StorageManager {
 
         // Early rejection if dht is not online
         if !self.dht_is_online() {
-            apibail_try_again!("dht is not online");
+            tx_try_again!(self, NotOnline, "dht is not online");
         }
 
         // Build the signed value data for this set from the raw data and the record's writer
@@ -1571,7 +1660,7 @@ impl StorageManager {
                 let required = record_state.required_strict_consensus_count();
                 if updated_consensus.strict_consensus_count < required {
                     // Otherwise, ask the app to try the set again to continue to attempt consensus
-                    apibail_try_again!("set did not reach consensus");
+                    tx_try_again!(self, SetConsensus, "set did not reach consensus");
                 }
                 // Return that the set updated with consensus successfully
                 return Ok(None);
@@ -1834,6 +1923,12 @@ impl StorageManager {
         records_lock: Arc<StorageManagerRecordsLockGuard>,
         transaction_handle: OutboundTransactionHandle,
     ) {
+        veilid_stats!(
+            self.transaction_quality
+                .lock()
+                .mitigations
+                .transactions_failed += 1
+        );
         let (rollback_params, opt_cleanup) = {
             let mut inner = self.inner.lock();
             let otm = &mut inner.outbound_transaction_manager;

veilid-core/src/storage_manager/transaction_begin.rs

@@ -100,6 +100,8 @@ impl StorageManager {
             config.internal().network.dht.set_value_fanout as usize,
         );
         let required_strict_consensus_count = params.record_params.required_strict_consensus_count;
+        #[cfg(feature = "stats")]
+        let begin_start = Timestamp::now();
 
         let timeout = self
             .rpc_processor()
@@ -589,6 +591,20 @@ impl StorageManager {
             ctx.seqs.clone()
         };
 
+        veilid_stats!({
+            let accepted = ctx.accepted_rtts.len();
+            self.transaction_quality().lock().record_command(
+                TransactionCommandKind::Begin,
+                CommandOutcome {
+                    answered_valid: accepted as u64,
+                    answered_invalid: ctx.refused_nodes.len() as u64,
+                    short_of_required: accepted < required_strict_consensus_count,
+                    duration: Timestamp::now().duration_since(begin_start),
+                    ..Default::default()
+                },
+            );
+        });
+
         let result = OutboundTransactBeginResult {
             params,
             fanout_result,

veilid-core/src/storage_manager/transaction_command.rs

@@ -42,8 +42,10 @@ pub(in crate::storage_manager) enum TransactCommandDisposition {
     Valid,
     /// The node responded but the transaction is no longer valid
     Invalid,
-    /// The node was not waited for due to early consensus exit
+    /// The node did not answer within the RPC timeout
     Skipped,
+    /// Still in flight when the command returned; the answer is collected in the background
+    Pending,
 }
 
 /// The result of the outbound_transact_command operation
@@ -125,7 +127,6 @@ impl StorageManager {
                 command = ?params.command,
                 nodes = params.nodes.len(),
                 pre_authorized = params.pre_authorized_valid_count,
-                post_consensus_window_ms = tracing::field::Empty,
             ))
     )]
     pub(in crate::storage_manager) async fn outbound_transact_command(
@@ -179,8 +180,14 @@ impl StorageManager {
                 .ok_or_else(|| VeilidAPIError::internal("record does not exist in transaction"))?
         };
 
+        #[cfg(feature = "verbose-tracing")]
         let total_nodes = params.nodes.len();
 
+        #[cfg(feature = "stats")]
+        let cmd_start = Timestamp::now();
+        #[cfg(feature = "stats")]
+        let mut outcome = CommandOutcome::default();
+
         #[cfg(feature = "verbose-tracing")]
         let diag_start = {
             veilid_log!(self debug "TransactCmd start: cmd={} key={}{} nodes={} required_consensus={}",
@@ -193,306 +200,241 @@ impl StorageManager {
             Timestamp::now()
         };
 
-        // Retry unanswered nodes (with a new safety route each attempt) until
-        // consensus is reached or no progress is made.
         let mut per_node_results: Vec<OutboundTransactCommandPerNodeResult> = Vec::new();
         // Seed with auto-promoted nodes (e.g. Commit's no-op set); the fanout
         // can then trip consensus on fewer RPC responses.
         let mut valid_response_count = params.pre_authorized_valid_count;
-        let mut nodes_to_send = params.nodes.clone();
-        #[cfg(feature = "verbose-tracing")]
-        let mut attempt = 0usize;
+        let nodes_to_send = &params.nodes;
+        let mut pending_lnxids: HashSet<LocalNodeTransactionId> = HashSet::new();
 
-        loop {
-            if nodes_to_send.is_empty() {
-                break;
-            }
+        // Wait the full rpc timeout per node; consensus early-exit below ends the
+        // wait sooner, and a shorter bound drops in-flight answers under load
+        let rpc_timeout =
+            TimestampDuration::new_ms(self.config().internal().network.rpc.timeout_ms.into());
 
-            #[cfg(feature = "verbose-tracing")]
-            {
-                attempt += 1;
-                if attempt > 1 {
-                    veilid_log!(self debug "TransactCmd retry: cmd={} key={}{} attempt={} retrying_nodes={} valid_so_far={}/{}",
+        // Best-effort cleanup (rollback, required==0): fire RPCs in the background so
+        // the records lock isn't held on a dead node's full timeout.
+        let fire_and_forget = params.required_strict_consensus_count == 0;
+        let mut unord = FuturesUnordered::new();
+        let mut in_flight: HashSet<LocalNodeTransactionId> =
+            nodes_to_send.iter().map(|n| n.lnxid).collect();
+
+        veilid_stats!(outcome.rpcs_sent += nodes_to_send.len() as u64);
+
+        for n in nodes_to_send {
+            let registry = self.registry();
+            let lnxid = n.lnxid;
+            let rnxid = n.rnxid.clone();
+            let node_ref = n.node_ref.clone();
+            let descriptor = descriptor.clone();
+            let params = params.clone();
+            #[cfg(feature = "instrument")]
+            let command = params.command;
+            let node_start = Timestamp::now();
+            let per_node_timeout = rpc_timeout;
+
+            let fut = async move {
+                let rpc_processor = registry.rpc_processor();
+
+                let result = rpc_processor
+                    .rpc_call_transact_command(
+                        Destination::direct(
+                            node_ref.routing_domain_filtered(routing_domain),
+                            Some(params.safety_selection.clone()),
+                        ),
+                        params.opaque_record_key.clone(),
+                        descriptor,
+                        rnxid.xid(),
                         params.command,
-                        params.opaque_record_key,
-                        if let Some(subkey) = params.opt_subkey { format!(" #{}", subkey) } else { "".to_string() },
-                        attempt,
-                        nodes_to_send.len(),
-                        valid_response_count,
-                        params.required_strict_consensus_count,
-                    );
-                }
-            }
+                        params.opt_seqs.clone(),
+                        params.opt_subkey,
+                        params.opt_value.clone(),
+                    )
+                    .await
+                    .map_err(VeilidAPIError::from)?;
 
-            let prev_valid_count = valid_response_count;
-            #[cfg(feature = "verbose-tracing")]
-            let attempt_node_count = nodes_to_send.len();
+                let node_elapsed = Timestamp::now().duration_since(node_start);
 
-            // Wait the full rpc timeout per node; consensus early-exit below ends the
-            // wait sooner, and a shorter bound drops in-flight answers under load
-            let rpc_timeout =
-                TimestampDuration::new_ms(self.config().internal().network.rpc.timeout_ms.into());
-
-            // Best-effort cleanup (rollback, required==0): fire RPCs in the background so
-            // the records lock isn't held on a dead node's full timeout.
-            let fire_and_forget = params.required_strict_consensus_count == 0;
-            let mut unord = FuturesUnordered::new();
-
-            for n in &nodes_to_send {
-                let registry = self.registry();
-                let lnxid = n.lnxid;
-                let rnxid = n.rnxid.clone();
-                let node_ref = n.node_ref.clone();
-                let descriptor = descriptor.clone();
-                let params = params.clone();
-                #[cfg(feature = "instrument")]
-                let command = params.command;
-                let node_start = Timestamp::now();
-                let per_node_timeout = rpc_timeout;
-
-                let fut = async move {
-                    let rpc_processor = registry.rpc_processor();
-
-                    let result = rpc_processor
-                        .rpc_call_transact_command(
-                            Destination::direct(
-                                node_ref.routing_domain_filtered(routing_domain),
-                                Some(params.safety_selection.clone()),
-                            ),
-                            params.opaque_record_key.clone(),
-                            descriptor,
-                            rnxid.xid(),
-                            params.command,
-                            params.opt_seqs.clone(),
-                            params.opt_subkey,
-                            params.opt_value.clone(),
-                        )
-                        .await
-                        .map_err(VeilidAPIError::from)?;
-
-                    let node_elapsed = Timestamp::now().duration_since(node_start);
-
-                    match result {
-                        NetworkResult::Timeout | NetworkResult::NoConnection(_) => {
-                            #[cfg(feature = "verbose-tracing")]
-                            {
-                                let dial_info_str = node_ref
-                                    .node_info(routing_domain)
-                                    .map(|ni| {
-                                        let dids = ni.dial_info_detail_list();
-                                        if dids.is_empty() {
-                                            "no_dialinfo".to_string()
-                                        } else {
-                                            dids.iter()
-                                                .map(|d| format!("{}", d))
-                                                .collect::<Vec<_>>()
-                                                .join(",")
-                                        }
-                                    })
-                                    .unwrap_or_else(|| "no_nodeinfo".to_string());
-                                let caps = node_ref
-                                    .node_info(routing_domain)
-                                    .map(|ni| format!("{:?}", ni.capabilities()))
-                                    .unwrap_or_default();
-                                veilid_log!(registry debug "TransactCmd node NO_RESPONSE: cmd={} key={}{} node={} elapsed={} dial_info=[{}] caps={}",
-                                    params.command, params.opaque_record_key,
-                                    if let Some(subkey) = params.opt_subkey { format!(" #{}", subkey) } else { "".to_string() },
-                                    node_ref, node_elapsed,
-                                    dial_info_str, caps);
-                            }
-                            VeilidAPIResult::Ok(None)
+                match result {
+                    NetworkResult::Timeout | NetworkResult::NoConnection(_) => {
+                        #[cfg(feature = "verbose-tracing")]
+                        {
+                            let dial_info_str = node_ref
+                                .node_info(routing_domain)
+                                .map(|ni| {
+                                    let dids = ni.dial_info_detail_list();
+                                    if dids.is_empty() {
+                                        "no_dialinfo".to_string()
+                                    } else {
+                                        dids.iter()
+                                            .map(|d| format!("{}", d))
+                                            .collect::<Vec<_>>()
+                                            .join(",")
+                                    }
+                                })
+                                .unwrap_or_else(|| "no_nodeinfo".to_string());
+                            let caps = node_ref
+                                .node_info(routing_domain)
+                                .map(|ni| format!("{:?}", ni.capabilities()))
+                                .unwrap_or_default();
+                            veilid_log!(registry debug "TransactCmd node NO_RESPONSE: cmd={} key={}{} node={} elapsed={} dial_info=[{}] caps={}",
+                                params.command, params.opaque_record_key,
+                                if let Some(subkey) = params.opt_subkey { format!(" #{}", subkey) } else { "".to_string() },
+                                node_ref, node_elapsed,
+                                dial_info_str, caps);
                         }
-                        NetworkResult::ServiceUnavailable(_)
-                        | NetworkResult::AlreadyExists(_)
-                        | NetworkResult::InvalidMessage(_) => {
+                        VeilidAPIResult::Ok(None)
+                    }
+                    NetworkResult::ServiceUnavailable(_)
+                    | NetworkResult::AlreadyExists(_)
+                    | NetworkResult::InvalidMessage(_) => {
+                        #[cfg(feature = "verbose-tracing")]
+                        veilid_log!(registry debug "TransactCmd node result: cmd={} key={}{} node={} result=SERVICE_ERROR elapsed={}",
+                            params.command, params.opaque_record_key,
+                            if let Some(subkey) = params.opt_subkey { format!(" #{}", subkey) } else { "".to_string() },
+                            node_ref, node_elapsed,
+                        );
+                        Ok(None)
+                    }
+                    NetworkResult::Value(tva) => {
+                        let disposition = if tva.answer.transaction_valid {
                             #[cfg(feature = "verbose-tracing")]
-                            veilid_log!(registry debug "TransactCmd node result: cmd={} key={}{} node={} result=SERVICE_ERROR elapsed={}",
+                            veilid_log!(registry debug "TransactCmd node result: cmd={} key={}{} node={} result=VALID elapsed={}",
                                 params.command, params.opaque_record_key,
                                 if let Some(subkey) = params.opt_subkey { format!(" #{}", subkey) } else { "".to_string() },
                                 node_ref, node_elapsed,
                             );
-                            Ok(None)
-                        }
-                        NetworkResult::Value(tva) => {
-                            let disposition = if tva.answer.transaction_valid {
-                                #[cfg(feature = "verbose-tracing")]
-                                veilid_log!(registry debug "TransactCmd node result: cmd={} key={}{} node={} result=VALID elapsed={}",
-                                    params.command, params.opaque_record_key,
-                                    if let Some(subkey) = params.opt_subkey { format!(" #{}", subkey) } else { "".to_string() },
-                                    node_ref, node_elapsed,
-                                );
-                                TransactCommandDisposition::Valid
-                            } else {
-                                #[cfg(feature = "verbose-tracing")]
-                                veilid_log!(registry debug "TransactCmd node INVALID (no longer valid): cmd={} key={}{} node={} elapsed={}",
-                                    params.command, params.opaque_record_key,
-                                    if let Some(subkey) = params.opt_subkey { format!(" #{}", subkey) } else { "".to_string() },
-                                    node_ref, node_elapsed,
-                                );
-                                TransactCommandDisposition::Invalid
-                            };
+                            TransactCommandDisposition::Valid
+                        } else {
+                            #[cfg(feature = "verbose-tracing")]
+                            veilid_log!(registry debug "TransactCmd node INVALID (no longer valid): cmd={} key={}{} node={} elapsed={}",
+                                params.command, params.opaque_record_key,
+                                if let Some(subkey) = params.opt_subkey { format!(" #{}", subkey) } else { "".to_string() },
+                                node_ref, node_elapsed,
+                            );
+                            TransactCommandDisposition::Invalid
+                        };
 
-                            // Only record RTT for Valid responses — Invalid means
-                            // the server rejected the transaction, which can be a
-                            // fast/cheap response that doesn't reflect real RTT.
-                            let opt_rtt = matches!(disposition, TransactCommandDisposition::Valid)
-                                .then_some(node_elapsed);
+                        // Only record RTT for Valid responses — Invalid means
+                        // the server rejected the transaction, which can be a
+                        // fast/cheap response that doesn't reflect real RTT.
+                        let opt_rtt = matches!(disposition, TransactCommandDisposition::Valid)
+                            .then_some(node_elapsed);
 
-                            Ok(Some(OutboundTransactCommandPerNodeResult {
-                                lnxid,
-                                rnxid,
-                                disposition,
-                                opt_seqs: tva.answer.opt_seqs,
-                                opt_subkey: tva.answer.opt_subkey,
-                                opt_value: tva.answer.opt_value,
-                                opt_expiration: tva.answer.opt_expiration,
-                                opt_rtt,
-                            }))
-                        }
+                        Ok(Some(OutboundTransactCommandPerNodeResult {
+                            lnxid,
+                            rnxid,
+                            disposition,
+                            opt_seqs: tva.answer.opt_seqs,
+                            opt_subkey: tva.answer.opt_subkey,
+                            opt_value: tva.answer.opt_value,
+                            opt_expiration: tva.answer.opt_expiration,
+                            opt_rtt,
+                        }))
                     }
-                };
-                #[cfg(feature = "instrument")]
-                let fut = fut.instrument(tracing::trace_span!(
-                    target: "dht",
-                    "outbound_transact_command per-node",
-                    command = ?command,
-                ));
-                // RTT-bounded per-node wait; timeout reports no-response (retry-eligible).
-                let fut = async move {
-                    match Box::pin(fut.timeout_duration(per_node_timeout)).await {
-                        Ok(inner) => inner,
-                        Err(_) => VeilidAPIResult::Ok(None),
-                    }
-                };
-                if fire_and_forget {
-                    self.background_operation_processor.add_future(async move {
-                        let _ = fut.await;
-                    });
-                } else {
-                    unord.push(Box::pin(fut));
                 }
-            }
+            };
+            #[cfg(feature = "instrument")]
+            let fut = fut.instrument(tracing::trace_span!(
+                target: "dht",
+                "outbound_transact_command per-node",
+                command = ?command,
+            ));
+            // Bounded per-node wait; a timeout reports no response
+            let fut = async move {
+                let res = match Box::pin(fut.timeout_duration(per_node_timeout)).await {
+                    Ok(inner) => inner,
+                    Err(_) => VeilidAPIResult::Ok(None),
+                };
+                (lnxid, res)
+            };
             if fire_and_forget {
-                // RPCs fired in the background; no consensus to await.
-                break;
+                self.background_operation_processor.add_future(async move {
+                    let _ = fut.await;
+                });
+            } else {
+                unord.push(Box::pin(fut));
             }
+        }
+        if fire_and_forget {
+            // RPCs fired in the background; no consensus to await
+            return Ok(self.finish_transact_command(
+                params,
+                per_node_results,
+                pending_lnxids,
+                #[cfg(feature = "stats")]
+                outcome,
+                #[cfg(feature = "stats")]
+                cmd_start,
+                valid_response_count,
+            ));
+        }
 
-            // Collect results. Once consensus is reached, keep collecting up to
-            // a per-node-RTT-bounded post-consensus deadline; anything still in
-            // flight at deadline is detached so rpc_processor sees natural
-            // per-RPC completion (no abandoned-wait stigma on slow nodes).
+        // Collect answers until consensus; stragglers settle in the background
+        #[cfg(feature = "verbose-tracing")]
+        let mut responded_xids = HashSet::new();
+
+        while let Some((lnxid, result)) = unord.next().await {
+            in_flight.remove(&lnxid);
+            let opt_pnr = result.inspect_err(|e| {
+                veilid_log!(self error target:"network_result",
+                    "Error performing transaction command: {}", e);
+            })?;
+
+            let Some(pnr) = opt_pnr else {
+                // No answer within the wait
+                veilid_stats!(outcome.no_response += 1);
+                continue;
+            };
+
+            if pnr.disposition == TransactCommandDisposition::Valid {
+                valid_response_count += 1;
+                veilid_stats!(outcome.answered_valid += 1);
+            } else {
+                veilid_stats!(outcome.answered_invalid += 1);
+            }
             #[cfg(feature = "verbose-tracing")]
-            let attempt_node_count_diag = attempt_node_count;
-            let mut attempt_responded_xids = HashSet::new();
-            let mut consensus_reached = false;
-            let mut post_consensus_deadline: Option<Timestamp> = None;
-            let rpc_timeout_us = ms_to_us(self.config().internal().network.rpc.timeout_ms);
+            responded_xids.insert(pnr.lnxid);
+            per_node_results.push(pnr);
 
-            loop {
-                let result = match post_consensus_deadline {
-                    Some(deadline) => {
-                        let now = Timestamp::now_non_decreasing();
-                        if now >= deadline {
-                            break;
-                        }
-                        let remaining = deadline
-                            .duration_since(now)
-                            .max(TimestampDuration::new_ms(1));
-                        match unord.next().timeout_duration(remaining).await {
-                            Ok(Some(x)) => x,
-                            Ok(None) => break,
-                            Err(_) => break,
-                        }
-                    }
-                    None => match unord.next().await {
-                        Some(x) => x,
-                        None => break,
-                    },
-                };
-
-                let opt_pnr = result.inspect_err(|e| {
-                    veilid_log!(self error target:"network_result",
-                        "Error performing transaction command: {}", e);
-                })?;
-
-                let Some(pnr) = opt_pnr else {
-                    // None (timeout/no-response): excluded from responded set, eligible for retry.
-                    continue;
-                };
-
-                if pnr.disposition == TransactCommandDisposition::Valid {
-                    valid_response_count += 1;
-                }
-                attempt_responded_xids.insert(pnr.lnxid);
-                per_node_results.push(pnr);
-
-                // Arm the post-consensus deadline once, at first consensus
-                // - bound: max of the fastest required_strict_consensus_count Valid RTTs
-                // - capped by POST_CONSENSUS_GRACE_MS, for the answer wave trailing
-                //   consensus rather than dead stragglers
-                if !consensus_reached
-                    && valid_response_count >= params.required_strict_consensus_count
-                {
-                    consensus_reached = true;
-                    let mut valid_rtts_us: Vec<u64> = per_node_results
-                        .iter()
-                        .filter(|pnr| pnr.disposition == TransactCommandDisposition::Valid)
-                        .filter_map(|pnr| pnr.opt_rtt.map(|rtt| rtt.as_u64()))
-                        .collect();
-                    valid_rtts_us.sort_unstable();
-                    let take = params
-                        .required_strict_consensus_count
-                        .min(valid_rtts_us.len());
-                    let max_bound_us: u64 = valid_rtts_us
-                        .into_iter()
-                        .take(take)
-                        .max()
-                        .unwrap_or(0)
-                        .saturating_mul(POST_CONSENSUS_RTT_FACTOR)
-                        .min(rpc_timeout_us)
-                        .min(ms_to_us(POST_CONSENSUS_GRACE_MS as u32));
-                    let now = Timestamp::now_non_decreasing();
-                    post_consensus_deadline =
-                        Some(Timestamp::new(now.as_u64().saturating_add(max_bound_us)));
-                    #[cfg(feature = "instrument")]
-                    tracing::Span::current()
-                        .record("post_consensus_window_ms", max_bound_us / 1000);
-                    #[cfg(feature = "verbose-tracing")]
-                    {
-                        let responded = attempt_responded_xids.len();
-                        veilid_log!(self debug "TransactCmd consensus reached: cmd={} key={}{} valid={}/{} responded={}/{} post_consensus_window_ms={}",
-                            params.command,
-                            params.opaque_record_key,
-                            if let Some(subkey) = params.opt_subkey { format!(" #{}", subkey) } else { "".to_string() },
-                            valid_response_count,
-                            params.required_strict_consensus_count,
-                            responded,
-                            attempt_node_count_diag,
-                            max_bound_us / 1000,
-                        );
-                    }
-                }
+            if valid_response_count >= params.required_strict_consensus_count {
+                #[cfg(feature = "verbose-tracing")]
+                veilid_log!(self debug "TransactCmd consensus reached: cmd={} key={}{} valid={}/{} responded={}/{}",
+                    params.command,
+                    params.opaque_record_key,
+                    if let Some(subkey) = params.opt_subkey { format!(" #{}", subkey) } else { "".to_string() },
+                    valid_response_count,
+                    params.required_strict_consensus_count,
+                    responded_xids.len(),
+                    total_nodes,
+                );
+                break;
             }
+        }
 
-            // Pending futures (deadline expired) are dropped here. The RPC
-            // questions inside are protected by `RPCProcessor`'s race-completion
-            // pool, so the answers still arrive and complete naturally.
+        veilid_stats!({
+            let n = unord.len() as u64;
+            outcome.abandoned_in_flight += n;
+            if n > 0 {
+                outcome.post_consensus_window_expired = true;
+            }
+        });
+        // In-flight Set answers still settle into node state; other commands drop
+        // theirs, and the reply pool completes the question either way
+        if params.command == TransactCommand::Set && !unord.is_empty() {
+            pending_lnxids.extend(in_flight.drain());
+            let registry = self.registry();
+            let subkey = params.opt_subkey.unwrap_or_log();
+            let value = params.opt_value.clone().unwrap_or_log();
+            self.background_operation_processor.add_future(async move {
+                while let Some((lnxid, res)) = unord.next().await {
+                    registry
+                        .storage_manager()
+                        .record_late_transact_set_result(lnxid, subkey, &value, res);
+                }
+            });
+        } else {
             drop(unord);
-
-            // If consensus reached, we're done — don't retry.
-            if consensus_reached {
-                break;
-            }
-
-            // Check if progress was made this attempt
-            if valid_response_count <= prev_valid_count {
-                // No new valid responses — stop retrying
-                break;
-            }
-
-            // Progress was made but consensus not yet reached.
-            // Identify non-responding nodes from this attempt for retry.
-            nodes_to_send.retain(|n| !attempt_responded_xids.contains(&n.lnxid));
         }
 
         // Log summary
@@ -505,7 +447,7 @@ impl StorageManager {
             let responded_count = per_node_results.len();
             let no_response_count = total_nodes.saturating_sub(responded_count);
             let diag_elapsed = Timestamp::now().duration_since(diag_start);
-            veilid_log!(self debug "TransactCmd done: cmd={} key={}{} valid={} invalid={} no_response={} skipped={} total={} required={} elapsed={} attempts={} result={}",
+            veilid_log!(self debug "TransactCmd done: cmd={} key={}{} valid={} invalid={} no_response={} skipped={} total={} required={} elapsed={} result={}",
                 params.command,
                 params.opaque_record_key,
                 if let Some(subkey) = params.opt_subkey { format!(" #{}", subkey) } else { "".to_string() },
@@ -516,22 +458,58 @@ impl StorageManager {
                 total_nodes,
                 params.required_strict_consensus_count,
                 diag_elapsed,
-                attempt,
                 if valid_response_count >= params.required_strict_consensus_count { "CONSENSUS" } else { "FAILED" },
             );
         }
 
-        // Add Skipped entries for nodes that never responded across all attempts
+        Ok(self.finish_transact_command(
+            params,
+            per_node_results,
+            pending_lnxids,
+            #[cfg(feature = "stats")]
+            outcome,
+            #[cfg(feature = "stats")]
+            cmd_start,
+            valid_response_count,
+        ))
+    }
+
+    /// Record the command's outcome and fill in the nodes that never answered:
+    /// Pending if their answer is still being collected, Skipped if the wait ran out
+    fn finish_transact_command(
+        &self,
+        params: Arc<OutboundTransactCommandParams>,
+        mut per_node_results: Vec<OutboundTransactCommandPerNodeResult>,
+        pending_lnxids: HashSet<LocalNodeTransactionId>,
+        #[cfg(feature = "stats")] mut outcome: CommandOutcome,
+        #[cfg(feature = "stats")] cmd_start: Timestamp,
+        valid_response_count: usize,
+    ) -> OutboundTransactCommandResult {
+        #[cfg(not(feature = "stats"))]
+        let _ = valid_response_count;
+        veilid_stats!({
+            outcome.short_of_required = params.required_strict_consensus_count > 0
+                && valid_response_count < params.required_strict_consensus_count;
+            outcome.duration = Timestamp::now().duration_since(cmd_start);
+            self.transaction_quality()
+                .lock()
+                .record_command(params.command.into(), outcome);
+        });
+
         let responded_lnxids: HashSet<_> = per_node_results.iter().map(|pnr| pnr.lnxid).collect();
-        if responded_lnxids.len() < total_nodes {
-            let skipped: Vec<_> = params
+        if responded_lnxids.len() < params.nodes.len() {
+            let unanswered: Vec<_> = params
                 .nodes
                 .iter()
                 .filter(|n| !responded_lnxids.contains(&n.lnxid))
                 .map(|n| OutboundTransactCommandPerNodeResult {
                     lnxid: n.lnxid,
                     rnxid: n.rnxid.clone(),
-                    disposition: TransactCommandDisposition::Skipped,
+                    disposition: if pending_lnxids.contains(&n.lnxid) {
+                        TransactCommandDisposition::Pending
+                    } else {
+                        TransactCommandDisposition::Skipped
+                    },
                     opt_seqs: None,
                     opt_subkey: None,
                     opt_value: None,
@@ -539,7 +517,7 @@ impl StorageManager {
                     opt_rtt: None,
                 })
                 .collect();
-            per_node_results.extend(skipped);
+            per_node_results.extend(unanswered);
         }
 
         // Sort per node results by distance from record to assist with strict consensus checking
@@ -556,10 +534,31 @@ impl StorageManager {
             dist_a.cmp(&dist_b)
         });
 
-        Ok(OutboundTransactCommandResult {
+        OutboundTransactCommandResult {
             params,
             per_node_results,
-        })
+        }
+    }
+
+    /// A Set answer that arrived after its command returned
+    fn record_late_transact_set_result(
+        &self,
+        lnxid: LocalNodeTransactionId,
+        subkey: ValueSubkey,
+        value: &Arc<SignedValueData>,
+        res: VeilidAPIResult<Option<OutboundTransactCommandPerNodeResult>>,
+    ) {
+        let opt_pnr = match res {
+            Ok(opt_pnr) => opt_pnr,
+            Err(e) => {
+                veilid_log!(self debug "late transaction set answer failed: {}", e);
+                None
+            }
+        };
+        let mut inner = self.inner.lock();
+        inner
+            .outbound_transaction_manager
+            .record_late_transact_set_result(lnxid, subkey, value, opt_pnr);
     }
 
     ////////////////////////////////////////////////////////////////////////

veilid-core/src/tests/mocks/fixture_veilid_core.rs

@@ -250,8 +250,8 @@ pub fn fixture_startup_options() -> VeilidStartupOptions {
         .unwrap()
 }
 
-static VEILID_TEST_INSTANCE: LazyLock<Arc<core::sync::atomic::AtomicUsize>> =
-    LazyLock::new(|| Arc::new(core::sync::atomic::AtomicUsize::new(0)));
+static VEILID_TEST_INSTANCE: LazyLock<Arc<AtomicUsize>> =
+    LazyLock::new(|| Arc::new(AtomicUsize::new(0)));
 
 #[must_use]
 pub fn fixture_veilid_test_instance() -> String {

veilid-core/src/veilid_api/debug.rs

@@ -308,6 +308,7 @@ enum DebugRouteSubcommand {
         /// - stability: `rel` or `low`
         /// - hop count: positive integer
         /// - direction: `in` or `out`
+        /// - avoid: node id(s) that must not be hops
         #[arg(allow_hyphen_values = true, value_name = "allocate_arg")]
         params: Vec<String>,
     },
@@ -359,6 +360,16 @@ enum DebugRouteSubcommand {
         #[arg(value_name = "route_id")]
         route_id: String,
     },
+    /// Release the automatic safety route pool and allocate a fresh one now.
+    #[command(help_template = DEBUG_HELP_TEMPLATE)]
+    Reallocate,
+    /// Show each hop's dial info and the contact methods between adjacent hops per sequencing.
+    #[command(help_template = DEBUG_HELP_TEMPLATE)]
+    Diag {
+        /// Allocated route id (full or prefix).
+        #[arg(value_name = "route_id")]
+        route_id: String,
+    },
 }
 
 /// Subcommands supported by `record`.
@@ -1963,6 +1974,7 @@ impl VeilidAPI {
         let mut stability = Stability::default();
         let mut hop_count = default_route_hop_count;
         let mut directions = DirectionSet::all();
+        let mut avoid_nodes = Vec::new();
 
         while ai < args.len() {
             if let Ok(seq) =
@@ -1981,6 +1993,10 @@ impl VeilidAPI {
                 get_debug_argument_at(&args, ai, "debug_route", "direction_set", get_direction_set)
             {
                 directions = ds;
+            } else if let Ok(node_id) =
+                get_debug_argument_at(&args, ai, "debug_route", "avoid_node_id", get_node_id)
+            {
+                avoid_nodes.push(node_id);
             } else {
                 return Ok(format!("Invalid argument specified: {}", args[ai]));
             }
@@ -1994,7 +2010,7 @@ impl VeilidAPI {
             stability,
             sequencing,
             directions,
-            avoid_nodes: Vec::new(),
+            avoid_nodes,
             automatic: false,
         };
         let out = match rss.allocate_route(allocate_route_params).await {
@@ -2237,9 +2253,134 @@ impl VeilidAPI {
             DebugRouteSubcommand::List => self.debug_route_list(vec![]),
             DebugRouteSubcommand::Import { blob } => self.debug_route_import(vec![blob]),
             DebugRouteSubcommand::Test { route_id } => self.debug_route_test(vec![route_id]).await,
+            DebugRouteSubcommand::Diag { route_id } => self.debug_route_diag(vec![route_id]),
+            DebugRouteSubcommand::Reallocate => self.debug_route_reallocate().await,
         }
     }
 
+    /// Drop every automatic unpublished route and refill the pool immediately, so a run on a
+    /// warmed-up node can be compared against a cold start
+    async fn debug_route_reallocate(&self) -> VeilidAPIResult<String> {
+        let registry = self.core_context()?.registry();
+        let routing_table = registry.routing_table();
+        let (released, allocated) = routing_table
+            .get_specific_routing_domain_controller::<PublicInternetRoutingDomainController>()
+            .reallocate_safety_routes()
+            .await
+            .map_err(VeilidAPIError::internal)?;
+        Ok(format!("released {}, allocated {}", released, allocated))
+    }
+
+    /// Per-leg contact methods for an allocated route, computed from the peer info we hold
+    fn debug_route_diag(&self, args: Vec<String>) -> VeilidAPIResult<String> {
+        // <route id>
+        let registry = self.core_context()?.registry();
+        let routing_table = registry.routing_table();
+        let rss = routing_table.route_spec_store();
+
+        let route_id = get_debug_argument_at(
+            &args,
+            0,
+            "debug_route",
+            "route_id",
+            get_route_id(registry.clone(), true, false),
+        )?;
+        let Some(info) = rss
+            .get_allocated_route_test_info(&AllocatedRouteSetId::from_route_id(route_id.clone()))
+        else {
+            return Ok("Route not found".to_owned());
+        };
+        let Some(our_pi) = routing_table.get_published_peer_info(RoutingDomain::PublicInternet)
+        else {
+            return Ok("No published PublicInternet peer info".to_owned());
+        };
+
+        let mut out = format!(
+            "Route {} hops={} orderings={:?}\n",
+            route_id,
+            info.hops.len(),
+            info.orderings
+        );
+
+        // Legs run self -> hop1 -> ... -> hopN and back
+        let mut legs: Vec<(String, Arc<PeerInfo>)> = vec![("self".to_owned(), our_pi)];
+        for (i, hop) in info.hops.iter().enumerate() {
+            let name = format!("hop{}", i + 1);
+            let Some(pi) = hop.get_peer_info(RoutingDomain::PublicInternet) else {
+                out.push_str(&format!(
+                    "  {}: {} has no PublicInternet peer info\n",
+                    name, hop
+                ));
+                return Ok(out);
+            };
+            let dial_info = pi
+                .node_info()
+                .dial_info_detail_list()
+                .iter()
+                .map(|did| did.to_string())
+                .collect::<Vec<_>>()
+                .join(", ");
+            let relays = pi
+                .node_info()
+                .relay_info_list()
+                .iter()
+                .map(|ri| format!("{}:{:?}", ri.node_ids(), ri.relay_kind()))
+                .collect::<Vec<_>>()
+                .join(", ");
+            out.push_str(&format!(
+                "  {}: {} dialinfo=[{}] relays=[{}]\n",
+                name,
+                hop.best_node_id(),
+                dial_info,
+                relays
+            ));
+            legs.push((name, pi));
+        }
+
+        let probes = [
+            ("ENO", Sequencing::EnsureOrdered, DialInfoFilter::all()),
+            ("PRU", Sequencing::PreferUnordered, DialInfoFilter::all()),
+            (
+                "PRU/udp",
+                Sequencing::PreferUnordered,
+                DialInfoFilter::ensure_ordering(SequenceOrdering::Unordered),
+            ),
+        ];
+        let mut describe_leg = |a: &(String, Arc<PeerInfo>), b: &(String, Arc<PeerInfo>)| {
+            let cms = probes
+                .iter()
+                .map(|(label, sequencing, dial_info_filter)| {
+                    let cm = routing_table.get_best_contact_method(
+                        RoutingDomain::PublicInternet,
+                        ContactMethodRequest {
+                            peer_a: a.1.clone(),
+                            peer_a_published: true,
+                            peer_b: b.1.clone(),
+                            dial_info_filter: *dial_info_filter,
+                            sequencing: *sequencing,
+                        },
+                    );
+                    format!(
+                        "{}={}",
+                        label,
+                        cm.map(|cm| cm.to_string())
+                            .unwrap_or_else(|| "none".to_owned())
+                    )
+                })
+                .collect::<Vec<_>>()
+                .join(" ");
+            out.push_str(&format!("  {}->{}: {}\n", a.0, b.0, cms));
+        };
+        for pair in legs.windows(2) {
+            describe_leg(&pair[0], &pair[1]);
+        }
+        for pair in legs.windows(2).rev() {
+            describe_leg(&pair[1], &pair[0]);
+        }
+
+        Ok(out)
+    }
+
     fn debug_record_list(&self, args: Vec<String>) -> VeilidAPIResult<String> {
         // <local|remote>
         let registry = self.core_context()?.registry();

veilid-core/src/veilid_api/mock/transactions.rs

@@ -1,5 +1,4 @@
 use super::*;
-use std::sync::atomic::{AtomicU64, Ordering};
 use std::sync::LazyLock;
 
 /// Identifies one open transaction on a simulated node.

veilid-core/src/veilid_api/routing_context.rs

@@ -43,6 +43,14 @@ impl fmt::Debug for RoutingContext {
     }
 }
 
+/// Blob results in the api log: length plus a truncated human-readable preview
+fn fmt_blob_result(ret: &VeilidAPIResult<Bytes>) -> String {
+    match ret {
+        Ok(b) => format!("Ok(len={} {})", b.len(), human_byte_data(b, Some(64))),
+        Err(e) => format!("Err({})", e),
+    }
+}
+
 impl RoutingContext {
     ////////////////////////////////////////////////////////////////
 
@@ -277,7 +285,7 @@ impl RoutingContext {
             let recorder = DurationRecorder::new("RoutingContext::app_call", |name, start| {
                 veilid_log!(self debug
                     "{}[start={:#}](self: {:?}, target: {:?}, message_len: {})", name, start, self, target, message_len);
-                veilid_log!(self trace "message: {:?}", message);
+                veilid_log!(self trace "message: len={} {}", message.len(), human_byte_data(&message, Some(64)));
             });
             recorder.record_fut(
                 async {
@@ -288,7 +296,7 @@ impl RoutingContext {
                 },
                 |name, start, dur, ret| {
                     veilid_log!(self debug
-                        "{}[start={:#} dur={:#}](ret: {:?})", name, start, dur, ret);
+                        "{}[start={:#} dur={:#}](ret: {})", name, start, dur, fmt_blob_result(&ret));
                     ret
                 },
             ).await
@@ -362,7 +370,7 @@ impl RoutingContext {
             let recorder = DurationRecorder::new("RoutingContext::app_message", |name, start| {
                 veilid_log!(self debug
                     "{}[start={:#}](self: {:?}, target: {:?}, message_len: {})", name, start, self, target, message_len);
-                veilid_log!(self trace "message: {:?}", message);
+                veilid_log!(self trace "message: len={} {}", message.len(), human_byte_data(&message, Some(64)));
             });
             recorder.record_fut(
                 async {

veilid-core/src/veilid_api/types/atomic_option_timestamp.rs

@@ -1,5 +1,3 @@
-use std::sync::atomic::AtomicU64;
-
 use super::*;
 
 /// Atomic wrapper for optional timestamps used in structs so we can avoid locks

veilid-core/src/veilid_api/types/atomic_timestamp.rs

@@ -1,5 +1,3 @@
-use std::sync::atomic::AtomicU64;
-
 use super::*;
 
 /// Atomic wrapper for timestamps used in structs so we can avoid locks

veilid-core/src/veilid_api/types/safety.rs

@@ -20,6 +20,25 @@ pub enum Sequencing {
 }
 
 impl Sequencing {
+    /// The ordering a route allocated for this sequencing carries
+    pub fn preferred_ordering(&self) -> SequenceOrdering {
+        match self {
+            Sequencing::PreferUnordered => SequenceOrdering::Unordered,
+            Sequencing::PreferOrdered | Sequencing::EnsureOrdered => SequenceOrdering::Ordered,
+        }
+    }
+
+    /// What to send over a route carrying only `orderings`: a preference the route cannot
+    /// honor becomes the one it has, a requirement never changes
+    pub fn for_route_orderings(&self, orderings: SequenceOrderingSet) -> Sequencing {
+        match self {
+            Sequencing::PreferUnordered if !orderings.contains(SequenceOrdering::Unordered) => {
+                Sequencing::PreferOrdered
+            }
+            _ => *self,
+        }
+    }
+
     /// Returns true if the given ordering satisfies this sequencing requirement.
     #[must_use]
     pub fn matches_ordering(&self, ordering: SequenceOrdering) -> bool {

veilid-core/src/veilid_api/types/timestamp.rs

@@ -1,7 +1,6 @@
 //! Monotonically non-decreasing and monotonically increasing microseconds-since epoch timestamp
 
 use super::*;
-use core::sync::atomic::{AtomicU64, Ordering};
 
 aligned_u64_type!(Timestamp);
 aligned_u64_type_default_debug_impl!(Timestamp);

veilid-remote-api/smoketest/Cargo.lock

@@ -543,9 +543,9 @@ dependencies = [
 
 [[package]]
 name = "cc"
-version = "1.4.5"
+version = "1.4.6"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "005ec2760ca554fae18df7a11195552ec576cd665632a881bc011d5bb2fd4d80"
+checksum = "a3eb0f42d6c360dc3f8a821f6bf2fdea7f72bfd36b3076eb0e6d1e9e0752fff4"
 dependencies = [
  "find-msvc-tools",
  "shlex",

veilid-tools/public-api.txt

@@ -2,6 +2,7 @@ pub mod veilid_tools
 pub use veilid_tools::<<tokio_util::compat::*>>
 pub use veilid_tools::Arc
 pub use veilid_tools::AtomicBool
+pub use veilid_tools::AtomicU64
 pub use veilid_tools::AtomicUsize
 pub use veilid_tools::BTreeMap
 pub use veilid_tools::BTreeSet
@@ -822,6 +823,7 @@ pub trait veilid_tools::network_result::NetworkResultResultExt<T, E>
 pub fn veilid_tools::network_result::NetworkResultResultExt::into_result_network_result(self) -> core::result::Result<veilid_tools::NetworkResult<T>, E>
 impl<T, E> veilid_tools::NetworkResultResultExt<T, E> for veilid_tools::NetworkResult<core::result::Result<T, E>>
 pub fn veilid_tools::NetworkResult<core::result::Result<T, E>>::into_result_network_result(self) -> core::result::Result<veilid_tools::NetworkResult<T>, E>
+pub fn veilid_tools::network_result::is_connection_refused(&core::io::error::Error) -> bool
 pub mod veilid_tools::pin
 pub type veilid_tools::pin::PinBox<T> = core::pin::Pin<alloc::boxed::Box<T>>
 pub type veilid_tools::pin::PinBoxFuture<'a, T> = veilid_tools::PinBox<(dyn core::future::future::Future<Output = T> + core::marker::Send + 'a)>
@@ -2085,6 +2087,7 @@ pub fn veilid_tools::ipv6addr_is_unicast_site_local(&core::net::ip_addr::Ipv6Add
 pub fn veilid_tools::ipv6addr_is_unique_local(&core::net::ip_addr::Ipv6Addr) -> bool
 pub fn veilid_tools::ipv6addr_is_unspecified(&core::net::ip_addr::Ipv6Addr) -> bool
 pub fn veilid_tools::ipv6addr_multicast_scope(&core::net::ip_addr::Ipv6Addr) -> core::option::Option<veilid_tools::Ipv6MulticastScope>
+pub fn veilid_tools::is_connection_refused(&core::io::error::Error) -> bool
 pub fn veilid_tools::is_ipc_socket_path<P: core::convert::AsRef<std::path::Path>>(P) -> bool
 pub fn veilid_tools::is_ipv4_supported() -> bool
 pub fn veilid_tools::is_ipv6_supported() -> bool

veilid-tools/smoketest/Cargo.lock

@@ -292,9 +292,9 @@ checksum = "37b2a672a2cb129a2e41c10b1224bb368f9f37a2b16b612598138befd7b37eb5"
 
 [[package]]
 name = "cc"
-version = "1.4.5"
+version = "1.4.6"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "005ec2760ca554fae18df7a11195552ec576cd665632a881bc011d5bb2fd4d80"
+checksum = "a3eb0f42d6c360dc3f8a821f6bf2fdea7f72bfd36b3076eb0e6d1e9e0752fff4"
 dependencies = [
  "find-msvc-tools",
  "shlex",

veilid-tools/src/lib.rs

@@ -194,7 +194,7 @@ pub use std::str::FromStr;
 #[doc(no_inline)]
 pub use std::string::{String, ToString};
 #[doc(no_inline)]
-pub use std::sync::atomic::{AtomicBool, AtomicUsize, Ordering};
+pub use std::sync::atomic::{AtomicBool, AtomicU64, AtomicUsize, Ordering};
 #[doc(no_inline)]
 pub use std::sync::{Arc, LazyLock, Weak};
 #[doc(no_inline)]

veilid-tools/src/log_unwrap.rs

@@ -223,7 +223,7 @@ fn failed_with(msg: &str, value: &dyn fmt::Debug) -> ! {
             location.line(),
             location.column(),
             msg,
-            &value
+            value
         );
     }
 
@@ -252,7 +252,7 @@ fn discarded_with(msg: &str, value: &dyn fmt::Debug) {
             location.line(),
             location.column(),
             msg,
-            &value
+            value
         );
     }
 

veilid-tools/src/network_result.rs

@@ -31,6 +31,19 @@ pub trait IoNetworkResultExt<T> {
     fn into_network_result(self) -> io::Result<NetworkResult<T>>;
 }
 
+/// A refused connect proves the path carried packets both ways (an RST or ICMP unreachable
+/// came back). Keyed on the os error only: wasm reports every failure as refused by kind.
+#[must_use]
+pub fn is_connection_refused(e: &io::Error) -> bool {
+    #[cfg(unix)]
+    let refused = libc::ECONNREFUSED;
+    #[cfg(windows)]
+    let refused = winapi::um::winsock2::WSAECONNREFUSED;
+    #[cfg(not(any(unix, windows)))]
+    let refused = i32::MIN;
+    e.raw_os_error() == Some(refused)
+}
+
 fn io_error_kind_from_error<T>(e: io::Error) -> io::Result<NetworkResult<T>> {
     #[cfg(not(all(target_arch = "wasm32", target_os = "unknown")))]
     if let Some(os_err) = e.raw_os_error() {

veilid-wasm/tests/extension/background.ts

@@ -24,7 +24,7 @@ chrome.runtime.onMessageExternal.addListener(
     }
     (async () => {
       try {
-        const results = await runSuites(message.suites ?? [], 'extension');
+        const results = await runSuites(message.suites ?? [], 'extension', undefined, message.caseFilter);
         sendResponse({ type: 'done', ok: true, results });
       } catch (err) {
         sendResponse({ type: 'done', ok: false, error: String(err) });

veilid-wasm/tests/src/ContextRunner.test.ts

@@ -1,8 +1,8 @@
 import init from 'veilid-wasm';
 import { driveContext } from './harness/drive.js';
-import { selectedContext, selectedSuiteNames } from './harness/select.js';
+import { selectedCaseFilter, selectedContext, selectedSuiteNames } from './harness/select.js';
 import { suitesByName } from './suites/registry.js';
-import type { CaseResult } from './harness/types.js';
+import { caseSelected, type CaseResult } from './harness/types.js';
 
 await init();
 
@@ -10,6 +10,7 @@ await init();
 // then reported as its own mocha test so the spec reporter shows what actually ran where.
 const context = selectedContext();
 const suiteNames = selectedSuiteNames();
+const caseFilter = selectedCaseFilter();
 const suites = suitesByName(suiteNames);
 
 let resultsPromise: Promise<CaseResult[]>;
@@ -33,12 +34,12 @@ async function ensureRun(): Promise<CaseResult[]> {
 describe(`veilid-wasm [${context}]`, () => {
   before('run selected suites in context', () => {
     // Kick the run off once; each case below waits on it and reports its own outcome.
-    resultsPromise = driveContext(context, suiteNames);
+    resultsPromise = driveContext(context, suiteNames, caseFilter);
   });
 
   for (const suite of suites) {
     describe(suite.name, () => {
-      for (const testCase of suite.cases()) {
+      for (const testCase of suite.cases().filter((c) => caseSelected(c, caseFilter))) {
         it(testCase.name, async function () {
           const all = await ensureRun();
           const result = all.find(

veilid-wasm/tests/src/harness/drive.ts

@@ -11,20 +11,21 @@ const RUN_TIMEOUT_MS = 50 * 60 * 1000;
 export async function driveContext(
   context: ContextName,
   suites: string[],
+  caseFilter?: string,
 ): Promise<CaseResult[]> {
   switch (context) {
     case 'window': {
       const { runSuites } = await import('./run-suites.js');
-      return runSuites(suites, context, (s) => console.log(`[window] ${s}`));
+      return runSuites(suites, context, (s) => console.log(`[window] ${s}`), caseFilter);
     }
     case 'dedicated':
-      return driveWorker(context, suites);
+      return driveWorker(context, suites, caseFilter);
     case 'shared':
-      return driveSharedWorker(context, suites);
+      return driveSharedWorker(context, suites, caseFilter);
     case 'service':
-      return driveServiceWorker(context, suites);
+      return driveServiceWorker(context, suites, caseFilter);
     case 'extension':
-      return driveExtension(context, suites);
+      return driveExtension(context, suites, caseFilter);
   }
 }
 
@@ -36,6 +37,7 @@ function collect(
   onMessage: (handler: (data: any) => void) => void,
   onError: (handler: (message: string) => void) => void,
   suites: string[],
+  caseFilter?: string,
 ): Promise<CaseResult[]> {
   return new Promise((resolve, reject) => {
     let lastStep = 'startup';
@@ -63,11 +65,15 @@ function collect(
       reject(new Error(`${context} error: ${message} (last step: ${lastStep})`));
     });
 
-    post({ type: 'run', suites });
+    post({ type: 'run', suites, caseFilter });
   });
 }
 
-function driveWorker(context: ContextName, suites: string[]): Promise<CaseResult[]> {
+function driveWorker(
+  context: ContextName,
+  suites: string[],
+  caseFilter?: string,
+): Promise<CaseResult[]> {
   const worker = new Worker(new URL('../workers/dedicated.worker.ts', import.meta.url), {
     type: 'module',
   });
@@ -80,10 +86,15 @@ function driveWorker(context: ContextName, suites: string[]): Promise<CaseResult
       worker.onmessageerror = () => h('message deserialization error');
     },
     suites,
+    caseFilter,
   ).finally(() => worker.terminate());
 }
 
-function driveSharedWorker(context: ContextName, suites: string[]): Promise<CaseResult[]> {
+function driveSharedWorker(
+  context: ContextName,
+  suites: string[],
+  caseFilter?: string,
+): Promise<CaseResult[]> {
   const worker = new SharedWorker(
     new URL('../workers/shared.worker.ts', import.meta.url),
     { type: 'module' },
@@ -95,12 +106,14 @@ function driveSharedWorker(context: ContextName, suites: string[]): Promise<Case
     (h) => (worker.port.onmessage = (e) => h(e.data)),
     (h) => (worker.onerror = (e) => h(e.message)),
     suites,
+    caseFilter,
   );
 }
 
 async function driveServiceWorker(
   context: ContextName,
   suites: string[],
+  caseFilter?: string,
 ): Promise<CaseResult[]> {
   // Pre-bundled by `npm run build:sw`; vite's dev-server module output cannot start in a SW.
   const reg = await navigator.serviceWorker.register('/service-worker.js', {
@@ -121,6 +134,7 @@ async function driveServiceWorker(
       (h) => (channel.port1.onmessage = (e) => h(e.data)),
       () => {},
       suites,
+      caseFilter,
     );
   } finally {
     // A busy worker can leave unregister() pending; never block teardown on it.
@@ -167,6 +181,7 @@ async function waitUntilServiceWorkerResponds(sw: ServiceWorker, timeoutMs = 600
 async function driveExtension(
   _context: ContextName,
   suites: string[],
+  caseFilter?: string,
 ): Promise<CaseResult[]> {
   if (typeof chrome === 'undefined' || !chrome.runtime?.sendMessage) {
     throw new Error(
@@ -209,7 +224,7 @@ async function driveExtension(
     await new Promise((r) => setTimeout(r, 500));
   }
 
-  const result = await send({ type: 'run', suites }, RUN_TIMEOUT_MS);
+  const result = await send({ type: 'run', suites, caseFilter }, RUN_TIMEOUT_MS);
   if (!result?.ok) {
     throw new Error(result?.error ?? 'extension run failed');
   }

veilid-wasm/tests/src/harness/run-suites.ts

@@ -14,6 +14,7 @@ import { appCallEventTarget, appMessageEventTarget } from './app-events.js';
 import { expect } from './expect.js';
 import {
   caseRequiresNetwork,
+  caseSelected,
   contextSupportsNetwork,
   NETWORK_SKIP_NOTICE,
   type CaseResult,
@@ -24,6 +25,35 @@ import { suitesByName } from '../suites/registry.js';
 
 let wasmReady: Promise<unknown> | undefined;
 
+// Transaction quality counters are cumulative; one compact line per case lets the stress
+// analyzer diff consecutive snapshots. Absent when the build has no `stats` feature.
+let txQualityAvailable: boolean | undefined;
+async function logTxQuality(label: string): Promise<void> {
+  if (txQualityAvailable === false) {
+    return;
+  }
+  // Without the `stats` feature the command answers with a plain "unsupported" line
+  let stats;
+  try {
+    stats = JSON.parse(await veilidClient.debug('stats print'));
+  } catch {
+    txQualityAvailable = false;
+    return;
+  }
+  txQualityAvailable = true;
+  const late: { kind: string; count: number }[] =
+    stats?.components?.rpc_processor?.answers_after_waiter_dropped ?? [];
+  const line = {
+    case: label,
+    tx: stats?.components?.storage_manager?.transaction_quality,
+    late_answers: late.reduce((sum, k) => sum + Number(k.count), 0),
+    late_transact_answers: late
+      .filter((k) => k.kind === 'TransactCommandA')
+      .reduce((sum, k) => sum + Number(k.count), 0),
+  };
+  console.log(`===TX_QUALITY=== ${JSON.stringify(line)}`);
+}
+
 // VeilidAPIError is a plain object, not an Error, so String() on it yields "[object Object]".
 function describeError(e: unknown): string {
   if (e instanceof Error) {
@@ -44,13 +74,14 @@ export async function runSuites(
   suiteNames: string[],
   context: ContextName,
   progress: (step: string) => void = () => {},
+  caseFilter?: string,
 ): Promise<CaseResult[]> {
   await (wasmReady ??= init());
   const suites: Suite[] = suitesByName(suiteNames);
   const results: CaseResult[] = [];
   const plan: { suite: Suite; cases: ReturnType<Suite['cases']> }[] = suites.map((s) => ({
     suite: s,
-    cases: s.cases(),
+    cases: s.cases().filter((c) => caseSelected(c, caseFilter)),
   }));
 
   const networkOk = contextSupportsNetwork(context);
@@ -118,8 +149,10 @@ export async function runSuites(
             error: describeError(e),
           });
         }
+        await logTxQuality(`${suite.name}: ${c.name}`);
       }
     }
+    await logTxQuality('TOTAL');
   } finally {
     progress('shutdownCore');
     await veilidClient.shutdownCore();

veilid-wasm/tests/src/harness/select.ts

@@ -26,6 +26,12 @@ export function selectedSuiteNames(): string[] {
   return names;
 }
 
+// Case-name substring selected with --case; unset runs every case.
+export function selectedCaseFilter(): string | undefined {
+  const text = (env.VEILID_TEST_CASE ?? '').trim();
+  return text.length > 0 ? text : undefined;
+}
+
 // Context selected with --context, defaulting to the page. The runner script invokes wdio once
 // per context, so a single run only ever has one.
 export function selectedContext(): ContextName {

veilid-wasm/tests/src/harness/types.ts

@@ -42,6 +42,10 @@ export const NETWORK_SKIP_NOTICE =
   'needs an attached node, and this context has no usable WebSocket. ' +
   'These require a secure context and will be enabled when WebTransport support lands.';
 
+export function caseSelected(c: TestCase, caseFilter?: string): boolean {
+  return caseFilter === undefined || c.name.includes(caseFilter);
+}
+
 export function caseRequiresNetwork(suite: Suite, c: TestCase): boolean {
   return c.requiresNetwork ?? suite.requiresNetwork ?? false;
 }

veilid-wasm/tests/src/workers/dedicated.worker.ts

@@ -8,7 +8,7 @@ self.onmessage = async (e: MessageEvent) => {
   const step = (s: string) => self.postMessage({ type: 'progress', step: s });
   try {
     const { runSuites } = await import('../harness/run-suites.js');
-    const results = await runSuites(e.data.suites, 'dedicated', step);
+    const results = await runSuites(e.data.suites, 'dedicated', step, e.data.caseFilter);
     self.postMessage({ type: 'done', ok: true, results });
   } catch (err) {
     self.postMessage({ type: 'done', ok: false, error: String(err) });

veilid-wasm/tests/src/workers/service.worker.ts

@@ -12,7 +12,7 @@ import { runSuites } from '../harness/run-suites.js';
 const sw = self as any;
 type ExtendableEventLike = { waitUntil: (p: Promise<unknown>) => void };
 type ExtendableMessageEventLike = ExtendableEventLike & {
-  data?: { type?: string; suites?: string[] };
+  data?: { type?: string; suites?: string[]; caseFilter?: string };
   ports: MessagePort[];
 };
 
@@ -32,7 +32,7 @@ sw.addEventListener('message', (event: ExtendableMessageEventLike) => {
   event.waitUntil(
     (async () => {
       try {
-        const results = await runSuites(event.data?.suites ?? [], 'service', step);
+        const results = await runSuites(event.data?.suites ?? [], 'service', step, event.data?.caseFilter);
         port?.postMessage({ type: 'done', ok: true, results });
       } catch (err) {
         port?.postMessage({ type: 'done', ok: false, error: String(err) });

veilid-wasm/tests/src/workers/shared.worker.ts

@@ -14,7 +14,7 @@ type SharedWorkerScope = { onconnect: (e: MessageEvent) => void };
     }
     try {
       const { runSuites } = await import('../harness/run-suites.js');
-      const results = await runSuites(ev.data.suites, 'shared', step);
+      const results = await runSuites(ev.data.suites, 'shared', step, ev.data.caseFilter);
       port.postMessage({ type: 'done', ok: true, results });
     } catch (err) {
       port.postMessage({ type: 'done', ok: false, error: String(err) });

veilid-wasm/wasm_test_js.sh

@@ -13,7 +13,10 @@ FEATURE_LIST=""
 TESTS=""
 CONTEXTS=""
 DEBUG_MODE=""
+CASE_FILTER=""
 MOCK_MODE=""
+# Transaction quality counters ride along with every stress run
+STATS_MODE="${STRESS:+1}"
 
 # Parse arguments
 for arg in "$@"; do
@@ -28,6 +31,9 @@ for arg in "$@"; do
     --tests=*)
       TESTS="${arg#--tests=}"
       ;;
+    --case=*)
+      CASE_FILTER="${arg#--case=}"
+      ;;
     --context=*)
       CONTEXTS="${arg#--context=}"
       ;;
@@ -41,6 +47,12 @@ for arg in "$@"; do
       FEATURE_LIST="$FEATURE_LIST,mock-api"
       MOCK_MODE=1
       ;;
+    --stats)
+      STATS_MODE=1
+      ;;
+    --no-stats)
+      STATS_MODE=""
+      ;;
     --debug)
       DEBUG_MODE=1
       ;;
@@ -59,6 +71,7 @@ for arg in "$@"; do
       echo "                        routing        - VeilidRoutingContext tests"
       echo "                        dht            - DHT kitchen sink tests"
       echo "                        transactions   - DHT transaction tests"
+      echo "  --case=TEXT         Run only the cases whose name contains TEXT."
       echo "  --context=LIST      Comma-separated list of JS contexts to run the suites in,"
       echo "                      each in turn. If omitted, only 'window' is used."
       echo "                      Available contexts:"
@@ -77,6 +90,9 @@ for arg in "$@"; do
       echo "                      Every suite runs with no attach, no sockets and no live DHT."
       echo "  --verbose-tracing   Enable verbose-tracing cargo feature"
       echo "  --aimd              Enable the aimd-dht cargo feature"
+      echo "  --stats             Enable the stats cargo feature and log transaction quality"
+      echo "                      counters after every case (===TX_QUALITY=== lines). Default"
+      echo "                      when STRESS=1; --no-stats turns it off. Not with --mock."
       echo "  --debug             Set DEBUG=1 environment variable"
       echo "  -- [args]           Pass remaining arguments to wdio"
       echo ""
@@ -85,6 +101,7 @@ for arg in "$@"; do
       echo "  $0 --mock                                   # All suites against the mock"
       echo "  $0 --tests=transactions --debug             # DHT transaction tests, with debug output"
       echo "  $0 --tests=client,crypto                    # Client and crypto suites"
+      echo "  $0 --tests=transactions --case=\"bulk store 4MB\"  # One case, by name substring"
       echo "  $0 --tests=pstore --context=window,dedicated,shared,service,extension"
       echo "  $0 --context=dedicated                      # Every suite, in a dedicated worker"
       echo "  $0 --release-build --tests=routing          # Release build, routing suite only"
@@ -104,6 +121,14 @@ for arg in "$@"; do
   shift
 done
 
+if [[ -n "$STATS_MODE" ]]; then
+  if [[ -n "$MOCK_MODE" ]]; then
+    echo "--stats cannot be combined with --mock (the mock has no stats)" >&2
+    exit 1
+  fi
+  FEATURE_LIST="$FEATURE_LIST,stats"
+fi
+
 if [ -n "$FEATURE_LIST" ]; then
   CARGO_FEATURES="--features ${FEATURE_LIST#,}"
 fi
@@ -172,6 +197,7 @@ if [[ " ${CONTEXT_LIST[*]} " == *" extension "* ]]; then
 fi
 
 export VEILID_TEST_SUITES="$TESTS"
+export VEILID_TEST_CASE="$CASE_FILTER"
 
 status=0
 for context in "${CONTEXT_LIST[@]}"; do