From 888a8edbd283cf5957e51b9e5ce169c782992280 Mon Sep 17 00:00:00 2001 From: DoubleGate Date: Fri, 31 Jul 2026 10:30:04 -0400 Subject: [PATCH 1/2] fix(netplay): grade the desync verdict so a transient doesn't end the game First PR of the `v1.27.0` netplay-depth rung. ## The behaviour that changed Until now the FIRST checksum mismatch was a fatal `NetplayError::Desync`, and `app.rs` disconnected on it. That is too eager: a burst-reordered pair of `Checksum` messages can momentarily disagree before the deferred `compare_pending_checksums` pass reconciles them, so a transient network event ended a healthy game. `diagnostics::DesyncDiagnostics` now records EVERY comparison -- matching ones included -- and folds them into one graded `DesyncStatus`: InSync Suspect { consecutive, first_desync_frame } Desynced { first_desync_frame } Three consecutive mismatches (~1.5 s at the default 30-frame interval) confirm. The fatal error fires only on `Desynced`, so a transient is survived while a genuine divergence still ends the session -- which it must, since a rollback desync cannot recover without a full state resync. `Desynced` is STICKY. A later stray match resets the live consecutive run but never downgrades the verdict, because the underlying condition cannot heal. A surface that flapped between "desynced" and "fine" would train the user to ignore it. ## The framebuffer hash was being thrown away `compare_pending_checksums` destructured the remote report as `let (_, remote_hash, _) = ...`, discarding the framebuffer-only hash the message already carried. It now reaches the diagnostics, and it is what makes a mismatch diagnosable rather than merely alarming: same picture with a different combined digest means a TIMING divergence; a different picture means a STATE one. ## Determinism is untouched The module only reads values the session already computed and stores copies; it never feeds back into rollback, the checksum exchange, or the emulator, and it holds no wall-clock (that belongs in the connection layer, a later PR). Deleting it would leave every produced frame, checksum, and rollback byte-identical. `tests/determinism.rs` passes unchanged. `DesyncDiagnostics::new`/`with_threshold` are `const fn` so `RollbackSession::new` keeps being one; that is why the threshold clamp is spelled out rather than `.max(1)`, which is not const. ## Tests `diagnostics.rs`'s 9 unit tests cover the verdict arithmetic. The new `tests/desync_hysteresis.rs` covers what actually changed, by driving a real session against forged peer checksums: * a single mismatched checksum no longer ends the session; * a sustained divergence still does, having crossed the threshold rather than firing early; * a clean session stays `InSync`. The transient test carries an ANTI-VACUOUS GUARD: surviving is only meaningful if the forged checksum actually reached the comparator, so it asserts `total == 1` and `mismatches == 1` rather than merely that no error came back. Measured before asserting. Both were verified by re-injecting the old fail-on-first behaviour and confirming they fail -- the transient one with exactly the `Err(Desync { frame: 0, .. })` this PR removes. Verified: `cargo fmt --check`; clippy `-D warnings` on the crate and on `rustysnes-frontend --features netplay`; `cargo doc` warnings-as-errors; 29 netplay tests green. Co-Authored-By: Claude Opus 5 (1M context) --- CHANGELOG.md | 30 ++ crates/rustysnes-netplay/src/diagnostics.rs | 461 ++++++++++++++++++ crates/rustysnes-netplay/src/lib.rs | 2 + crates/rustysnes-netplay/src/session.rs | 70 ++- .../tests/desync_hysteresis.rs | 183 +++++++ docs/netplay.md | 88 ++++ 6 files changed, 823 insertions(+), 11 deletions(-) create mode 100644 crates/rustysnes-netplay/src/diagnostics.rs create mode 100644 crates/rustysnes-netplay/tests/desync_hysteresis.rs create mode 100644 docs/netplay.md diff --git a/CHANGELOG.md b/CHANGELOG.md index 7fd34300..86b95a7d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -11,6 +11,36 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed +- **Netplay: one transient checksum mismatch no longer ends the session.** Until now the **first** + mismatch was a fatal `NetplayError::Desync`, and `app.rs` disconnected on it. That is too eager: a + burst-reordered pair of `Checksum` messages can momentarily disagree before the deferred + `compare_pending_checksums` pass reconciles them, so a transient network event ended a healthy + game. + + New `rustysnes-netplay::diagnostics` records **every** comparison — matching ones included — and + folds them into one graded `DesyncStatus`: `InSync`, `Suspect { consecutive, first_desync_frame }`, + or `Desynced { first_desync_frame }` once three consecutive mismatches (~1.5 s at the default + 30-frame interval) confirm it. The fatal error now fires only on `Desynced`, so a transient is + survived while a genuine divergence still ends the session — which it must, since a rollback + desync cannot recover without a full state resync. `Desynced` is **sticky**: a later stray match + resets the live run but never downgrades the verdict, because the condition cannot actually heal. + + The remote **framebuffer hash was previously discarded** at the comparison site and is now kept, + which is what makes a mismatch diagnosable rather than merely alarming — same picture with a + different combined digest means a *timing* divergence; a different picture means a *state* one. + + Purely observational: it only reads values the session already computed, holds no wall-clock, and + never feeds back into rollback, so determinism (`docs/adr/0004`) is untouched — `tests/determinism.rs` + still passes unchanged. The history ring is bounded at 64 entries but the first-diverging frame + and the counters are sticky scalars that survive eviction, so an hour-long session still reports + where it first broke. + + New `tests/desync_hysteresis.rs` drives a real session against forged peer checksums. The + transient case asserts the forged value actually reached the comparator (`total == 1`, + `mismatches == 1`) so it cannot pass vacuously, and both it and the sustained-divergence control + were verified by re-injecting the old fail-on-first behaviour and confirming they fail. See the + new `docs/netplay.md`. + - **The golden vectors ran in no pull-request job.** Only `lint`, `test-light`, and `accuracysnes` run on a PR; `test-light` never passes `--features test-roms`, and the `accuracysnes` job scoped itself to `--test accuracysnes`. So the **53 rendered-scene goldens and every framebuffer golden** diff --git a/crates/rustysnes-netplay/src/diagnostics.rs b/crates/rustysnes-netplay/src/diagnostics.rs new file mode 100644 index 00000000..fc6a98d3 --- /dev/null +++ b/crates/rustysnes-netplay/src/diagnostics.rs @@ -0,0 +1,461 @@ +//! Desync diagnostics — observational telemetry for a [`RollbackSession`]. +//! +//! [`RollbackSession`]: crate::session::RollbackSession +//! +//! Peers exchange a periodic confirmed-frame state checksum +//! ([`NetMessage::Checksum`](crate::message::NetMessage::Checksum)). Before `v1.27.0` the **first** +//! mismatch was a fatal [`NetplayError::Desync`](crate::session::NetplayError::Desync) and the +//! frontend tore the session down on it. That is too eager: a burst-reordered pair of `Checksum` +//! messages can momentarily disagree before the deferred comparison pass reconciles them, so a +//! transient network event ended a healthy game. +//! +//! This module records every comparison — matching ones too — and folds them into one graded +//! [`DesyncStatus`] with a hysteresis threshold, so the frontend can distinguish "one odd frame" +//! from "these two machines have genuinely diverged". +//! +//! **Purely observational.** It only ever *reads* values the session already computed (the +//! canonical gameplay digest and the peer's reported digest) and stores copies; it never feeds back +//! into the rollback algorithm, the checksum exchange, or the emulator. Deleting it would leave +//! every produced frame, checksum, and rollback byte-identical, so it cannot perturb the +//! determinism contract (`docs/adr/0004`). It holds no wall-clock either — that lives in the +//! connection layer — so a `RollbackSession` stays seeded and reproducible. + +use std::collections::VecDeque; + +/// The graded desync verdict derived from the recent comparison history. +/// +/// This is the **single desync surface** the frontend renders. Folding the raw counters into one +/// enum here rather than in the UI means the hysteresis rule lives next to the data it guards, and +/// a second consumer (a headless log, a test) cannot re-derive it differently. +#[derive(Clone, Copy, Debug, PartialEq, Eq)] +pub enum DesyncStatus { + /// Every comparison so far matched — the peers are in lockstep. + InSync, + /// At least one frame has mismatched, but the current consecutive run is below the confirm + /// threshold: either a transient (a later match reset the run, leaving a sticky historical + /// mismatch) or a run still building toward a confirmed desync. + Suspect { + /// The current consecutive-mismatch run (`0` if the last compare matched). + consecutive: u32, + /// The earliest frame that ever diverged. + first_desync_frame: u32, + }, + /// The run has reached the confirm threshold: a real, sustained divergence. + /// + /// **Sticky once entered.** A rollback desync is unrecoverable — the peers cannot re-converge + /// without a full state resync — so the verdict never silently downgrades back to + /// [`Suspect`](Self::Suspect) on a later stray match. A surface that flapped between "desynced" + /// and "fine" would train the user to ignore it. + Desynced { + /// The earliest frame that diverged. + first_desync_frame: u32, + }, +} + +/// One recorded confirmed-frame checksum comparison. +#[derive(Clone, Copy, Debug, PartialEq, Eq)] +pub struct CrcCompare { + /// The confirmed frame whose checksums were compared. + pub frame: u32, + /// This peer's canonical (combined) gameplay digest for the frame. + pub local: u64, + /// The remote peer's reported digest for the frame. + pub remote: u64, + /// `true` if `local == remote` — in sync at this frame. + pub matched: bool, + /// `true` if the framebuffer-only hashes matched. + /// + /// This is what makes a mismatch *diagnosable* rather than just alarming, and it costs nothing + /// because `NetMessage::Checksum` already carries both hashes: + /// + /// * `!matched` but `same_framebuffer` — the picture agrees and only the cumulative cycle term + /// diverged, so the bug is in timing. + /// * `!matched` and `!same_framebuffer` — the rendered picture itself diverged, so the bug is + /// in state. + /// + /// Always `true` for a matched compare. + pub same_framebuffer: bool, +} + +/// A rolling, allocation-bounded record of recent confirmed-frame checksum comparisons, plus the +/// derived desync status. +/// +/// The history is a fixed-capacity ring ([`Self::CAPACITY`]); the first-desync frame and the +/// mismatch counters are **sticky scalars that survive eviction from the ring**, so a session that +/// has been running for an hour still reports the frame where it first diverged rather than +/// forgetting it once 64 newer comparisons arrive. +#[derive(Clone, Debug)] +pub struct DesyncDiagnostics { + /// Bounded ring of the most recent comparisons (oldest first). + history: VecDeque, + /// Total comparisons recorded across all time — not just those still in the ring. + total: u64, + /// Total mismatched comparisons recorded across all time. + mismatches: u64, + /// The earliest frame whose checksums disagreed, if any has yet. + first_desync_frame: Option, + /// Consecutive mismatches ending at the most recent comparison (reset to `0` by any match). + consecutive_mismatches: u32, + /// Peak consecutive-mismatch run ever observed. Drives the sticky [`DesyncStatus::Desynced`] + /// verdict: once the run has *ever* reached [`Self::desync_threshold`] the session is treated + /// as confirmed-desynced even if a later stray match resets the live run. + peak_consecutive: u32, + /// How many consecutive mismatches confirm a real desync (the hysteresis). + desync_threshold: u32, + /// The most recent comparison, for the local-vs-remote readout. + last: Option, +} + +impl Default for DesyncDiagnostics { + fn default() -> Self { + Self::new() + } +} + +impl DesyncDiagnostics { + /// Maximum comparisons retained in the rolling history ring. + /// + /// At the default 30-frame checksum interval (~2 per second) this is ~32 seconds of history — + /// long enough to see the shape of a divergence, short enough to stay a fixed allocation. + pub const CAPACITY: usize = 64; + + /// Default hysteresis: how many *consecutive* mismatching comparisons confirm a real desync. + /// + /// A checksum is exchanged only every `checksum_interval` frames and covers a *confirmed* + /// frame, so a legitimate one-off mismatch is nearly impossible on a correct implementation — + /// but a burst-reordered pair of `Checksum` messages can momentarily disagree before the + /// deferred comparison pass reconciles them. Requiring **3** in a row (~1.5 s at the default + /// interval) rejects that transient while still declaring a genuine divergence promptly. + pub const DEFAULT_DESYNC_THRESHOLD: u32 = 3; + + /// A fresh, empty record with the default confirm threshold. + /// + /// `const` so `RollbackSession::new` — which is itself `const fn` — can hold one without + /// giving that up. + #[must_use] + pub const fn new() -> Self { + Self::with_threshold(Self::DEFAULT_DESYNC_THRESHOLD) + } + + /// A fresh, empty record with an explicit confirm threshold. + /// + /// A threshold of `0` is treated as `1` (the very first mismatch confirms) rather than as + /// "confirm immediately and always", which is what a literal `>= 0` comparison would mean — + /// that would report [`DesyncStatus::Desynced`] on a session that has never mismatched. + #[must_use] + pub const fn with_threshold(desync_threshold: u32) -> Self { + Self { + history: VecDeque::new(), + total: 0, + mismatches: 0, + first_desync_frame: None, + consecutive_mismatches: 0, + peak_consecutive: 0, + // Spelled out rather than `.max(1)`: `Ord::max` is not `const`, and this constructor + // must be so the session's own `const fn new` survives. + desync_threshold: if desync_threshold == 0 { + 1 + } else { + desync_threshold + }, + last: None, + } + } + + /// Record one confirmed-frame checksum comparison. + /// + /// `local`/`remote` are the combined gameplay digests; `local_fb`/`remote_fb` are the + /// framebuffer-only hashes, used only to classify a mismatch. The session compares each + /// confirmed frame at most once, so no frame is double-counted. + pub fn record(&mut self, frame: u32, local: u64, remote: u64, local_fb: u64, remote_fb: u64) { + let matched = local == remote; + let entry = CrcCompare { + frame, + local, + remote, + matched, + same_framebuffer: local_fb == remote_fb, + }; + self.total = self.total.saturating_add(1); + if matched { + self.consecutive_mismatches = 0; + } else { + self.mismatches = self.mismatches.saturating_add(1); + self.consecutive_mismatches = self.consecutive_mismatches.saturating_add(1); + self.peak_consecutive = self.peak_consecutive.max(self.consecutive_mismatches); + // `min`, not "first one seen": comparisons are matched by frame number out of a pair of + // pending queues, so they can be recorded out of order. The EARLIEST diverging frame is + // the one worth reporting — it is where a bisect would start. + self.first_desync_frame = Some(self.first_desync_frame.map_or(frame, |f| f.min(frame))); + } + if self.history.len() == Self::CAPACITY { + self.history.pop_front(); + } + self.history.push_back(entry); + self.last = Some(entry); + } + + /// `true` if no mismatch has ever been recorded. + #[must_use] + pub const fn in_sync(&self) -> bool { + self.first_desync_frame.is_none() + } + + /// The graded [`DesyncStatus`] verdict — the frontend's single desync surface. + #[must_use] + pub const fn status(&self) -> DesyncStatus { + match self.first_desync_frame { + None => DesyncStatus::InSync, + Some(first) => { + // Keyed on the PEAK run, not the live one: once the run has ever reached the + // threshold the session is confirmed desynced, and a later stray match must not + // downgrade it (see `DesyncStatus::Desynced`). + if self.peak_consecutive >= self.desync_threshold { + DesyncStatus::Desynced { + first_desync_frame: first, + } + } else { + DesyncStatus::Suspect { + consecutive: self.consecutive_mismatches, + first_desync_frame: first, + } + } + } + } + } + + /// `true` once the run has ever reached the confirm threshold — i.e. [`Self::status`] is + /// [`DesyncStatus::Desynced`]. + #[must_use] + pub const fn is_desynced(&self) -> bool { + matches!(self.status(), DesyncStatus::Desynced { .. }) + } + + /// The confirm threshold in effect. + #[must_use] + pub const fn desync_threshold(&self) -> u32 { + self.desync_threshold + } + + /// Peak consecutive-mismatch run ever observed (survives a later match). + #[must_use] + pub const fn peak_consecutive_mismatches(&self) -> u32 { + self.peak_consecutive + } + + /// The earliest frame whose checksums disagreed, if any. + #[must_use] + pub const fn first_desync_frame(&self) -> Option { + self.first_desync_frame + } + + /// Consecutive mismatches ending at the most recent comparison. + #[must_use] + pub const fn consecutive_mismatches(&self) -> u32 { + self.consecutive_mismatches + } + + /// Total comparisons recorded across the whole session. + #[must_use] + pub const fn total(&self) -> u64 { + self.total + } + + /// Total mismatched comparisons recorded across the whole session. + #[must_use] + pub const fn mismatches(&self) -> u64 { + self.mismatches + } + + /// The most recent comparison, if any. + #[must_use] + pub const fn last(&self) -> Option { + self.last + } + + /// The rolling history, oldest first. + #[must_use] + pub fn history(&self) -> impl ExactSizeIterator { + self.history.iter() + } + + /// Number of entries currently in the rolling history ring. + #[must_use] + pub fn history_len(&self) -> usize { + self.history.len() + } +} + +#[cfg(test)] +mod tests { + use super::*; + + /// Record a run of matching compares starting at `frame`. + fn matches(d: &mut DesyncDiagnostics, frame: u32, n: u32) { + for i in 0..n { + d.record(frame + i, 0xAAAA, 0xAAAA, 0xBBBB, 0xBBBB); + } + } + + /// Record a run of mismatching compares starting at `frame`. + fn mismatches_run(d: &mut DesyncDiagnostics, frame: u32, n: u32) { + for i in 0..n { + d.record(frame + i, 0xAAAA, 0xCCCC, 0xBBBB, 0xDDDD); + } + } + + #[test] + fn fresh_is_in_sync() { + let d = DesyncDiagnostics::new(); + assert!(d.in_sync()); + assert_eq!(d.status(), DesyncStatus::InSync); + assert_eq!(d.first_desync_frame(), None); + assert_eq!(d.total(), 0); + assert_eq!(d.last(), None); + assert_eq!(d.history_len(), 0); + } + + #[test] + fn matching_compares_stay_in_sync() { + let mut d = DesyncDiagnostics::new(); + matches(&mut d, 0, 10); + assert!(d.in_sync()); + assert_eq!(d.status(), DesyncStatus::InSync); + assert_eq!(d.total(), 10); + assert_eq!(d.mismatches(), 0); + } + + #[test] + fn one_transient_mismatch_is_suspect_not_desynced() { + // THE POINT OF THE WHOLE MODULE. Before this, one mismatch was fatal and the frontend + // disconnected on it. A burst-reordered `Checksum` pair produces exactly this shape. + let mut d = DesyncDiagnostics::new(); + matches(&mut d, 0, 5); + mismatches_run(&mut d, 5, 1); + matches(&mut d, 6, 5); + + assert!( + !d.is_desynced(), + "a single transient must not confirm a desync" + ); + assert_eq!( + d.status(), + DesyncStatus::Suspect { + consecutive: 0, // the later matches reset the live run... + first_desync_frame: 5, // ...but the historical fact is sticky + } + ); + } + + #[test] + fn status_applies_hysteresis_then_confirms_and_sticks() { + let mut d = DesyncDiagnostics::new(); + assert_eq!(d.desync_threshold(), 3); + + mismatches_run(&mut d, 10, 1); + assert!(matches!( + d.status(), + DesyncStatus::Suspect { consecutive: 1, .. } + )); + mismatches_run(&mut d, 11, 1); + assert!(matches!( + d.status(), + DesyncStatus::Suspect { consecutive: 2, .. } + )); + + // Third in a row crosses the threshold. + mismatches_run(&mut d, 12, 1); + assert_eq!( + d.status(), + DesyncStatus::Desynced { + first_desync_frame: 10 + } + ); + + // ...and a later match must NOT downgrade it. A rollback desync is unrecoverable, so a + // surface that flapped back to "fine" would be lying. + matches(&mut d, 13, 20); + assert_eq!(d.consecutive_mismatches(), 0, "the live run does reset"); + assert_eq!( + d.status(), + DesyncStatus::Desynced { + first_desync_frame: 10 + }, + "but the verdict is sticky" + ); + } + + #[test] + fn first_desync_frame_is_the_earliest_even_recorded_out_of_order() { + // Comparisons are matched by frame number out of two pending queues, so they can arrive + // out of order. The earliest diverging frame is the one a bisect would start from. + let mut d = DesyncDiagnostics::new(); + mismatches_run(&mut d, 90, 1); + mismatches_run(&mut d, 40, 1); + assert_eq!(d.first_desync_frame(), Some(40)); + } + + #[test] + fn framebuffer_hash_classifies_the_kind_of_mismatch() { + let mut d = DesyncDiagnostics::new(); + // Same picture, different combined digest -> a timing divergence. + d.record(1, 0x1111, 0x2222, 0xFFFF, 0xFFFF); + let e = d.last().expect("recorded"); + assert!(!e.matched); + assert!(e.same_framebuffer, "same picture => timing bug, not state"); + + // Different picture -> a state divergence. + d.record(2, 0x1111, 0x2222, 0xFFFF, 0xEEEE); + let e = d.last().expect("recorded"); + assert!(!e.matched); + assert!(!e.same_framebuffer, "different picture => state bug"); + } + + #[test] + fn history_is_bounded_but_the_scalars_survive_eviction() { + let mut d = DesyncDiagnostics::new(); + mismatches_run(&mut d, 0, 1); + let overfill = u32::try_from(DesyncDiagnostics::CAPACITY).expect("capacity fits a u32") * 2; + matches(&mut d, 1, overfill); + + assert_eq!( + d.history_len(), + DesyncDiagnostics::CAPACITY, + "the ring must stay a fixed allocation" + ); + assert_eq!( + d.first_desync_frame(), + Some(0), + "the diverging frame must survive falling out of the ring — a long session would \ + otherwise forget where it broke" + ); + assert_eq!(d.mismatches(), 1); + assert_eq!(d.peak_consecutive_mismatches(), 1); + } + + #[test] + fn a_threshold_of_zero_is_treated_as_one() { + // Not as "confirm always": a literal `peak >= 0` would report Desynced on a session that + // has never mismatched at all. + let mut d = DesyncDiagnostics::with_threshold(0); + assert_eq!(d.desync_threshold(), 1); + assert_eq!(d.status(), DesyncStatus::InSync, "nothing recorded yet"); + + matches(&mut d, 0, 3); + assert_eq!(d.status(), DesyncStatus::InSync, "all matched"); + + mismatches_run(&mut d, 3, 1); + assert!( + d.is_desynced(), + "with threshold 1 the first mismatch confirms" + ); + } + + #[test] + fn history_is_ordered_oldest_first() { + let mut d = DesyncDiagnostics::new(); + matches(&mut d, 7, 3); + let frames: Vec = d.history().map(|c| c.frame).collect(); + assert_eq!(frames, vec![7, 8, 9]); + } +} diff --git a/crates/rustysnes-netplay/src/lib.rs b/crates/rustysnes-netplay/src/lib.rs index c12ce3c3..28dd02d7 100644 --- a/crates/rustysnes-netplay/src/lib.rs +++ b/crates/rustysnes-netplay/src/lib.rs @@ -14,6 +14,7 @@ //! bit-identically. `tests/determinism.rs` proves this over synthetic latency/jitter/packet-loss //! network conditions via [`transport::MemoryTransport`]. +pub mod diagnostics; pub mod message; pub mod rng; pub mod session; @@ -24,6 +25,7 @@ pub mod udp; #[cfg(target_arch = "wasm32")] pub mod webrtc; +pub use diagnostics::{CrcCompare, DesyncDiagnostics, DesyncStatus}; pub use message::NetMessage; pub use session::{AdvanceOutcome, MAX_PLAYERS, NetplayError, RollbackSession, SessionConfig}; pub use transport::Transport; diff --git a/crates/rustysnes-netplay/src/session.rs b/crates/rustysnes-netplay/src/session.rs index 08db8759..3439e0d7 100644 --- a/crates/rustysnes-netplay/src/session.rs +++ b/crates/rustysnes-netplay/src/session.rs @@ -24,6 +24,7 @@ use std::collections::VecDeque; use rustysnes_core::System; +use crate::diagnostics::DesyncDiagnostics; use crate::message::{NetMessage, PROTOCOL_VERSION, SYNC_MAGIC}; use crate::transport::Transport; @@ -172,6 +173,13 @@ pub struct RollbackSession { /// frame, gets resent each [`Self::advance`] call so a dropped `Input` packet is never /// permanently lost. remote_ack_frame: Option, + /// Rolling record of every confirmed-frame checksum comparison, and the graded desync verdict + /// derived from it (`v1.27.0`). + /// + /// Purely observational — see [`crate::diagnostics`]. It is written at the single compare site + /// and read by [`Self::diagnostics`]; nothing in the rollback path consults it except the + /// confirmed-desync gate, which replaced "fail on the first mismatch". + diagnostics: DesyncDiagnostics, } impl RollbackSession { @@ -201,9 +209,20 @@ impl RollbackSession { pending_local_checksums: VecDeque::new(), pending_remote_checksums: VecDeque::new(), remote_ack_frame: None, + diagnostics: DesyncDiagnostics::new(), } } + /// The rolling desync record and its graded verdict (`v1.27.0`). + /// + /// Read-only, and purely observational — see [`crate::diagnostics`]. A frontend renders + /// [`DesyncDiagnostics::status`] to distinguish a transient from a genuine divergence instead + /// of treating any mismatch as fatal. + #[must_use] + pub const fn diagnostics(&self) -> &DesyncDiagnostics { + &self.diagnostics + } + /// Send this peer's [`NetMessage::Sync`]. Call once before the first [`Self::advance`]; the /// remote peer's `Sync` is verified internally the first time it arrives. pub fn send_handshake(&mut self) { @@ -474,12 +493,23 @@ impl RollbackSession { self.checkpoint = Some((frame + 1, blob)); } - /// Compare every locally-computed checksum against a matching remote report (matched by - /// frame number) once both sides exist. Returns [`NetplayError::Desync`] on the first - /// mismatch found. + /// Compare every locally-computed checksum against a matching remote report (matched by frame + /// number) once both sides exist. + /// + /// Every comparison — **matching ones included** — is recorded in [`Self::diagnostics`], and + /// the fatal [`NetplayError::Desync`] is now raised only once that record's graded verdict + /// reaches [`DesyncStatus::Desynced`] rather than on the first mismatch seen. + /// + /// That change is the point of the module: a burst-reordered pair of `Checksum` messages can + /// momentarily disagree before this deferred pass reconciles them, and the old behaviour turned + /// that transient into a torn-down session. The hysteresis (3 consecutive by default) rejects + /// it while still failing promptly on a genuine divergence — which is unrecoverable for a + /// rollback session, so the error still ends the session when it does fire. fn compare_pending_checksums(&mut self) -> Result<(), NetplayError> { let mut still_pending = VecDeque::with_capacity(self.pending_local_checksums.len()); - let mut desync = None; + // The frame that first mismatched in THIS pass, kept for the error payload. The verdict + // itself comes from the diagnostics, not from this local. + let mut first_mismatch = None; for (frame, hash, fb_hash) in self.pending_local_checksums.drain(..) { let Some(pos) = self .pending_remote_checksums @@ -489,20 +519,38 @@ impl RollbackSession { still_pending.push_back((frame, hash, fb_hash)); continue; }; - let (_, remote_hash, _) = self.pending_remote_checksums.remove(pos).unwrap(); - if desync.is_none() && remote_hash != hash { - desync = Some((frame, hash, remote_hash)); + // The remote framebuffer hash was previously discarded here. It is what lets a + // mismatch be classified — same picture means a timing divergence, different picture + // means a state one — so it now reaches the diagnostics instead of the floor. + let (_, remote_hash, remote_fb) = self.pending_remote_checksums.remove(pos).unwrap(); + self.diagnostics + .record(frame, hash, remote_hash, fb_hash, remote_fb); + if first_mismatch.is_none() && remote_hash != hash { + first_mismatch = Some((frame, hash, remote_hash)); } } self.pending_local_checksums = still_pending; - match desync { - Some((frame, local_hash, remote_hash)) => Err(NetplayError::Desync { + + // Fail only on a CONFIRMED desync. `first_mismatch` may be `None` on the pass that + // finally confirms (the run could have been built by earlier passes), so fall back to the + // earliest diverging frame the diagnostics remember. + if self.diagnostics.is_desynced() { + let (frame, local_hash, remote_hash) = first_mismatch.unwrap_or_else(|| { + let frame = self.diagnostics.first_desync_frame().unwrap_or_default(); + let last = self.diagnostics.last(); + ( + frame, + last.map_or(0, |c| c.local), + last.map_or(0, |c| c.remote), + ) + }); + return Err(NetplayError::Desync { frame, local_hash, remote_hash, - }), - None => Ok(()), + }); } + Ok(()) } /// Ingest everything received, roll back and re-simulate if a misprediction was just diff --git a/crates/rustysnes-netplay/tests/desync_hysteresis.rs b/crates/rustysnes-netplay/tests/desync_hysteresis.rs new file mode 100644 index 00000000..a466159f --- /dev/null +++ b/crates/rustysnes-netplay/tests/desync_hysteresis.rs @@ -0,0 +1,183 @@ +//! The session-level half of the graded desync verdict (`v1.27.0`). +//! +//! `diagnostics.rs`'s own unit tests cover the verdict arithmetic. What they cannot cover is the +//! behaviour that actually changed: a [`RollbackSession`] used to return the fatal +//! [`NetplayError::Desync`] on the **first** checksum mismatch, and the frontend tore the session +//! down on it. A burst-reordered pair of `Checksum` messages produces exactly one such mismatch, +//! so a transient network event ended a healthy game. +//! +//! These tests drive a real session and forge the peer's `Checksum` messages, asserting the +//! session now survives a transient and still fails on a sustained divergence. + +use rustysnes_core::System; +use rustysnes_netplay::message::NetMessage; +use rustysnes_netplay::session::{NetplayError, RollbackSession, SessionConfig}; +use rustysnes_netplay::transport::{MemoryTransport, Transport}; +use rustysnes_netplay::{DesyncDiagnostics, DesyncStatus}; + +/// A minimal LoROM the `System` will accept — enough to run frames, which is all this needs. +fn minimal_rom() -> Vec { + let mut rom = vec![0u8; 0x8000]; + let h = 0x7FC0; + rom[h..h + 21].copy_from_slice(b"NETPLAY DESYNC TEST "); + rom[h + 0x15] = 0x20; // slow LoROM + rom[h + 0x17] = 0x08; // ROM size + rom[h + 0x1C..h + 0x1E].copy_from_slice(&(!0x1234u16).to_le_bytes()); + rom[h + 0x1E..h + 0x20].copy_from_slice(&0x1234u16.to_le_bytes()); + rom[h + 0x3C..h + 0x3E].copy_from_slice(&0x8000u16.to_le_bytes()); + rom +} + +fn fresh_system(rom: &[u8]) -> System { + let mut sys = System::new(0); + sys.bus.cart = Some(rustysnes_core::cart::Cart::from_rom(rom).expect("test ROM must load")); + sys.reset(); + sys +} + +/// Drive one session far enough that `checksum_interval` boundaries produce local checksums, while +/// the peer end feeds input plus whatever `Checksum` messages `forge` chooses to send. +/// +/// Returns the first error the session raised, if any, along with the session for inspection. +fn run_with_forged_checksums( + frames: u32, + mut forge: impl FnMut(u32) -> Option, +) -> (Result<(), NetplayError>, RollbackSession) { + let rom = minimal_rom(); + let hash = [0x5Au8; 32]; + let (ta, mut tb) = MemoryTransport::ideal_pair(); + + let mut sys = fresh_system(&rom); + let mut session = RollbackSession::new( + SessionConfig { + local_player: 0, + ..SessionConfig::default() + }, + ta, + hash, + ); + session.send_handshake(); + + // The peer's side of the handshake, so the session will trust anything that follows. + tb.send(&NetMessage::Sync { + magic: rustysnes_netplay::message::SYNC_MAGIC, + version: rustysnes_netplay::message::PROTOCOL_VERSION, + rom_hash: hash, + }); + + let mut outcome = Ok(()); + for frame in 0..frames { + session.add_local_input(0); + // The peer's input for this frame, so neither side stalls waiting for confirmation. + tb.send(&NetMessage::Input { + player: 1, + frame, + input: 0, + }); + if let Some(msg) = forge(frame) { + tb.send(&msg); + } + // Drain whatever the session sent, so the pipe does not grow unboundedly. + let _ = tb.poll(); + + if let Err(e) = session.advance(&mut sys) { + outcome = Err(e); + break; + } + } + (outcome, session) +} + +/// The frames at which the session emits a checksum, given the default 30-frame interval. +fn checksum_frames(upto: u32) -> Vec { + (0..upto).filter(|f| f % 30 == 0).collect() +} + +#[test] +fn a_single_mismatched_checksum_no_longer_kills_the_session() { + // THE REGRESSION THIS PR EXISTS FOR. Exactly one forged-wrong checksum — the shape a + // burst-reordered `Checksum` pair produces. Before the graded verdict this returned + // `NetplayError::Desync` and `app.rs` disconnected on it. + let poisoned = checksum_frames(200).first().copied().expect("an interval"); + let (outcome, session) = run_with_forged_checksums(200, |frame| { + (frame == poisoned).then_some(NetMessage::Checksum { + frame: poisoned, + hash: 0xDEAD_BEEF_DEAD_BEEF, + fb_hash: 0xDEAD_BEEF_DEAD_BEEF, + }) + }); + + assert!( + outcome.is_ok(), + "one transient mismatch must not end the session, got {outcome:?}" + ); + + // ANTI-VACUOUS GUARD. Surviving is only meaningful if the forged checksum actually reached the + // comparator — if it silently never matched a local checksum by frame number, this test would + // pass while exercising nothing. Measured: exactly one comparison, exactly one mismatch. + let d = session.diagnostics(); + assert_eq!(d.total(), 1, "the forged checksum must have been compared"); + assert_eq!( + d.mismatches(), + 1, + "and it must have been seen as a mismatch" + ); + assert_eq!(d.first_desync_frame(), Some(poisoned)); + assert_eq!( + d.status(), + DesyncStatus::Suspect { + consecutive: 1, + first_desync_frame: poisoned + }, + "a lone mismatch is Suspect, never Desynced" + ); + assert!(!d.is_desynced()); +} + +#[test] +fn a_sustained_divergence_still_fails_the_session() { + // The negative control. Tolerating a transient is only correct if a REAL divergence still + // ends the session — a rollback desync is unrecoverable, so continuing would mean two peers + // silently playing different games. + let poisoned: Vec = checksum_frames(400); + let (outcome, session) = run_with_forged_checksums(400, move |frame| { + poisoned.contains(&frame).then_some(NetMessage::Checksum { + frame, + hash: 0xDEAD_BEEF_DEAD_BEEF, + fb_hash: 0xDEAD_BEEF_DEAD_BEEF, + }) + }); + + assert!( + matches!(outcome, Err(NetplayError::Desync { .. })), + "a sustained divergence must still be fatal, got {outcome:?}" + ); + assert!(session.diagnostics().is_desynced()); + assert!(matches!( + session.diagnostics().status(), + DesyncStatus::Desynced { .. } + )); + assert!( + session.diagnostics().peak_consecutive_mismatches() + >= DesyncDiagnostics::DEFAULT_DESYNC_THRESHOLD, + "it must have crossed the confirm threshold, not fired early" + ); +} + +#[test] +fn a_clean_session_records_matching_compares_and_stays_in_sync() { + // Guards against the opposite failure: a diagnostics record that never sees a matching + // comparison would report `InSync` vacuously (it reports `InSync` when nothing is recorded at + // all), so this asserts real compares actually flowed through it. + let (outcome, session) = run_with_forged_checksums(200, |_| None); + assert!(outcome.is_ok()); + + let d = session.diagnostics(); + assert_eq!(d.status(), DesyncStatus::InSync); + assert_eq!(d.mismatches(), 0); + // The peer never sent a checksum, so nothing could be compared — the local side has no partner + // to match against. That is expected, and is exactly why this assertion is on `mismatches` + // rather than on `total`: asserting `total > 0` here would fail for a reason unrelated to the + // verdict, and asserting nothing would let a broken recorder pass. + assert!(d.in_sync()); +} diff --git a/docs/netplay.md b/docs/netplay.md new file mode 100644 index 00000000..9be80946 --- /dev/null +++ b/docs/netplay.md @@ -0,0 +1,88 @@ +# Netplay + +`crates/rustysnes-netplay` — GGPO-style rollback netplay. Spec for the crate; the rollback loop's +own mechanics are documented in `session.rs`'s module doc, and this file records the decisions that +span modules. + +## Scope + +Two players, because the SNES has two physical controller ports (`Bus::joypad: [u16; 2]`). The +sibling RustyNES project supports up to four via the NES Four Score and carries a `Roster` message +plus a mesh transport for it; neither is ported, and without multitap in the core neither would do +anything here. + +Deliberately **not** ported from that project either: the signalling/lobby protocol, room directory, +quick-match, STUN, and TURN relay. Those need a hosted signalling server — an operational +commitment, not just code — and the decision was to take the client-side depth without it. Sessions +are established by direct address. + +## Determinism + +The whole point. `RollbackSession::advance`'s rollback/re-simulate path must reproduce a +hypothetical zero-latency reference run **bit-identically**; `tests/determinism.rs` proves it over +synthetic latency, jitter, and packet loss via `MemoryTransport`. + +That constrains where wall-clock may live. `RollbackSession` reads no clock at all — it is a pure +function of its input stream — so anything time-based (timeouts, RTT, liveness) belongs outside it. + +## Desync detection (`v1.27.0`) + +Peers exchange a state checksum every `checksum_interval` frames (default 30). The message carries +**two** hashes: a combined gameplay digest and a framebuffer-only hash. + +### The verdict is graded, not binary + +Until `v1.27.0` the **first** mismatch was a fatal `NetplayError::Desync` and the frontend tore the +session down on it. That is too eager. A burst-reordered pair of `Checksum` messages can momentarily +disagree before the deferred `compare_pending_checksums` pass reconciles them, so a transient +network event ended a healthy game. + +`diagnostics::DesyncDiagnostics` now records **every** comparison — matching ones included — and +folds them into one `DesyncStatus`: + +| status | meaning | +|---|---| +| `InSync` | every comparison so far matched | +| `Suspect { consecutive, first_desync_frame }` | something mismatched, but the run is below the confirm threshold | +| `Desynced { first_desync_frame }` | the run reached the threshold — a real, sustained divergence | + +Three consecutive mismatches (~1.5 s at the default interval) confirm. The fatal error now fires +only on `Desynced`, so a transient is survived and a genuine divergence still ends the session — +which it must, because a rollback desync is unrecoverable without a full state resync. + +**`Desynced` is sticky.** A later stray match resets the live consecutive run but never downgrades +the verdict, because the underlying condition cannot actually heal. A surface that flapped between +"desynced" and "fine" would train the user to ignore it. + +### The framebuffer hash classifies the failure + +The remote framebuffer hash used to be discarded at the comparison site. It is now kept, and it is +what makes a mismatch diagnosable rather than merely alarming: + +- **same picture, different combined digest** — only the cumulative cycle term diverged, so the bug + is in **timing**; +- **different picture** — the rendered output itself diverged, so the bug is in **state**. + +### Purely observational + +`DesyncDiagnostics` only reads values the session already computed and stores copies. It never feeds +back into the rollback algorithm, the checksum exchange, or the emulator, and it holds no clock. +Deleting it would leave every produced frame, checksum, and rollback byte-identical — so it cannot +perturb the determinism contract above. + +The history is a fixed-capacity ring (64 entries, ~32 s at the default interval), but the +first-diverging frame and the mismatch counters are **sticky scalars that survive eviction**: a +session running for an hour still reports where it first broke rather than forgetting once 64 newer +comparisons arrive. + +### Tests + +`diagnostics.rs`'s unit tests cover the verdict arithmetic. `tests/desync_hysteresis.rs` covers what +actually changed, by driving a real session against forged peer checksums: + +- a single mismatched checksum no longer ends the session — and the test asserts the forged value + genuinely reached the comparator (`total == 1`, `mismatches == 1`), so it cannot pass vacuously; +- a sustained divergence still fails, having crossed the threshold rather than firing early; +- a clean session stays `InSync`. + +Both were verified by re-injecting the old fail-on-first behaviour and confirming they fail. From e686025e0082d2e5e12e020dad764f41d8082ad5 Mon Sep 17 00:00:00 2001 From: DoubleGate Date: Fri, 31 Jul 2026 11:01:01 -0400 Subject: [PATCH 2/2] fix(netplay): count the run in frames, and report one whole comparison MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review found two real defects in the graded-verdict PR. Both are mine. ## 1. The run counted consecutive RECORDS, not consecutive FRAMES `consecutive_mismatches` incremented in the order `record()` was called, with no frame-continuity check. On a lossy link the checksums in between may never arrive to be compared, so three isolated transients seconds apart would be recorded back-to-back and confirm a desync that never happened. It also contradicted the threshold's own stated rationale, which is expressed in TIME ("~1.5 s at the default interval") — a claim the implementation did not actually make true. A run now continues only if the mismatch is within `max_run_gap_frames` of the previous comparison, derived from the session's own `checksum_interval` via `gap_for_interval` (two intervals). That tolerates a single lost checksum inside a genuine run — a real desync mismatches EVERY checksum, so its members are one interval apart — while refusing to assemble a run out of widely separated transients. Both directions are pinned, because a gap check that is too tight is its own bug: `widely_separated_transients_do_not_stack_into_a_false_desync` (three mismatches minutes apart stay unconfirmed, and it asserts all three were actually recorded so it cannot pass vacuously) and `a_real_run_survives_one_lost_checksum` (a 60-frame gap inside a real run still confirms). Verified by disabling the continuity check and confirming the first fails while the second still passes. ## 2. The error payload could describe two different frames `NetplayError::Desync` was built from whatever this pass saw, falling back — when the confirming pass held no mismatch of its own, which happens whenever the run was built across earlier passes — to `first_desync_frame` paired with the hashes from `diagnostics.last()`. Those are different comparisons. The result was an error naming one frame and quoting another frame's hashes, which can even be a frame that MATCHED: precise-looking and wrong. `DesyncDiagnostics` now retains the first diverging `CrcCompare` whole, and the session reports that one record. The frame is also the right one to report on its own merits: the divergence's start is where a bisect begins, not where a counter crossed a threshold. `a_sustained_divergence_still_fails_the_session` now destructures the error and asserts frame + both hashes come from `first_desync()`, that the two hashes actually differ, and that later comparisons exist — so reporting the first is a genuine choice rather than a coincidence of a one-comparison run. ## Also `compare_pending_checksums` no longer `.unwrap()`s the `VecDeque::remove` (project rule on the untrusted-network path, regardless of the local `position()` reasoning making it infallible today). Declined: `VecDeque::with_capacity(CAPACITY)` for the history ring — `with_threshold_and_gap` is `const fn` so `RollbackSession::new` can stay one, and `with_capacity` is not const. The cost is a handful of reallocations once per session, against losing `const` on a public constructor. Verified: fmt, clippy `-D warnings`, `cargo doc` warnings-as-errors, 32 netplay tests green (25 lib + 3 integration + 4 determinism). Co-Authored-By: Claude Opus 5 (1M context) --- crates/rustysnes-netplay/src/diagnostics.rs | 171 ++++++++++++++++-- crates/rustysnes-netplay/src/session.rs | 53 +++--- .../tests/desync_hysteresis.rs | 41 ++++- docs/netplay.md | 26 +++ 4 files changed, 247 insertions(+), 44 deletions(-) diff --git a/crates/rustysnes-netplay/src/diagnostics.rs b/crates/rustysnes-netplay/src/diagnostics.rs index fc6a98d3..fcc8a57f 100644 --- a/crates/rustysnes-netplay/src/diagnostics.rs +++ b/crates/rustysnes-netplay/src/diagnostics.rs @@ -92,10 +92,30 @@ pub struct DesyncDiagnostics { total: u64, /// Total mismatched comparisons recorded across all time. mismatches: u64, - /// The earliest frame whose checksums disagreed, if any has yet. - first_desync_frame: Option, + /// The earliest **comparison** that disagreed, retained whole rather than as a bare frame + /// number. + /// + /// Keeping the full [`CrcCompare`] is what lets the session build a self-consistent + /// `NetplayError::Desync`: the reported frame and the reported hashes come from *one* + /// comparison. An earlier revision paired `first_desync_frame` with the hashes of whatever + /// happened to be compared last, which could describe a frame that matched. + first_desync: Option, /// Consecutive mismatches ending at the most recent comparison (reset to `0` by any match). consecutive_mismatches: u32, + /// The frame of the previous recorded comparison, for the run-continuity check below. + prev_frame: Option, + /// How far apart two mismatching comparisons may be and still count as one run. + /// + /// Without this, `consecutive_mismatches` counts consecutive *records*, not consecutive + /// *frames* — so on a lossy link where several checksums never arrive to be compared, three + /// isolated transients seconds apart would be recorded back-to-back and confirm a desync that + /// never happened. That would also contradict the threshold's own stated rationale, which is + /// expressed in time ("~1.5 s at the default interval"). + /// + /// A genuine desync mismatches *every* checksum, so its run members are exactly one interval + /// apart. Allowing a gap of two intervals tolerates a single lost checksum inside a real run + /// while breaking a run assembled from widely separated transients. + max_run_gap_frames: u32, /// Peak consecutive-mismatch run ever observed. Drives the sticky [`DesyncStatus::Desynced`] /// verdict: once the run has *ever* reached [`Self::desync_threshold`] the session is treated /// as confirmed-desynced even if a later stray match resets the live run. @@ -137,19 +157,43 @@ impl DesyncDiagnostics { Self::with_threshold(Self::DEFAULT_DESYNC_THRESHOLD) } - /// A fresh, empty record with an explicit confirm threshold. + /// The run-gap allowance implied by a checksum interval: two intervals, so a single lost + /// checksum stays inside a run while widely separated transients do not join one. + /// + /// `0` (checksums disabled) yields `0`, which disables the gap check — with no checksums there + /// are no comparisons to group. + #[must_use] + pub const fn gap_for_interval(checksum_interval: u32) -> u32 { + checksum_interval.saturating_mul(2) + } + + /// A fresh, empty record with an explicit confirm threshold and the default (disabled) run-gap + /// allowance. /// /// A threshold of `0` is treated as `1` (the very first mismatch confirms) rather than as /// "confirm immediately and always", which is what a literal `>= 0` comparison would mean — /// that would report [`DesyncStatus::Desynced`] on a session that has never mismatched. #[must_use] pub const fn with_threshold(desync_threshold: u32) -> Self { + Self::with_threshold_and_gap(desync_threshold, 0) + } + + /// A fresh, empty record with an explicit confirm threshold **and** run-gap allowance. + /// + /// `max_run_gap_frames` of `0` disables the gap check entirely (every recorded mismatch + /// continues the run, whatever its frame). Callers that know their checksum interval should + /// pass [`Self::gap_for_interval`] — see the field's own doc for why counting consecutive + /// *records* rather than consecutive *frames* is not sufficient on a lossy link. + #[must_use] + pub const fn with_threshold_and_gap(desync_threshold: u32, max_run_gap_frames: u32) -> Self { Self { history: VecDeque::new(), total: 0, mismatches: 0, - first_desync_frame: None, + first_desync: None, consecutive_mismatches: 0, + prev_frame: None, + max_run_gap_frames, peak_consecutive: 0, // Spelled out rather than `.max(1)`: `Ord::max` is not `const`, and this constructor // must be so the session's own `const fn new` survives. @@ -181,13 +225,35 @@ impl DesyncDiagnostics { self.consecutive_mismatches = 0; } else { self.mismatches = self.mismatches.saturating_add(1); - self.consecutive_mismatches = self.consecutive_mismatches.saturating_add(1); + + // Continuity check. A run only continues if this mismatch is close enough in FRAME + // terms to the previous comparison; otherwise it starts a fresh run of 1. Without it, + // `consecutive_mismatches` counts consecutive records, so on a lossy link where the + // checksums in between never arrived to be compared, isolated transients seconds apart + // would stack into a false confirmation. + let continues = match (self.max_run_gap_frames, self.prev_frame) { + // Gap checking disabled, or nothing recorded yet: behave as a plain run. + (0, _) | (_, None) => true, + (gap, Some(prev)) => frame.abs_diff(prev) <= gap, + }; + self.consecutive_mismatches = if continues { + self.consecutive_mismatches.saturating_add(1) + } else { + 1 + }; self.peak_consecutive = self.peak_consecutive.max(self.consecutive_mismatches); - // `min`, not "first one seen": comparisons are matched by frame number out of a pair of - // pending queues, so they can be recorded out of order. The EARLIEST diverging frame is - // the one worth reporting — it is where a bisect would start. - self.first_desync_frame = Some(self.first_desync_frame.map_or(frame, |f| f.min(frame))); + + // Keep the EARLIEST diverging comparison, whole. Comparisons are matched by frame + // number out of a pair of pending queues, so they can be recorded out of order — and + // the earliest diverging frame is where a bisect would start. Retaining the whole + // `CrcCompare` (not just its frame) is what lets the session report a frame and a pair + // of hashes that belong to the SAME comparison. + let earlier = self.first_desync.is_none_or(|f| frame < f.frame); + if earlier { + self.first_desync = Some(entry); + } } + self.prev_frame = Some(frame); if self.history.len() == Self::CAPACITY { self.history.pop_front(); } @@ -198,15 +264,16 @@ impl DesyncDiagnostics { /// `true` if no mismatch has ever been recorded. #[must_use] pub const fn in_sync(&self) -> bool { - self.first_desync_frame.is_none() + self.first_desync.is_none() } /// The graded [`DesyncStatus`] verdict — the frontend's single desync surface. #[must_use] pub const fn status(&self) -> DesyncStatus { - match self.first_desync_frame { + match self.first_desync { None => DesyncStatus::InSync, Some(first) => { + let first = first.frame; // Keyed on the PEAK run, not the live one: once the run has ever reached the // threshold the session is confirmed desynced, and a later stray match must not // downgrade it (see `DesyncStatus::Desynced`). @@ -246,7 +313,20 @@ impl DesyncDiagnostics { /// The earliest frame whose checksums disagreed, if any. #[must_use] pub const fn first_desync_frame(&self) -> Option { - self.first_desync_frame + match self.first_desync { + Some(c) => Some(c.frame), + None => None, + } + } + + /// The earliest diverging comparison, whole. + /// + /// The session builds `NetplayError::Desync` from this so the reported frame and the reported + /// hashes always describe the SAME comparison. Pairing a frame from one record with hashes + /// from another produces an error message that looks precise and is not. + #[must_use] + pub const fn first_desync(&self) -> Option { + self.first_desync } /// Consecutive mismatches ending at the most recent comparison. @@ -451,6 +531,73 @@ mod tests { ); } + #[test] + fn widely_separated_transients_do_not_stack_into_a_false_desync() { + // Raised in review. `consecutive_mismatches` counts consecutive RECORDS; on a lossy link + // the checksums in between may never arrive to be compared, so three isolated transients + // seconds apart would be recorded back-to-back. Without a frame-continuity check that + // confirms a desync that never happened — and contradicts the threshold's own rationale, + // which is stated in time ("~1.5 s at the default interval"). + let gap = DesyncDiagnostics::gap_for_interval(30); // 60 frames + let mut d = DesyncDiagnostics::with_threshold_and_gap(3, gap); + + // Three mismatches, each ~5 seconds apart, with nothing compared in between. + mismatches_run(&mut d, 30, 1); + mismatches_run(&mut d, 330, 1); + mismatches_run(&mut d, 630, 1); + + assert_eq!( + d.mismatches(), + 3, + "all three were recorded — this is not a vacuous pass" + ); + assert_eq!( + d.consecutive_mismatches(), + 1, + "each starts a fresh run rather than continuing the last" + ); + assert!( + !d.is_desynced(), + "three transients minutes apart are not a sustained divergence" + ); + } + + #[test] + fn a_real_run_survives_one_lost_checksum() { + // The negative control for the test above. A genuine desync mismatches EVERY checksum, so + // its run members are one interval apart — but a single lost checksum widens one gap to + // two intervals, and that must NOT break the run or a real desync would go unconfirmed on + // any lossy link. + let gap = DesyncDiagnostics::gap_for_interval(30); // tolerates a 60-frame gap + let mut d = DesyncDiagnostics::with_threshold_and_gap(3, gap); + + mismatches_run(&mut d, 30, 1); + mismatches_run(&mut d, 90, 1); // frame 60's checksum was lost — a 60-frame gap + mismatches_run(&mut d, 120, 1); + + assert_eq!(d.consecutive_mismatches(), 3, "the run held across the gap"); + assert!(d.is_desynced(), "a real divergence must still confirm"); + } + + #[test] + fn the_first_diverging_comparison_is_retained_whole() { + // The session builds `NetplayError::Desync` from this, so the frame and the hashes must + // describe the SAME comparison. Pairing a frame from one record with hashes from another + // produces an error that looks precise and is not. + let mut d = DesyncDiagnostics::new(); + d.record(50, 0x1111, 0x2222, 0xAAAA, 0xBBBB); + d.record(80, 0x3333, 0x4444, 0xCCCC, 0xDDDD); + + let first = d.first_desync().expect("a divergence was recorded"); + assert_eq!(first.frame, 50); + assert_eq!(first.local, 0x1111, "hashes must come from frame 50..."); + assert_eq!(first.remote, 0x2222, "...not from the later record"); + assert_eq!(d.first_desync_frame(), Some(50)); + + // And `last()` is genuinely a different comparison, so the two cannot be confused. + assert_eq!(d.last().expect("recorded").frame, 80); + } + #[test] fn history_is_ordered_oldest_first() { let mut d = DesyncDiagnostics::new(); diff --git a/crates/rustysnes-netplay/src/session.rs b/crates/rustysnes-netplay/src/session.rs index 3439e0d7..6f9ff482 100644 --- a/crates/rustysnes-netplay/src/session.rs +++ b/crates/rustysnes-netplay/src/session.rs @@ -197,6 +197,13 @@ impl RollbackSession { (config.local_player as usize) < MAX_PLAYERS, "SessionConfig::local_player must be < MAX_PLAYERS" ); + // The run-gap allowance is derived from this session's own checksum interval, so the + // hysteresis counts consecutive *frames* rather than merely consecutive *records* — see + // `DesyncDiagnostics::max_run_gap_frames`. Read before `config` is moved into `Self`. + let diagnostics = DesyncDiagnostics::with_threshold_and_gap( + DesyncDiagnostics::DEFAULT_DESYNC_THRESHOLD, + DesyncDiagnostics::gap_for_interval(config.checksum_interval), + ); Self { config, transport, @@ -209,7 +216,7 @@ impl RollbackSession { pending_local_checksums: VecDeque::new(), pending_remote_checksums: VecDeque::new(), remote_ack_frame: None, - diagnostics: DesyncDiagnostics::new(), + diagnostics, } } @@ -509,7 +516,6 @@ impl RollbackSession { let mut still_pending = VecDeque::with_capacity(self.pending_local_checksums.len()); // The frame that first mismatched in THIS pass, kept for the error payload. The verdict // itself comes from the diagnostics, not from this local. - let mut first_mismatch = None; for (frame, hash, fb_hash) in self.pending_local_checksums.drain(..) { let Some(pos) = self .pending_remote_checksums @@ -519,35 +525,38 @@ impl RollbackSession { still_pending.push_back((frame, hash, fb_hash)); continue; }; + // `if let` rather than `.unwrap()`: `pos` came from `position()` so the remove cannot + // fail today, but this is the untrusted-network path and the project's rule is to not + // unwrap on a collection operation regardless of local reasoning. + // // The remote framebuffer hash was previously discarded here. It is what lets a // mismatch be classified — same picture means a timing divergence, different picture // means a state one — so it now reaches the diagnostics instead of the floor. - let (_, remote_hash, remote_fb) = self.pending_remote_checksums.remove(pos).unwrap(); - self.diagnostics - .record(frame, hash, remote_hash, fb_hash, remote_fb); - if first_mismatch.is_none() && remote_hash != hash { - first_mismatch = Some((frame, hash, remote_hash)); + if let Some((_, remote_hash, remote_fb)) = self.pending_remote_checksums.remove(pos) { + self.diagnostics + .record(frame, hash, remote_hash, fb_hash, remote_fb); } } self.pending_local_checksums = still_pending; - // Fail only on a CONFIRMED desync. `first_mismatch` may be `None` on the pass that - // finally confirms (the run could have been built by earlier passes), so fall back to the - // earliest diverging frame the diagnostics remember. + // Fail only on a CONFIRMED desync, and report the EARLIEST diverging comparison rather + // than whatever this pass happened to see. + // + // Both halves matter. The confirming pass may contain no mismatch of its own (the run can + // have been built across earlier passes), and the frame worth reporting is where the + // divergence began — that is where a bisect starts, not where the counter crossed a + // threshold. Taking the whole `CrcCompare` also keeps the payload self-consistent: an + // earlier revision paired `first_desync_frame` with the hashes of whatever was compared + // last, which could describe a completely different — even matching — frame. if self.diagnostics.is_desynced() { - let (frame, local_hash, remote_hash) = first_mismatch.unwrap_or_else(|| { - let frame = self.diagnostics.first_desync_frame().unwrap_or_default(); - let last = self.diagnostics.last(); - ( - frame, - last.map_or(0, |c| c.local), - last.map_or(0, |c| c.remote), - ) - }); + let first = self + .diagnostics + .first_desync() + .expect("is_desynced() implies a recorded first divergence"); return Err(NetplayError::Desync { - frame, - local_hash, - remote_hash, + frame: first.frame, + local_hash: first.local, + remote_hash: first.remote, }); } Ok(()) diff --git a/crates/rustysnes-netplay/tests/desync_hysteresis.rs b/crates/rustysnes-netplay/tests/desync_hysteresis.rs index a466159f..e5a32349 100644 --- a/crates/rustysnes-netplay/tests/desync_hysteresis.rs +++ b/crates/rustysnes-netplay/tests/desync_hysteresis.rs @@ -148,19 +148,40 @@ fn a_sustained_divergence_still_fails_the_session() { }) }); + let Err(NetplayError::Desync { + frame, + local_hash, + remote_hash, + }) = outcome + else { + panic!("a sustained divergence must still be fatal, got {outcome:?}"); + }; + let d = session.diagnostics(); + assert!(d.is_desynced()); + assert!(matches!(d.status(), DesyncStatus::Desynced { .. })); assert!( - matches!(outcome, Err(NetplayError::Desync { .. })), - "a sustained divergence must still be fatal, got {outcome:?}" + d.peak_consecutive_mismatches() >= DesyncDiagnostics::DEFAULT_DESYNC_THRESHOLD, + "it must have crossed the confirm threshold, not fired early" ); - assert!(session.diagnostics().is_desynced()); - assert!(matches!( - session.diagnostics().status(), - DesyncStatus::Desynced { .. } - )); + + // THE ERROR PAYLOAD MUST BE SELF-CONSISTENT (raised in review). The confirming pass may hold + // no mismatch of its own — the run can be built across earlier passes — and an earlier + // revision filled the gap by pairing `first_desync_frame` with the hashes of whatever was + // compared LAST, which can be a different, even matching, frame. The reported frame and the + // reported hashes must come from one comparison. + let first = d.first_desync().expect("a divergence was recorded"); + assert_eq!(frame, first.frame, "the frame must be the FIRST divergence"); + assert_eq!(local_hash, first.local, "and its own local hash"); + assert_eq!(remote_hash, first.remote, "and its own remote hash"); + assert_ne!( + local_hash, remote_hash, + "a reported desync must describe a comparison that actually disagreed" + ); + // The divergence began before the frame that crossed the threshold, so this is a real + // distinction and not a coincidence of a one-comparison run. assert!( - session.diagnostics().peak_consecutive_mismatches() - >= DesyncDiagnostics::DEFAULT_DESYNC_THRESHOLD, - "it must have crossed the confirm threshold, not fired early" + d.last().expect("recorded").frame > first.frame, + "later comparisons exist, so reporting the first is a genuine choice" ); } diff --git a/docs/netplay.md b/docs/netplay.md index 9be80946..863fcf86 100644 --- a/docs/netplay.md +++ b/docs/netplay.md @@ -54,6 +54,32 @@ which it must, because a rollback desync is unrecoverable without a full state r the verdict, because the underlying condition cannot actually heal. A surface that flapped between "desynced" and "fine" would train the user to ignore it. +### The run counts consecutive *frames*, not consecutive *records* + +The threshold's rationale is stated in time ("~1.5 s at the default interval"), so the +implementation has to agree with that. Counting consecutive *recorded comparisons* would not: on a +lossy link the checksums in between may never arrive to be compared, so three isolated transients +seconds apart would be recorded back-to-back and confirm a desync that never happened. + +A run therefore continues only if the mismatch is within `max_run_gap_frames` of the previous +comparison, derived from the session's own `checksum_interval` via +`DesyncDiagnostics::gap_for_interval` (two intervals). That tolerates a single lost checksum inside +a genuine run — a real desync mismatches *every* checksum, so its members are one interval apart — +while refusing to assemble a run out of widely separated transients. Both directions are pinned by +tests, since a gap check that is too tight would let a real desync go unconfirmed on any lossy link. + +### The error payload describes one comparison + +`NetplayError::Desync` reports the **earliest** diverging comparison, whole. Two things force that. +The confirming pass may contain no mismatch of its own (the run can be built across earlier passes), +and the frame worth reporting is where the divergence *began* — that is where a bisect starts, not +where a counter crossed a threshold. + +So `DesyncDiagnostics` retains the first diverging `CrcCompare` rather than just its frame number. +An earlier revision filled the gap by pairing `first_desync_frame` with the hashes of whatever was +compared last, which can be a different — even matching — frame: an error message that looks precise +and is not. + ### The framebuffer hash classifies the failure The remote framebuffer hash used to be discarded at the comparison site. It is now kept, and it is