From 1eb52ebd52d6d17dfbe534fdc22b11543f2e447b Mon Sep 17 00:00:00 2001 From: DoubleGate Date: Wed, 19 Aug 2026 03:07:50 -0400 Subject: [PATCH 1/2] fix(probe): carry provenance across the three restores that were clearing it MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Running the Latency Oracle or the RAM Atlas emptied both the Pixel Provenance and the Audio Provenance panels. `Nes::restore_inner` clears both stores, which is right for a genuine timeline change and wrong for a restore that puts back the state the user is still looking at. v2.3.6 added `Nes::take_provenance` / `put_provenance` for exactly that exception and wired it into `RunAhead::finish`, the one call site the bug report had named. `rustynes-probe` has three more same-timeline restores and none of them used it: * `Probe::run_uncounted` restores the anchor once per trial, and `latency::measure_in_place` runs up to 21 trials against the LIVE emulator. * `latency::measure_in_place` restores the caller's state on the way out, a restore that sits OUTSIDE every per-trial guard, so fixing the trial path alone leaves it broken. * The RAM Atlas panel's `TimelineGuard` restores after each observation. Both stores are cumulative. "Which instruction last wrote this" can point thousands of frames back — a palette byte written at level load, a `$4008` linear-counter reload written once during init — so the records were not rebuilt by the next frame. They were gone for the session. Closed by moving the stash into `rustynes_probe::TrialGuard`, renamed from `CaptureGuard` because it no longer carries only the rewind flag. The two are the same category of state and belong behind one guard: both live outside the save state, so neither is carried by a snapshot round trip, and both must therefore be carried deliberately. The guard is now entered BEFORE the anchor restore rather than after it, since that restore is one of the things the stores need protecting from. Restoring in `Drop` keeps the unwind path covered, and unlike the snapshot restore declined for a `Drop` guard on PR #385, putting a stash back is infallible, so nothing fallible is being hidden. `rustynes-probe` gains a `debug-hooks` passthrough feature. Without it the new code would compile out in precisely the builds that need it: cargo's feature unification already switches on `rustynes-core/debug-hooks` for a frontend build, so the clearing is live, while a `cfg` on a feature the crate does not declare is never true. Four tests, four independent mutations, one per store and one per site: removing either put-back, entering the guard after the restore, or unguarding `measure_in_place` each fails exactly the test that pins it and no other. The per-site pair is deliberate — a fix covering only `run_uncounted` passes the trial test and fails the measurement one. The existing `measure_in_place_restores_the_live_timeline` could not have caught this. It compares `nes.snapshot()` before and after, and provenance is deliberately not in the snapshot, so the assertion was true throughout while the state its own name claims to cover was being destroyed. A test fixture note for whoever writes the next one: the first `run_frame` after `Nes::from_rom` returns on an already-pending frame-complete flag without executing an instruction, so a one-frame fixture leaves the PC at the reset vector and the attribution table empty. `docs/pixel-provenance.md` described run-ahead as "the one caller that needs the exception". The rule stated there is right; the enumeration under it was not. Both that sentence and the v2.3.6 retraction it already carried are kept in place rather than rewritten, because the pair is the evidence. No emulation-core file is touched — the change is confined to `rustynes-probe` and the frontend panel — so AccuracyCoin 141/141 and nestest 0-diff hold by construction rather than by assertion. Co-Authored-By: Claude Opus 5 --- CHANGELOG.md | 33 +++ crates/rustynes-frontend/Cargo.toml | 2 +- .../src/debugger/atlas_panel.rs | 26 ++ crates/rustynes-probe/Cargo.toml | 12 + crates/rustynes-probe/src/atlas.rs | 8 +- crates/rustynes-probe/src/latency.rs | 15 +- crates/rustynes-probe/src/lib.rs | 256 +++++++++++++++++- docs/audio-provenance.md | 47 ++++ docs/pixel-provenance.md | 34 ++- 9 files changed, 409 insertions(+), 24 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index db084505..bb5ed4c1 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -81,6 +81,39 @@ cycle-accurate core later replaced. ### Fixed +- **The Latency Oracle and the RAM Atlas no longer empty the provenance + panels.** Both drive the emulator and then put the timeline back, and + `Nes::restore_inner` clears the pixel- and audio-provenance stores — correctly + for a genuine timeline change, wrongly for a restore of the state the user is + still looking at. `rustynes-probe` had three such restores and none of them + used the `take_provenance` / `put_provenance` stash that v2.3.6 added for + exactly this: `Probe::run_uncounted` (once per trial, and a latency + measurement runs up to 21 of them), `latency::measure_in_place` (the final + restore, which sits outside every per-trial guard), and the RAM Atlas panel's + `TimelineGuard`. Both stores are **cumulative** — "which instruction last + wrote this" can point thousands of frames back, to a palette byte from level + load or a `$4008` reload from init — so the records were not rebuilt by the + next frame; they were gone for the session. + + This is the defect class v2.3.6 was written about, found in three more places. + The v2.3.6 fix was correct at the call site the bug report named and stopped + there, and `docs/pixel-provenance.md` then described run-ahead as "the one + caller that needs the exception" — a correct rule with an incomplete + enumeration under it. Closed by moving the stash into + `rustynes_probe::TrialGuard`, the guard that already carried rewind capture + across a trial for the same underlying reason: state that lives outside the + save state is not carried by a snapshot round trip. + + Pinned by four tests under four independent mutations — one per store and one + per site — so a fix that put back only one store, or guarded only one of the + two probe restores, fails. The existing + `measure_in_place_restores_the_live_timeline` could not have caught it: it + compares `nes.snapshot()` before and after, and provenance is deliberately not + in the snapshot, so it asserted something strictly weaker than the contract it + is named for. `rustynes-probe` gains a `debug-hooks` passthrough feature, + without which the guard would have compiled out in precisely the builds that + need it. + - **VRC7 save states now carry the FM synthesizer, so rewind no longer garbles the music.** `Vrc7::save_state` wrote the *shadow* OPLL register bytes and never the live synthesizer — not `opll`, not `opll_clock_counter`, not diff --git a/crates/rustynes-frontend/Cargo.toml b/crates/rustynes-frontend/Cargo.toml index fa830bb8..64d144e7 100644 --- a/crates/rustynes-frontend/Cargo.toml +++ b/crates/rustynes-frontend/Cargo.toml @@ -147,7 +147,7 @@ browser-cheevos = [] # alias just lets `cargo clippy -p rustynes-frontend --features debug-hooks` # resolve to the same build; it adds nothing (the dependency below is the real # enable). The output-only `debug-hooks` core code is determinism-neutral. -debug-hooks = ["rustynes-core/debug-hooks"] +debug-hooks = ["rustynes-core/debug-hooks", "rustynes-probe/debug-hooks"] # v1.6.0 "Studio" Workstream G — A/V recording (default OFF, native-only). # diff --git a/crates/rustynes-frontend/src/debugger/atlas_panel.rs b/crates/rustynes-frontend/src/debugger/atlas_panel.rs index de7e3031..6f1578ab 100644 --- a/crates/rustynes-frontend/src/debugger/atlas_panel.rs +++ b/crates/rustynes-frontend/src/debugger/atlas_panel.rs @@ -585,15 +585,33 @@ struct TimelineGuard<'a> { nes: &'a mut Nes, snapshot: Vec, restored: bool, + /// v2.3.7 — the pixel- and audio-provenance stores, held across the restore. + /// + /// The same reasoning as `rustynes_probe::TrialGuard`, and it has to be + /// repeated here because this guard owns its own restore: both stores live + /// OUTSIDE the save state, and `Nes::restore_quiet` clears them, so putting + /// the timeline back also emptied whatever the Pixel Provenance and Audio + /// Provenance panels had accumulated. Cumulative attribution is not + /// rebuilt by the next frame — a palette byte or a `$4008` write from level + /// load does not happen again — so the loss was permanent for the session. + #[cfg(feature = "debug-hooks")] + provenance: ( + rustynes_core::rustynes_ppu::ProvenanceStash, + rustynes_core::rustynes_apu::provenance::AudioProvenanceStash, + ), } impl<'a> TimelineGuard<'a> { fn capture(nes: &'a mut Nes) -> Self { let snapshot = nes.snapshot(); + #[cfg(feature = "debug-hooks")] + let provenance = (nes.take_provenance(), nes.take_audio_provenance()); Self { nes, snapshot, restored: false, + #[cfg(feature = "debug-hooks")] + provenance, } } @@ -613,6 +631,14 @@ impl Drop for TimelineGuard<'_> { // a panic during unwinding aborts. let _ = self.nes.restore_quiet(&self.snapshot); } + // AFTER any restore, on both paths, so the stores are put back into a + // timeline that has already stopped being rewritten. + #[cfg(feature = "debug-hooks")] + { + let (pixel, audio) = core::mem::take(&mut self.provenance); + self.nes.put_provenance(pixel); + self.nes.put_audio_provenance(audio); + } } } diff --git a/crates/rustynes-probe/Cargo.toml b/crates/rustynes-probe/Cargo.toml index f5b88e5e..78ecaba5 100644 --- a/crates/rustynes-probe/Cargo.toml +++ b/crates/rustynes-probe/Cargo.toml @@ -19,6 +19,18 @@ authors.workspace = true repository.workspace = true description = "Deterministic re-simulation probe: anchor, replay under variation, locate the first divergence" +[features] +# Off by default, forwarded from `rustynes-frontend/debug-hooks`. +# +# The probe crate needs to SEE this feature, not merely inherit its effects. +# Cargo's feature unification means a frontend build with `debug-hooks` already +# switches on `rustynes-core/debug-hooks`, so `Nes::restore_quiet` starts +# clearing the provenance stores — while any `#[cfg(feature = "debug-hooks")]` +# code in THIS crate stays compiled out, because a crate can only `cfg` on +# features it declares. Without this passthrough the guard that preserves those +# stores would be dead code in exactly the build that needs it. +debug-hooks = ["rustynes-core/debug-hooks"] + [dependencies] rustynes-core = { path = "../rustynes-core" } diff --git a/crates/rustynes-probe/src/atlas.rs b/crates/rustynes-probe/src/atlas.rs index 0ac55dba..43bbbe2f 100644 --- a/crates/rustynes-probe/src/atlas.rs +++ b/crates/rustynes-probe/src/atlas.rs @@ -171,7 +171,9 @@ where // far larger than cache. let mut frame_major: Vec = Vec::with_capacity(WRAM_LEN * frames as usize); // Rewind capture is suppressed for the whole window, by the same guard a - // trial uses. These frames advance the live emulator and the caller rolls + // trial uses — which also moves the provenance stores out, so an + // observation's 180 rolled-back frames cannot contribute attributions to a + // timeline they never happened on (v2.3.7). These frames advance the live emulator and the caller rolls // them back, so they never happened on the user's timeline — letting them // into the ring would allow rewinding *into an observation*, which is exactly // the defect this crate had just fixed for `verify_liveness` and then @@ -180,7 +182,7 @@ where // The guard also makes this panic-safe: an observation is 180 frames, and a // panic part-way through must not leave capture disabled on a `Nes` the // caller keeps using. - let guard = crate::CaptureGuard::suppress(nes); + let guard = crate::TrialGuard::enter(nes); for f in 0..frames { let (p1, p2) = input(f); guard.nes.set_buttons(0, p1); @@ -737,7 +739,7 @@ mod tests { /// fixed for `verify_liveness` and then reintroduced one function away, caught /// in review on PR #392. /// - /// Mutation-checked: removing the `CaptureGuard` from `observe` fails this + /// Mutation-checked: removing the `TrialGuard` from `observe` fails this /// with the ring grown by the window length. #[test] fn observing_does_not_pollute_the_callers_rewind_ring() { diff --git a/crates/rustynes-probe/src/latency.rs b/crates/rustynes-probe/src/latency.rs index 187efdc7..ce0e48f1 100644 --- a/crates/rustynes-probe/src/latency.rs +++ b/crates/rustynes-probe/src/latency.rs @@ -189,7 +189,13 @@ pub fn measure(nes: &mut Nes, anchor: &Nes, cfg: LatencyConfig) -> LatencyReport pub fn measure_in_place(nes: &mut Nes, cfg: LatencyConfig) -> LatencyReport { let restore_point = nes.snapshot(); let mut probe = Probe::anchor(&*nes, budget_for(cfg)); - let report = run_measurement(&mut probe, nes, cfg); + // v2.3.7 — the guard spans the measurement AND the final restore below, + // which is the whole point of putting it here rather than relying on the + // per-trial guards inside `run_measurement`. Those end with their trial, so + // the final restore on the way out sat outside all of them and cleared the + // provenance stores after every one of them had carefully preserved it. + let guard = crate::TrialGuard::enter(nes); + let report = run_measurement(&mut probe, &mut *guard.nes, cfg); // Put the user's timeline back exactly. A measurement that leaves the game // 400 frames further on would be a worse bug than the one it measures. // @@ -205,8 +211,13 @@ pub fn measure_in_place(nes: &mut Nes, cfg: LatencyConfig) -> LatencyReport { // the snapshot format cannot round-trip itself; returning normally would // hand the user a report while leaving their game several hundred frames // ahead, which is precisely the outcome this line exists to prevent. - nes.restore_quiet(&restore_point) + guard + .nes + .restore_quiet(&restore_point) .expect("a snapshot taken from this instance restores to it"); + // Explicit, so the order is stated rather than inferred from scope: the + // stores go back AFTER the restore that would otherwise have cleared them. + drop(guard); report } diff --git a/crates/rustynes-probe/src/lib.rs b/crates/rustynes-probe/src/lib.rs index 2445a126..45b6b015 100644 --- a/crates/rustynes-probe/src/lib.rs +++ b/crates/rustynes-probe/src/lib.rs @@ -220,9 +220,7 @@ impl Probe { // there changed only `measure_in_place`'s FINAL restore — which left // every trial's restore, the actual source, untouched. Fixed here at the // one site all trials share. - nes.restore_quiet(&self.snapshot) - .expect("probe anchor round-trips: it came from Nes::snapshot"); - + // // A trial's frames are re-simulated: they never happened on the user's // timeline. Letting them into the rewind ring would let the user rewind // *into a measurement* — the same reason run-ahead suppresses capture @@ -235,7 +233,17 @@ impl Probe { // on a `Nes` the caller keeps using. That failure would be silent and // durable: rewind would simply stop recording, with nothing to indicate // why. (PR #392 review.) - let guard = CaptureGuard::suppress(nes); + // + // The guard is entered BEFORE the restore, not after. It carries the + // provenance stores as well as the rewind flag (see [`TrialGuard`]), and + // the restore on the very next line is one of the things they need + // protecting from — `restore_inner` clears both. Constructing it after + // would put the stores back intact and then have already lost them. + let guard = TrialGuard::enter(nes); + guard + .nes + .restore_quiet(&self.snapshot) + .expect("probe anchor round-trips: it came from Nes::snapshot"); // The perturbation, if any: applied to the freshly-restored anchor before // frame 0, so it is the ONLY difference between this trial and a @@ -365,8 +373,20 @@ impl Probe { } } -/// Suppresses rewind capture for the lifetime of a trial and restores the -/// caller's setting on drop — including on an unwinding panic. +/// Holds the caller's *unserialised* emulator state across a trial and puts it +/// back on drop — including on an unwinding panic. +/// +/// Two things, for one reason. Both rewind capture and the provenance stores +/// live outside the save state, so a probe's snapshot/restore round trip does +/// not carry them: they are whatever the trial left behind. This guard is the +/// list of everything in that category, and a new entry belongs here rather +/// than in a second guard beside it. +/// +/// # Rewind capture +/// +/// Suppressed for the trial's frames. They are re-simulated and never happened +/// on the user's timeline, so letting them into the ring would allow rewinding +/// *into a measurement*. /// /// A plain save-and-restore around the trial body is correct on the happy path /// and wrong on the unwind: a panic inside `Nes::run_frame` or the perturbation @@ -374,6 +394,35 @@ impl Probe { /// caller keeps using. Rewind would then stop recording silently, with nothing /// to indicate why. /// +/// # Provenance (v2.3.7) +/// +/// Both provenance stores are moved out for the duration and put back after. +/// They are **cumulative**, which is what makes this necessary rather than +/// tidy: pixel provenance's per-byte write attribution and audio provenance's +/// per-register attribution answer "which instruction last wrote this", and +/// "last" can be thousands of frames ago — a palette byte written at level +/// load, a `$4008` linear-counter reload written once during init. +/// +/// `Nes::restore_inner` clears both, correctly: a restored state's bytes were +/// not written by any instruction this session executed, so keeping their PCs +/// would report a timeline that no longer exists. But a probe's restore is the +/// case that reasoning does not cover — it puts back the SAME timeline the user +/// is still looking at, which is precisely what `Nes::take_provenance` and +/// `Nes::take_audio_provenance` were added for. Only `RunAhead::finish` used +/// them; every probe restore did not, so asking "how much input lag does this +/// game have?" silently emptied both panels, and the RAM Atlas did the same. +/// +/// The trial's own frames are left unrecorded rather than recorded and +/// discarded: with the stores moved out, the emulator is unarmed for the +/// duration, so a re-simulated frame cannot contribute an attribution to a +/// timeline it never happened on. +/// +/// This is the same defect class as the one v2.3.6 was written about — a +/// rollback wiping a store before any UI could read it — and it went unnoticed +/// for the same reason: `measure_in_place_restores_the_live_timeline` asserts +/// the two snapshots match, and provenance is not IN the snapshot, so the +/// weaker assertion passed while the state it did not cover was destroyed. +/// /// Worth contrasting with the `Drop` guard declined for /// `latency::measure_in_place` on PR #385, because the reasoning genuinely /// differs rather than being applied inconsistently. There, the guard would have @@ -384,24 +433,61 @@ impl Probe { /// `panic = "abort"` argument does not rescue this case either: in a build that /// does unwind, this flag outlives the panic, whereas an advanced timeline in a /// dying process does not. -pub(crate) struct CaptureGuard<'a> { +pub(crate) struct TrialGuard<'a> { pub(crate) nes: &'a mut Nes, restore_to: bool, + /// The caller's pixel- and audio-provenance stores, moved out for the + /// duration so neither the anchor restore nor the trial's frames can touch + /// them. `None` in a build without the feature, and cheap when unarmed: + /// each stash is one moved `Option>`. + #[cfg(feature = "debug-hooks")] + provenance: ( + rustynes_core::rustynes_ppu::ProvenanceStash, + rustynes_core::rustynes_apu::provenance::AudioProvenanceStash, + ), } -impl<'a> CaptureGuard<'a> { - pub(crate) const fn suppress(nes: &'a mut Nes) -> Self { +impl<'a> TrialGuard<'a> { + // Not `const fn`: with `debug-hooks` on it calls `Nes::take_provenance`, + // which allocates nothing but is not const. Clippy only sees the + // feature-off body, where the whole function is a bool read and a bool + // write, so it asks for a `const` the other configuration cannot provide. + // Allowed on that configuration alone rather than unconditionally, so the + // lint keeps working everywhere else in the crate. + #[cfg_attr( + not(feature = "debug-hooks"), + allow( + clippy::missing_const_for_fn, + reason = "const only in the feature-off body; see comment above" + ) + )] + pub(crate) fn enter(nes: &'a mut Nes) -> Self { // The caller's setting, not an assumed `true`: someone who deliberately // disabled capture must not have it switched back on by a probe. let restore_to = nes.rewind_capture_enabled(); nes.set_rewind_capture(false); - Self { nes, restore_to } + #[cfg(feature = "debug-hooks")] + let provenance = (nes.take_provenance(), nes.take_audio_provenance()); + Self { + nes, + restore_to, + #[cfg(feature = "debug-hooks")] + provenance, + } } } -impl Drop for CaptureGuard<'_> { +impl Drop for TrialGuard<'_> { fn drop(&mut self) { self.nes.set_rewind_capture(self.restore_to); + #[cfg(feature = "debug-hooks")] + { + // `mem::take` because `Drop` has only `&mut self`. The guard is + // being destroyed, so leaving default stashes behind is invisible. + let (pixel, audio) = core::mem::take(&mut self.provenance); + self.nes.put_provenance(pixel); + self.nes.put_audio_provenance(audio); + } } } @@ -493,6 +579,154 @@ mod tests { (Buttons::empty(), Buttons::empty()) } + /// An NROM that writes one APU register and then spins, so a test has a + /// register attribution with a *known* PC to look for. + /// + /// `synth_nrom` cannot serve here: it spins immediately, never touches + /// `$4000-$4017`, and the only writes in its lifetime come from `Apu::reset` + /// before provenance is armed — so its attribution table is empty, and a + /// test built on it would assert "still empty" and pass no matter what. + #[cfg(feature = "debug-hooks")] + fn reg_writing_nrom() -> Vec { + let mut bytes = Vec::new(); + bytes.extend_from_slice(b"NES\x1A"); + bytes.push(1); // 16 KiB PRG + bytes.push(1); // 8 KiB CHR + bytes.push(0); + bytes.push(0); + bytes.extend_from_slice(&[0u8; 8]); + let mut prg = vec![0u8; 16 * 1024]; + // $C000: LDA #$3F / STA $4000 / JMP $C005 (spin on itself) + prg[0..8].copy_from_slice(&[0xA9, 0x3F, 0x8D, 0x00, 0x40, 0x4C, 0x05, 0xC0]); + let len = prg.len(); + prg[len - 6] = 0x00; // NMI + prg[len - 5] = 0xC0; + prg[len - 4] = 0x00; // RESET + prg[len - 3] = 0xC0; + prg[len - 2] = 0x00; // IRQ + prg[len - 1] = 0xC0; + bytes.extend_from_slice(&prg); + bytes.extend_from_slice(&vec![0u8; 8 * 1024]); + bytes + } + + /// A `Nes` with audio provenance armed and exactly one register write on the + /// record, plus that write. + #[cfg(feature = "debug-hooks")] + fn armed_with_a_recorded_write() -> (Nes, rustynes_core::rustynes_apu::provenance::RegWrite) { + let mut n = Nes::from_rom(®_writing_nrom()).expect("fixture parses"); + n.set_audio_provenance(true); + // Three frames, not one. The first `run_frame` after construction + // returns on an already-pending frame-complete flag without executing an + // instruction, so a one-frame fixture leaves the PC at the reset vector + // and the attribution table empty — which would have made this helper's + // own premise assertion the thing under test. + for _ in 0..3 { + n.run_frame(); + } + let rec = n + .register_attribution() + .expect("armed") + .get(0x4000) + .expect("premise: the fixture's STA $4000 was attributed"); + assert_eq!( + rec.value, 0x3F, + "premise: the fixture wrote what it meant to" + ); + (n, rec) + } + + /// A probe trial must leave the caller's audio provenance EXACTLY as it + /// found it. + /// + /// Not "non-empty" — that weaker assertion is how an incomplete fix clears + /// review. The store must hold the same record, from the same PC, at the + /// same cycle: a trial that wiped it and let its own re-simulated frames + /// refill it would satisfy "non-empty" while reporting instructions that + /// never executed on this timeline. + /// + /// The defect this pins: `run_uncounted` restores the anchor with + /// `restore_quiet`, and `Nes::restore_inner` clears both provenance stores. + /// `latency::measure_in_place` runs up to 21 trials against the LIVE + /// emulator, so asking for a latency measurement emptied the Audio + /// Provenance panel — the same shape as the run-ahead rollback that left + /// Pixel Provenance broken for four releases. + #[cfg(feature = "debug-hooks")] + #[test] + fn a_trial_preserves_the_callers_audio_provenance() { + let (mut n, before) = armed_with_a_recorded_write(); + let mut probe = Probe::anchor(&n, Budget::default()); + + probe + .run(&mut n, 6, Observable::Framebuffer, idle) + .expect("within budget"); + + let after = n + .register_attribution() + .expect("the store is still armed after a trial") + .get(0x4000) + .expect("the attribution survived the trial"); + assert_eq!( + before, after, + "a probe trial rewrote the caller's audio provenance" + ); + } + + /// The same contract for the pixel-provenance store, which the same restore + /// clears through the same call. Asserted separately because they are two + /// stores behind two independent `take`/`put` pairs, and a fix that put back + /// only one would pass the other test. + #[cfg(feature = "debug-hooks")] + #[test] + fn a_trial_preserves_the_callers_pixel_provenance() { + let mut n = Nes::from_rom(®_writing_nrom()).expect("fixture parses"); + n.set_pixel_provenance(true); + for _ in 0..3 { + n.run_frame(); + } + assert!( + n.pixel_provenance().is_some(), + "premise: the pixel store is armed" + ); + + let mut probe = Probe::anchor(&n, Budget::default()); + probe + .run(&mut n, 6, Observable::Framebuffer, idle) + .expect("within budget"); + + assert!( + n.pixel_provenance().is_some(), + "a probe trial disarmed the caller's pixel provenance" + ); + } + + /// `latency::measure_in_place` runs its trials AND a final restore, and that + /// final restore sits outside every per-trial guard. Pinned separately for + /// exactly that reason: fixing `run_uncounted` alone leaves this path broken + /// while the per-trial test passes. + #[cfg(feature = "debug-hooks")] + #[test] + fn measure_in_place_preserves_the_callers_audio_provenance() { + let (mut n, before) = armed_with_a_recorded_write(); + + let report = + crate::latency::measure_in_place(&mut n, crate::latency::LatencyConfig::default()); + assert!( + report.trials_used > 0, + "premise: the measurement actually ran" + ); + + let after = n + .register_attribution() + .expect("the store is still armed after a measurement") + .get(0x4000) + .expect("the attribution survived the measurement"); + assert_eq!( + before, after, + "a latency measurement rewrote the caller's audio provenance" + ); + } + /// THE contract the whole engine rests on: two trials with identical inputs /// produce identical samples, frame for frame. If this fails, nothing else /// here means anything. diff --git a/docs/audio-provenance.md b/docs/audio-provenance.md index ea736a3a..c8ec9644 100644 --- a/docs/audio-provenance.md +++ b/docs/audio-provenance.md @@ -176,6 +176,53 @@ change as the feature**, not after a bug report: - A control test proves a plain run populates the trace, so a failure of the run-ahead test cannot be misread as a bad assertion. +### The same trap, three more times: the probe engine + +The list above is complete for *run-ahead* and was read as complete full stop. +It was not. `Nes::restore_inner` clears both provenance stores, and run-ahead is +not the only same-timeline restore in the tree — `rustynes-probe` has three +more, none of which used the stash: + +| Path | What it restores | Whose provenance it destroyed | +| --- | --- | --- | +| `Probe::run_uncounted` | the anchor, once per trial | every trial; `latency::measure_in_place` runs up to **21** | +| `latency::measure_in_place` | the caller's state, on the way out | the one restore that sits outside every per-trial guard | +| `atlas_panel::TimelineGuard` | the live timeline after an observation | one per RAM Atlas observation | + +So running the **Latency Oracle** or the **RAM Atlas** emptied the Pixel +Provenance and Audio Provenance panels. Both stores are cumulative — "which +instruction last wrote this" has an answer that can be thousands of frames old, +a palette byte from level load or a `$4008` linear-counter reload from init — so +the loss was not repaired by the next frame. It was permanent for the session. + +Two things let it through, and both are worth naming because neither was +carelessness: + +1. **The enumeration was of one caller, not of the mechanism.** `RunAhead::finish` + was the path the bug report named. The fix was correct there and stopped there. + The same shape had already been recorded once in `AGENTS.md` — a rewind-ring + fix that changed `measure_in_place`'s final restore and left all 21 trial + restores untouched — and this is the same function, missed the same way. +2. **The test that should have caught it asserted something weaker than the + contract.** `measure_in_place_restores_the_live_timeline` compares + `nes.snapshot()` before and after. Provenance is deliberately **not** in the + snapshot, so the assertion was true while the state it did not cover was + being destroyed. "Restores the live timeline" was exactly the claim being + made, and the strongest available check of it did not check it. + +Closed in v2.3.7 by moving the stash into `rustynes_probe::TrialGuard` — the +guard that already existed for rewind capture, which is the same category of +state: unserialised, therefore not carried by a snapshot round trip, therefore +the guard's job. Four independent mutations pin it, one per site plus one for +each store, so a fix that put back only one store or guarded only one site +fails. + +`rustynes-probe` also gains a `debug-hooks` passthrough feature, without which +the guard would have been dead code in exactly the builds that need it: cargo's +feature unification already switched on `rustynes-core/debug-hooks` for a +frontend build, so the clearing was live, while a `cfg` in a crate that does not +declare the feature is never true. + Both assertions are floored at 20,000 records rather than "non-empty", because the APU's 8-cycle reset sequence alone produces eight records — a non-emptiness check would pass on a run that emulated nothing at all. diff --git a/docs/pixel-provenance.md b/docs/pixel-provenance.md index 4f2af75f..40803ec5 100644 --- a/docs/pixel-provenance.md +++ b/docs/pixel-provenance.md @@ -111,13 +111,33 @@ those offsets describe a timeline that no longer exists. kept are the **visible** frame's — one frame ahead of the restored persistent state, and exactly the frame on screen. -This is the one caller that needs the exception, and not because its restore is -different: because of *when* it happens. Run-ahead's rollback is the last thing -before the frontend releases the emulator lock, so the UI's first chance to look -is always after it. Clearing there discards the frame the user is looking at -rather than a stale timeline. Every other caller — a user-driven save-state load, -netplay rollback — still clears, and still should. The stash is a move of two -boxed stores, skipped entirely when neither is armed. +Run-ahead needs the exception because of *when* its restore happens, not because +the restore is different. Its rollback is the last thing before the frontend +releases the emulator lock, so the UI's first chance to look is always after it. +Clearing there discards the frame the user is looking at rather than a stale +timeline. A user-driven save-state load and a netplay rollback still clear, and +still should. The stash is a move of two boxed stores, skipped entirely when +neither is armed. + +> **This section used to call run-ahead "the one caller that needs the +> exception."** It is not, and v2.3.7 found three more — all in `rustynes-probe`, +> all restoring a state snapshotted from the same timeline moments earlier: +> `Probe::run_uncounted` (once per trial, and a latency measurement runs up to +> 21), `latency::measure_in_place` (the final restore, which sits outside every +> per-trial guard), and the RAM Atlas panel's `TimelineGuard`. Running the +> **Latency Oracle** or the **RAM Atlas** therefore emptied this panel. The +> criterion in the paragraph above was right — a same-timeline restore whose +> result the user keeps looking at — and the enumeration under it was wrong, +> which is a more comfortable error to make than it looks: the rule was stated +> correctly and then applied to exactly the one caller a bug report had named. +> Closed by moving the stash into `rustynes_probe::TrialGuard`, the guard that +> already held rewind capture for the same reason: state that lives outside the +> save state is not carried by a snapshot round trip, so something has to carry +> it deliberately. See `docs/audio-provenance.md` for the full account. + +That retraction is the second one this section has needed, and the first is kept +below rather than deleted, because the pair is the point: the same store, missed +twice, both times because a confident sentence stood where a check belonged. > **This paragraph used to say the opposite of the code.** Until v2.3.6 it read: > "Under run-ahead the per-frame `restore_quiet` therefore leaves exactly the From cd3c15a3bc255ee7996a80fe39396a9e13c7fc6a Mon Sep 17 00:00:00 2001 From: DoubleGate Date: Wed, 19 Aug 2026 06:54:54 -0400 Subject: [PATCH 2/2] =?UTF-8?q?test(probe):=20complete=20the=202x2=20matri?= =?UTF-8?q?x=20=E2=80=94=20review=20found=20the=20fourth=20cell=20missing?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Both review findings on the PR were correct, and one of them was not a wording problem. `CHANGELOG.md` claimed the fix was "pinned by four tests under four independent mutations — one per store and one per site". There were three tests. The missing one is `measure_in_place` against the PIXEL store, and it is a real gap rather than an off-by-one in prose: the `measure_in_place` mutation fails only the AUDIO test, so a final restore that put back the audio stash and dropped the pixel one would have passed every test on the branch. The claim was written before the fourth test existed, which is the shape of error this project keeps meeting from the other direction — prose asserting a property the tree does not have. Adding the test rather than softening the sentence, because the sentence described the right contract. Verified load-bearing: removing the pixel put-back now fails both pixel tests instead of one. Also corrected, from the same review: the `TrialGuard::provenance` doc said the field is "`None` in a build without the feature". It is not `None`, it is `cfg`d out entirely — a distinction that matters to whoever edits this next, since "present and empty" invites a runtime check where there is no field at all. The rewrite also states the consequence the old wording obscured: without `debug-hooks` there is no per-trial cost of any kind, not merely a cheap one. And the `mem::take` rationale is mirrored onto the frontend's `TimelineGuard`, which uses the identical pattern for the identical reason and had the explanation only at the other site. The CHANGELOG now describes the full 2x2 rather than a count, and records that the fourth cell was missing until review caught it. A matrix is checkable; a number is not. Verified: fmt, `rustynes-probe` clippy and tests in both feature configurations (50 tests with the feature on), the frontend under `debug-hooks`, both wasm32 invocations, and rustdoc. Co-Authored-By: Claude Opus 5 --- CHANGELOG.md | 11 +++-- .../src/debugger/atlas_panel.rs | 3 ++ crates/rustynes-probe/src/lib.rs | 41 ++++++++++++++++++- 3 files changed, 50 insertions(+), 5 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index bb5ed4c1..0262d704 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -104,9 +104,14 @@ cycle-accurate core later replaced. across a trial for the same underlying reason: state that lives outside the save state is not carried by a snapshot round trip. - Pinned by four tests under four independent mutations — one per store and one - per site — so a fix that put back only one store, or guarded only one of the - two probe restores, fails. The existing + Pinned by the **full 2x2 matrix** — each of the two stores against each of the + two probe restores — under four independent mutations, so a fix that put back + only one store, or guarded only one of the two restores, fails. The fourth cell + (`measure_in_place` against the *pixel* store) was **missing until review + caught it**, and it was not a rounding error: the `measure_in_place` mutation + fails only the audio test, so a final restore that put back the audio stash and + dropped the pixel one would have passed everything. The claim of "four tests" + was written before the fourth existed. The existing `measure_in_place_restores_the_live_timeline` could not have caught it: it compares `nes.snapshot()` before and after, and provenance is deliberately not in the snapshot, so it asserted something strictly weaker than the contract it diff --git a/crates/rustynes-frontend/src/debugger/atlas_panel.rs b/crates/rustynes-frontend/src/debugger/atlas_panel.rs index 6f1578ab..90405fd1 100644 --- a/crates/rustynes-frontend/src/debugger/atlas_panel.rs +++ b/crates/rustynes-frontend/src/debugger/atlas_panel.rs @@ -635,6 +635,9 @@ impl Drop for TimelineGuard<'_> { // timeline that has already stopped being rewritten. #[cfg(feature = "debug-hooks")] { + // `mem::take` because `Drop` has only `&mut self`. The guard is + // being destroyed, so leaving default stashes behind is invisible — + // the same pattern, for the same reason, as `TrialGuard::drop`. let (pixel, audio) = core::mem::take(&mut self.provenance); self.nes.put_provenance(pixel); self.nes.put_audio_provenance(audio); diff --git a/crates/rustynes-probe/src/lib.rs b/crates/rustynes-probe/src/lib.rs index 45b6b015..41af2c6f 100644 --- a/crates/rustynes-probe/src/lib.rs +++ b/crates/rustynes-probe/src/lib.rs @@ -438,8 +438,12 @@ pub(crate) struct TrialGuard<'a> { restore_to: bool, /// The caller's pixel- and audio-provenance stores, moved out for the /// duration so neither the anchor restore nor the trial's frames can touch - /// them. `None` in a build without the feature, and cheap when unarmed: - /// each stash is one moved `Option>`. + /// them. + /// + /// The field does not exist at all without `debug-hooks` — it is `cfg`d out + /// rather than present-and-empty — so there is no per-trial cost of any kind + /// in a build that cannot record provenance. With the feature on it is cheap + /// when unarmed: each stash is one moved `Option>`. #[cfg(feature = "debug-hooks")] provenance: ( rustynes_core::rustynes_ppu::ProvenanceStash, @@ -672,6 +676,39 @@ mod tests { ); } + /// The fourth cell of the matrix: `measure_in_place` x the PIXEL store. + /// + /// Added after review pointed out that the CHANGELOG claimed "four tests" + /// while three existed, and that the missing one was not a rounding error — + /// it is a real gap. The `measure_in_place` mutation fails only the AUDIO + /// test, so a final restore that put back the audio stash and dropped the + /// pixel one would have passed every test here. + #[cfg(feature = "debug-hooks")] + #[test] + fn measure_in_place_preserves_the_callers_pixel_provenance() { + let mut n = Nes::from_rom(®_writing_nrom()).expect("fixture parses"); + n.set_pixel_provenance(true); + for _ in 0..3 { + n.run_frame(); + } + assert!( + n.pixel_provenance().is_some(), + "premise: the pixel store is armed" + ); + + let report = + crate::latency::measure_in_place(&mut n, crate::latency::LatencyConfig::default()); + assert!( + report.trials_used > 0, + "premise: the measurement actually ran" + ); + + assert!( + n.pixel_provenance().is_some(), + "a latency measurement disarmed the caller's pixel provenance" + ); + } + /// The same contract for the pixel-provenance store, which the same restore /// clears through the same call. Asserted separately because they are two /// stores behind two independent `take`/`put` pairs, and a fix that put back