diff --git a/Cargo.lock b/Cargo.lock index 608c0883..c9406810 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -4072,9 +4072,9 @@ checksum = "cf54715a573b99ac80df0bc206da022bcd442c974952c7b9720069370852e21f" [[package]] name = "rustypot" -version = "1.8.0" +version = "1.12.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "39a0c413607b5e70a9535110885e131e778e5e515bcded41380c04f2ee4deac5" +checksum = "3771fb5c072caa6761ec9a5a9844137ce41d67d40d551e7a34ab66bfed02c082" dependencies = [ "clap", "env_logger", @@ -4630,7 +4630,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "32497e9a4c7b38532efcdebeef879707aa9f794296a4f0244f6f69e9bc8574bd" dependencies = [ "fastrand", - "getrandom 0.3.4", + "getrandom 0.4.3", "once_cell", "rustix", "windows-sys 0.61.2", diff --git a/duck-control/Cargo.toml b/duck-control/Cargo.toml index b53d572e..a92fe062 100644 --- a/duck-control/Cargo.toml +++ b/duck-control/Cargo.toml @@ -36,7 +36,7 @@ ort = { version = "=2.0.0-rc.11", default-features = false, features = ["load-dy # for the same kind of reason — it de-stuffs protocol 2.0 status packets whose payload # contains `FF FF FD`, and before it such a read came back oversized and every fixed-size # sync read in `bus` decoded garbage. A present current of -1 is enough to trigger that. -rustypot = "1.8.0" +rustypot = "1.12.0" # `default-features = false` drops serialport's `libudev` feature, which exists only for # enumerating ports (`available_ports`). We open one by path from the params file and never # enumerate — and libudev-sys needs a pkg-config sysroot that the board's cross-build does diff --git a/duck-control/src/bus.rs b/duck-control/src/bus.rs index da13fa7f..49c6e8a1 100644 --- a/duck-control/src/bus.rs +++ b/duck-control/src/bus.rs @@ -395,7 +395,7 @@ impl DynamixelIo { let values = self .controller .sync_read_present_position(&JOINT_IDS) - .map_err(|e| IoError::Bus(format!("read present positions: {e}")))?; + .map_err(|e| sync_read_error("read present positions", e))?; if values.len() != NUM_JOINTS { return Err(IoError::ShortRead { what: "present positions", @@ -515,7 +515,7 @@ impl RobotIo for DynamixelIo { let blocks = self .controller .sync_read_raw_data(&self.ids, READ_ADDR, READ_LEN) - .map_err(|e| IoError::Bus(format!("combined imu+motor sync_read: {e}")))?; + .map_err(|e| sync_read_error("combined imu+motor sync_read", e))?; if blocks.len() != self.ids.len() { return Err(IoError::ShortRead { @@ -630,7 +630,7 @@ impl RobotIo for DynamixelIo { let blocks = self .controller .sync_read_raw_data(&JOINT_IDS, SLOW_READ_ADDR, SLOW_READ_LEN) - .map_err(|e| IoError::Bus(format!("voltage+temperature sync_read: {e}")))?; + .map_err(|e| sync_read_error("voltage+temperature sync_read", e))?; if blocks.len() != NUM_JOINTS { return Err(IoError::ShortRead { @@ -724,6 +724,18 @@ impl RobotIo for DynamixelIo { } } +/// A failed sync read, keeping the device the bus says it stopped at. +fn sync_read_error(what: &'static str, e: Box) -> IoError { + match e.downcast_ref::() { + Some(at) => IoError::Device { + what, + id: at.id, + cause: at.cause.to_string(), + }, + None => IoError::Bus(format!("{what}: {e}")), + } +} + #[cfg(test)] mod tests { use super::*; @@ -742,6 +754,27 @@ mod tests { /// The block parsed per servo must cover current, velocity and position without /// overrunning. If `READ_LEN` and the offsets below ever disagree, joints get each /// other's values — which reads as a wiring fault, not a code bug. + #[test] + fn a_sync_read_failure_keeps_the_device_it_stopped_at() { + let at = rustypot::SyncReadError { + id: IMU_DXL_ID, + cause: Box::new(rustypot::CommunicationErrorKind::ParsingError), + }; + let e = sync_read_error("combined imu+motor sync_read", Box::new(at)); + assert_eq!(e.device(), Some(IMU_DXL_ID)); + assert_eq!( + e.to_string(), + "bus transaction failed: combined imu+motor sync_read: device 200: Parsing error" + ); + + // The port itself is nobody's. + let e = sync_read_error( + "combined imu+motor sync_read", + Box::new(std::io::Error::other("unplugged")), + ); + assert_eq!(e.device(), None); + } + #[test] fn read_block_is_long_enough_for_every_field() { assert_eq!(READ_LEN as usize, IMU_BLOCK_LEN); diff --git a/duck-control/src/io.rs b/duck-control/src/io.rs index 498fd3ff..a339f460 100644 --- a/duck-control/src/io.rs +++ b/duck-control/src/io.rs @@ -59,6 +59,15 @@ pub enum IoError { }, #[error("bus transaction failed: {0}")] Bus(String), + /// A sync read the bus says went wrong at one device's answer — which device, from what + /// arrived (`rustypot`'s `SyncReadError`). The device is where the answer broke, not proof + /// the rest are fine: see `duck_ipc_proto::BusHealth::failing`. + #[error("bus transaction failed: {what}: device {id}: {cause}")] + Device { + what: &'static str, + id: u8, + cause: String, + }, /// A `sync_read` that returns the wrong number of blocks, or a block of the wrong /// length, means a device did not answer. Reported rather than papered over: a /// silently short read would leave stale values in half the joint array. @@ -72,6 +81,16 @@ pub enum IoError { Simulated, } +impl IoError { + /// The device the bus pinned this failure on, when it could. + pub fn device(&self) -> Option { + match self { + Self::Device { id, .. } => Some(*id), + _ => None, + } + } +} + pub type Result = std::result::Result; /// What the servos report about their own supply and case, rather than their motion. diff --git a/duck-control/src/model.rs b/duck-control/src/model.rs index 731c0821..f7f708e6 100644 --- a/duck-control/src/model.rs +++ b/duck-control/src/model.rs @@ -97,8 +97,9 @@ pub fn mouth_target(open: f64) -> f64 { } /// The `imu_to_dxl` v2 board's Dynamixel ID. It rides the motor bus and is read in the -/// same transaction as the servos ([`crate::bus`]). -pub const IMU_DXL_ID: u8 = 200; +/// same transaction as the servos ([`crate::bus`]). Protocol, so a client naming a device a +/// failed read stopped at uses the same number. +pub use duck_ipc_proto::IMU_DXL_ID; pub const BAUD_RATE: u32 = 1_000_000; diff --git a/duck-ipc-proto/src/lib.rs b/duck-ipc-proto/src/lib.rs index 9715c1e9..4a56a2a6 100644 --- a/duck-ipc-proto/src/lib.rs +++ b/duck-ipc-proto/src/lib.rs @@ -457,7 +457,19 @@ pub const JSONRPC_VERSION: &str = "2.0"; /// [`method::ROBOT_VETBOOK`] and [`method::ROBOT_VETBOOK_NOTE`]: the robot's lifetime record — /// hours on, distance walked, falls and pickups, every servo `robotd` has adopted and how long /// the one before it lasted, and dated notes ([`vetbook`]). New routes: a `robotd` predating them answers METHOD_NOT_FOUND, by name. -pub const API_VERSION: u32 = 42; +/// +/// # v43 — which device a run of failed bus reads stopped at +/// +/// [`BusHealth::failing`]: the device each failed read of the current run was pinned on — a servo, +/// or the IMU board. "motor bus: 1 read failures running" said the bus dropped a read and not +/// where, and on a robot whose drops are all one device's, the device is the whole finding. +/// +/// [`BusHealth::drops`] and [`BusHealth::unnamed_drops`]: every failed read since `robotd` +/// started, by device. A count that resets on the next good read is invisible to a client +/// sampling once a second; a total that only grows is not. +/// +/// Additive: absent from an older `robotd`, and empty reads as "not told". +pub const API_VERSION: u32 = 43; /// The observation width every policy this robot family runs is built against. /// @@ -586,6 +598,11 @@ pub const JOINT_IDS: [u8; 15] = [ 10, 11, 12, 13, 14, // right leg ]; +/// The IMU board's Dynamixel ID. It rides the motor bus and answers first in the combined read, so +/// it is a device [`BusHealth::failing`] can name. `duck-control` re-exports it, as it does +/// [`JOINT_IDS`]. +pub const IMU_DXL_ID: u8 = 200; + /// The joint a Dynamixel ID drives, if it is one of [`JOINT_IDS`]. pub fn joint_of(id: u8) -> Option<&'static str> { JOINT_IDS @@ -3689,6 +3706,24 @@ pub struct BusHealth { /// unplugged, and naming them is the point. #[serde(skip_serializing_if = "Vec::is_empty")] pub missing: Vec, + /// While `consecutive_errors` is non-zero: the device each failed read of the run stopped at, + /// once each, in the order first seen — a servo ID, or [`IMU_DXL_ID`]. Emptied with the count. + /// + /// The read is one transaction for every device, so this is where the answer went wrong, not + /// a proof the others are fine: a cable that breaks at one device silences every one past + /// it, and the first silent one is the one named. A failure the bus could not pin on a device + /// (the port itself) adds nothing, so a run can be counted with nobody named. + #[serde(skip_serializing_if = "Vec::is_empty")] + pub failing: Vec, + /// Failed reads since `robotd` started, by the device each stopped at — a servo ID, or + /// [`IMU_DXL_ID`]. Only ever grows, and that is the point: an isolated drop holds + /// `consecutive_errors` for one 20 ms tick, which a client sampling health once a second sees + /// one time in fifty. A total that went up says a drop happened in between, and where. + #[serde(skip_serializing_if = "std::collections::BTreeMap::is_empty")] + pub drops: std::collections::BTreeMap, + /// Failed reads since `robotd` started that the bus could not pin on a device. + #[serde(skip_serializing_if = "is_zero")] + pub unnamed_drops: u64, } impl BusHealth { @@ -3700,17 +3735,62 @@ impl BusHealth { /// The missing servos as people read them: `32 head_yaw, 33 head_roll`. pub fn describe_missing(&self) -> String { - self.missing + describe_devices(&self.missing) + } + + /// The devices the current run of failures stopped at, the same way: `200 imu, 34 mouth`. + pub fn describe_failing(&self) -> String { + describe_devices(&self.failing) + } + + /// Every failed read since `robotd` started. + pub fn total_drops(&self) -> u64 { + self.drops.values().sum::() + self.unnamed_drops + } + + /// Where the reads since `robotd` started dropped: `20 left_hip_yaw ×2, 32 head_yaw ×1`. + pub fn describe_drops(&self) -> String { + let mut by_device: Vec = self + .drops .iter() - .map(|&id| match joint_of(id) { - Some(joint) => format!("{id} {joint}"), - None => id.to_string(), - }) - .collect::>() - .join(", ") + .map(|(&id, n)| format!("{} ×{n}", describe_device(id))) + .collect(); + if self.unnamed_drops > 0 { + by_device.push(format!("unknown device ×{}", self.unnamed_drops)); + } + by_device.join(", ") + } + + /// The current run of failed reads, for a client to show while `consecutive_errors` is + /// non-zero: `3 read failures running, at 200 imu`. + pub fn describe_run(&self) -> String { + let n = self.consecutive_errors; + let run = format!("{n} read failure{} running", if n == 1 { "" } else { "s" }); + if self.failing.is_empty() { + run + } else { + format!("{run}, at {}", self.describe_failing()) + } } } +/// A bus device as people read it: the ID printed on the part, and what it is — `34 mouth`, +/// `200 imu`. +pub fn describe_device(id: u8) -> String { + match joint_of(id) { + Some(joint) => format!("{id} {joint}"), + None if id == IMU_DXL_ID => format!("{id} imu"), + None => id.to_string(), + } +} + +fn describe_devices(ids: &[u8]) -> String { + ids.iter() + .map(|&id| describe_device(id)) + .collect::>() + .join(", ") +} + /// The IMU board, which rides the motor bus. /// /// `#[serde(default)]` on the struct, not on each field, and for the same reason the parent @@ -6609,6 +6689,43 @@ mod tests { assert_eq!(answer.bus.startup_failures, 0); } + #[test] + fn the_devices_a_run_stopped_at_name_the_imu_board_too() { + let bus = BusHealth { + consecutive_errors: 2, + failing: vec![IMU_DXL_ID, 34, 99], + ..BusHealth::default() + }; + assert_eq!(bus.describe_failing(), "200 imu, 34 mouth, 99"); + assert_eq!( + bus.describe_run(), + "2 read failures running, at 200 imu, 34 mouth, 99" + ); + let unnamed = BusHealth { + consecutive_errors: 1, + ..BusHealth::default() + }; + assert_eq!(unnamed.describe_run(), "1 read failure running"); + + let drops = BusHealth { + drops: [(32, 1), (20, 2)].into(), + unnamed_drops: 1, + ..BusHealth::default() + }; + assert_eq!(drops.total_drops(), 4); + assert_eq!( + drops.describe_drops(), + "20 left_hip_yaw ×2, 32 head_yaw ×1, unknown device ×1" + ); + // A map keyed by ID crosses JSON with string keys, and comes back the same. + let json = serde_json::to_string(&drops).unwrap(); + assert!(json.contains(r#""drops":{"20":2,"32":1}"#), "{json}"); + assert_eq!(serde_json::from_str::(&json).unwrap(), drops); + // Not told is not serialised: an older client sees the section it always did. + let json = serde_json::to_string(&BusHealth::default()).unwrap(); + assert!(!json.contains("failing"), "{json}"); + } + /// An absent battery must stay absent, not become zero volts. /// /// This is the answer for the first second after startup, for a bus that cannot reply, diff --git a/duckctl/src/udp_pad.rs b/duckctl/src/udp_pad.rs index b3e23d82..9ab08d76 100644 --- a/duckctl/src/udp_pad.rs +++ b/duckctl/src/udp_pad.rs @@ -73,6 +73,8 @@ pub struct Notices { alarms: Vec<(&'static str, panel::Level)>, /// The last refusal said, and when the robot made it. refused: Option<(String, String, Instant)>, + /// The bus's drop totals as last seen, `None` before the first report carrying health. + drops: Option<(std::collections::BTreeMap, u64)>, } impl Notices { @@ -149,6 +151,10 @@ impl Notices { } self.alarms = now.iter().map(|a| (a.key, a.level)).collect(); + if let Some(h) = &report.health { + lines.extend(self.drops(&h.bus)); + } + if let Some(r) = &report.refused { let happened = at .checked_sub(Duration::from_millis(r.ago_ms)) @@ -168,6 +174,57 @@ impl Notices { lines } + /// A line for each device whose drop total went up since the last report — every drop, even + /// the ones over between two reports, which is why totals and not the running count. + /// + /// The first report says what is already there, in one line. A total going down is `robotd` + /// restarted, and its totals are said again the same way. + fn drops(&mut self, bus: &duck_ipc_proto::BusHealth) -> Vec { + let now = (bus.drops.clone(), bus.unnamed_drops); + let was = self.drops.replace(now.clone()).filter(|(drops, unnamed)| { + *unnamed <= now.1 + && drops + .iter() + .all(|(id, n)| now.0.get(id).is_some_and(|m| m >= n)) + }); + let Some((was, was_unnamed)) = was else { + let total = bus.total_drops(); + return if total == 0 { + Vec::new() + } else { + vec![format!( + "⚠ motor bus: {total} read{} dropped since robotd started — {}", + if total == 1 { "" } else { "s" }, + bus.describe_drops() + )] + }; + }; + let dropped = |by: u64, at: String, total: u64| { + let what = if by == 1 { + "read dropped".to_owned() + } else { + format!("{by} reads dropped") + }; + format!("⚠ motor bus: {what} at {at} ({total} since robotd started)") + }; + let mut lines: Vec = bus + .drops + .iter() + .filter_map(|(&id, &n)| { + let by = n - was.get(&id).copied().unwrap_or(0); + (by > 0).then(|| dropped(by, duck_ipc_proto::describe_device(id), n)) + }) + .collect(); + if bus.unnamed_drops > was_unnamed { + lines.push(dropped( + bus.unnamed_drops - was_unnamed, + "an unknown device".to_owned(), + bus.unnamed_drops, + )); + } + lines + } + /// Whether the duck is connected, once per change of kind. Led by the same verdict the /// panel shows, so a scrolled-back log reads the same as the screen. pub fn link(&mut self, to: &str, state: State) -> Option { @@ -612,6 +669,44 @@ mod tests { assert_eq!(n.robot(&refused(50), at(7_000)).len(), 1, "a new one"); } + /// A drop holds the running count for one tick; the totals are what a report a second + /// apart can still see. + #[test] + fn every_bus_drop_gets_a_line_even_between_reports() { + use duck_ipc_proto as proto; + let at = |ms| Instant::now() + Duration::from_millis(ms); + let drops = |drops: &[(u8, u64)]| RobotReport { + health: Some(proto::HealthResult { + healthy: true, + bus: proto::BusHealth { + drops: drops.iter().copied().collect(), + ..Default::default() + }, + ..Default::default() + }), + ..Default::default() + }; + let mut n = Notices::default(); + assert_eq!( + n.robot(&drops(&[(20, 2)]), at(0)), + ["⚠ motor bus: 2 reads dropped since robotd started — 20 left_hip_yaw ×2"] + ); + assert!(n.robot(&drops(&[(20, 2)]), at(1_000)).is_empty()); + assert_eq!( + n.robot(&drops(&[(20, 2), (32, 1)]), at(2_000)), + ["⚠ motor bus: read dropped at 32 head_yaw (1 since robotd started)"] + ); + assert_eq!( + n.robot(&drops(&[(20, 4), (32, 1)]), at(3_000)), + ["⚠ motor bus: 2 reads dropped at 20 left_hip_yaw (4 since robotd started)"] + ); + // robotd restarted: its totals start again, and are said again. + assert_eq!( + n.robot(&drops(&[(200, 1)]), at(4_000)), + ["⚠ motor bus: 1 read dropped since robotd started — 200 imu ×1"] + ); + } + #[test] fn host_without_port_gets_the_default() { assert_eq!(target("10.0.0.5"), "10.0.0.5:4210"); diff --git a/duckctl/src/udp_pad/panel.rs b/duckctl/src/udp_pad/panel.rs index 3b20b9f4..c5ebdbe9 100644 --- a/duckctl/src/udp_pad/panel.rs +++ b/duckctl/src/udp_pad/panel.rs @@ -155,10 +155,7 @@ pub fn alarms(r: &RobotReport) -> Vec { push( "motors", Level::Warn, - format!( - "motor bus: {} read failures running", - h.bus.consecutive_errors - ), + format!("motor bus: {}", h.bus.describe_run()), ); } if let Some(imu) = &h.imu { @@ -643,6 +640,14 @@ fn render_robot(frame: &mut ratatui::Frame, v: &View, area: Rect) { Some(a) => Span::styled(a.text.clone(), a.level.style()), None => Span::styled("bus ok", Style::new().fg(Color::Green)), }); + // Drops since start: none of them is an alarm, all of them are where to look. + if h.bus.total_drops() > 0 { + motors.push(dim(format!( + " · {} dropped: {}", + h.bus.total_drops(), + h.bus.describe_drops() + ))); + } lines.push(row("motors", motors)); } } @@ -965,6 +970,25 @@ mod tests { assert!(alarms(&RobotReport::default()).is_empty()); } + /// The device is the finding: "1 read failure" alone says the bus dropped a read, not where. + #[test] + fn a_bus_drop_names_the_device_it_stopped_at() { + let report = RobotReport { + health: Some(proto::HealthResult { + healthy: true, + bus: proto::BusHealth { + consecutive_errors: 1, + failing: vec![proto::IMU_DXL_ID], + ..Default::default() + }, + ..Default::default() + }), + ..Default::default() + }; + let texts: Vec<_> = alarms(&report).into_iter().map(|a| a.text).collect(); + assert_eq!(texts, ["motor bus: 1 read failure running, at 200 imu"]); + } + #[test] fn the_robot_block_shows_power_motors_pose_and_refusals() { let link = Link::default(); diff --git a/pad-map/src/wire.rs b/pad-map/src/wire.rs index 70dec074..34be051b 100644 --- a/pad-map/src/wire.rs +++ b/pad-map/src/wire.rs @@ -382,6 +382,9 @@ mod tests { consecutive_errors: 3, startup_failures: 0, missing: (10..25).collect(), + failing: vec![proto::IMU_DXL_ID], + drops: [(proto::IMU_DXL_ID, 3)].into(), + unnamed_drops: 1, }, ..Default::default() }), diff --git a/robotctl/src/main.rs b/robotctl/src/main.rs index fe91e46b..b3edf151 100644 --- a/robotctl/src/main.rs +++ b/robotctl/src/main.rs @@ -2064,7 +2064,14 @@ fn render_health(report: &HealthReport) -> String { format!("servos ok, waiting for the IMU board, {n} attempts") } (0, n) => format!("waiting for a robot to answer, {n} attempts"), - (n, _) => format!("{n} consecutive read failures"), + (_, _) => health.bus.describe_run(), + }; + let bus = match health.bus.total_drops() { + 0 => bus, + n => format!( + "{bus} · {n} dropped since start: {}", + health.bus.describe_drops() + ), }; let _ = writeln!(out, " {:<9} {bus}", "bus"); @@ -7076,6 +7083,8 @@ mod tests { bus: proto::BusHealth { consecutive_errors: 7, startup_failures: 0, + failing: vec![34], + drops: [(34, 7)].into(), ..Default::default() }, imu: Some(proto::ImuHealth { @@ -7089,7 +7098,12 @@ mod tests { None, )); - assert!(out.contains("7 consecutive read failures"), "{out}"); + assert!( + out.contains( + "7 read failures running, at 34 mouth · 7 dropped since start: 34 mouth ×7" + ), + "{out}" + ); assert!(out.contains("orientation frozen"), "{out}"); assert!(out.contains("41 stale reads running"), "{out}"); } diff --git a/robotctl/src/monitor.rs b/robotctl/src/monitor.rs index 35ba189b..628fd84a 100644 --- a/robotctl/src/monitor.rs +++ b/robotctl/src/monitor.rs @@ -2216,12 +2216,21 @@ impl View { // at all — is already the degraded reason above, and saying it twice on one row costs // the temperatures for no information. if health.bus.consecutive_errors > 0 { + said.push(Span::styled( + format!(" · bus {}", health.bus.describe_run()), + Style::new().fg(Color::Yellow), + )); + } + // Every drop since start, by device: a single drop is over within a tick, and a refresh + // later only these totals say it happened. + if health.bus.total_drops() > 0 { said.push(Span::styled( format!( - " · bus {} read failures running", - health.bus.consecutive_errors + " · bus {} dropped: {}", + health.bus.total_drops(), + health.bus.describe_drops() ), - Style::new().fg(Color::Yellow), + Style::new().add_modifier(Modifier::DIM), )); } diff --git a/robotd/src/main.rs b/robotd/src/main.rs index 21e2f065..b777d622 100644 --- a/robotd/src/main.rs +++ b/robotd/src/main.rs @@ -551,6 +551,15 @@ struct RobotState { achieved_hz: AtomicU64, /// Consecutive failed bus reads. Reset by any success. consecutive_errors: AtomicU32, + /// The devices this run of failed reads stopped at, once each — `BusHealth::failing`. + /// Emptied with `consecutive_errors`; written only by a failure and by the success that + /// ends a run, so an ordinary tick never touches it. + bus_failing: ArcSwap>, + /// Every failed read since startup, by the device it stopped at — `BusHealth::drops`. + /// Written only by a failure. + bus_drops: ArcSwap>, + /// The failed reads the bus could not pin on a device — `BusHealth::unnamed_drops`. + bus_unnamed_drops: AtomicU64, /// Failed attempts to bring the bus up — opening it, verifying its registers, or /// reading the startup pose. Non-zero means the loop is still waiting for a robot to /// answer and has never commanded anything. @@ -732,6 +741,9 @@ impl RobotState { last_tick_us: AtomicU64::new(0), achieved_hz: AtomicU64::new(0), consecutive_errors: AtomicU32::new(0), + bus_failing: ArcSwap::from_pointee(Vec::new()), + bus_drops: ArcSwap::from_pointee(Default::default()), + bus_unnamed_drops: AtomicU64::new(0), startup_bus_failures: AtomicU32::new(0), startup_missing: ArcSwap::from_pointee(Vec::new()), startup_imu_missing: AtomicBool::new(false), @@ -783,6 +795,37 @@ impl RobotState { } } + /// A good bus read: the run of failures, if there was one, is over. + fn bus_read_ok(&self) { + if self.consecutive_errors.swap(0, Ordering::Relaxed) > 0 { + self.bus_failing.store(Arc::new(Vec::new())); + } + } + + /// A failed bus read, and the device the bus pinned it on if it could. The run's length. + fn bus_read_failed(&self, device: Option) -> u32 { + match device { + Some(id) => { + if !self.bus_failing.load().contains(&id) { + self.bus_failing.rcu(|failing| { + let mut failing = Vec::clone(failing); + failing.push(id); + failing + }); + } + self.bus_drops.rcu(|drops| { + let mut drops = std::collections::BTreeMap::clone(drops); + *drops.entry(id).or_default() += 1; + drops + }); + } + None => { + self.bus_unnamed_drops.fetch_add(1, Ordering::Relaxed); + } + } + self.consecutive_errors.fetch_add(1, Ordering::Relaxed) + 1 + } + fn health(&self) -> proto::HealthResult { // Everything the robot can say about itself, attached to every answer whatever the // verdict — and consulted by none of the checks below. @@ -810,6 +853,9 @@ impl RobotState { consecutive_errors: self.consecutive_errors.load(Ordering::Relaxed), startup_failures: self.startup_bus_failures.load(Ordering::Relaxed), missing: self.startup_missing.load().as_ref().clone(), + failing: self.bus_failing.load().as_ref().clone(), + drops: self.bus_drops.load().as_ref().clone(), + unnamed_drops: self.bus_unnamed_drops.load(Ordering::Relaxed), }, imu: Some(proto::ImuHealth { ready: self.imu_ready.load(Ordering::Relaxed), @@ -905,7 +951,18 @@ impl RobotState { let errors = self.consecutive_errors.load(Ordering::Relaxed); if errors >= self.max_consecutive_errors { - return unhealthy(format!("{errors} consecutive bus read failures")); + let bus = proto::BusHealth { + failing: self.bus_failing.load().as_ref().clone(), + ..Default::default() + }; + return unhealthy(if bus.failing.is_empty() { + format!("{errors} consecutive bus read failures") + } else { + format!( + "{errors} consecutive bus read failures, at {}", + bus.describe_failing() + ) + }); } // A wedged loop stops stamping. This is what turns a hung control thread into an @@ -2363,12 +2420,12 @@ async fn control_loop( let read_at = proto::clock::monotonic_ns(); let fresh = match safety.read() { Ok(sensors) => { - state.consecutive_errors.store(0, Ordering::Relaxed); + state.bus_read_ok(); sensors_read_ns = read_at; Some(sensors) } Err(e) => { - let n = state.consecutive_errors.fetch_add(1, Ordering::Relaxed) + 1; + let n = state.bus_read_failed(e.device()); bus_drops_window += 1; // A run of them is a fault, and stays as loud as it was: every tenth, at once. @@ -6494,6 +6551,42 @@ mod tests { assert!(health.reason.unwrap().contains("consecutive")); } + /// A run names each device it stopped at once, and the good read ending it forgets them — + /// "running" means now, for the devices as for the count. + #[test] + fn a_run_of_bus_failures_names_its_devices_until_it_ends() { + let s = state(); + ticked(&s, 100); + assert_eq!(s.bus_read_failed(Some(200)), 1); + assert_eq!(s.bus_read_failed(None), 2); + assert_eq!(s.bus_read_failed(Some(34)), 3); + assert_eq!(s.bus_read_failed(Some(200)), 4); + let bus = s.health().bus; + assert_eq!((bus.consecutive_errors, bus.failing), (4, vec![200, 34])); + + s.bus_read_ok(); + let bus = s.health().bus; + assert_eq!((bus.consecutive_errors, bus.failing), (0, vec![])); + // The run is over; what it dropped is not forgotten. + assert_eq!(bus.drops, [(34, 1), (200, 2)].into()); + assert_eq!(bus.unnamed_drops, 1); + + s.bus_read_failed(Some(34)); + assert_eq!(s.health().bus.drops, [(34, 2), (200, 2)].into()); + } + + /// The update gate quotes this reason when it rolls a release back, so it names the device. + #[test] + fn sustained_bus_failures_name_where_they_stop() { + let s = state(); + ticked(&s, 100); + for _ in 0..10 { + s.bus_read_failed(Some(34)); + } + let reason = s.health().reason.unwrap(); + assert!(reason.ends_with("failures, at 34 mouth"), "{reason}"); + } + /// `--unhealthy` must win over a healthy loop: it exists to exercise rollback. #[test] fn forced_unhealthy_overrides_a_running_loop() {