From 49db52f270fc1a900b2a836eece7129a5d9fccf7 Mon Sep 17 00:00:00 2001 From: ConWan30 <218774523+ConWan30@users.noreply.github.com> Date: Wed, 11 Nov 2026 08:50:34 -0600 Subject: [PATCH] Watchdog: a frame stored after `now` is fresh data, not a stall The capture watchdog computed `now - last` on u64 ms. `last_data_ms` is written by the reader thread, so a frame stored between the two reads makes `last > now`; in release builds (no overflow checks) the subtraction wraps to a huge gap and the watchdog kills a healthy capture. Practice match-20261111-081216 (e8509dc build) logged "no data from device for 4s" at 14:15:16.638Z while encoder progress showed frames flowing (frame=10111, drop=0 at 14:15:13.97Z); the recording split into video.part2.mp4. The wrap is consistent with that log; it was not reproduced on the PC. The check moves into `watchdog_stalled`, which uses saturating_sub. Threshold (`> grace`) and grace values (15 s first data, --watchdog after) are unchanged. Unit tests cover last > now, gaps at or under grace, and gaps over grace. No change to receipts, receipt.v0, contracts/, schema/, the capture ffmpeg arguments or the recording bytes. --- src/engine.rs | 25 ++++++++++++++++++++++++- 1 file changed, 24 insertions(+), 1 deletion(-) diff --git a/src/engine.rs b/src/engine.rs index 21a99c0..f340f17 100644 --- a/src/engine.rs +++ b/src/engine.rs @@ -935,7 +935,7 @@ impl Engine { let now = me.ms(); let last = me.last_data_ms.load(Ordering::Relaxed).max(start); let grace = if last == start { 15_000 } else { wd }; - if me.shutdown.load(Ordering::SeqCst) || now - last > grace { + if me.shutdown.load(Ordering::SeqCst) || watchdog_stalled(now, last, grace) { if !me.shutdown.load(Ordering::SeqCst) { let m = format!("no data from device for {}s: treating as frozen/unplugged, restarting", grace / 1000); error!("{m}"); me.set_state("reopening", Some(m)); } let _ = child.lock().unwrap_or_else(|e| e.into_inner()).kill(); break; @@ -985,6 +985,11 @@ impl Engine { } } +/// Watchdog stall test on the engine's u64 ms clock. `last` is stored by the reader thread and can be +/// read after `now` was taken, so `last > now` happens when a frame lands between the two reads; that +/// means data just arrived, never a stall. A plain `now - last` wraps there in release builds. +fn watchdog_stalled(now: u64, last: u64, grace: u64) -> bool { now.saturating_sub(last) > grace } + struct StopPublisher { flag: Arc, handle: Option> } impl Drop for StopPublisher { fn drop(&mut self) { @@ -1031,6 +1036,24 @@ pub fn parse_bitrate(s: &str) -> Option { #[cfg(test)] mod tests { use super::*; + #[test] + fn watchdog_last_after_now_is_not_a_stall() { + // A frame stored last_data_ms 7 ms after the watchdog read `now` (match-20261111-081216). + assert!(!watchdog_stalled(100_000, 100_007, 4_000)); + assert!(!watchdog_stalled(0, u64::MAX, 4_000)); + } + #[test] + fn watchdog_gap_under_grace_is_not_a_stall() { + assert!(!watchdog_stalled(100_000, 100_000, 4_000)); + assert!(!watchdog_stalled(103_999, 100_000, 4_000)); + assert!(!watchdog_stalled(104_000, 100_000, 4_000)); + } + #[test] + fn watchdog_gap_over_grace_is_a_stall() { + assert!(watchdog_stalled(104_001, 100_000, 4_000)); + assert!(watchdog_stalled(200_000, 100_000, 4_000)); + assert!(watchdog_stalled(15_001, 0, 15_000)); + } struct Boom { fail: &'static str } impl SyncWrite for Boom { fn write_all_buf(&mut self, _: &[u8]) -> std::io::Result<()> { Ok(()) }