From 900d1e56751fad6daa127637780a88803a2fa922 Mon Sep 17 00:00:00 2001 From: DoubleGate Date: Wed, 19 Aug 2026 09:13:38 -0400 Subject: [PATCH 1/3] feat(perf): measure the two-acquisition race instead of reasoning about it MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit v2.3.9 item B recorded a hypothesis: the `needs_nes` render arm — taken exactly when a debugger or tool panel is open — acquires the emulator lock TWICE per redraw. Once to copy the framebuffer the user will see, and again sixty lines later for `run_shell_ui`, where panels read `&mut Nes`. The guard is dropped between them so the composite work does not hold the emulator, which means the emulation thread can take the lock in that gap. If it does, the screen shows frame N while a panel describes N+1 — a confidently wrong answer in Pixel Provenance, whose whole purpose is explaining the pixel you are looking at. That was written down as a hypothesis rather than a defect, with the experiment attached, because this line has already retracted one conclusion drawn from reading rather than measuring. This is the experiment. `Nes::cycle()` is read at both acquisitions and the readings compared. The choice of quantity matters: it is cumulative and monotonic, and `produce_one_frame` holds the lock across a WHOLE frame, so any difference at all means at least one complete frame landed in the gap — there is no partial-frame reading to misinterpret. No frame counter exists on `Nes`, and adding one would have been a second source of truth for something the cycle counter already answers. Both counters are kept, not just the hits. "The race did not fire" and "nothing was observed" both read as zero hits, and only the denominator separates them — the same distinction this release keeps insisting on, applied to its own instrument. The denominator counts redraws where the race COULD have fired: both readings present, meaning a ROM is loaded and the arm ran twice. Counting ROM-less redraws would dilute the rate toward zero and manufacture the reassuring answer. Surfaced in the Performance panel as a rate with the counts beside it, and the hover text says what a zero does and does not mean: it BOUNDS the effect over that capture, it is not proof the race cannot happen. A measurement that reads as a verdict is how the next person stops looking. `debug-hooks`-gated throughout, so the shipped default carries neither the two reads nor the counters. Two tests pin the counter's semantics — that an unobserved redraw is not a clean one, and that hits and observations move independently. What this does NOT do is fix anything. The rate has to be observed on a real session with a panel open before a fix is chosen, because the obvious fix — merging the two acquisitions — puts the composite work back under the emulator lock, which is exactly the regression v2.3.0 fixed. Verified: fmt, workspace clippy with the feature OFF, `debug-hooks` and `full` frontend combos, both wasm32 invocations, rustdoc, and the frontend suite at 522. Co-Authored-By: Claude Opus 5 --- crates/rustynes-frontend/src/app.rs | 31 +++++++ .../src/debugger/perf_panel.rs | 38 +++++++++ crates/rustynes-frontend/src/perf.rs | 85 +++++++++++++++++++ 3 files changed, 154 insertions(+) diff --git a/crates/rustynes-frontend/src/app.rs b/crates/rustynes-frontend/src/app.rs index 3f01bedb..3ebc8c3d 100644 --- a/crates/rustynes-frontend/src/app.rs +++ b/crates/rustynes-frontend/src/app.rs @@ -7275,6 +7275,11 @@ impl App { perf_view.render_work = r.work; perf_view.render_lock = r.lock; perf_view.render_cpu = r.cpu; + #[cfg(feature = "debug-hooks")] + { + perf_view.lock_gap_hits = r.lock_gap_hits; + perf_view.lock_gap_obs = r.lock_gap_obs; + } // F16 — how many frames the compositor composited but never scanned // out, cumulative. A rising count means THIS SURFACE IS NOT BEING SHOWN; // it is the signal that distinguishes that from "this compositor reports @@ -9726,9 +9731,19 @@ impl ApplicationHandler for App { // scope mirrors the common `else` branch exactly; the only reason // this branch later re-takes the lock is that the debugger pass // needs a live `&mut Nes`, which the common branch does not. + // v2.3.9 item B — the emulator's cumulative cycle at the moment + // the framebuffer the user will SEE is copied. Declared out here + // so it outlives the scoped guard below and can be compared at + // the egui pass; see `RenderPerf::record_lock_gap`. + #[cfg(feature = "debug-hooks")] + let cycle_at_fb: Option; { let mut guard = self.emu.lock_timed(&mut lock_wait); let emu = &mut *guard; + #[cfg(feature = "debug-hooks")] + { + cycle_at_fb = emu.nes.as_ref().map(rustynes_core::Nes::cycle); + } // Backfill the presented framebuffer into staging under the // held lock (a ROM may or may not be loaded). The debugger // panels read `nes` from the re-acquired lock below. v1.7.1 @@ -9942,6 +9957,22 @@ impl ApplicationHandler for App { // fold producer blocking into the UI phase, which is the // same defect the F8 wait clock had. let mut guard = self.emu.lock_timed(&mut lock_wait); + // v2.3.9 item B — did the emulation thread take the lock + // in the gap since the framebuffer copy? Recorded BEFORE + // `run_shell_ui`, because that is the read whose + // consistency with the presented frame is in question. + // Both sides must be `Some` for the comparison to mean + // anything: a redraw with no ROM loaded is not an + // observation, and counting it would dilute the rate + // toward zero — the denominator has to be redraws where + // the race COULD have fired. + #[cfg(feature = "debug-hooks")] + if let (Some(before), Some(now)) = ( + cycle_at_fb, + guard.nes.as_ref().map(rustynes_core::Nes::cycle), + ) { + self.render_perf.record_lock_gap(before != now); + } #[cfg(not(target_arch = "wasm32"))] let t_ui = Instant::now(); let nes_for_render = guard.nes.as_mut(); diff --git a/crates/rustynes-frontend/src/debugger/perf_panel.rs b/crates/rustynes-frontend/src/debugger/perf_panel.rs index 708bdfef..fc971ebd 100644 --- a/crates/rustynes-frontend/src/debugger/perf_panel.rs +++ b/crates/rustynes-frontend/src/debugger/perf_panel.rs @@ -258,6 +258,44 @@ pub fn show( stats_row(ui, "produce cost", &v.produce_cost, v.target_ms); }); + // v2.3.9 item B — the two-acquisition race, MEASURED. + // + // The `needs_nes` render arm takes the emulator lock twice per + // redraw: once for the framebuffer the user sees, again for the egui + // pass where panels read `&mut Nes`. If the emulation thread takes it + // in between, the screen shows one frame while a panel describes the + // next — which in Pixel Provenance would be a confidently wrong + // answer. + // + // Shown as a rate rather than a verdict. Zero over a long capture + // BOUNDS the race; it does not prove absence, and the label says so + // rather than letting a reader infer it. + #[cfg(feature = "debug-hooks")] + if v.lock_gap_obs > 0 { + ui.separator(); + // Percentage of observations, computed in f64 so a long capture + // does not lose precision the way an f32 ratio would. + #[expect( + clippy::cast_precision_loss, + reason = "display-only ratio; u64 counts here are far below 2^53" + )] + let pct = (v.lock_gap_hits as f64) * 100.0 / (v.lock_gap_obs as f64); + ui.label(egui::RichText::new("panel/screen frame skew").strong()); + ui.label(format!( + "{} of {} redraws ({pct:.1}%)", + v.lock_gap_hits, v.lock_gap_obs + )) + .on_hover_text( + "Redraws where the emulator advanced between the framebuffer \ + copy and the panel read, so a debugger panel described a \ + LATER frame than the one on screen. Counted only while a \ + panel that needs `&mut Nes` is open and a ROM is loaded — \ + that is when the race can fire at all. A zero here bounds \ + the effect over this capture; it is not proof it cannot \ + happen.", + ); + } + // feature K — the live frame-time sparkline (presented = bright, // produced = faint, with the frame-deadline reference line). ui.separator(); diff --git a/crates/rustynes-frontend/src/perf.rs b/crates/rustynes-frontend/src/perf.rs index 60ff9a7e..c27cd659 100644 --- a/crates/rustynes-frontend/src/perf.rs +++ b/crates/rustynes-frontend/src/perf.rs @@ -220,6 +220,31 @@ pub struct RenderPerf { /// Subtracted out of `work` so that series finally means work alone: /// `work = total - wait - lock`. lock: SampleRing, + /// v2.3.9 item B — redraws where the emulator advanced BETWEEN the + /// framebuffer copy and the egui pass, and the total observed. + /// + /// The `needs_nes` render arm — taken exactly when a debugger or tool panel + /// is open — acquires the emulator lock TWICE per redraw: once to copy the + /// framebuffer the user will see, and again sixty lines later for + /// `run_shell_ui`, where panels read `&mut Nes`. The guard is dropped + /// between them so the composite work does not hold the emulator. + /// + /// If the emulation thread takes the lock in that gap, the screen shows + /// frame `N` while a panel describes `N+1` — which would be a confidently + /// wrong answer in Pixel Provenance, whose whole purpose is explaining the + /// pixel you are looking at. + /// + /// Counted rather than assumed. The plan recorded it as a hypothesis from + /// reading the lock structure, and this line has already retracted one + /// conclusion drawn from reading rather than measuring, so it is measured: + /// `hits` non-zero confirms the race fires, zero over a long capture with a + /// panel open bounds it. + #[cfg(feature = "debug-hooks")] + lock_gap_hits: u64, + /// Denominator for [`Self::lock_gap_hits`] — redraws where both + /// observations were taken (a ROM is loaded and the arm ran twice). + #[cfg(feature = "debug-hooks")] + lock_gap_obs: u64, /// v2.3.3 — CPU time actually CONSUMED across the `work` span. /// /// `work` is wall time, so it cannot tell 27 ms of computation from 27 ms @@ -239,6 +264,13 @@ pub struct RenderPerf { /// theoretical risk. #[derive(Debug, Clone, Copy, Default)] pub struct RenderStats { + /// v2.3.9 item B — redraws where the emulator advanced between the + /// framebuffer copy and the egui pass. See `RenderPerf::record_lock_gap`. + #[cfg(feature = "debug-hooks")] + pub lock_gap_hits: u64, + /// Denominator for [`Self::lock_gap_hits`]. + #[cfg(feature = "debug-hooks")] + pub lock_gap_obs: u64, /// egui shell build. pub ui: IntervalStats, /// GPU encode + submit + present. @@ -314,6 +346,24 @@ impl RenderPerf { work: self.work.stats(), lock: self.lock.stats(), cpu: self.cpu.stats(), + #[cfg(feature = "debug-hooks")] + lock_gap_hits: self.lock_gap_hits, + #[cfg(feature = "debug-hooks")] + lock_gap_obs: self.lock_gap_obs, + } + } + + /// v2.3.9 item B — record one redraw's two-acquisition observation. + /// + /// `advanced` is whether `Nes::cycle()` differed between the framebuffer + /// copy and the egui pass. The cycle counter is cumulative and monotonic, + /// and `produce_one_frame` holds the lock across a WHOLE frame, so any + /// change at all means at least one complete frame landed in the gap. + #[cfg(feature = "debug-hooks")] + pub const fn record_lock_gap(&mut self, advanced: bool) { + self.lock_gap_obs = self.lock_gap_obs.saturating_add(1); + if advanced { + self.lock_gap_hits = self.lock_gap_hits.saturating_add(1); } } @@ -688,6 +738,15 @@ pub struct PerfView { /// v2.3.3 F15 — interval between display-tick sends, milliseconds. See /// `PerfStats::tick_iv`. pub tick_iv: IntervalStats, + /// v2.3.9 item B — redraws where the emulator advanced between the + /// framebuffer copy and the egui pass, and the total observed. See + /// `RenderPerf::record_lock_gap` (plain code span: the method is + /// `debug-hooks`-gated, so a default doc build cannot resolve a link). + #[cfg(feature = "debug-hooks")] + pub lock_gap_hits: u64, + /// Denominator for [`Self::lock_gap_hits`]. + #[cfg(feature = "debug-hooks")] + pub lock_gap_obs: u64, /// v2.3.3 — egui shell build cost (winit thread). See [`RenderPerf`]. pub render_ui: IntervalStats, /// v2.3.3 — GPU encode + present cost (winit thread). See [`RenderPerf`]. @@ -828,6 +887,32 @@ pub struct PerfView { pub recent_produced_ms: Vec, } +#[cfg(all(test, feature = "debug-hooks"))] +mod lock_gap_tests { + use super::RenderPerf; + + /// The counter must distinguish "the race did not fire" from "nothing was + /// observed". Both read as zero hits, and only the denominator separates + /// them — which is the whole reason a rate is reported rather than a count. + #[test] + fn an_unobserved_redraw_is_not_a_clean_one() { + let p = RenderPerf::default(); + let s = p.stats(); + assert_eq!((s.lock_gap_hits, s.lock_gap_obs), (0, 0)); + } + + #[test] + fn hits_and_observations_are_counted_separately() { + let mut p = RenderPerf::default(); + p.record_lock_gap(false); + p.record_lock_gap(true); + p.record_lock_gap(false); + let s = p.stats(); + assert_eq!(s.lock_gap_obs, 3, "every observation counts"); + assert_eq!(s.lock_gap_hits, 1, "only the advancing redraw is a hit"); + } +} + #[cfg(test)] mod tests { use super::*; From 453b583185c3516366c91555454bbb6442fa3f64 Mon Sep 17 00:00:00 2001 From: DoubleGate Date: Wed, 19 Aug 2026 09:20:55 -0400 Subject: [PATCH 2/3] fix(ci): two ordering defects in the apt retry, both caught in review MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review on #408 found two problems with `.github/scripts/apt-install-retry.sh`, and both would have made it worse than nothing on the exact path it exists to protect. ELEVATION MUST BE OUTERMOST, WITH `timeout` INSIDE IT. The original had `timeout` on the outside, which sends the signal to the elevation helper rather than to `apt-get`. The helper may not forward it, leaving `apt-get` orphaned while still holding the dpkg lock — so every subsequent retry fails on the lock rather than on the original problem. A retry loop that guarantees its own retries fail is worse than no retry loop. `DEBIAN_FRONTEND=noninteractive`, for the same class of reason. A package that prompts for configuration blocks on stdin that will never arrive in CI, burning the whole timeout budget waiting for a human who is not there — the exact failure this script bounds, arriving through a door it had left open. Passed explicitly because the environment is scrubbed on elevation. Re-verified with the same stubs: fail-fail-succeed still names the attempt it succeeded on and exits 0. shellcheck clean. Both are recorded in the plan beside the item rather than only here, because the lesson generalises past this script: wrapping a command for reliability puts the wrapper in the signal path, and the wrapper's own failure modes then belong to the thing it was protecting. Co-Authored-By: Claude Opus 5 --- .github/scripts/apt-install-retry.sh | 15 +++++++++++++-- to-dos/plans/v2.3.9-crucible-plan.md | 13 +++++++++++++ 2 files changed, 26 insertions(+), 2 deletions(-) diff --git a/.github/scripts/apt-install-retry.sh b/.github/scripts/apt-install-retry.sh index a605640a..399ee96d 100755 --- a/.github/scripts/apt-install-retry.sh +++ b/.github/scripts/apt-install-retry.sh @@ -41,9 +41,20 @@ readonly UPDATE_TIMEOUT=180 readonly INSTALL_TIMEOUT=300 readonly ATTEMPTS=3 +# Elevation on the OUTSIDE, `timeout` on the inside. Review on #408 caught the +# ordering and it is not cosmetic: with `timeout` outermost the SIGTERM goes to +# the elevation helper, which may not forward it — leaving `apt-get` orphaned +# while still holding the dpkg lock, so every subsequent retry fails on the lock +# rather than on the original problem. A retry loop that guarantees its own +# retries fail is worse than no retry loop at all. +# +# `DEBIAN_FRONTEND=noninteractive` for the same class of reason: a package that +# prompts for configuration blocks on stdin that will never arrive in CI, burning +# the whole timeout budget waiting for a human who is not there. Passed through +# explicitly because the environment is scrubbed on elevation. for attempt in $(seq 1 "$ATTEMPTS"); do - if timeout "$UPDATE_TIMEOUT" sudo apt-get update -qq && - timeout "$INSTALL_TIMEOUT" sudo apt-get install -yq "$APT_PACKAGE"; then + if sudo DEBIAN_FRONTEND=noninteractive timeout "$UPDATE_TIMEOUT" apt-get update -qq && + sudo DEBIAN_FRONTEND=noninteractive timeout "$INSTALL_TIMEOUT" apt-get install -yq "$APT_PACKAGE"; then echo "Installed ${APT_PACKAGE} on attempt ${attempt}." exit 0 fi diff --git a/to-dos/plans/v2.3.9-crucible-plan.md b/to-dos/plans/v2.3.9-crucible-plan.md index 8d03d1ed..6ea8698a 100644 --- a/to-dos/plans/v2.3.9-crucible-plan.md +++ b/to-dos/plans/v2.3.9-crucible-plan.md @@ -169,6 +169,19 @@ all-attempts-fail produces three warnings and exits 1; fail-fail-succeed produce two warnings, reports the attempt it succeeded on, and exits 0. The unset-package guard exits 1 rather than guessing. shellcheck clean. +**Two ordering defects caught in review on #408**, both of which would have made +the script worse than nothing on the exact path it exists to protect: + +- **Elevation must be outermost, `timeout` inside it.** With `timeout` on the + outside the signal goes to the elevation helper, which may not forward it — + leaving `apt-get` orphaned and still holding the dpkg lock, so every subsequent + retry fails on the lock rather than on the original problem. A retry loop that + guarantees its own retries fail is worse than no retry loop. +- **`DEBIAN_FRONTEND=noninteractive`.** A package that prompts for configuration + blocks on stdin that will never arrive in CI, burning the whole timeout budget + waiting for a human who is not there — the same failure this script exists to + bound, arriving through a door it had left open. + **Scope discipline:** deliberately not a general-purpose apt wrapper. One package, taken from a workflow `env:` and never from event data — which is the injection vector the Actions security guidance names — and a hard failure when From 6c99d5af2ca42eaf2fa7eb550d0edb146e0c1e07 Mon Sep 17 00:00:00 2001 From: DoubleGate Date: Wed, 19 Aug 2026 09:49:31 -0400 Subject: [PATCH 3/3] fix(perf): reset the lock-gap counters on clear, plus three review corrections MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Four findings from the #409 review, one of them a real defect in the instrument this PR exists to add. `RenderPerf::clear()` did not reset the new `lock_gap_*` counters. It is documented as a regime-change reset, so a ROM change or pacing-regime change would have cleared every sample ring and left the numerator and denominator of the skew rate standing — mixing two populations into one percentage and presenting it as a single measurement. That is exactly the defect the `wait` series had before it, and the comment explaining that fix sits four lines above the place the new counters were missing from. Adding to `stats()` and forgetting `clear()` is evidently the shape of this mistake; the test now pins it and the mutation fails without the reset. The `cycle_at_fb` comment said the reading is taken "at the moment the framebuffer is copied". It is taken on ACQUIRING the lock, a few lines earlier. Equivalent — the emulator cannot advance while the guard is held, so every reading inside that scope names the same frame — but "close enough to be misleading" is how prose stops being checked, and a reviewer asking means the next reader would have. The comment now says where it is read and why that is the same thing. `DEBIAN_FRONTEND` is now set with `env` rather than as a bare assignment to the elevation helper. Both work on a standard runner, but the bare form additionally requires SETENV in sudoers, and on a stricter host it fails by refusing to run at all — breaking the wrapper rather than degrading it. Raised independently by both reviewers, which is usually a sign the point is real. And the counters use plain `+= 1`: one increment per redraw cannot overflow a `u64` in any run that terminates, so `saturating_add` implied a bound worth reasoning about where there is none. Verified: shellcheck, the stub replay (fail-fail-succeed still names its attempt and exits 0), fmt, workspace clippy, frontend under `debug-hooks` at 523 tests. Co-Authored-By: Claude Opus 5 --- .github/scripts/apt-install-retry.sh | 12 ++++++-- crates/rustynes-frontend/src/app.rs | 18 +++++++++--- crates/rustynes-frontend/src/perf.rs | 41 ++++++++++++++++++++++++++-- 3 files changed, 63 insertions(+), 8 deletions(-) diff --git a/.github/scripts/apt-install-retry.sh b/.github/scripts/apt-install-retry.sh index 399ee96d..4ccc1504 100755 --- a/.github/scripts/apt-install-retry.sh +++ b/.github/scripts/apt-install-retry.sh @@ -52,9 +52,17 @@ readonly ATTEMPTS=3 # prompts for configuration blocks on stdin that will never arrive in CI, burning # the whole timeout budget waiting for a human who is not there. Passed through # explicitly because the environment is scrubbed on elevation. +# +# Set via `env` rather than as a bare `VAR=value` argument to the elevation +# helper. Both work on a standard GitHub runner (`ALL=(ALL) NOPASSWD:ALL` +# implies the privilege), but the bare form additionally requires SETENV in +# sudoers, so on a stricter host it fails outright — and it fails by refusing to +# run at all, which would break the wrapper rather than degrade it. `env` is a +# plain command and needs no such privilege. (Review on #409; both reviewers +# raised it independently.) for attempt in $(seq 1 "$ATTEMPTS"); do - if sudo DEBIAN_FRONTEND=noninteractive timeout "$UPDATE_TIMEOUT" apt-get update -qq && - sudo DEBIAN_FRONTEND=noninteractive timeout "$INSTALL_TIMEOUT" apt-get install -yq "$APT_PACKAGE"; then + if sudo env DEBIAN_FRONTEND=noninteractive timeout "$UPDATE_TIMEOUT" apt-get update -qq && + sudo env DEBIAN_FRONTEND=noninteractive timeout "$INSTALL_TIMEOUT" apt-get install -yq "$APT_PACKAGE"; then echo "Installed ${APT_PACKAGE} on attempt ${attempt}." exit 0 fi diff --git a/crates/rustynes-frontend/src/app.rs b/crates/rustynes-frontend/src/app.rs index 3ebc8c3d..57d09566 100644 --- a/crates/rustynes-frontend/src/app.rs +++ b/crates/rustynes-frontend/src/app.rs @@ -9731,10 +9731,20 @@ impl ApplicationHandler for App { // scope mirrors the common `else` branch exactly; the only reason // this branch later re-takes the lock is that the debugger pass // needs a live `&mut Nes`, which the common branch does not. - // v2.3.9 item B — the emulator's cumulative cycle at the moment - // the framebuffer the user will SEE is copied. Declared out here - // so it outlives the scoped guard below and can be compared at - // the egui pass; see `RenderPerf::record_lock_gap`. + // v2.3.9 item B — the emulator's cumulative cycle for the frame + // whose framebuffer this pass will copy. + // + // Read on ACQUIRING the lock, a few lines before the copy itself + // rather than at it. Equivalent, and worth stating why rather + // than leaving it to be re-derived: the emulator cannot advance + // while this guard is held, so every reading taken anywhere + // inside this scope names the same frame. The earlier wording + // said "at the moment the framebuffer is copied", which was + // close enough to be misleading — review on #409 asked, which + // means the next reader would have too. + // + // Declared outside the scope so it outlives the guard and can be + // compared at the egui pass; see `RenderPerf::record_lock_gap`. #[cfg(feature = "debug-hooks")] let cycle_at_fb: Option; { diff --git a/crates/rustynes-frontend/src/perf.rs b/crates/rustynes-frontend/src/perf.rs index c27cd659..c70e4771 100644 --- a/crates/rustynes-frontend/src/perf.rs +++ b/crates/rustynes-frontend/src/perf.rs @@ -361,9 +361,12 @@ impl RenderPerf { /// change at all means at least one complete frame landed in the gap. #[cfg(feature = "debug-hooks")] pub const fn record_lock_gap(&mut self, advanced: bool) { - self.lock_gap_obs = self.lock_gap_obs.saturating_add(1); + // Plain `+= 1`: one increment per redraw, so a `u64` cannot overflow in + // any run that ends. `saturating_add` here suggested a bound worth + // reasoning about and there is none. (Review nitpick on #409.) + self.lock_gap_obs += 1; if advanced { - self.lock_gap_hits = self.lock_gap_hits.saturating_add(1); + self.lock_gap_hits += 1; } } @@ -381,6 +384,18 @@ impl RenderPerf { self.work.clear(); self.lock.clear(); self.cpu.clear(); + // v2.3.9 — and the lock-gap counters, for exactly the reason the `wait` + // comment above gives. A rate is a ratio over a population; carrying the + // numerator and denominator across a ROM change or a pacing-regime + // change mixes two populations into one percentage and reports it as a + // single measurement. Caught in review on #409 — the new counters had + // been added to `stats()` and not to `clear()`, which is precisely how + // `wait` went wrong before them. + #[cfg(feature = "debug-hooks")] + { + self.lock_gap_hits = 0; + self.lock_gap_obs = 0; + } } } @@ -901,6 +916,28 @@ mod lock_gap_tests { assert_eq!((s.lock_gap_hits, s.lock_gap_obs), (0, 0)); } + /// `clear()` must reset the counters with everything else. A rate is a + /// ratio over a population, and carrying the numerator and denominator + /// across a ROM or pacing-regime change mixes two populations into one + /// percentage and reports it as a single measurement. Caught in review on + /// #409, which is the same defect the `wait` series had before it. + #[test] + fn clear_resets_the_lock_gap_counters_too() { + let mut p = RenderPerf::default(); + p.record_lock_gap(true); + p.record_lock_gap(false); + assert_eq!(p.stats().lock_gap_obs, 2, "premise: something was counted"); + + p.clear(); + + let s = p.stats(); + assert_eq!( + (s.lock_gap_hits, s.lock_gap_obs), + (0, 0), + "a rate carried across a regime change is two populations in one number" + ); + } + #[test] fn hits_and_observations_are_counted_separately() { let mut p = RenderPerf::default();