From d633ecc376cf765a5cb259521ad3a118887ae59b Mon Sep 17 00:00:00 2001 From: DoubleGate Date: Tue, 18 Aug 2026 17:32:34 -0400 Subject: [PATCH 1/5] docs(plans): add the v2.3.7 "Overtone" plan v2.3.7 had no plan doc. Every release since v1.3.0 has one under `to-dos/plans/`, and this one is unusual in that the release is already half-written: the VRC7 OPLL save-state defect closed in #398, and six further PRs sit merged in `[Unreleased]`. Writing the doc late means it has to RECORD those rather than propose them, or the next session rebuilds work that is already on `main`. WHAT THE DOC LEADS WITH, AND WHY IT IS NOT THE FEATURE Section A0 is "READ THIS FIRST", and it is about how Pixel Provenance shipped NON-FUNCTIONAL for four releases: run-ahead defaults to 1, and its per-frame rollback cleared the provenance store after the visible frame was harvested and before the UI could take the lock, while a comment two lines above asserted the opposite. Audio Provenance rides the same rollback and inherits the same hazard, so four things are marked non-negotiable -- carry the store around the rollback by extending the existing `take_provenance`/`put_provenance` path, reason about netplay rollback SEPARATELY because it uses the same `restore_quiet` but is not the same case, drive the real produce path at `run_ahead = 1` in a mutation-checked test, and let no comment claim a behaviour the code lacks. Putting the design first and the hazard in a footnote is how a project gets the same bug twice. WHAT NOT TO BUILD A reuse table maps each need to the mechanism that already exists: `set_attrib_context` already pushes PC + cycle down once per instruction, `EventKind::ApuWrite` already intercepts `$4000-$4017`, the PPU's `write_attrib` is the shape to copy, and `set_pixel_provenance` is the API shape. With the caveat that decides the design: `EventRec` carries no PC and no CPU cycle and is scanline-oriented rather than sample-oriented, so the event log is the interception POINT worth reusing and is not the record. Without that sentence the obvious move is to extend it, and the mismatch surfaces late. TWO THINGS THE ORIGINAL SPEC DID NOT HAVE Workstream B is recorded as DONE in detail, including the finding that hand-tracing located one of four reachable panics while a randomized sweep found the rest -- and that the single fixed all-`0xFF` payload CONCEALED one, because all-ones `update_requests` forced a recompute that hid it. That is written as a directive for workstream A rather than as history: if Audio Provenance grows any parse or restore surface, fuzz it instead of reasoning about it. And sizing is settled with the number rather than left to judgement: ~734 samples/frame at 44.1 kHz against 61,440 pixels/frame for the video store, 1.2%. The register-write side rides at 1.789 MHz and the sample side does not, which is the distinction that actually matters when bounding the store. VERIFIED Every claim was checked against the tree rather than carried over from the four-release plan: all nine `file:line` citations resolve to the code they name, the three line counts are exact, `rustynes-apu` genuinely declares only `std` today (so the first step is real work), both benches exist, and neither the panel nor `docs/audio-provenance.md` exists yet. markdownlint passes. Documentation only -- no code, and no CHANGELOG entry, since a plan doc is not user-visible behaviour. --- to-dos/plans/v2.3.7-overtone-plan.md | 275 +++++++++++++++++++++++++++ 1 file changed, 275 insertions(+) create mode 100644 to-dos/plans/v2.3.7-overtone-plan.md diff --git a/to-dos/plans/v2.3.7-overtone-plan.md b/to-dos/plans/v2.3.7-overtone-plan.md new file mode 100644 index 00000000..25009d09 --- /dev/null +++ b/to-dos/plans/v2.3.7-overtone-plan.md @@ -0,0 +1,275 @@ +# v2.3.7 "Overtone" — Audio Provenance, and the Half Already Written + +**Status:** IN PROGRESS · base `a7407a66` (post-v2.3.6 `main`, green) · v2.3.6 "Sounding" cut 2026-08-18, tagged `3f99a3dd` + +## Goal + +Give audio the causal chain video already has. Point at a moment in the output +waveform and get back **why it sounds like that** — the mixed sample, which +channel dominated it, that channel's live state, the `$4000-$4017` write that set +it, and the CPU instruction and cycle that performed the write. + +Every ingredient but the last one already ships. `audio_scope.rs` plots the +per-channel waveforms, `audio_mixer.rs` exposes per-channel gain, +`Apu::pulse1_out()` and friends expose live channel outputs, and the trace logger +has PC and cycle. **What is missing is the link between a sample and the +instruction that caused it** — precisely the gap the pixel-provenance design +identified for video in v2.3.2, and the reason that feature exists. + +**Two workstreams are already done and in the tree.** This release is partly +written: the VRC7 OPLL save-state defect closed in #398, and six other merged +PRs sit in `[Unreleased]`. They are recorded here as **DONE** so the release +ceremony does not re-derive them from `git log`, and so nobody rebuilds them. + +--- + +## Why this release exists at all + +`docs/accuracy-ledger.md` carried the OPLL row as *"Frontier — documented, not +closed"* from v2.2.3: `Vrc7::save_state` wrote the shadow register bytes and +never the live synthesizer, so after a rewind, netplay rollback, or TAS restore +the FM voice resumed from arbitrary envelope and phase state. Rewind a VRC7 game +and the music came back wrong. That was the most actionable open item in the +ledger, it was audio, and it was a determinism gap in a project whose central +claim is determinism. + +It is now closed — which leaves this release its marquee alone, and a clear +question to answer: **the video side can explain any pixel; audio can explain +nothing.** + +--- + +## Work items + +### A — Audio Provenance (marquee, OPEN) + +The APU analogue of v2.3.2's Pixel Provenance, built to the same spec shape. +`docs/pixel-provenance.md` (487 lines, phase-structured) is the model, down to +the "what the feature answers" framing. + +#### A0 — READ THIS FIRST: the trap this feature inherits + +**Pixel Provenance shipped non-functional for four releases**, from v2.3.2 until +v2.3.6 fixed it. Run-ahead defaults to 1, and its per-frame rollback cleared both +provenance stores *after* the visible frame was harvested and *before* the UI +could take the lock — so the panel could never observe a populated record. A +comment two lines above the clear asserted the opposite, and that prose is what +stopped anyone checking. + +Audio Provenance rides the same rollback and inherits the same hazard. The fix +already exists and must be extended, not reinvented: + +- `Nes::take_provenance` / `put_provenance` (`crates/rustynes-core/src/nes.rs:915`) +- carried around the restore in `crates/rustynes-frontend/src/runahead.rs:103-107` +- `ProvenanceStash` (`crates/rustynes-ppu/src/provenance.rs:441`) + +**Non-negotiable for this workstream:** + +1. The audio store is carried around run-ahead's rollback, by extending + `ProvenanceStash` or adding its audio equivalent alongside. +2. **Netplay rollback is reasoned about explicitly and written down** — it uses + the same `restore_quiet` path and is *not* the same case. +3. A test drives the real produce path at `run_ahead = 1` and asserts a + populated record survives. That is the test that did not exist for video, and + its absence is the entire reason the defect lived four releases. +4. No comment claims a behaviour the code does not have. If the two disagree, + the code wins and the comment gets corrected *in place, quoting the old + claim*. + +#### A1 — Reuse, do not rebuild + +Exploration confirmed the design is a symmetric mirror of the video side and that +most of the machinery exists. Build nothing that duplicates these: + +| need | reuse | location | +| --- | --- | --- | +| PC + cycle, pushed down once per instruction | `set_attrib_context(pc, cycles)` | `crates/rustynes-core/src/nes.rs:604`, `:674` | +| `$4000-$4017` writes already intercepted and classified | `EventKind::ApuWrite` | `crates/rustynes-core/src/bus.rs:4347` | +| the per-byte attribution shape to copy | `write_attrib: Option>`, `attrib_pc`, `attrib_cycle` | `crates/rustynes-ppu/src/ppu.rs:1096-1125` | +| arm / disarm / accessor API shape | `set_pixel_provenance`, `pixel_provenance`, `clear_pixel_provenance` | `crates/rustynes-core/src/nes.rs:860-899` | +| the register-write entry point | `Apu::write_register` | `crates/rustynes-apu/src/apu.rs:1552` | +| live per-channel outputs | `Apu::pulse1_out` / `pulse2_out` / `triangle_out` / `noise_out` | `crates/rustynes-apu/src/apu.rs:485-500` | + +**One caveat that decides the design.** `EventRec` +(`crates/rustynes-core/src/bus.rs`) carries `kind / scanline / dot / addr / +value` — **no PC, no CPU cycle**, and it is scanline-oriented rather than +sample-oriented. So the event log is the interception *point* worth reusing; it +is not the record. Do not try to make it one. + +#### A2 — Steps + +1. **Add a `debug-hooks` feature to `crates/rustynes-apu/Cargo.toml`.** It + currently declares only `std` — verified, this is real work. Forward it from + `crates/rustynes-core/Cargo.toml:56`, which today reads + `debug-hooks = ["std", "rustynes-ppu/debug-hooks"]` and must gain + `rustynes-apu/debug-hooks`. + + The frontend already pulls the core with `debug-hooks` unconditionally, so — + exactly as with pixel provenance — **the thing that is default-off is the + runtime arm, not the feature**: a lazily-allocated `Option` whose disarmed + cost is one discriminant test per register write. Output-only and + determinism-neutral. + +2. **Per-register write attribution.** 24 entries for `$4000-$4017`, each + carrying `(value, cpu_cycle, pc)`. This is the direct analogue of the PPU's + `write_attrib`, and the attribution split follows the established precedent: + the **bus has the PC**, the **APU has the destination register**, and the PC + is pushed down once per instruction from the existing debug block — so + `rustynes-cpu` is untouched, exactly as it was for video. + +3. **Per-sample record** of the channel outputs actually mixed. + + **Sizing is a non-issue, and the number is worth stating so nobody + re-litigates it:** ~734 samples/frame at 44.1 kHz / 60.0988 fps, against + 61,440 pixels/frame for the video store — **1.2%**. Bound it anyway and + document the bound; the register-write side rides at 1.789 MHz even though + the sample side does not. + +4. **`Tools → Audio Provenance` panel** + (`crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs`), + cross-linked from `audio_scope.rs` (136 lines) and `audio_mixer.rs` (437 + lines), with "jump to trace" and "break on next write to this register". + + Learn from the video panel's second defect: it shipped with **no click + hit-test at all** while the docs promised "point at any pixel". Whatever + gesture this panel documents, it must implement. + +5. **`docs/audio-provenance.md`**, written in the same change as the code, not + after it. + +#### A3 — Research obligation + +Before wiring the causal chain, confirm against the NESdev APU pages which +register writes have **delayed or side-band effects**, so the chain does not +attribute a change to the wrong write: + +- envelope restart on `$4003` / `$4007` +- length-counter load timing (and the halt/reload-vs-clock ordering v2.1.5 modelled) +- the `$4017` reset delay +- `$4010`-`$4013` DMC interactions + +Record what was checked. A provenance tool that confidently names the wrong +instruction is worse than no tool, on exactly the argument v2.3.6 was built on. + +### B — The VRC7 OPLL save-state defect — **DONE** (#398) + +Closed, not carried. Recorded so it is not re-proposed: + +- `Opll::snapshot` / `Opll::restore` (`OPLL_SNAPSHOT_VERSION` 1, fixed + `OPLL_SNAPSHOT_LEN`) carrying the register shadow, EG/LFO counters, per-channel + patch selection, all 18 operator slots, the user patch pair and the mix. +- VRC7 mapper section **v2**, additive — a v1 blob still loads. A build without + `mapper-audio` writes v1 and validates-then-ignores a v2 tail. +- `load_state` made **atomic**: it parses the tail into a staged value before the + first write, so a rejected load leaves the mapper byte-identical. +- The **parse boundary hardened**. A randomized sweep found four panics reachable + from a hand-edited save state — `patch.tl` and `blk_fnum` indexing the TLL + table, `eg_shift` used as a shift amount, the operator feedback pair summed as + two arbitrary `i32`s, and `eg_rate_l` indexing a 4-entry table. All masked or + clamped at the parse boundary. +- `Opll` registered in `crates/rustynes-test-harness/tests/snapshot_schema_audit.rs`, + which had never been able to see that surface. +- Ledger row now reads *"VRC7 OPLL synthesizer state carried by the mapper save + state (v2.2.3 → **v2.3.7**)"*. + +**The lesson worth carrying into workstream A:** hand-tracing which fields reach +a subscript found one of four panics. A deterministic randomized sweep found the +rest — and the single fixed all-`0xFF` payload *concealed* one, because all-ones +`update_requests` forced a recompute that hid it. If Audio Provenance grows any +parse or restore surface, fuzz it rather than reason about it. + +### C — Carry the APU thread (OPEN, small) + +Re-run `apu_throughput` (`crates/rustynes-apu/benches/`) and +`full_frame` (`crates/rustynes-core/benches/`) after the `debug-hooks` plumbing +lands, to confirm the **shipped default (hooks off) is unmoved**. The APU is +18.7% of frame time; a discriminant test per register write should be invisible, +but "should be" is not a measurement. + +**D2 and D4 stay unmeasured on purpose.** Their prior is a null, not an unknown — +see `docs/performance.md`. Do not re-open them without a reason that is not +"they are still on the list". + +### D — Already merged into `[Unreleased]` — record only + +These land in v2.3.7 whichever way the marquee goes. All are on `main` and +already have CHANGELOG entries: + +| PR | | +| --- | --- | +| #396 | **Rad Racer** horizon artifact — `ale_splice` splices from the live `v`, not the ALE-time `address_bus` snapshot | +| #397 | dependency graph refresh; egui/wgpu **held** at 0.35/29 with a `dependabot.yml` `ignore` and the failing wasm error recorded | +| #399 | the **browser** applied no per-game header corrections — third load path to skip them | +| #400 | per-job `timeout-minutes` in `ci.yml`; a hung 4-minute job had silently blocked a release for five hours | +| #401 | `taiki-e/install-action` 2.85.13 → 2.86.1 | +| #402 | `security.yml`'s prebuilt-binary rationale was stale and self-contradictory | +| #403 | the `scanline_frame_180` visual vector #396 moved | + +--- + +## Verification bar + +**Every release, before anything lands** — the standing gate: + +```bash +cargo fmt --all --check +cargo clippy --workspace --all-targets -- -D warnings +cargo clippy -p rustynes-frontend --all-targets --features scripting -- -D warnings +cargo clippy -p rustynes-frontend --all-targets --features scripting,hd-pack -- -D warnings +cargo clippy -p rustynes-frontend --all-targets --features retroachievements -- -D warnings +cargo clippy -p rustynes-frontend --target wasm32-unknown-unknown --lib --bins -- -D warnings +cargo clippy -p rustynes-frontend --target wasm32-unknown-unknown --lib --bins \ + --no-default-features --features wasm-canvas -- -D warnings +RUSTDOCFLAGS="-D warnings" cargo doc --workspace --no-deps +cargo build -p rustynes-core --target thumbv7em-none-eabihf --no-default-features +``` + +Plus, because this release adds a feature to a chip crate: + +```bash +cargo clippy -p rustynes-apu --all-targets --no-default-features -- -D warnings +cargo test -p rustynes-apu --no-default-features +``` + +**The accuracy contract, verified and not asserted** (confirm a non-zero test +count — a filter matching nothing prints `0 passed` and exits 0): + +```bash +cargo test -p rustynes-test-harness --features test-roms --test accuracycoin # 141/141, RAM decoder +cargo test -p rustynes-test-harness --features test-roms --test nestest # 0-diff +``` + +Audio Provenance is output-only and default-off at the arm, so the shipped +default should be byte-identical **by construction** — verify it anyway. This +release touches `rustynes-apu`, and v2.3.4's lesson is that "by construction" +claims about a crate you edited are the ones that turn out false. + +**Specific to this release:** + +- The `run_ahead = 1` produce-path test (A0.3) must **fail on the unfixed tree + and pass after** — mutation-checked. A test that passes both ways is what + four releases of broken Pixel Provenance looked like. +- Benches before and after the `debug-hooks` plumbing (workstream C). +- `test-roms` is **full-run only** — skipped on feature PRs, run on `main`. Watch + `main` CI to green after merging; #403 is the worked example of what that + catches and a PR cannot. + +--- + +## Carried forward + +- **v2.3.8 "Parallax" — the Divergence Lens.** Two `Nes` instances from one + anchor, advanced in lockstep under differing configuration, first divergence + located by the v2.3.6 probe engine's bisection. Cheap *because* it hands the + diverging pixel to Pixel Provenance and the diverging sample to this release's + Audio Provenance — which is why it comes third. +- **v2.3.9 "Crucible" — testing, performance, correctness, quality.** Its item + A5, *"make `test-roms` reachable at review time"*, has a fresh worked example + in #403 and should be re-read with it in hand. +- **Latency Oracle:** per-game persistence, and the end-to-end millisecond figure + (measured internal lag plus the frontend pipeline cost `perf.rs` tracks). +- **RAM Atlas:** export paths (Watch/Cheat seeding, Lua, RetroAchievements + authoring) and per-game persistence. +- **`libretro/docs#1180`** and the upstream `.info` sync — deferred to **v2.4.0** + by maintainer decision. A **licence change overrides this** and syncs + immediately. From 33ca16c3fc0d6a70756ffc4a8db8513ad8694c64 Mon Sep 17 00:00:00 2001 From: DoubleGate Date: Tue, 18 Aug 2026 19:10:03 -0400 Subject: [PATCH 2/5] =?UTF-8?q?feat(apu):=20audio=20provenance=20=E2=80=94?= =?UTF-8?q?=20the=20instruction=20behind=20every=20mixed=20cycle?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Point at a moment in the frame and read why it sounds like that. This is the APU counterpart of pixel provenance and deliberately the same shape: a per-register write attribution answering "what wrote this, and from which instruction", and a per-CPU-cycle mix trace answering "what were the channels actually doing". Surfaced at Tools -> Audio -> Audio Provenance. Output-only, runtime-default-off, and not serialized, so the deterministic audio contract is unaffected whether it is armed or not. ## Why this is not wiring up panels that already exist Every ingredient but one already shipped. audio_scope.rs plots the per-channel waveforms; audio_mixer.rs exposes per-channel gain; Apu::pulse1_out() and its siblings expose live channel outputs; the Trace Logger has PC and cycle; the Event Viewer already intercepts and classifies $4000-$4017 writes as EventKind::ApuWrite. What existed nowhere is the link between a sample and the instruction that caused it. EventRec carries kind / scanline / dot / addr / value -- no PC, no CPU cycle -- and it is scanline-oriented rather than sample-oriented. So the event log is the interception POINT this feature reuses; it is not the record. ## Cadence: per CPU cycle, and why that is the honest choice The mix is computed once per CPU cycle (1.789 MHz NTSC) and handed to blip, which decimates to 44,100 Hz -- roughly one output sample per 40.6 CPU cycles. The plan specified a PER-SAMPLE record at ~734 records/frame. The code disproved that estimate and it is corrected in the plan doc rather than quietly replaced. Recording at output rate would mean choosing which of those ~40 mixes "is" the sample, and band-limited synthesis makes that choice ill-posed: an output sample is a weighted sum of transitions across the filter kernel, not a copy of one instant. A tool that picked one anyway would be answering a question its own signal chain cannot answer, and would do it confidently. So the trace records what was genuinely mixed, at the cadence it was mixed: 29,781 records/frame NTSC against the pixel store's 61,440, which is 0.48x the video record count -- cheaper than the video side, not the 1.2% the estimate claimed. MIX_CAP is sized from DENDY (35,464 cycles/frame), not from the NTSC figure that comes to mind first; sizing it from NTSC would silently truncate the last 16% of every Dendy frame. Over the cap the trace reports truncated() rather than returning a short buffer that looks complete. ## Phase 1 -- register attribution One slot per address across $4000-$4017, each holding (value, cpu_cycle, pc). LAST WRITE, NOT A HISTORY. The question is "what is the register holding, and who put it there"; a ring would need a retention policy nobody has a principled value for, and the Event Viewer already keeps the per-frame write SEQUENCE. This keeps the per-register CAUSE, which it does not. A `written` flag rather than a sentinel cycle, because cycle 0 is a legitimate value: the reset sequence performs real writes, and a sentinel would misreport the earliest writes in a run as "never written". $4014 (OAM DMA) and $4016 (controller strobe) fall inside the range and are not APU registers. They are tracked anyway and labelled for what they are: the range is what the bus already classifies as ApuWrite, one contiguous index space costs two slots, and a hole would invite off-by-one arithmetic at every call site. The attribution is NOT cleared per frame -- "which instruction last wrote $4003" has an answer that legitimately predates this frame. It is cleared on a cold boot, where the history it describes genuinely ended. ## Phase 2 -- the mix trace Per CPU cycle: the five channel outputs that went into the mix, the expansion contribution, and the result. The index IS the cycle offset from first_cycle, so no per-record timestamp is stored. Channel values are the raw pre-mix outputs (0-15 for the pulses, triangle and noise; 0-127 for the DMC) -- what the non-linear mixer consumes. They are NOT scaled by the frontend's mixer gains: those are a presentation control, and recording post-gain values would make the record describe the user's slider rather than the chip. dominant() compares each channel's share of ITS OWN full scale, not raw magnitude, because the raw values are not commensurable -- a DMC 127 and a pulse 15 are both full scale on different scales. ## Phase 3 -- attribution plumbing The split follows the precedent pixel provenance set: the bus has the PC, the APU has the destination register, and the PC is pushed down once per instruction from the existing debug block in Nes::run_frame. rustynes-cpu is untouched. Both push-down sites are mirrored -- run_frame and step_instruction -- so single-stepping through a $4003 store in the debugger attributes the write to the stepped instruction rather than to whatever run_frame last left latched. Recording happens in Apu::write_register BEFORE the write dispatches, so the recorded value is what the CPU put on the bus rather than whatever a channel decided to keep. Both mix paths record: the v2.3.5 default-configuration fast specialization and the gated general path. A record that existed on only one of two byte-identical paths would be a trap for whoever next changed the other. ## The trap this feature inherited, closed up front Pixel provenance shipped NON-FUNCTIONAL for four releases (v2.3.2 through v2.3.6) because run-ahead's per-frame rollback cleared the store AFTER the visible frame was harvested and BEFORE the frontend released the emulator lock, so the UI could never observe a populated record. A comment two lines above the clear asserted the opposite, and that prose is what stopped anyone checking. Audio provenance rides the identical rollback. So the carry landed in the same change as the feature, not after a bug report: - Nes::take_audio_provenance / put_audio_provenance, called around restore_quiet in RunAhead::finish. - Save-state loads and netplay rollback still clear, unchanged -- those are genuine timeline changes. Run-ahead's rollback is not; it returns to the timeline it just left. - runahead_preserves_audio_provenance drives the real produce path at run_ahead = 1, the default, and looks at the first moment the UI could. Mutation-checked: dropping the stash turns it red. - 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. 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. One further note recorded because it cost time: a single run_frame immediately after from_rom can advance ZERO cycles, since the PPU starts at a frame boundary. The control runs three frames for that reason, exactly as the pixel-provenance control does. ## Phase 4 -- the panel The panel reads the CORE for the armed state every frame rather than keeping a mirror. The v2.3.6 pixel panel kept one and edge-detected on it, which desynced permanently the moment a ROM load installed a fresh Nes: checkbox ticked, core unarmed, no way back but unticking and re-ticking. It distinguishes three empty states rather than rendering one confident blank report: not armed, armed but nothing recorded yet, and trace truncated. Register rows carry their SIDE-BAND effects, because naming the right instruction and then describing the wrong effect is its own failure. A write to $4003 does not merely set the period -- it also loads the length counter, resets the duty sequencer, and restarts the envelope. Those annotations were confirmed against this emulator's own implementation (Pulse::write_timer_hi, Triangle::write_linear, Apu::write_status, and the $4017 alignment comment in Apu::write_register), not from memory. ## Workstream C -- the disarmed cost, measured three times The plan required re-running apu_throughput after the plumbing landed, to confirm the shipped default was unmoved. It was not unmoved, and the diagnosis in between was wrong. The configuration that matters is feature-compiled-in / arm-off, because crates/rustynes-frontend/Cargo.toml pulls rustynes-core with debug-hooks unconditionally. "Default-off" describes the runtime arm, not the code, so every user compiles this in and a feature nobody enabled can still charge them. C2a -- MixRecord was built BEFORE the arm test, so a disarmed build recomputed all five channel outputs every CPU cycle, and Pulse::output is not free (it calls muted(), which calls sweep_target()). Measured +14% to +23%. Fixed by hoisting the arm check to the top of the function. C2b -- with the check first, a quiet-host A/B still measured +9.2% / -2.0% / +9.7%. Diagnosed as Apu field-layout disturbance from four new inline fields (reg_attrib, mix_trace, attrib_pc, attrib_cycle) and fixed by consolidating them behind a single Option>. Re-measured: +7.98% / +2.88% / +11.03%, order-bias control +0.11% / +0.76% / +0.67%. THE DIAGNOSIS WAS WRONG. The consolidation is kept because one pointer is the better shape, but it is not what fixed anything, and the claim that it would is recorded rather than deleted. C2c -- the actual cause. The tell was in the numbers all along: the absolute costs were +33 us, +15 us and +65 us, wildly non-uniform. A branch taken once per CPU cycle costs a constant number of cycles and therefore a constant number of microseconds; it cannot vary four-fold across workloads. record_mix was still being INLINED into tick_with_external -- the arm check skipped the WORK, but the five output() calls were still emitted inside the hot function, inflating it past the point where the mixer and the channel ticks kept their register allocation and their I-cache line. The body is now outlined behind #[cold] + #[inline(never)], leaving exactly one null test on the hot path. Final measurement, disarmed, against an order-bias control that drifted -0.8% to -1.4% over the same interval: apu_tick_silent_frame -0.63% (control -1.41%) net +0.8%, within drift apu_tick_active_frame -5.60% (control -0.80%) net -4.8% apu_tick_active_frame_with_ext +0.00% (control -0.29%) net +0.3%, within drift (p = 0.99) The -4.8% is NOT claimed as an optimization. It is code-layout luck in the favourable direction, the same phenomenon that produced +11% in the unfavourable one, and an unrelated future change will erase it. The project bar is >3% same-runner AND byte-identical AND attributable to a mechanism; an effect nobody can point at a mechanism for does not meet it, and adopting it would be adopting noise. Method: apu_throughput built twice (with and without debug-hooks) with both binaries copied aside BEFORE any measurement, so no run is contaminated by its own compile -- the ab_check.sh hazard AGENTS.md records. Executed on a host held below 1.00 load, A -> B -> A, the trailing A being the order-bias control. full_frame was deliberately not run: a whole-frame bench dilutes an APU effect by roughly 5x, and both regressions were found at the instrument with the resolution to see them. Recorded as a deliberate omission, not an oversight. Three lessons carried into docs/performance.md: - A default-off feature can charge the default path without executing one line of its own code. Twice here, by two different mechanisms. - A branch that skips the work does not skip the code. An early return leaves the whole body inlined in the caller, costing registers and I-cache even though it never executes. - Non-uniform absolute deltas rule out a per-cycle mechanism. Read the microseconds before the percentages when deciding what KIND of cost you are looking at. ## Determinism and the save state Output-only throughout. Nothing recorded is read back into synthesis, and none of it is serialized. The new Apu field is registered in snapshot_schema_audit.rs as output-only with a written reason -- the audit caught all four original fields the moment they were added and refused to pass until they were classified. The attribution is deliberately NOT carried in a save state, for the same reason the PPU's write_attrib is not: a restored state's registers were not written by any instruction this session ran, so carrying PCs across a restore would report a timeline that no longer exists. ## Provenance Implemented from the NESdev wiki and from this repository's own APU implementation. No reference-emulator source was consulted; the register side-effect table was confirmed by reading rustynes-apu, not from memory. ## Files - crates/rustynes-apu/src/provenance.rs (new, 540 lines) -- RegWrite, Slot, RegisterAttribution (24 slots), MixRecord, MixTrace (MIX_CAP from Dendy), AudioProvenance, AudioProvenanceStash; 9 unit tests. - crates/rustynes-apu/src/apu.rs (+177) -- the audio_prov field, the outlined record_mix_armed, the write_register hook, and the arm/accessor API. - crates/rustynes-apu/Cargo.toml (+10) -- the debug-hooks feature. - crates/rustynes-core/{Cargo.toml,src/nes.rs} (+79) -- feature forwarding, the two mirrored push-down sites, per-frame re-anchoring, cold-boot clear, and the Nes-level API including the run-ahead stash pair. - crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs (new, 305) -- the inspector, with the register side-effect table. - crates/rustynes-frontend/src/{debugger/mod.rs,ui_shell.rs} (+40) -- panel registration and the Tools -> Audio menu entry. - crates/rustynes-frontend/src/runahead.rs (+89) -- the stash carry around restore_quiet, plus the control and regression tests. - crates/rustynes-test-harness/tests/snapshot_schema_audit.rs (+14). - docs/audio-provenance.md (new, 265), docs/performance.md (+62), mkdocs.yml, CHANGELOG.md, to-dos/plans/v2.3.7-overtone-plan.md. ## Verification - cargo fmt --all --check: clean. - clippy -D warnings: workspace --all-targets; rustynes-apu with debug-hooks; rustynes-frontend with scripting, scripting+hd-pack, retroachievements, full; and BOTH wasm32-unknown-unknown invocations (default and wasm-canvas). - RUSTDOCFLAGS="-D warnings" cargo doc --workspace --no-deps: clean. - cargo build -p rustynes-core --target thumbv7em-none-eabihf --no-default-features: builds (no_std stays clean). - cargo test --workspace: 124 suites green, 0 failures. - cargo test -p rustynes-apu --features debug-hooks provenance: 9 passed. - cargo test -p rustynes-frontend audio_provenance: 2 passed. - cargo test -p rustynes-test-harness --test snapshot_schema_audit: 7 passed. - AccuracyCoin: 100.00% over 141 assigned tests via the authoritative RAM decoder (the framebuffer decoder's 120 is the known grid-stride bug). - nestest: nestest_pc_c000_matches_golden_log passing, 0-diff. This release touches rustynes-apu, so the accuracy gates are VERIFIED rather than true by construction. Co-Authored-By: Claude Opus 5 --- CHANGELOG.md | 73 +++ crates/rustynes-apu/Cargo.toml | 10 + crates/rustynes-apu/src/apu.rs | 177 ++++++ crates/rustynes-apu/src/lib.rs | 2 + crates/rustynes-apu/src/provenance.rs | 540 ++++++++++++++++++ crates/rustynes-core/Cargo.toml | 2 +- crates/rustynes-core/src/nes.rs | 78 +++ .../src/debugger/audio_provenance_panel.rs | 305 ++++++++++ crates/rustynes-frontend/src/debugger/mod.rs | 26 + crates/rustynes-frontend/src/runahead.rs | 89 +++ crates/rustynes-frontend/src/ui_shell.rs | 14 + .../tests/snapshot_schema_audit.rs | 14 + docs/audio-provenance.md | 265 +++++++++ docs/performance.md | 62 ++ mkdocs.yml | 1 + to-dos/plans/v2.3.7-overtone-plan.md | 66 ++- 16 files changed, 1709 insertions(+), 15 deletions(-) create mode 100644 crates/rustynes-apu/src/provenance.rs create mode 100644 crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs create mode 100644 docs/audio-provenance.md diff --git a/CHANGELOG.md b/CHANGELOG.md index 5f5252c2..598cd0ad 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -14,6 +14,79 @@ cycle-accurate core later replaced. ## [Unreleased] +### Added + +- **Audio provenance — point at a moment in the frame and read why it sounds + like that.** The APU counterpart of pixel provenance, and deliberately the + same shape: a per-register write attribution answering *what wrote this, and + from which instruction*, and a per-CPU-cycle mix trace answering *what were + the channels actually doing*. Surfaced at **Tools → Audio → Audio + Provenance**. Output-only, runtime-default-off, and not serialized, so the + deterministic audio contract is unaffected whether it is armed or not. + + Every ingredient but one already shipped — the Audio Scope plots the + waveforms, the Audio Mixer sets the gains, `Apu::pulse1_out()` and its + siblings expose live channel outputs, and the Event Viewer already classifies + `$4000-$4017` writes as `EventKind::ApuWrite`. What existed nowhere is the + link from a sample back to the instruction that caused it: `EventRec` carries + `kind / scanline / dot / addr / value` — no PC, no CPU cycle — and is + scanline-oriented rather than sample-oriented. So the event log is the + interception *point* this reuses; it is not the record. + + The trace is per **CPU cycle**, the cadence at which the mix is genuinely + computed, rather than per output sample. `blip` decimates to 44.1 kHz — about + one sample per 40.6 CPU cycles — and an output sample is a weighted sum of + transitions across the filter kernel, not a copy of one instant. Recording at + output rate would mean picking which of those ~40 mixes "is" the sample, which + the signal chain cannot answer; the panel reports the cycle window and says so + instead. `MIX_CAP` is sized from **Dendy** (35,464 cycles/frame), not the NTSC + figure that comes to mind first, and reports `truncated()` rather than + returning a short buffer that looks complete. + + Register rows carry their **side-band effects**, because naming the right + instruction and then describing the wrong effect is its own failure: a write + to `$4003` does not merely set the period, it also loads the length counter, + resets the duty sequencer and restarts the envelope. Those annotations were + confirmed against this emulator's own implementation, not from memory. + + **The trap this feature inherited was closed in the same change as the + feature, not after a bug report.** Pixel provenance shipped non-functional for + four releases because run-ahead's per-frame rollback cleared the store before + the frontend released the emulator lock, so the UI could never observe a + populated record — and a comment asserted the opposite, which is what stopped + anyone checking. Audio provenance rides the identical rollback, so + `take_audio_provenance` / `put_audio_provenance` carry the state around + `restore_quiet` in `RunAhead::finish` from the outset. Save-state loads and + netplay rollback still clear, unchanged: those are genuine timeline changes, + and run-ahead's is not. The regression test drives the real produce path at + `run_ahead = 1` — the default — and is mutation-checked. Both it and its + control are floored at 20,000 records rather than "non-empty", because the + APU's reset sequence alone produces eight, so a non-emptiness check would pass + on a run that emulated nothing. + + Spec: `docs/audio-provenance.md`. `rustynes-apu` gains a `debug-hooks` + feature, forwarded from the core's. + +### Changed + +- **The disarmed cost of audio provenance was measured, and it was not free.** + Workstream C re-ran `apu_throughput` after the plumbing landed and found the + shipped APU slower in the configuration every user runs — feature compiled in, + arm off, because the frontend pulls the core's `debug-hooks` unconditionally. + Two distinct mechanisms, and the diagnosis in between was wrong: + building the `MixRecord` before testing the arm (**+14% to +23%**, fixed by + hoisting the check), then a suspected `Apu` field-layout effect whose fix + **changed nothing** (still +7.98% / +2.88% / +11.03% after consolidating four + fields behind one `Option>`), and finally the real cause — the body + was still being *inlined* into the hot mix path, so the branch skipped the + work but not the code. Outlining it behind `#[cold] #[inline(never)]` returns + the disarmed path to baseline. What broke the wrong diagnosis open was the + absolute column: +33 µs / +15 µs / +65 µs cannot be a per-cycle cost, because + a per-cycle branch costs a constant number of cycles. One workload measures + −4.8% and that is **not** claimed as an optimization — it is code-layout luck + in the favourable direction, and adopting it would be adopting noise. Numbers, + method and the order-bias control: `docs/performance.md` §v2.3.7 C2. + ### Fixed - **VRC7 save states now carry the FM synthesizer, so rewind no longer garbles diff --git a/crates/rustynes-apu/Cargo.toml b/crates/rustynes-apu/Cargo.toml index a57b4fb3..dbd71781 100644 --- a/crates/rustynes-apu/Cargo.toml +++ b/crates/rustynes-apu/Cargo.toml @@ -23,6 +23,16 @@ workspace = true # would then quietly opt every consumer in to `std`, masking no_std regressions # from cross-target CI gates that build with `--no-default-features`. std = [] +# v2.3.7 "Overtone" — audio provenance: per-register write attribution (which +# instruction wrote `$4000-$4017`) and a per-CPU-cycle trace of the channel +# outputs actually mixed. Mirrors `rustynes-ppu/debug-hooks`, and like it the +# feature is only half the gate: `rustynes-core` forwards it and the frontend +# enables it unconditionally, so **the thing that is default-off is the runtime +# ARM**, a lazily-allocated `Option` whose disarmed cost is one discriminant +# test per register write and per mixed cycle. Output-only: nothing here is read +# back into synthesis or carried in the save state, so the shipped default is +# byte-identical and the determinism contract is untouched. +debug-hooks = [] [dependencies] bitflags.workspace = true diff --git a/crates/rustynes-apu/src/apu.rs b/crates/rustynes-apu/src/apu.rs index 0b7b0b22..bb93249d 100644 --- a/crates/rustynes-apu/src/apu.rs +++ b/crates/rustynes-apu/src/apu.rs @@ -305,6 +305,15 @@ pub struct Apu { /// audio — the visualization samples a copy, exactly like the base-channel /// `*_out()` DAC accessors already do. pub(crate) last_external: f32, + + /// v2.3.7 "Overtone" — audio provenance, behind ONE pointer. + /// + /// `None` until armed via [`Apu::set_audio_provenance`]. Consolidated into a + /// single `Option>` after `apu_throughput` measured +9% on the + /// DISARMED path with this state spread across four inline fields — see + /// `crate::provenance::AudioProvenance`. + #[cfg(feature = "debug-hooks")] + pub(crate) audio_prov: Option>, } /// All [`Apu::channel_mask`] bits set — every channel audible (the default and @@ -383,9 +392,161 @@ impl Apu { channel_mask: CHANNEL_MASK_ALL, channel_gain: CHANNEL_GAIN_UNITY, last_external: 0.0, + #[cfg(feature = "debug-hooks")] + audio_prov: None, + } + } + + // ----------------------------------------------------------------- + // v2.3.7 "Overtone" — audio provenance (output-only, off by default) + // ----------------------------------------------------------------- + + /// Record one mixed CPU cycle — the OUTLINED half. + /// + /// Called from both mix paths so the fast default-configuration + /// specialization and the gated general path produce the same trace: a + /// provenance record that existed on only one of two byte-identical paths + /// would be a trap for whoever next changed the other. + /// + /// # Why `#[cold]` and `#[inline(never)]` are load-bearing + /// + /// This function is measurement-driven twice over, and the second lesson is + /// the less obvious one. + /// + /// The FIRST version built the `MixRecord` before testing whether + /// provenance was armed, so a DISARMED build recomputed all five channel + /// outputs every CPU cycle — and `Pulse::output` is not free (it calls + /// `muted()`, which calls `sweep_target()`). `apu_throughput` measured + /// **+14% to +23%** in the feature-on/arm-off configuration the shipped + /// frontend runs. Hoisting the arm check to the top fixed that. + /// + /// It was NOT enough. With the check first, a quiet-host A/B still measured + /// **+7.98% / +2.88% / +11.03%** on the three `apu_throughput` workloads + /// (order-bias control: +0.11% / +0.76% / +0.67%, so the deltas are real). + /// The absolute costs — +33 µs, +15 µs, +65 µs — are wildly non-uniform, + /// which a per-cycle branch cannot produce: a constant branch costs a + /// constant number of cycles. The cause was that this body was still being + /// INLINED into `tick_with_external`. The five `output()` calls sat in the + /// hot function even though the branch skipped over them, inflating it past + /// the point where the mixer and the channel ticks kept their registers and + /// their I-cache line. + /// + /// So the hot path now contains exactly one null test, and everything else + /// lives out of line behind it. `#[cold]` additionally tells LLVM to lay + /// this block out away from the fall-through path. It pessimizes the ARMED + /// case, which is the correct trade: armed is an interactive debugging mode + /// and disarmed is what every user runs. + #[cfg(feature = "debug-hooks")] + #[cold] + #[inline(never)] + fn record_mix_armed(&mut self, mixed: f32, external: f32) { + let rec = crate::provenance::MixRecord { + mixed, + external, + pulse1: self.pulse1.output(), + pulse2: self.pulse2.output(), + triangle: self.triangle.output(), + noise: self.noise.output(), + dmc: self.dmc.output(), + }; + if let Some(p) = self.audio_prov.as_mut() { + p.mix_trace.push(rec); + } + } + + /// Arm or disarm audio provenance. + /// + /// Arming allocates both stores; disarming frees them. Mirrors + /// `Ppu::set_pixel_provenance`, including that re-arming an already-armed + /// APU is a no-op rather than a silent wipe — the frontend re-asserts the + /// arm every frame (a lesson from the pixel panel, whose edge-triggered + /// mirror desynced permanently the moment a ROM load installed a fresh + /// core). + #[cfg(feature = "debug-hooks")] + pub fn set_audio_provenance(&mut self, enabled: bool) { + if enabled { + if self.audio_prov.is_none() { + self.audio_prov = Some(alloc::boxed::Box::new( + crate::provenance::AudioProvenance::new(), + )); + } + } else { + self.audio_prov = None; } } + /// Whether audio provenance is armed. + #[cfg(feature = "debug-hooks")] + #[must_use] + pub const fn audio_provenance_armed(&self) -> bool { + self.audio_prov.is_some() + } + + /// The per-register write attribution, or `None` when disarmed. + #[cfg(feature = "debug-hooks")] + #[must_use] + pub fn register_attribution(&self) -> Option<&crate::provenance::RegisterAttribution> { + self.audio_prov.as_ref().map(|p| &p.reg_attrib) + } + + /// The per-CPU-cycle mix trace, or `None` when disarmed. + #[cfg(feature = "debug-hooks")] + #[must_use] + pub fn mix_trace(&self) -> Option<&crate::provenance::MixTrace> { + self.audio_prov.as_ref().map(|p| &p.mix_trace) + } + + /// Begin a new frame's mix trace, anchored at `first_cycle`. + /// + /// The register attribution is deliberately NOT cleared here: "which + /// instruction last wrote `$4003`" is a question whose answer legitimately + /// predates the current frame, and clearing it every frame would report a + /// register nobody has touched this frame as never written. + #[cfg(feature = "debug-hooks")] + pub fn begin_audio_provenance_frame(&mut self, first_cycle: u64) { + if let Some(p) = self.audio_prov.as_mut() { + p.mix_trace.clear(first_cycle); + } + } + + /// Forget the register attribution history. Called on a cold boot, where + /// the history it describes genuinely ended. + #[cfg(feature = "debug-hooks")] + pub fn clear_audio_provenance_history(&mut self) { + if let Some(p) = self.audio_prov.as_mut() { + p.reg_attrib.clear(); + } + } + + /// Push the writing instruction's PC + cycle down, mirroring the PPU's + /// write-attribution context. Called once per instruction by the core. + #[cfg(feature = "debug-hooks")] + pub const fn set_attrib_context(&mut self, pc: u16, cycle: u64) { + // No-op when disarmed: nothing reads these, so skipping the stores keeps + // the disarmed per-instruction cost at one null test. + if let Some(p) = self.audio_prov.as_mut() { + p.attrib_pc = pc; + p.attrib_cycle = cycle; + } + } + + /// Lift both stores out for a same-timeline restore (run-ahead), leaving the + /// APU disarmed. See [`crate::provenance::AudioProvenanceStash`] for why + /// this exists at all. + #[cfg(feature = "debug-hooks")] + #[must_use] + pub fn take_audio_provenance(&mut self) -> crate::provenance::AudioProvenanceStash { + crate::provenance::AudioProvenanceStash { + state: self.audio_prov.take(), + } + } + + /// Put back stores taken by [`Self::take_audio_provenance`]. + #[cfg(feature = "debug-hooks")] + pub fn put_audio_provenance(&mut self, stash: crate::provenance::AudioProvenanceStash) { + self.audio_prov = stash.state; + } + /// Reset (warm). Per nesdev: most APU state is preserved across reset /// except `$4015` is cleared (channels disabled, DMC silenced). /// @@ -1086,6 +1247,10 @@ impl Apu { self.noise.output(), self.dmc.output(), ) + external; + #[cfg(feature = "debug-hooks")] + if self.audio_prov.is_some() { + self.record_mix_armed(mixed, external); + } self.blip.add_sample(mixed); // Nothing follows the general path's `add_sample` but comments -- // the get/put flip moved to `dmc_tick_end` under M-2 -- so there is @@ -1140,6 +1305,10 @@ impl Apu { scale(3, gate(3, self.noise.output()), 15), scale(4, gate(4, self.dmc.output()), 127), ) + if mask & (1 << 5) != 0 { ext } else { 0.0 }; + #[cfg(feature = "debug-hooks")] + if self.audio_prov.is_some() { + self.record_mix_armed(mixed, ext); + } self.blip.add_sample(mixed); // v2.0 interleaved-DMA Phase A: toggle the global get/put flip-flop once @@ -1550,6 +1719,14 @@ impl Apu { /// CPU register write (`$4000-$4017` excluding `$4014`). pub fn write_register(&mut self, addr: u16, value: u8) { + // v2.3.7 "Overtone" — attribute the write BEFORE dispatching it, so the + // recorded value is what the CPU put on the bus rather than whatever a + // channel decided to keep. One `Option` test when disarmed. + #[cfg(feature = "debug-hooks")] + if let Some(p) = self.audio_prov.as_mut() { + p.reg_attrib + .record(addr, p.attrib_pc, p.attrib_cycle, value); + } match addr { 0x4000 => self.pulse1.write_ctrl(value), 0x4001 => self.pulse1.write_sweep(value), diff --git a/crates/rustynes-apu/src/lib.rs b/crates/rustynes-apu/src/lib.rs index 157be09f..018bc1ca 100644 --- a/crates/rustynes-apu/src/lib.rs +++ b/crates/rustynes-apu/src/lib.rs @@ -44,6 +44,8 @@ mod length; mod mixer; mod noise; mod opll; +#[cfg(feature = "debug-hooks")] +pub mod provenance; mod pulse; mod snapshot; mod triangle; diff --git a/crates/rustynes-apu/src/provenance.rs b/crates/rustynes-apu/src/provenance.rs new file mode 100644 index 00000000..a74cf6d5 --- /dev/null +++ b/crates/rustynes-apu/src/provenance.rs @@ -0,0 +1,540 @@ +// SPDX-License-Identifier: GPL-3.0-or-later +//! Audio provenance (v2.3.7 "Overtone") — why does this moment sound like that? +//! +//! The APU analogue of the PPU's `rustynes_ppu::provenance` (a plain code span, +//! not an intra-doc link: `rustynes-apu` does not depend on `rustynes-ppu`, and a +//! bracketed link to a crate outside the graph fails `RUSTDOCFLAGS=-D warnings` +//! while clippy stays green), and deliberately +//! built to the same shape: a **register-attribution** half that answers "what +//! wrote this, and from which instruction", and a **per-cycle mix trace** that +//! answers "what were the channels actually doing". +//! +//! # What was missing before this +//! +//! Every other ingredient already shipped. The frontend's audio scope plots the +//! per-channel waveforms, the audio mixer exposes per-channel gain, +//! [`crate::Apu::pulse1_out`] and its siblings expose live channel outputs, and +//! the trace logger has PC and cycle. What did not exist anywhere is the **link +//! between a sample and the instruction that caused it** — exactly the gap the +//! pixel-provenance design identified for video. +//! +//! # Cadence, and why it is per CPU cycle rather than per output sample +//! +//! The mix is computed **once per CPU cycle** (1.789 MHz NTSC) and handed to the +//! band-limited `blip` decimator, which produces output samples at 44.1 kHz — +//! about one per 40.6 CPU cycles. Recording at *output* rate would therefore +//! require choosing which of those 40 mixes "is" the sample, and band-limited +//! synthesis makes that choice ill-posed: an output sample is a weighted sum of +//! transitions across the filter kernel, not a copy of one instant. +//! +//! So this records what was genuinely mixed, at the cadence it was mixed. The +//! panel maps a clicked output sample back to its CPU-cycle window; the doc says +//! plainly that the window is a kernel width, not a point. **A provenance tool +//! that answers a question it cannot actually answer is worse than one that +//! declines** — the whole argument v2.3.6 was built on. +//! +//! The cost is smaller than it sounds: 29,781 records per NTSC frame against the +//! pixel store's 61,440 — **0.48x the record count of the video side**. +//! +//! # Determinism +//! +//! Output-only. Nothing here is read back into synthesis, none of it is part of +//! the save state, and every store is behind a runtime arm that is off by +//! default. With the arm off the cost is one `Option` discriminant test per +//! register write and per mixed cycle. + +use alloc::boxed::Box; +use alloc::vec::Vec; + +/// First APU/IO register address covered by [`RegisterAttribution`]. +pub const REG_BASE: u16 = 0x4000; + +/// Number of register slots tracked: `$4000-$4017` inclusive. +/// +/// `$4014` (OAM DMA) and `$4016` (controller strobe) are inside the range and +/// are NOT APU registers. They are tracked anyway rather than punched out: the +/// range is what the bus already classifies as [`EventKind::ApuWrite`], keeping +/// one contiguous index space costs two slots, and a hole would be a permanent +/// invitation to off-by-one arithmetic at every call site. +/// +/// [`EventKind::ApuWrite`]: https://docs.rs/rustynes-core +pub const REG_COUNT: usize = 0x18; + +/// [`REG_COUNT`] as a `u16`, so address arithmetic never needs a cast. +pub const REG_COUNT_U16: u16 = 0x18; + +/// Largest CPU-cycle count in one frame across every supported region, which is +/// what [`MixTrace`] is sized for. +/// +/// Dendy is the worst case, not NTSC: 1,773,448 Hz / 50.007 fps = **35,464** +/// cycles per frame, against PAL's 33,247 and NTSC's 29,781. Sizing this from +/// the NTSC number — the one that comes to mind first — would silently truncate +/// the last 16% of every Dendy frame. +pub const MIX_CAP: usize = 36_864; + +// --------------------------------------------------------------------------- +// Register attribution — "what wrote $4003, and from where?" +// --------------------------------------------------------------------------- + +/// One register write: the byte, the CPU cycle, and the instruction that did it. +/// +/// `cycle` is the CPU cycle counter at the writing instruction, which is what +/// makes a record comparable against the Trace Logger and the Event Viewer for +/// the same frame. Mirrors `rustynes_ppu::provenance::WriteAttrib`, which +/// carries the same three fields for VRAM/OAM/palette bytes. +#[derive(Clone, Copy, Debug, Eq, PartialEq, Hash)] +pub struct RegWrite { + /// CPU cycle count at the writing instruction. + pub cycle: u64, + /// Program counter of the writing instruction. + pub pc: u16, + /// The byte written, as the CPU put it on the bus. + pub value: u8, +} + +/// Storage-side mirror of [`RegWrite`] with a `Default`, so a slot array can be +/// built without inventing a meaningless public default PC. +#[derive(Clone, Copy, Debug, Default, Eq, PartialEq, Hash)] +struct RegWriteInner { + cycle: u64, + pc: u16, + value: u8, +} + +/// One attribution slot plus whether anything has been written yet. +/// +/// A `written` flag rather than a sentinel cycle, for the reason the PPU side +/// documents: **cycle 0 is a legitimate value** — the reset sequence performs +/// real writes — so a sentinel would silently misreport the earliest writes in a +/// run as "never written". +#[derive(Clone, Copy, Debug, Default, Eq, PartialEq, Hash)] +struct Slot { + rec: RegWriteInner, + written: bool, +} + +impl Slot { + const fn get(self) -> Option { + if self.written { + Some(RegWrite { + cycle: self.rec.cycle, + pc: self.rec.pc, + value: self.rec.value, + }) + } else { + None + } + } +} + +/// Last write to each of `$4000-$4017`, with its cause. +/// +/// **Last write, not a history.** One slot per address rather than a ring, +/// because the question this half answers is "what is the register holding, and +/// who put it there" — and a ring would need a retention policy nobody has a +/// principled value for. The Event Viewer already keeps the per-frame write +/// *sequence*; this keeps the per-register *cause*, which it does not. +#[derive(Clone, Debug)] +pub struct RegisterAttribution { + slots: [Slot; REG_COUNT], +} + +impl RegisterAttribution { + /// A fresh table with every slot unwritten. + #[must_use] + pub const fn new() -> Self { + Self { + slots: [Slot { + rec: RegWriteInner { + cycle: 0, + pc: 0, + value: 0, + }, + written: false, + }; REG_COUNT], + } + } + + /// Forget every recorded write. + pub fn clear(&mut self) { + *self = Self::new(); + } + + /// Record a write to `addr`. Addresses outside `$4000-$4017` are dropped + /// rather than wrapping into an unrelated slot. + pub const fn record(&mut self, addr: u16, pc: u16, cycle: u64, value: u8) { + let Some(idx) = Self::index(addr) else { + return; + }; + self.slots[idx] = Slot { + rec: RegWriteInner { cycle, pc, value }, + written: true, + }; + } + + /// The last write to `addr`, or `None` if the address is out of range or + /// nothing has written it since the last [`Self::clear`]. + #[must_use] + pub const fn get(&self, addr: u16) -> Option { + match Self::index(addr) { + Some(idx) => self.slots[idx].get(), + None => None, + } + } + + /// Map a register address to a slot index, or `None` when out of range. + const fn index(addr: u16) -> Option { + if addr < REG_BASE { + return None; + } + let idx = (addr - REG_BASE) as usize; + if idx < REG_COUNT { Some(idx) } else { None } + } +} + +impl Default for RegisterAttribution { + fn default() -> Self { + Self::new() + } +} + +// --------------------------------------------------------------------------- +// Mix trace — "what were the channels doing?" +// --------------------------------------------------------------------------- + +/// The five channel outputs that went into one mixed CPU-cycle sample, plus the +/// result. +/// +/// Channel values are the raw pre-mix outputs each channel presented — 0-15 for +/// the two pulses, the triangle and the noise, 0-127 for the DMC — which is what +/// the non-linear mixer consumes. They are NOT scaled by the frontend's mixer +/// gains: those are a presentation control, and recording post-gain values would +/// make the record describe the user's slider rather than the chip. +#[derive(Clone, Copy, Debug, Default, PartialEq)] +pub struct MixRecord { + /// The mixed sample handed to the band-limited decimator, including any + /// expansion audio. + pub mixed: f32, + /// The expansion-audio contribution (`0.0` on a cartridge without one). + pub external: f32, + /// Pulse 1 output, 0-15. + pub pulse1: u8, + /// Pulse 2 output, 0-15. + pub pulse2: u8, + /// Triangle output, 0-15. + pub triangle: u8, + /// Noise output, 0-15. + pub noise: u8, + /// DMC output, 0-127. + pub dmc: u8, +} + +impl MixRecord { + /// Which channel contributed most to this sample, as an index into the + /// conventional order (0 = pulse 1 … 4 = DMC), or `None` when every channel + /// is silent. + /// + /// Compares each channel's share of the **non-linear** mixer rather than its + /// raw value, because the raw values are not commensurable: a DMC 127 and a + /// pulse 15 are both "full scale" on different scales. The comparison is + /// therefore on normalised share, which is the only ordering that answers + /// the question a user is actually asking. + #[must_use] + pub fn dominant(&self) -> Option { + let shares = [ + f32::from(self.pulse1) / 15.0, + f32::from(self.pulse2) / 15.0, + f32::from(self.triangle) / 15.0, + f32::from(self.noise) / 15.0, + f32::from(self.dmc) / 127.0, + ]; + let mut best = None; + let mut best_share = 0.0f32; + for (i, &s) in shares.iter().enumerate() { + if s > best_share { + best_share = s; + best = Some(i); + } + } + best + } +} + +/// One frame's worth of per-CPU-cycle mix records. +/// +/// The index **is** the cycle offset from [`Self::first_cycle`], so no per-record +/// timestamp is stored — that is what keeps the record at 16 bytes and the frame +/// at ~465 KiB. +#[derive(Clone, Debug)] +pub struct MixTrace { + recs: Vec, + first_cycle: u64, + /// Set when a frame produced more cycles than [`MIX_CAP`] and records were + /// dropped. Surfaced rather than silent: a truncated trace that looks + /// complete is the failure mode this whole subsystem exists to avoid. + truncated: bool, +} + +impl MixTrace { + /// An empty trace with capacity for the worst-case region. + #[must_use] + pub fn new() -> Self { + Self { + recs: Vec::with_capacity(MIX_CAP), + first_cycle: 0, + truncated: false, + } + } + + /// Drop every record and re-anchor the trace at `first_cycle`. + pub fn clear(&mut self, first_cycle: u64) { + self.recs.clear(); + self.first_cycle = first_cycle; + self.truncated = false; + } + + /// Append one mixed cycle. Beyond [`MIX_CAP`] the record is dropped and the + /// trace is flagged [`Self::truncated`]. + pub fn push(&mut self, rec: MixRecord) { + if self.recs.len() >= MIX_CAP { + self.truncated = true; + return; + } + self.recs.push(rec); + } + + /// CPU cycle the first record corresponds to. + #[must_use] + pub const fn first_cycle(&self) -> u64 { + self.first_cycle + } + + /// Whether records were dropped for exceeding [`MIX_CAP`]. + #[must_use] + pub const fn truncated(&self) -> bool { + self.truncated + } + + /// Every record, oldest first. + #[must_use] + pub fn records(&self) -> &[MixRecord] { + &self.recs + } + + /// The record for absolute CPU `cycle`, or `None` if it is outside the + /// trace. + #[must_use] + pub fn at_cycle(&self, cycle: u64) -> Option { + let idx = usize::try_from(cycle.checked_sub(self.first_cycle)?).ok()?; + self.recs.get(idx).copied() + } +} + +impl Default for MixTrace { + fn default() -> Self { + Self::new() + } +} + +// --------------------------------------------------------------------------- +// Run-ahead carry +// --------------------------------------------------------------------------- + +/// Both audio stores, lifted out of the APU so a same-timeline restore can put +/// them back. +/// +/// **This exists because of a shipped bug, not a hypothetical one.** Pixel +/// Provenance was non-functional from v2.3.2 to v2.3.6 because run-ahead's +/// per-frame rollback cleared the provenance store *after* the visible frame was +/// produced and *before* the UI could read it — so the panel could never observe +/// a populated record, and a comment two lines above the clear asserted the +/// opposite. Audio Provenance rides the identical rollback. +/// +/// The frontend takes this before `restore_quiet` and puts it back after, which +/// leaves the restore's own reasoning completely intact: a save-state load and a +/// netplay rollback still clear, because those are genuine timeline changes. +/// Run-ahead's rollback is not — it returns to the timeline it just left. +#[derive(Debug, Default)] +pub struct AudioProvenanceStash { + pub(crate) state: Option>, +} + +impl AudioProvenanceStash { + /// Whether the store was armed when this stash was taken, so the caller can + /// skip the put-back on the common path where nothing is armed. + #[must_use] + pub const fn is_armed(&self) -> bool { + self.state.is_some() + } +} + +/// Everything audio provenance owns, behind ONE pointer. +/// +/// **Consolidated after measurement, not for tidiness.** The first shape put +/// four fields directly on `Apu` — two `Option>` plus the `u16`/`u64` +/// attribution context. That grew the struct on the hot path and the +/// `apu_throughput` bench read **+9%** on two of three workloads with the arm +/// OFF, which is the configuration the shipped frontend runs. One `Option` +/// costs eight bytes and one null test when disarmed, and everything else moves +/// behind the allocation where only an armed session pays for it. +#[derive(Clone, Debug)] +pub struct AudioProvenance { + /// Last write to each of `$4000-$4017`, with its cause. + pub reg_attrib: RegisterAttribution, + /// This frame's per-CPU-cycle mix records. + pub mix_trace: MixTrace, + /// PC of the instruction currently executing, pushed down once per + /// instruction by the core so `write_register` can attribute a write. + pub attrib_pc: u16, + /// CPU-cycle counterpart of [`Self::attrib_pc`]. + pub attrib_cycle: u64, +} + +impl AudioProvenance { + /// A freshly-armed store. + #[must_use] + pub fn new() -> Self { + Self { + reg_attrib: RegisterAttribution::new(), + mix_trace: MixTrace::new(), + attrib_pc: 0, + attrib_cycle: 0, + } + } +} + +impl Default for AudioProvenance { + fn default() -> Self { + Self::new() + } +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn unwritten_slots_report_none() { + let a = RegisterAttribution::new(); + for addr in REG_BASE..REG_BASE + REG_COUNT_U16 { + assert_eq!(a.get(addr), None, "{addr:#06X} should be unwritten"); + } + } + + #[test] + fn cycle_zero_is_a_real_write_not_a_sentinel() { + // The reset sequence performs writes at cycle 0. A sentinel-cycle design + // would report these as "never written". + let mut a = RegisterAttribution::new(); + a.record(0x4000, 0, 0, 0); + assert_eq!( + a.get(0x4000), + Some(RegWrite { + cycle: 0, + pc: 0, + value: 0 + }) + ); + } + + #[test] + fn out_of_range_addresses_are_dropped_not_wrapped() { + let mut a = RegisterAttribution::new(); + a.record(0x3FFF, 0x1234, 9, 0xAA); + a.record(0x4018, 0x1234, 9, 0xBB); + a.record(0xFFFF, 0x1234, 9, 0xCC); + for addr in REG_BASE..REG_BASE + REG_COUNT_U16 { + assert_eq!(a.get(addr), None, "{addr:#06X} was written by a stray addr"); + } + assert_eq!(a.get(0x4018), None); + } + + #[test] + fn last_write_wins_per_address_and_addresses_are_independent() { + let mut a = RegisterAttribution::new(); + a.record(0x4003, 0x8000, 10, 0x11); + a.record(0x4003, 0x8100, 20, 0x22); + a.record(0x4007, 0x8200, 30, 0x33); + assert_eq!( + a.get(0x4003).map(|w| (w.pc, w.cycle, w.value)), + Some((0x8100, 20, 0x22)) + ); + assert_eq!( + a.get(0x4007).map(|w| (w.pc, w.cycle, w.value)), + Some((0x8200, 30, 0x33)) + ); + } + + #[test] + fn mix_trace_index_is_the_cycle_offset() { + let mut t = MixTrace::new(); + t.clear(1_000); + for i in 0..4u8 { + t.push(MixRecord { + pulse1: i, + ..MixRecord::default() + }); + } + assert_eq!(t.at_cycle(1_000).map(|r| r.pulse1), Some(0)); + assert_eq!(t.at_cycle(1_003).map(|r| r.pulse1), Some(3)); + assert_eq!(t.at_cycle(999), None, "before the anchor"); + assert_eq!(t.at_cycle(1_004), None, "past the end"); + } + + #[test] + fn truncation_is_reported_rather_than_silent() { + let mut t = MixTrace::new(); + t.clear(0); + for _ in 0..MIX_CAP { + t.push(MixRecord::default()); + } + assert!(!t.truncated(), "exactly at capacity is not truncation"); + t.push(MixRecord::default()); + assert!(t.truncated(), "over capacity must be visible to the caller"); + assert_eq!(t.records().len(), MIX_CAP); + } + + #[test] + fn mix_cap_covers_the_worst_case_region() { + // Dendy, not NTSC, is the worst case: 1_773_448 / 50.007 = 35,464. + // Sizing from the NTSC number would truncate 16% of every Dendy frame. + // Integer arithmetic: a float cast here would trip the truncation + // lint that this crate denies, and ceil-divide is the exact operation + // the bound needs anyway. + let dendy_cycles_per_frame = (1_773_448_000_usize).div_ceil(50_007); + assert!( + MIX_CAP >= dendy_cycles_per_frame, + "MIX_CAP {MIX_CAP} < Dendy {dendy_cycles_per_frame}" + ); + } + + #[test] + fn dominant_compares_normalised_share_not_raw_value() { + // DMC 100/127 (0.787) beats pulse 15/15? No — pulse is 1.0. The point is + // that raw magnitude would pick the DMC, and share picks the pulse. + let r = MixRecord { + pulse1: 15, + dmc: 100, + ..MixRecord::default() + }; + assert_eq!(r.dominant(), Some(0), "pulse at full scale must win"); + + let r = MixRecord { + pulse1: 8, + dmc: 100, + ..MixRecord::default() + }; + assert_eq!(r.dominant(), Some(4), "DMC 0.787 beats pulse 0.533"); + + assert_eq!( + MixRecord::default().dominant(), + None, + "silence has no winner" + ); + } + + #[test] + fn a_stash_reports_unarmed_when_empty() { + assert!(!AudioProvenanceStash::default().is_armed()); + } +} diff --git a/crates/rustynes-core/Cargo.toml b/crates/rustynes-core/Cargo.toml index 519338c7..2d1f62af 100644 --- a/crates/rustynes-core/Cargo.toml +++ b/crates/rustynes-core/Cargo.toml @@ -53,7 +53,7 @@ cpu-instr-cycle-trace = ["rustynes-cpu/cpu-instr-cycle-trace"] # determinism contract; the frontend enables it. The hooks are output-only (they may # stop the frame early or record state) and never mutate emulation, so even with the # feature ON the persistent timeline is unchanged. -debug-hooks = ["std", "rustynes-ppu/debug-hooks"] +debug-hooks = ["std", "rustynes-ppu/debug-hooks", "rustynes-apu/debug-hooks"] # v1.2.0 beta.2 (Workstream C3) — HD-pack tile-source telemetry. Forwards to # `rustynes-ppu/hd-pack`, which gates the per-pixel `HdTileSource` export inside # `emit_pixel`. Off by default so the shipped / wasm / no_std builds are diff --git a/crates/rustynes-core/src/nes.rs b/crates/rustynes-core/src/nes.rs index 2483e4a8..8b047ed8 100644 --- a/crates/rustynes-core/src/nes.rs +++ b/crates/rustynes-core/src/nes.rs @@ -504,6 +504,9 @@ impl Nes { { self.bus.ppu.clear_write_attribution(); self.bus.ppu.clear_pixel_provenance(); + // v2.3.7 — same for audio: a cold boot ends the history the + // register attribution describes. + self.bus.apu.clear_audio_provenance_history(); } } @@ -520,6 +523,12 @@ impl Nes { // VBL detection or DMA-stall heavy frames before declaring "stuck". const MAX_CYCLES_PER_FRAME: u64 = 150_000; let start = self.bus.cycle(); + // v2.3.7 "Overtone" — anchor this frame's mix trace. The trace is + // per-frame (the index IS the cycle offset from here); the REGISTER + // attribution deliberately is not, because "which instruction last wrote + // $4003" has an answer that legitimately predates this frame. + #[cfg(feature = "debug-hooks")] + self.bus.apu.begin_audio_provenance_frame(start); // T-110-C3 — the event viewer shows one frame; reset the log per frame. #[cfg(feature = "debug-hooks")] if self.bus.event_logging() { @@ -602,6 +611,15 @@ impl Nes { self.bus .ppu .set_attrib_context(self.cpu.pc, self.cpu.cycles); + // v2.3.7 "Overtone" — the same push-down for audio, so + // `Apu::write_register` can attribute a `$4000-$4017` write + // without `rustynes-cpu` knowing the feature exists. Same + // reasoning as the PPU line above: two unconditional stores are + // cheaper than testing an arm behind a `Box` across a crate + // boundary, in a block that already scans breakpoints. + self.bus + .apu + .set_attrib_context(self.cpu.pc, self.cpu.cycles); // T-110-C2 — cycle trace: record the about-to-execute // instruction's CPU state (ring-capped, oldest dropped). if self.trace_enabled { @@ -672,6 +690,10 @@ impl Nes { self.bus .ppu .set_attrib_context(self.cpu.pc, self.cpu.cycles); + #[cfg(feature = "debug-hooks")] + self.bus + .apu + .set_attrib_context(self.cpu.pc, self.cpu.cycles); self.cpu.step(&mut self.bus) } @@ -886,6 +908,62 @@ impl Nes { /// /// Default off. Arming allocates /// [`rustynes_ppu::PixelProvenanceFrame::HEAP_BYTES`]. Output-only, so + /// Arm or disarm **audio** provenance (v2.3.7 "Overtone"). + /// + /// Off by default. Arming allocates the per-register write attribution and + /// the per-CPU-cycle mix trace; disarming frees both. Output-only — nothing + /// recorded is read back into synthesis or carried in the save state, so the + /// deterministic audio contract is unaffected either way. + #[cfg(feature = "debug-hooks")] + pub fn set_audio_provenance(&mut self, enabled: bool) { + self.bus.apu.set_audio_provenance(enabled); + } + + /// Whether audio provenance is armed. + #[cfg(feature = "debug-hooks")] + #[must_use] + pub const fn audio_provenance_armed(&self) -> bool { + self.bus.apu.audio_provenance_armed() + } + + /// The per-register write attribution — which instruction last wrote each of + /// `$4000-$4017` — or `None` when disarmed. + #[cfg(feature = "debug-hooks")] + #[must_use] + pub fn register_attribution(&self) -> Option<&rustynes_apu::provenance::RegisterAttribution> { + self.bus.apu.register_attribution() + } + + /// This frame's per-CPU-cycle mix trace, or `None` when disarmed. + #[cfg(feature = "debug-hooks")] + #[must_use] + pub fn mix_trace(&self) -> Option<&rustynes_apu::provenance::MixTrace> { + self.bus.apu.mix_trace() + } + + /// Lift the audio provenance stores out for a same-timeline restore. + /// + /// The audio counterpart of [`Self::take_provenance`], and it exists for the + /// identical reason: run-ahead's rollback runs AFTER the visible frame is + /// produced and BEFORE the frontend releases the emulator lock, so a store + /// the restore clears can never be observed by the UI. That is exactly how + /// Pixel Provenance shipped non-functional from v2.3.2 to v2.3.6. Take + /// before the restore, [`Self::put_audio_provenance`] after. + /// + /// Save-state loads and netplay rollback still clear, unchanged — those are + /// genuine timeline changes. Run-ahead's rollback is not. + #[cfg(feature = "debug-hooks")] + #[must_use] + pub fn take_audio_provenance(&mut self) -> rustynes_apu::provenance::AudioProvenanceStash { + self.bus.apu.take_audio_provenance() + } + + /// Put back stores taken by [`Self::take_audio_provenance`]. + #[cfg(feature = "debug-hooks")] + pub fn put_audio_provenance(&mut self, stash: rustynes_apu::provenance::AudioProvenanceStash) { + self.bus.apu.put_audio_provenance(stash); + } + /// emulation is bit-identical either way. #[cfg(feature = "debug-hooks")] pub fn set_pixel_provenance(&mut self, enabled: bool) { diff --git a/crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs b/crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs new file mode 100644 index 00000000..47acc408 --- /dev/null +++ b/crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs @@ -0,0 +1,305 @@ +// SPDX-License-Identifier: GPL-3.0-or-later +//! Audio provenance inspector (v2.3.7 "Overtone"). +//! +//! Pick a moment in the frame and read why it sounds like that: what each +//! channel was putting out, which one dominated the mix, and — for every APU +//! register — the value it holds, the CPU cycle it was written on, and **the +//! instruction that wrote it**. +//! +//! # Relationship to the other audio panels +//! +//! Deliberately not a replacement for either. The Audio Scope plots *what the +//! waveform looks like*; the Audio Mixer sets *how loud each channel is*. This +//! answers *why* — which neither can, because neither has the link from a +//! sample back to the instruction responsible for it. +//! +//! # What it does not claim +//! +//! The trace is per **CPU cycle**, which is the cadence the mix is actually +//! computed at. Output samples come out of a band-limited decimator at ~40.6 +//! CPU cycles each, and an output sample is a weighted sum of transitions across +//! the filter kernel — not a copy of one instant. So this panel reports the +//! cycle window, and says so, rather than pretending a sample has a single +//! originating cycle. + +use crate::debugger::source_map::SourceMap; +use rustynes_core::Nes; + +/// The APU register names, indexed from `$4000`. +/// +/// `$4014` and `$4016` are inside the traced range and are not APU registers; +/// they are labelled for what they are rather than blanked, so a user who sees +/// a write to one is told why it is there. +const REG_NAMES: [&str; 0x18] = [ + "$4000 Pulse1 ctrl", + "$4001 Pulse1 sweep", + "$4002 Pulse1 timer lo", + "$4003 Pulse1 timer hi", + "$4004 Pulse2 ctrl", + "$4005 Pulse2 sweep", + "$4006 Pulse2 timer lo", + "$4007 Pulse2 timer hi", + "$4008 Tri linear", + "$4009 (unused)", + "$400A Tri timer lo", + "$400B Tri timer hi", + "$400C Noise ctrl", + "$400D (unused)", + "$400E Noise period", + "$400F Noise length", + "$4010 DMC ctrl", + "$4011 DMC DAC", + "$4012 DMC addr", + "$4013 DMC length", + "$4014 OAM DMA (not APU)", + "$4015 Status", + "$4016 Controller (not APU)", + "$4017 Frame counter", +]; + +/// Channel labels in the order [`rustynes_apu::provenance::MixRecord::dominant`] +/// indexes them. +const CHANNELS: [&str; 5] = ["Pulse 1", "Pulse 2", "Triangle", "Noise", "DMC"]; + +/// Side-band effects a write carries beyond the obvious one. +/// +/// **This is the research obligation the plan recorded, made visible.** A naive +/// reading of "last write to `$4003`" says "the period changed" — but that one +/// write ALSO loads the length counter, resets the duty sequencer, and restarts +/// the envelope. A provenance tool that names the right instruction and then +/// describes the wrong effect is precisely the failure this project keeps +/// paying for, so the extra effects are spelled out at the point of use. +/// +/// Confirmed against this emulator's own implementation rather than from memory: +/// `Pulse::write_timer_hi`, `Triangle::write_linear`, `Apu::write_status`, and +/// the `$4017` alignment comment in `Apu::write_register`. +const fn side_effects(idx: usize) -> Option<&'static str> { + match idx { + // $4003 / $4007 + 0x03 | 0x07 => Some( + "also loads the length counter, resets the duty sequencer, and restarts the envelope", + ), + // $4008 + 0x08 => { + Some("length-counter halt is DEFERRED — applied after the same-cycle half-frame clock") + } + // $400B + 0x0B => Some("also loads the length counter and sets the linear-counter reload flag"), + // $400F + 0x0F => Some("also loads the length counter and restarts the envelope"), + // $4015 + 0x15 => Some( + "enables/disables length counters; the DMC enable is latched and applied with a delay", + ), + // $4017 + 0x17 => Some("effects land 3 CPU cycles after the write on an APU clock, 4 otherwise"), + _ => None, + } +} + +/// Panel state: the pinned cycle, and nothing else the core already knows. +/// +/// **No mirror of the core's armed flag.** The v2.3.6 pixel panel kept one and +/// edge-detected on it, which desynced permanently the moment a ROM load +/// installed a fresh `Nes`: the checkbox stayed ticked over an unarmed core, +/// with no way back but unticking and re-ticking. The core is re-read every +/// frame here instead. +#[derive(Default)] +pub struct AudioProvenancePanelState { + /// Offset into the current frame's mix trace, in CPU cycles. + pin: usize, + /// Follow the newest recorded cycle instead of holding `pin`. + follow: bool, +} + +/// Render the inspector. +pub fn show( + ctx: &egui::Context, + detached: &mut std::collections::HashSet<&'static str>, + open: &mut bool, + state: &mut AudioProvenancePanelState, + nes: &mut Nes, + source_map: &SourceMap, +) { + // The CORE is the source of truth for the arm, re-read every frame, for the + // reason `AudioProvenancePanelState` documents. + let armed = nes.audio_provenance_armed(); + let mut want_armed = armed; + + super::detachable_window( + ctx, + detached, + "audio_provenance", + "Audio Provenance", + super::WindowCfg { + default_size: Some([520.0, 600.0]), + ..Default::default() + }, + open, + |ui| { + ui.horizontal(|ui| { + ui.checkbox(&mut want_armed, "Enable"); + ui.separator(); + ui.checkbox(&mut state.follow, "Follow newest"); + }); + ui.label( + egui::RichText::new( + "Records the channel outputs mixed on every CPU cycle, and which \ + instruction last wrote each APU register.", + ) + .small() + .weak(), + ); + ui.separator(); + + if !armed { + ui.label("Not armed — tick Enable, then let a frame run."); + return; + } + + let Some(trace) = nes.mix_trace() else { + ui.label("Armed, but the trace is not allocated yet."); + return; + }; + let recs = trace.records(); + if recs.is_empty() { + // Distinct from "not armed" on purpose. A panel whose only failure + // mode is a confident blank report cannot be trusted even once it + // works — the lesson the pixel inspector cost four releases. + ui.label("Armed, but no cycles recorded for this frame yet."); + return; + } + + if trace.truncated() { + ui.colored_label( + egui::Color32::from_rgb(0xE0, 0xA0, 0x30), + "⚠ Trace truncated — this frame produced more cycles than the buffer holds.", + ); + } + + if state.follow { + state.pin = recs.len() - 1; + } + state.pin = state.pin.min(recs.len() - 1); + + ui.horizontal(|ui| { + ui.label("Cycle offset:"); + ui.add( + egui::Slider::new(&mut state.pin, 0..=recs.len() - 1) + .clamping(egui::SliderClamping::Always), + ); + }); + + let rec = recs[state.pin]; + let abs_cycle = trace.first_cycle() + state.pin as u64; + ui.label(format!( + "CPU cycle {abs_cycle} ({} of {} this frame)", + state.pin + 1, + recs.len() + )); + ui.label( + egui::RichText::new( + "One output sample spans ~40.6 of these cycles; a sample is a \ + weighted sum across the filter kernel, not a copy of one cycle.", + ) + .small() + .weak(), + ); + ui.separator(); + + // --- the mix at that cycle --- + let dominant = rec.dominant(); + egui::Grid::new("audio_prov_mix") + .num_columns(3) + .striped(true) + .show(ui, |ui| { + ui.label(egui::RichText::new("Channel").strong()); + ui.label(egui::RichText::new("Output").strong()); + ui.label(egui::RichText::new("Share").strong()); + ui.end_row(); + + let vals = [rec.pulse1, rec.pulse2, rec.triangle, rec.noise, rec.dmc]; + let fulls = [15.0f32, 15.0, 15.0, 15.0, 127.0]; + for (i, name) in CHANNELS.iter().enumerate() { + let lead = dominant == Some(i); + let label = if lead { + egui::RichText::new(*name).strong() + } else { + egui::RichText::new(*name) + }; + ui.label(label); + ui.label(format!("{}", vals[i])); + ui.label(format!("{:.0}%", f32::from(vals[i]) / fulls[i] * 100.0)); + ui.end_row(); + } + }); + ui.label(format!( + "Mixed: {:.5} Expansion: {:.5}", + rec.mixed, rec.external + )); + ui.label(dominant.map_or_else( + || "Dominant: none — every channel silent".to_owned(), + |i| format!("Dominant: {}", CHANNELS[i]), + )); + + ui.separator(); + ui.label(egui::RichText::new("Register writes").strong()); + + // --- who wrote each register --- + let Some(attrib) = nes.register_attribution() else { + ui.label("No register attribution."); + return; + }; + egui::ScrollArea::vertical() + .max_height(240.0) + .show(ui, |ui| { + egui::Grid::new("audio_prov_regs") + .num_columns(4) + .striped(true) + .show(ui, |ui| { + ui.label(egui::RichText::new("Register").strong()); + ui.label(egui::RichText::new("Value").strong()); + ui.label(egui::RichText::new("Cycle").strong()); + ui.label(egui::RichText::new("Written by").strong()); + ui.end_row(); + + for (i, name) in REG_NAMES.iter().enumerate() { + let addr = 0x4000 + u16::try_from(i).unwrap_or(0); + let Some(w) = attrib.get(addr) else { + continue; + }; + ui.label(*name); + ui.label(format!("{:#04X}", w.value)); + ui.label(format!("{}", w.cycle)); + ui.label(source_map.annotation(w.pc).map_or_else( + || format!("{:#06X}", w.pc), + |s| format!("{:#06X} {s}", w.pc), + )); + ui.end_row(); + + if let Some(extra) = side_effects(i) { + ui.label(""); + ui.label(""); + ui.label(""); + ui.label(egui::RichText::new(extra).small().weak()); + ui.end_row(); + } + } + }); + }); + ui.label( + egui::RichText::new( + "Registers with no row have not been written since the last cold boot.", + ) + .small() + .weak(), + ); + }, + ); + + // Applied AFTER the body renders, so the core sees one arming change per + // frame and the panel never reads a store it just freed. + if want_armed != armed { + nes.set_audio_provenance(want_armed); + } +} diff --git a/crates/rustynes-frontend/src/debugger/mod.rs b/crates/rustynes-frontend/src/debugger/mod.rs index 8bc725cf..ebaabedb 100644 --- a/crates/rustynes-frontend/src/debugger/mod.rs +++ b/crates/rustynes-frontend/src/debugger/mod.rs @@ -147,6 +147,7 @@ mod nsf_panel; mod oam_panel; mod replay_panel; // v2.8.0 Phase 0 — frame-pacing / audio-health instrumentation panel. +mod audio_provenance_panel; mod perf_panel; mod ppu_panel; mod provenance_panel; @@ -222,6 +223,10 @@ pub enum ToolPanel { /// The variant is unconditional so the menu IA + dispatch match stay /// exhaustive; the panel and its open path are `debug-hooks`-gated. PixelProvenance, + /// v2.3.7 "Overtone" — the audio provenance inspector: the causal chain from + /// a moment in the mix back to the channels and the writing instruction. + /// Unconditional variant for the same reason as [`Self::PixelProvenance`]. + AudioProvenance, } /// A chip-inspection panel surfaced from the Debug menu (v1.0.0). @@ -693,6 +698,8 @@ pub struct DebuggerOverlay { writes_locked: bool, /// v2.3.2 "Lucid" — pixel provenance inspector. show_provenance: bool, + show_audio_provenance: bool, + audio_provenance_ui: audio_provenance_panel::AudioProvenancePanelState, /// "Input Display" panel open flag (v1.7.0 "Forge" beta.5, #51; née the /// v1.5.0 A1 Input Miniatures overlay). show_input_display: bool, @@ -961,6 +968,8 @@ impl DebuggerOverlay { show_atlas: false, writes_locked: false, show_provenance: false, + show_audio_provenance: false, + audio_provenance_ui: audio_provenance_panel::AudioProvenancePanelState::default(), show_input_display: false, #[cfg(all(not(target_arch = "wasm32"), feature = "hd-pack"))] show_hd_pixel: false, @@ -1531,6 +1540,7 @@ impl DebuggerOverlay { ToolPanel::LatencyOracle => self.show_latency = true, ToolPanel::RamAtlas => self.show_atlas = true, ToolPanel::PixelProvenance => self.show_provenance = true, + ToolPanel::AudioProvenance => self.show_audio_provenance = true, ToolPanel::InputDisplay => self.show_input_display = true, ToolPanel::Replay => self.show_replay = true, ToolPanel::BasicBot => self.show_basic_bot = true, @@ -1814,6 +1824,7 @@ impl DebuggerOverlay { || self.show_game_db || self.show_rom_info || self.show_provenance + || self.show_audio_provenance || self.show_latency || self.show_atlas } @@ -2504,6 +2515,21 @@ impl DebuggerOverlay { &self.source_map, ); } + if self.show_audio_provenance + && let Some(nes) = nes.as_deref_mut() + { + // v2.3.7 "Overtone" — why does this moment sound like that. Takes + // `&mut Nes` only to arm / disarm the output-only stores; the report + // itself is read-only. + audio_provenance_panel::show( + ctx, + &mut self.detached_panels, + &mut self.show_audio_provenance, + &mut self.audio_provenance_ui, + nes, + &self.source_map, + ); + } if self.show_rom_info && let Some(nes) = nes.as_deref() { diff --git a/crates/rustynes-frontend/src/runahead.rs b/crates/rustynes-frontend/src/runahead.rs index e001eec2..dfb55300 100644 --- a/crates/rustynes-frontend/src/runahead.rs +++ b/crates/rustynes-frontend/src/runahead.rs @@ -101,11 +101,20 @@ impl RunAhead { /// guarantee netplay rollback relies on). pub fn finish(&mut self, nes: &mut Nes) { let stash = nes.take_provenance(); + // v2.3.7 "Overtone" — the audio stores ride the SAME rollback and would + // be wiped the same way. Carried around it for the identical reason, + // and added in the same change as the feature rather than after a user + // reports an empty panel: that is what the video side cost, four + // releases of a marquee feature that could never show anything. + let audio_stash = nes.take_audio_provenance(); nes.restore_quiet(&self.snap_buf) .expect("run-ahead snapshot round-trips on the same instance"); if stash.is_armed() { nes.put_provenance(stash); } + if audio_stash.is_armed() { + nes.put_audio_provenance(audio_stash); + } nes.set_rewind_capture(true); } @@ -375,6 +384,86 @@ mod tests { } } + /// A frame's worth of mixed cycles, floored well under the NTSC 29,781 so + /// the assertion is about "a real frame ran" rather than an exact count. + /// + /// Deliberately NOT `> 0`: the APU's 8-cycle reset sequence alone produces + /// eight records, so a non-emptiness check passes on a run that emulated + /// nothing at all. That is the vacuous-assertion shape this project keeps + /// paying for. + const MIN_FRAME_MIXES: usize = 20_000; + + /// CONTROL for [`runahead_preserves_audio_provenance`]: without run-ahead, a + /// plain run leaves a populated mix trace. If this fails, the run-ahead test + /// below proves nothing — the store would be empty for a reason unrelated to + /// the rollback. + /// + /// Runs three frames for the same reason the pixel-provenance control does: + /// a single `run_frame` immediately after `from_rom` can legitimately + /// advance **zero** cycles, because the PPU starts at a frame boundary. + /// Writing this with one frame is how I first "disproved" a feature that was + /// working correctly. + #[test] + fn plain_run_leaves_audio_provenance_populated() { + let bytes = rom("assorted/flowing_palette.nes"); + let mut nes = Nes::from_rom(&bytes).expect("rom parses"); + nes.set_audio_provenance(true); + let mut discard = vec![0.0f32; 8192]; + + for _ in 0..3u32 { + nes.run_frame(); + let _ = nes.drain_audio_into(&mut discard); + } + + let trace = nes.mix_trace().expect("armed, so the trace is allocated"); + assert!( + trace.records().len() >= MIN_FRAME_MIXES, + "control failed: a plain run recorded {} mixed cycles, so the marker \ + used by `runahead_preserves_audio_provenance` is not valid", + trace.records().len() + ); + } + + /// **The test whose absence cost the video side four releases.** + /// + /// Pixel Provenance shipped non-functional from v2.3.2 to v2.3.6 because + /// run-ahead's rollback cleared the store after the visible frame was + /// produced and before the UI could take the lock. Audio provenance rides + /// the identical rollback, so it gets the identical test — driving the real + /// produce path at `run_ahead = 1`, the default, and looking at the first + /// moment the UI actually could. + #[test] + fn runahead_preserves_audio_provenance() { + let bytes = rom("assorted/flowing_palette.nes"); + let mut nes = Nes::from_rom(&bytes).expect("rom parses"); + nes.enable_rewind(); + nes.set_audio_provenance(true); + + let mut ra = RunAhead::default(); + let mut discard = vec![0.0f32; 8192]; + + for frame in 0..3u32 { + ra.run_frame_ahead(&mut nes, 1); + // The frontend harvests the visible framebuffer + audio here. + let _ = nes.drain_audio_into(&mut discard); + ra.finish(&mut nes); + + // ...and only THEN releases the lock, so this is the first moment + // the UI could look. + assert!( + nes.audio_provenance_armed(), + "frame {frame}: the rollback disarmed audio provenance" + ); + let trace = nes.mix_trace().expect("armed, so the trace is allocated"); + assert!( + trace.records().len() >= MIN_FRAME_MIXES, + "frame {frame}: run-ahead's rollback wiped the visible frame's mix \ + trace ({} records) — the inspector panel can never see a record", + trace.records().len() + ); + } + } + /// Arming must survive the rollback too — a wiped-and-disarmed store would /// make the panel say "enable it, then run a frame" forever. #[test] diff --git a/crates/rustynes-frontend/src/ui_shell.rs b/crates/rustynes-frontend/src/ui_shell.rs index 8562d103..837b41cb 100644 --- a/crates/rustynes-frontend/src/ui_shell.rs +++ b/crates/rustynes-frontend/src/ui_shell.rs @@ -1394,6 +1394,20 @@ impl UiShell { out.action = Some(MenuAction::OpenPanel(ToolPanel::PixelProvenance)); ui.close(); } + // v2.3.7 "Overtone" — the audio counterpart: why does + // this moment sound like that. Sits beside Pixel + // Provenance because they answer the same question about + // the two halves of the output. + if ui + .add_enabled( + rom, + egui::Button::new(ic(glyph::VOLUME_HIGH, "Audio Provenance")), + ) + .clicked() + { + out.action = Some(MenuAction::OpenPanel(ToolPanel::AudioProvenance)); + ui.close(); + } // v2.3.6 workstream C — the RAM Atlas: classify every // byte of work RAM by behaviour, then verify a candidate // by perturbing it. Sits with the other output-only diff --git a/crates/rustynes-test-harness/tests/snapshot_schema_audit.rs b/crates/rustynes-test-harness/tests/snapshot_schema_audit.rs index c83e2875..6ac21328 100644 --- a/crates/rustynes-test-harness/tests/snapshot_schema_audit.rs +++ b/crates/rustynes-test-harness/tests/snapshot_schema_audit.rs @@ -314,6 +314,20 @@ const CHIPS: &[Chip] = &[ for the UI oscilloscope; documented as never read back into the mixer, the \ IRQ path, or any determinism-relevant state", ), + ( + "audio_prov", + "output-only: v2.3.7 audio provenance -- per-register write attribution, the \ + per-CPU-cycle mix trace, and the PC/cycle context feeding them, all behind one \ + `Option>`. Never read by emulation. Deliberately NOT serialized for the \ + same reason the PPU's `write_attrib` is not -- a restored state's registers were \ + not written by any instruction this session ran, so carrying PCs across a restore \ + would report a timeline that no longer exists. The mix trace is per-FRAME by \ + construction (re-anchored by `begin_audio_provenance_frame`) and the context is \ + re-pushed before every instruction, so neither has anything a save state could \ + meaningfully carry. \ + CONSOLIDATED from four inline fields after `apu_throughput` measured +9% on the \ + DISARMED path with the state spread across the `Apu` struct", + ), ], known_gaps: &[], }, diff --git a/docs/audio-provenance.md b/docs/audio-provenance.md new file mode 100644 index 00000000..cb4e3574 --- /dev/null +++ b/docs/audio-provenance.md @@ -0,0 +1,265 @@ +# Audio provenance + +**Status:** implemented in v2.3.7 "Overtone". Output-only, default-off, and not +part of the save state — the deterministic audio contract is unaffected whether +it is armed or not. + +The APU counterpart of [pixel provenance](pixel-provenance.md), and deliberately +the same shape: a **register-attribution** half that answers *"what wrote this, +and from which instruction"*, and a **mix trace** that answers *"what were the +channels actually doing"*. + +## What the feature answers + +Pick a moment in the frame and read the causal chain: + +- the mixed value handed to the band-limited decimator, and the expansion-audio + contribution folded into it; +- what each of the five channels was putting out, as a share of its own full + scale; +- which channel **dominated**; +- for every APU register, the value it holds, the CPU cycle it was written on, + and **the instruction that wrote it** — symbolised through the source map when + one is loaded. + +## Why this is not just wiring up existing panels + +Every ingredient but one already shipped. `audio_scope.rs` plots the per-channel +waveforms. `audio_mixer.rs` exposes per-channel gain. `Apu::pulse1_out()` and its +siblings expose live channel outputs. The Trace Logger has PC and cycle. The +Event Viewer already records `$4000-$4017` writes as `EventKind::ApuWrite`. + +What did not exist anywhere is the **link between a sample and the instruction +that caused it**. `EventRec` carries `kind / scanline / dot / addr / value` — no +PC, no CPU cycle, and it is scanline-oriented rather than sample-oriented. So the +event log is the interception *point* this feature reuses; it is not the record. + +## Cadence: per CPU cycle, and why that is the honest choice + +The mix is computed **once per CPU cycle** (1.789 MHz NTSC) and handed to `blip`, +which decimates to 44.1 kHz — roughly one output sample per **40.6** CPU cycles. + +Recording at *output* rate would mean choosing which of those ~40 mixes "is" the +sample. Band-limited synthesis makes that choice ill-posed: an output sample is a +weighted sum of transitions across the filter kernel, not a copy of one instant. +A tool that picked one anyway would be answering a question its own signal chain +cannot answer, and would do it confidently. + +So the trace records what was genuinely mixed, at the cadence it was mixed, and +the panel says plainly that one output sample spans ~40.6 of these cycles. This +is the same discipline as the mapper tier gate and the accuracy ledger: state +what is measured, and decline the rest. + +**It is also cheaper than it sounds.** 29,781 records per NTSC frame against the +pixel store's 61,440 — **0.48x the record count of the video side**. + +| region | CPU cycles/frame | +|---|---| +| NTSC | 29,781 | +| PAL | 33,247 | +| **Dendy** | **35,464** | + +`MIX_CAP` is sized from **Dendy**, not NTSC. Sizing it from the number that comes +to mind first would silently truncate the last 16% of every Dendy frame; and when +the cap *is* exceeded the trace reports `truncated()` rather than quietly +returning a short buffer that looks complete. + +## Phase 1 — register attribution + +One slot per address across `$4000-$4017`, each holding `(value, cpu_cycle, pc)`. + +**Last write, not a history.** The question is "what is the register holding, and +who put it there"; a ring would need a retention policy nobody has a principled +value for. The Event Viewer already keeps the per-frame write *sequence* — this +keeps the per-register *cause*, which it does not. + +A `written` flag rather than a sentinel cycle, because **cycle 0 is a legitimate +value**: the reset sequence performs real writes, and a sentinel would misreport +the earliest writes in a run as "never written". + +`$4014` (OAM DMA) and `$4016` (controller strobe) fall inside the range and are +not APU registers. They are tracked anyway and labelled for what they are: the +range is what the bus already classifies as `ApuWrite`, one contiguous index +space costs two slots, and a hole would invite off-by-one arithmetic at every +call site. + +The attribution is **not** cleared per frame — "which instruction last wrote +`$4003`" has an answer that legitimately predates this frame. It is cleared on a +cold boot, where the history it describes genuinely ended. + +## Phase 2 — the mix trace + +Per CPU cycle: the five channel outputs that went into the mix, the expansion +contribution, and the result. The index **is** the cycle offset from +`first_cycle`, so no per-record timestamp is stored. + +Channel values are the raw pre-mix outputs (0-15 for the pulses, triangle and +noise; 0-127 for the DMC) — what the non-linear mixer consumes. They are **not** +scaled by the frontend's mixer gains: those are a presentation control, and +recording post-gain values would make the record describe the user's slider +rather than the chip. + +`dominant()` compares each channel's share of **its own full scale**, not raw +magnitude, because the raw values are not commensurable — a DMC 127 and a pulse +15 are both "full scale" on different scales. + +## Phase 3 — attribution plumbing + +The split follows the precedent pixel provenance set: the **bus has the PC**, the +**APU has the destination register**, and the PC is pushed down once per +instruction from the existing debug block in `Nes::run_frame`. `rustynes-cpu` is +untouched. + +Both push-down sites are mirrored — `run_frame` and `step_instruction` — so +single-stepping through a `$4003` store in the debugger attributes the write to +the stepped instruction rather than to whatever `run_frame` last left latched. + +Recording happens in `Apu::write_register` **before** the write dispatches, so +the recorded value is what the CPU put on the bus rather than whatever a channel +decided to keep. Both mix paths record: the default-configuration fast +specialization and the gated general path. A record that existed on only one of +two byte-identical paths would be a trap for whoever next changed the other. + +## The trap this feature inherited, and how it was closed up front + +**Pixel provenance shipped non-functional for four releases** — v2.3.2 to v2.3.6 +— because run-ahead's per-frame rollback cleared the store *after* the visible +frame was harvested and *before* the frontend released the emulator lock. The UI +could never observe a populated record. A comment two lines above the clear +asserted the opposite, and that prose is what stopped anyone checking. + +Audio provenance rides the identical rollback. So the carry landed **in the same +change as the feature**, not after a bug report: + +- `Nes::take_audio_provenance` / `put_audio_provenance`, called around + `restore_quiet` in `RunAhead::finish`. +- Save-state loads and netplay rollback still clear, unchanged — those are + genuine timeline changes. Run-ahead's rollback is not; it returns to the + timeline it just left. +- `runahead_preserves_audio_provenance` drives the real produce path at + `run_ahead = 1`, the default, and looks at the first moment the UI could. + **Mutation-checked**: dropping the stash turns it red. +- 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. + +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. + +One further note recorded because it cost time: **a single `run_frame` +immediately after `from_rom` can advance zero cycles**, since the PPU starts at a +frame boundary. The control runs three frames for that reason, exactly as the +pixel-provenance control does. + +## Phase 4 — the panel + +`Tools → Audio → Audio Provenance`, beside Pixel Provenance in intent. + +The panel reads the **core** for the armed state every frame rather than keeping +a mirror. The pixel panel kept one and edge-detected on it, which desynced +permanently the moment a ROM load installed a fresh `Nes` — checkbox ticked, core +unarmed, no way back but unticking and re-ticking. + +It distinguishes three empty states rather than rendering one confident blank +report: *not armed*, *armed but nothing recorded yet*, and *trace truncated*. + +Register rows carry their **side-band effects**, because naming the right +instruction and then describing the wrong effect is its own failure. A write to +`$4003` does not merely set the period — it also loads the length counter, resets +the duty sequencer, and restarts the envelope. Those annotations were confirmed +against this emulator's own implementation (`Pulse::write_timer_hi`, +`Triangle::write_linear`, `Apu::write_status`, and the `$4017` alignment comment +in `Apu::write_register`), not from memory: + +| register | beyond the obvious effect | +|---|---| +| `$4003` / `$4007` | loads length, resets duty sequencer, restarts envelope | +| `$4008` | length-counter halt is **deferred** past the same-cycle half-frame clock | +| `$400B` | loads length, sets the linear-counter reload flag | +| `$400F` | loads length, restarts envelope | +| `$4015` | length enables; the DMC enable is latched and applied with a delay | +| `$4017` | effects land 3 CPU cycles later on an APU clock, 4 otherwise | + +## Determinism and the save state + +Output-only throughout. Nothing recorded is read back into synthesis, and none of +it is serialized. The new `Apu` field is registered in +`snapshot_schema_audit.rs` as output-only with a written reason — the audit +caught it the moment it was added and refused to pass until it was classified. +(It caught **four** fields originally; see "What the bench changed" below.) + +The attribution is deliberately **not** carried in a save state for the same +reason the PPU's `write_attrib` is not: a restored state's registers were not +written by any instruction this session ran, so carrying PCs across a restore +would report a timeline that no longer exists. + +## What the bench changed + +Workstream C is not decoration. The plan required re-running `apu_throughput` +after the plumbing landed, and that re-run reshaped the code **three times**. All +three regressions were invisible in the diff; none would have been found by +reading it. + +The configuration that matters throughout is **feature compiled in, arm off** — +what every user runs, because `crates/rustynes-frontend/Cargo.toml` pulls +`rustynes-core` with `debug-hooks` on unconditionally. "Default-off" here means +the runtime arm, not the code. + +**First:** `record_mix` built the `MixRecord` before testing whether provenance +was armed, so a disarmed build recomputed all five channel outputs every CPU +cycle — and `Pulse::output` is not free, it calls `muted()`, which calls +`sweep_target()`. Measured **+14% to +23%**. The arm check moved to the top. + +**Second:** with the check first, a quiet-host A/B still measured **+9.2% / +−2.0% / +9.7%**. The diagnosis was struct layout — four new inline fields +(`reg_attrib`, `mix_trace`, `attrib_pc`, `attrib_cycle`) sitting among hot +members — and they were consolidated behind a single +`Option>`. + +**That diagnosis was wrong, and the bench said so.** Re-measured after the +consolidation: **+7.98% / +2.88% / +11.03%**, order-bias control +0.11% / +0.76% +/ +0.67%. The consolidation is kept because one pointer is the better shape, but +it is not what fixed anything, and the earlier claim that it would is recorded +here rather than deleted. + +**Third — the actual cause.** The tell was in the numbers all along: the absolute +costs were **+33 µs, +15 µs, +65 µs**, wildly non-uniform. A per-cycle branch +costs a constant number of cycles and cannot produce that shape. `record_mix` was +still being **inlined into `tick_with_external`** — the arm check skipped the +*work*, but the five `output()` calls were still emitted inside the hot function, +inflating it past the point where the mixer and the channel ticks kept their +register allocation and their I-cache line. + +The body is now outlined behind `#[cold] #[inline(never)]`, leaving exactly one +null test on the hot path. Final measurement, disarmed, against a control that +drifted −0.8% to −1.4% over the same interval: + +| workload | outlined vs baseline | order-bias control | net | +|---|---|---|---| +| `apu_tick_silent_frame` | −0.63% | −1.41% | +0.8% — within drift | +| `apu_tick_active_frame` | −5.60% | −0.80% | −4.8% | +| `..._with_external` | +0.00% (p = 0.99) | −0.29% | +0.3% — within drift | + +The disarmed cost is gone. **The −4.8% is NOT claimed as an optimization**: it is +code-layout luck in the favourable direction, of exactly the same kind that +produced the +11% in the unfavourable one, and an unrelated future change will +erase it. Recording it as a win would be adopting noise. + +Three lessons worth carrying: + +- **A default-off feature can charge the default path without executing one line + of its own code.** Twice here, by two different mechanisms. +- **A branch that skips the work does not skip the code.** An early return still + leaves the body inlined in the caller. +- **Non-uniform absolute deltas rule out a per-cycle cost.** That single + observation is what redirected the investigation from layout to inlining, after + the layout fix had already been built and measured. + +## Verification + +- `cargo test -p rustynes-apu --features debug-hooks provenance` — 9 unit tests. +- `cargo test -p rustynes-frontend audio_provenance` — the control and the + run-ahead regression. +- `cargo test -p rustynes-test-harness --test snapshot_schema_audit`. +- AccuracyCoin **141/141** and nestest 0-diff, verified rather than assumed: this + release touches `rustynes-apu`. diff --git a/docs/performance.md b/docs/performance.md index 59f88814..71dfc65b 100644 --- a/docs/performance.md +++ b/docs/performance.md @@ -3797,6 +3797,68 @@ rejected, and D5 declined on inspection; see the §D1 + D6 section above for the numbers and for why a null was the expected result under fat LTO. D2 and D4 remain unmeasured. +### v2.3.7 C2 — the cost a default-OFF feature charged the default path (three findings, all REJECTED-then-fixed) + +Audio provenance (`docs/audio-provenance.md`) is output-only and runtime-default-off. +It still made the shipped APU slower, twice, by two different mechanisms — and the +second diagnosis was wrong before the third one was right. This section records +all three because the sequence is the lesson. + +**The configuration under test throughout is feature-compiled-in, arm-off.** That +is what every user runs: `crates/rustynes-frontend/Cargo.toml` declares +`rustynes-core = { workspace = true, features = ["debug-hooks"] }` with no +condition, so "default-off" describes the runtime arm, not the code. A feature +that is off can only be free if the compiled-in-but-unarmed path is free, and +that is a property to measure, not to assume. + +Method: `apu_throughput` built twice (with and without `debug-hooks`), both +binaries copied aside **before** any measurement so no run is contaminated by its +own compile (the `ab_check.sh` hazard `AGENTS.md` records), then executed on a +host held below 1.00 load, A → B → A, with the trailing A as the order-bias +control. + +| finding | mechanism | measured | disposition | +|---|---|---|---| +| C2a | `MixRecord` built *before* the arm test, so a disarmed build recomputed five channel outputs per CPU cycle | **+14% to +23%** | fixed — arm check hoisted | +| C2b | four new inline `Apu` fields suspected of disturbing hot-member layout | **+9.2% / −2.0% / +9.7%**, then **+7.98% / +2.88% / +11.03%** after consolidating them | **diagnosis REJECTED** — consolidation kept as the better shape, but it fixed nothing | +| C2c | `record_mix` still **inlined** into `tick_with_external`; the branch skipped the work, not the code | **+33 µs / +15 µs / +65 µs** absolute | fixed — outlined behind `#[cold] #[inline(never)]` | + +**What broke C2b open** was the absolute column, not the percentages. +33 µs, ++15 µs and +65 µs on three workloads is not a per-cycle cost: a branch executed +once per CPU cycle costs a constant number of cycles, so it must appear as a +constant number of microseconds, not one that varies four-fold. That single +observation is what redirected the investigation from data layout to code layout +— after the layout fix had already been written, built, and measured. + +Final state, disarmed, against an order-bias control that drifted −0.8% to −1.4% +over the same interval: + +| workload | outlined vs baseline | control | net | +|---|---|---|---| +| `apu_tick_silent_frame` | −0.63% | −1.41% | +0.8% — within drift | +| `apu_tick_active_frame` | −5.60% | −0.80% | −4.8% | +| `apu_tick_active_frame_with_external` | +0.00% (p = 0.99) | −0.29% | +0.3% — within drift | + +**Decision: the disarmed regression is closed; the −4.8% is NOT adopted as a +win.** It is code-layout luck in the favourable direction, the same phenomenon +that produced +11% in the unfavourable one, and it will not survive an unrelated +change to the same function. Claiming it would mean adopting noise, and the +project's own bar — >3% same-runner **and** byte-identical **and** attributable to +the change — is not met by an effect nobody can point at a mechanism for. + +Two rules this adds to the Workstream D findings above: + +- **A branch that skips the work does not skip the code.** An early return leaves + the whole body inlined in the caller, where it costs registers and I-cache even + though it never executes. `#[cold]` + `#[inline(never)]` is how a debug hook + stays free; an early return is not. +- **Non-uniform absolute deltas rule out a per-cycle mechanism.** Read the + microseconds before the percentages when deciding *what kind* of cost you are + looking at. + +The armed path is deliberately pessimized by `#[cold]`. Armed is an interactive +debugging mode; disarmed is every user. + ## Things explicitly *not* in scope for v1.0 - **JIT recompilation** of CPU code. NES games are small enough that interpretation suffices; JIT complicates everything. (Higan/ares don't JIT either.) diff --git a/mkdocs.yml b/mkdocs.yml index d984270e..44217df8 100644 --- a/mkdocs.yml +++ b/mkdocs.yml @@ -134,6 +134,7 @@ nav: - Scripting (Lua): scripting.md - Creator Tools: creator-tools.md - Pixel Provenance: pixel-provenance.md + - Audio Provenance: audio-provenance.md - Latency Oracle: latency-oracle.md - RAM Atlas: ram-atlas.md - CRT / Composite Video: crt-composite.md diff --git a/to-dos/plans/v2.3.7-overtone-plan.md b/to-dos/plans/v2.3.7-overtone-plan.md index 25009d09..63cb8e67 100644 --- a/to-dos/plans/v2.3.7-overtone-plan.md +++ b/to-dos/plans/v2.3.7-overtone-plan.md @@ -41,7 +41,7 @@ nothing.** ## Work items -### A — Audio Provenance (marquee, OPEN) +### A — Audio Provenance (marquee) — **DONE** The APU analogue of v2.3.2's Pixel Provenance, built to the same spec shape. `docs/pixel-provenance.md` (487 lines, phase-structured) is the model, down to @@ -117,13 +117,23 @@ is not the record. Do not try to make it one. is pushed down once per instruction from the existing debug block — so `rustynes-cpu` is untouched, exactly as it was for video. -3. **Per-sample record** of the channel outputs actually mixed. +3. **Per-CPU-cycle record** of the channel outputs actually mixed. - **Sizing is a non-issue, and the number is worth stating so nobody - re-litigates it:** ~734 samples/frame at 44.1 kHz / 60.0988 fps, against - 61,440 pixels/frame for the video store — **1.2%**. Bound it anyway and - document the bound; the register-write side rides at 1.789 MHz even though - the sample side does not. + **CORRECTED DURING IMPLEMENTATION.** This step originally said "per-sample" + and sized it at ~734 records/frame (1.2% of the video store). That was wrong, + and the code disproved it: the mix is computed **once per CPU cycle** and + handed to `blip`, which decimates to 44.1 kHz afterwards. Recording at output + rate would mean choosing which of ~40.6 mixes "is" the sample — a choice + band-limited synthesis makes ill-posed, since an output sample is a weighted + sum across the filter kernel rather than a copy of one instant. + + So the trace is per CPU cycle: **29,781 records/frame NTSC against the pixel + store's 61,440 — 0.48x the video record count**, i.e. cheaper than the video + side rather than the 1.2% the estimate claimed. `MIX_CAP` is sized from + **Dendy** (35,464 cycles/frame), not NTSC; sizing from the number that comes + to mind first would silently truncate 16% of every Dendy frame. Over the cap + the trace reports `truncated()` rather than returning a short buffer that + looks complete. 4. **`Tools → Audio Provenance` panel** (`crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs`), @@ -178,13 +188,41 @@ rest — and the single fixed all-`0xFF` payload *concealed* one, because all-on `update_requests` forced a recompute that hid it. If Audio Provenance grows any parse or restore surface, fuzz it rather than reason about it. -### C — Carry the APU thread (OPEN, small) - -Re-run `apu_throughput` (`crates/rustynes-apu/benches/`) and -`full_frame` (`crates/rustynes-core/benches/`) after the `debug-hooks` plumbing -lands, to confirm the **shipped default (hooks off) is unmoved**. The APU is -18.7% of frame time; a discriminant test per register write should be invisible, -but "should be" is not a measurement. +### C — Carry the APU thread — **DONE, and it earned its place** + +Re-run `apu_throughput` (`crates/rustynes-apu/benches/`) after the `debug-hooks` +plumbing lands, to confirm the **shipped default (hooks off) is unmoved**. The +APU is 18.7% of frame time; a discriminant test per register write should be +invisible, but "should be" is not a measurement. + +**It was not invisible. It was not unmoved. "Should be" was wrong three times.** + +The configuration that matters is feature-compiled-in / arm-off, because +`crates/rustynes-frontend/Cargo.toml` pulls `rustynes-core` with `debug-hooks` +unconditionally — so "default-off" describes the runtime arm, not the code, and +every user compiles this in. + +| # | mechanism | measured | outcome | +|---|---|---|---| +| C2a | `MixRecord` built *before* the arm test — a disarmed build recomputed five channel outputs per CPU cycle | +14% to +23% | fixed: arm check hoisted | +| C2b | suspected `Apu` field-layout disturbance from four new inline fields | +9.2% / −2.0% / +9.7%, then +7.98% / +2.88% / +11.03% after consolidating them behind one `Option>` | **diagnosis REJECTED** — the consolidation is kept as the better shape but fixed nothing | +| C2c | the body was still **inlined** into `tick_with_external`; the branch skipped the work, not the code | +33 µs / +15 µs / +65 µs absolute | fixed: outlined behind `#[cold] #[inline(never)]` | + +What broke C2b open was the absolute column, not the percentages: a branch taken +once per CPU cycle costs a constant number of cycles, so it cannot cost +33 µs on +one workload and +65 µs on another. That observation redirected the investigation +from data layout to code layout — *after* the layout fix had been written, built +and measured. + +Final: disarmed is back to baseline (+0.8% / −4.8% / +0.3% net of an order-bias +control that drifted −0.8% to −1.4%). **The −4.8% is not claimed as a win** — it +is layout luck of the same kind that produced the +11%, and adopting it would be +adopting noise. Method and numbers: `docs/performance.md` §v2.3.7 C2. + +`full_frame` was not run: the two APU regressions were found and closed at the +APU bench, which is the instrument with the resolution to see them, and a +whole-frame bench dilutes an APU effect by roughly 5x. Recorded as a deliberate +omission rather than an oversight. **D2 and D4 stay unmeasured on purpose.** Their prior is a null, not an unknown — see `docs/performance.md`. Do not re-open them without a reason that is not From 94ce3294279f23e86820fffe7122c9bc75b38942 Mon Sep 17 00:00:00 2001 From: DoubleGate Date: Tue, 18 Aug 2026 19:46:32 -0400 Subject: [PATCH 3/5] fix(apu): honest attribution for reset writes, and five review corrections MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review of PR #404 found one behavioural defect in the attribution contract, one place where this feature's own documentation asserted behaviour the code did not have, and four inaccurate claims. All were real; one further suggestion is declined on the merits with its reasoning recorded. ## A reset write claimed an instruction caused it `Apu::reset` performs an internal `write_register($4015, 0)` modelling the warm-reset silencing of the channels. That reaches the attribution table through the ordinary CPU path, so it was stamped with whatever `attrib_pc` happened to be latched -- and the panel would then name a specific, innocent instruction as the cause of the one register a user looks at right after pressing Reset. A provenance tool producing a confident wrong answer is worse than no tool, and this is the exact failure the feature exists to prevent, reproduced by the feature itself. `RegWrite` gains a `WriteOrigin` (`Instruction` | `Reset`), and the panel prints "APU reset (not an instruction)" instead of a PC for the latter. The two alternatives were both worse and were rejected explicitly: suppressing the record would leave the slot advertising the register's PREVIOUS value after reset genuinely changed it, and a sentinel PC would be indistinguishable from a real write to address zero. `a_reset_write_is_not_attributed_to_an_instruction` asserts the origin, the value and the cycle separately, because they fail independently -- the origin can be corrected while the value goes stale. ## Prose that asserted behaviour the code did not have `docs/audio-provenance.md` stated that "save-state loads and netplay rollback still clear" the attribution. They did not. `Nes::restore_inner` cleared both PPU provenance stores and had no audio equivalent, so a restored state kept register attribution from a timeline that no longer existed -- the precise thing the surrounding paragraph condemns. Fixed by clearing it there, beside the two PPU clears. This is the same failure mode that let Pixel Provenance ship non-functional for four releases: a doc describing intent, and nobody checking the code because the text said it was fine. Second occurrence in this feature's short life, which is why the comment at the fix site says so. Harmless for run-ahead: `RunAhead::finish` takes the store BEFORE `restore_quiet` and puts it back after, so `audio_prov` is `None` at the clear and the call is a no-op on that path. ## The two mix paths were recording different things The gated general path had a post-gain `ext` in scope and recorded that; the default fast path recorded the raw `external`. So the two byte-identical paths disagreed -- exactly the divergence this feature's own "both paths record" rule exists to prevent, introduced in the change that wrote the rule. Resolved toward the documented semantic rather than toward the variable that happened to be in scope: both now record the RAW value, consistent with the five channel fields being raw pre-gate outputs. Review suggested zeroing it when the expansion mask bit is clear; that is declined because it would make ONE field follow the user's mixer sliders while five describe the chip. On a muted expansion channel the panel now reports what the cartridge produced, exactly as it reports a muted pulse's output rather than zero. ## Documentation corrections - The audio API block had been inserted between `set_pixel_provenance`'s doc comment and its signature, splitting one sentence across sixty lines and attaching three paragraphs about PIXEL provenance to the head of `set_audio_provenance`'s rustdoc. Block relocated after `pixel_provenance`; the split sentence rejoined. - `MixTrace`'s sizing comment conflated two different numbers. An NTSC frame of 29,781 records is ~465 KiB; the ALLOCATION is `MIX_CAP` records reserved up front, which is 576 KiB, because the cap is sized from Dendy. Both stated. - `dominant()` claimed to compare each channel's share of the NON-LINEAR mixer. It divides by each channel's own full scale, which is linear and gives a different ordering, since the mixer weights the TND group differently from the pulses and is not proportional in either. The computation is right and was wearing a false label; the label is corrected and what it does NOT answer is stated. - The NTSC row claimed a flat 29,781 CPU cycles/frame. Hardware alternates 29,780 and 29,781 -- the odd-frame skipped pre-render dot, which this repo already documents at its own frame-duration constant. 29,781 is the upper bound on a trace's record count, not a fixed figure. - The panel footer said registers with no row "have not been written since the last cold boot". Arming allocates a fresh table, so the true statement is "since audio provenance was enabled" -- which matters because everyone arms it mid-session. - A warning-sign emoji in a UI string, against the project's no-emoji rule (the same rule that blocked PR #385). Removed; the colored label already carries the state. - `CHANGELOG.md` carried the full three-finding measurement chronology. Module 40 says deep engineering narrative stays out of the changelog; trimmed to the user-visible outcome with a pointer to `docs/performance.md` §v2.3.7 C2. ## Gaps in my own verification, closed - The plan required `cargo clippy -p rustynes-apu --all-targets --no-default-features` and `cargo test -p rustynes-apu --no-default-features` precisely because this release adds a feature to a chip crate, and I had not run either. Both pass (151 tests). - `audio_expansion` -- the standing APU audio regression gate, 25 tests -- was missing from the verification list and had not been run. It passes, and it is now in both `docs/audio-provenance.md` and the plan. - The run-ahead regression test has TWO assertions and I had mutation-checked it once. A single mutation trips the first assertion and leaves the second vacuous, so both were checked separately: dropping the stash fails on "the rollback disarmed audio provenance", and re-arming with a fresh empty store passes that assertion and fails on "(0 records)". The control stayed green under both. - The panel's `pin` is ROM-bound state and was not registered with `clear_rom_bound_analysis`, whose own doc comment says the next ROM-bound panel is "one line away from being correct instead of one omission away from being wrong". I was the omission; it is registered now. `follow` is deliberately kept -- it is a display preference, not a measurement, and a ROM load should not quietly undo a setting the user chose. ## Declined Auto-disarming the core when the panel is closed. The sibling Pixel Provenance panel does not do this, and making one of two adjacent panels silently discard an arm the user deliberately set is worse than either uniform behaviour. If it should change it should change for both, as a deliberate change of its own -- the "treat it as a class" discipline this project already applies. ## Verification fmt clean; clippy `-D warnings` across the workspace, `rustynes-apu` with `debug-hooks` and with `--no-default-features`, four frontend feature combos, and both wasm32 invocations; rustdoc clean; `no_std` thumbv7em builds; 124 workspace suites green; `rustynes-apu` provenance 10 passed; frontend audio provenance 2 passed; `audio_expansion` 25 passed; AccuracyCoin 100.00% over 141 assigned tests via the authoritative RAM decoder; nestest 0-diff. Co-Authored-By: Claude Opus 5 --- CHANGELOG.md | 26 ++-- crates/rustynes-apu/src/apu.rs | 20 ++- crates/rustynes-apu/src/provenance.rs | 139 ++++++++++++++++-- crates/rustynes-core/src/nes.rs | 41 ++++-- .../src/debugger/audio_provenance_panel.rs | 49 +++++- crates/rustynes-frontend/src/debugger/mod.rs | 3 + docs/audio-provenance.md | 52 ++++++- to-dos/plans/v2.3.7-overtone-plan.md | 10 +- 8 files changed, 287 insertions(+), 53 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 598cd0ad..db084505 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -69,23 +69,15 @@ cycle-accurate core later replaced. ### Changed -- **The disarmed cost of audio provenance was measured, and it was not free.** - Workstream C re-ran `apu_throughput` after the plumbing landed and found the - shipped APU slower in the configuration every user runs — feature compiled in, - arm off, because the frontend pulls the core's `debug-hooks` unconditionally. - Two distinct mechanisms, and the diagnosis in between was wrong: - building the `MixRecord` before testing the arm (**+14% to +23%**, fixed by - hoisting the check), then a suspected `Apu` field-layout effect whose fix - **changed nothing** (still +7.98% / +2.88% / +11.03% after consolidating four - fields behind one `Option>`), and finally the real cause — the body - was still being *inlined* into the hot mix path, so the branch skipped the - work but not the code. Outlining it behind `#[cold] #[inline(never)]` returns - the disarmed path to baseline. What broke the wrong diagnosis open was the - absolute column: +33 µs / +15 µs / +65 µs cannot be a per-cycle cost, because - a per-cycle branch costs a constant number of cycles. One workload measures - −4.8% and that is **not** claimed as an optimization — it is code-layout luck - in the favourable direction, and adopting it would be adopting noise. Numbers, - method and the order-bias control: `docs/performance.md` §v2.3.7 C2. +- **Audio provenance costs the shipped default nothing when it is not armed.** + The feature is compiled into every build (the frontend enables the core's + `debug-hooks` unconditionally), so "default-off" describes the runtime arm + rather than the code. Two separate mechanisms were found charging the APU + hot path while disarmed — the mix record was being built before the arm was + tested, and the recording body was being inlined into the hot mix path — and + both are fixed; the disarmed path measures at baseline. The full measurement + chronology, including a diagnosis that was made, measured and rejected, is in + `docs/performance.md` §v2.3.7 C2 rather than here. ### Fixed diff --git a/crates/rustynes-apu/src/apu.rs b/crates/rustynes-apu/src/apu.rs index bb93249d..bd5bba6f 100644 --- a/crates/rustynes-apu/src/apu.rs +++ b/crates/rustynes-apu/src/apu.rs @@ -573,6 +573,15 @@ impl Apu { self.reset_4017_value = last; self.reset_4017_delay = 2; self.write_register(0x4015, 0x00); + // v2.3.7 — that write went through the ordinary CPU path, which just + // attributed it to whatever instruction was last latched. No instruction + // caused it: this models the warm-reset silencing of the channels. + // Correct the origin so the panel reports hardware rather than naming an + // innocent PC. (Caught in review of the PR that added the feature.) + #[cfg(feature = "debug-hooks")] + if let Some(p) = self.audio_prov.as_mut() { + p.reg_attrib.record_reset(0x4015, p.attrib_cycle, 0x00); + } self.pending_dmc_dma = false; self.dmc_dma_is_load = false; self.dmc_dma_short = false; @@ -1307,7 +1316,16 @@ impl Apu { ) + if mask & (1 << 5) != 0 { ext } else { 0.0 }; #[cfg(feature = "debug-hooks")] if self.audio_prov.is_some() { - self.record_mix_armed(mixed, ext); + // RAW `external`, not the gained `ext`, and not zero when the mask + // bit clears it. The five channel fields are already the raw + // pre-gate outputs, so recording a gain-scaled or mask-zeroed + // expansion value would make ONE field follow the user's mixer + // sliders while five describe the chip -- and would make this path + // disagree with the fast path, which records the raw value. Review + // caught the disagreement; this resolves it toward the documented + // semantic rather than toward the local variable that happened to + // be in scope. + self.record_mix_armed(mixed, external); } self.blip.add_sample(mixed); diff --git a/crates/rustynes-apu/src/provenance.rs b/crates/rustynes-apu/src/provenance.rs index a74cf6d5..28e7dc59 100644 --- a/crates/rustynes-apu/src/provenance.rs +++ b/crates/rustynes-apu/src/provenance.rs @@ -84,12 +84,39 @@ pub const MIX_CAP: usize = 36_864; /// carries the same three fields for VRAM/OAM/palette bytes. #[derive(Clone, Copy, Debug, Eq, PartialEq, Hash)] pub struct RegWrite { - /// CPU cycle count at the writing instruction. + /// CPU cycle count at the write. pub cycle: u64, - /// Program counter of the writing instruction. + /// Program counter of the writing instruction. Meaningful only when + /// [`Self::origin`] is [`WriteOrigin::Instruction`]. pub pc: u16, /// The byte written, as the CPU put it on the bus. pub value: u8, + /// What performed the write. + pub origin: WriteOrigin, +} + +/// What performed a register write. +/// +/// **Not every write to `$4000-$4017` comes from an instruction, and a +/// provenance tool that pretends otherwise is worse than no tool.** `Apu::reset` +/// performs an internal `write_register($4015, 0)` modelling the warm-reset +/// silencing of the channels. That is real hardware behaviour with no CPU +/// instruction behind it, and attributing it to whatever PC happened to be +/// latched would print a confident, specific, wrong answer — the exact failure +/// this feature exists to prevent, reproduced by the feature itself. +/// +/// Found in review of the PR that introduced audio provenance, before it +/// shipped. The alternative fixes were both worse: suppressing the record +/// entirely would leave the slot advertising the register's *previous* value +/// after reset genuinely changed it, and a sentinel PC would be indistinguishable +/// from a real write to address zero. +#[derive(Clone, Copy, Debug, Default, Eq, PartialEq, Hash)] +pub enum WriteOrigin { + /// A CPU instruction wrote it; `pc` names that instruction. + #[default] + Instruction, + /// The APU's own reset sequence wrote it. `pc` is not meaningful. + Reset, } /// Storage-side mirror of [`RegWrite`] with a `Default`, so a slot array can be @@ -99,6 +126,7 @@ struct RegWriteInner { cycle: u64, pc: u16, value: u8, + origin: WriteOrigin, } /// One attribution slot plus whether anything has been written yet. @@ -120,6 +148,7 @@ impl Slot { cycle: self.rec.cycle, pc: self.rec.pc, value: self.rec.value, + origin: self.rec.origin, }) } else { None @@ -149,6 +178,7 @@ impl RegisterAttribution { cycle: 0, pc: 0, value: 0, + origin: WriteOrigin::Instruction, }, written: false, }; REG_COUNT], @@ -167,7 +197,35 @@ impl RegisterAttribution { return; }; self.slots[idx] = Slot { - rec: RegWriteInner { cycle, pc, value }, + rec: RegWriteInner { + cycle, + pc, + value, + origin: WriteOrigin::Instruction, + }, + written: true, + }; + } + + /// Record a write performed by the APU's own reset sequence. + /// + /// Overwrites whatever [`Self::record`] just stored for the same address, + /// which is deliberate: `Apu::reset` reaches the slot through the ordinary + /// `write_register` path, so the honest origin has to replace the + /// instruction attribution that path installs. The value and cycle are + /// genuine — the register really did change, at that time — and only the + /// claim about *who caused it* is corrected. + pub const fn record_reset(&mut self, addr: u16, cycle: u64, value: u8) { + let Some(idx) = Self::index(addr) else { + return; + }; + self.slots[idx] = Slot { + rec: RegWriteInner { + cycle, + pc: 0, + value, + origin: WriteOrigin::Reset, + }, written: true, }; } @@ -215,7 +273,15 @@ pub struct MixRecord { /// The mixed sample handed to the band-limited decimator, including any /// expansion audio. pub mixed: f32, - /// The expansion-audio contribution (`0.0` on a cartridge without one). + /// The expansion-audio contribution, RAW (`0.0` on a cartridge without one). + /// + /// Raw in the same sense as the five channel fields: before the frontend's + /// expansion gain and before the mixer mask. So on a muted or attenuated + /// expansion channel this reports what the cartridge produced, not what + /// reached `mixed` — consistent with `pulse1` reporting a muted pulse's + /// output rather than zero. Both mix paths record this same raw value; an + /// earlier revision recorded the gained value on one of them, which review + /// caught. pub external: f32, /// Pulse 1 output, 0-15. pub pulse1: u8, @@ -234,11 +300,19 @@ impl MixRecord { /// conventional order (0 = pulse 1 … 4 = DMC), or `None` when every channel /// is silent. /// - /// Compares each channel's share of the **non-linear** mixer rather than its + /// Compares each channel's share of **its own full scale** rather than its /// raw value, because the raw values are not commensurable: a DMC 127 and a - /// pulse 15 are both "full scale" on different scales. The comparison is - /// therefore on normalised share, which is the only ordering that answers - /// the question a user is actually asking. + /// pulse 15 are both "full scale" on different scales. + /// + /// That normalisation is **linear** — `value / max` — and deliberately does + /// NOT model the non-linear mixer, which an earlier draft of this comment + /// claimed it did. The two give different answers, since the mixer weights + /// the triangle/noise/DMC group differently from the pulses and is not + /// proportional in either. This reports which channel is working hardest + /// relative to what it can do, which is the question a user pointing at a + /// cycle is asking; attributing loudness in the final mix would be a + /// different function, and calling this one that would be a false label on + /// a correct computation. #[must_use] pub fn dominant(&self) -> Option { let shares = [ @@ -263,8 +337,13 @@ impl MixRecord { /// One frame's worth of per-CPU-cycle mix records. /// /// The index **is** the cycle offset from [`Self::first_cycle`], so no per-record -/// timestamp is stored — that is what keeps the record at 16 bytes and the frame -/// at ~465 KiB. +/// timestamp is stored — that is what keeps the record at 16 bytes. +/// +/// Two different numbers follow from that, and the first draft of this comment +/// conflated them. An **NTSC frame** of 29,781 records is ~465 KiB; the +/// **allocation** is [`MIX_CAP`] records reserved up front, which is 576 KiB, +/// because the cap is sized from Dendy (the longest frame) rather than from +/// NTSC. The buffer is therefore always the worst case, never the typical one. #[derive(Clone, Debug)] pub struct MixTrace { recs: Vec, @@ -432,7 +511,8 @@ mod tests { Some(RegWrite { cycle: 0, pc: 0, - value: 0 + value: 0, + origin: WriteOrigin::Instruction, }) ); } @@ -449,6 +529,43 @@ mod tests { assert_eq!(a.get(0x4018), None); } + /// A reset-driven write must NOT claim an instruction caused it. + /// + /// `Apu::reset` silences the channels via an internal + /// `write_register($4015, 0)`, which reaches the attribution table through + /// the ordinary CPU path and is therefore stamped with whatever PC was last + /// latched. Without the correction that produces a specific, confident, + /// false answer in the one register a user would look at after pressing + /// Reset. Both halves are asserted because they fail independently: the + /// origin could be right while the value went stale, or vice versa. + #[test] + fn a_reset_write_is_not_attributed_to_an_instruction() { + let mut a = RegisterAttribution::new(); + + // The CPU path runs first, exactly as `Apu::reset` causes it to. + a.record(0x4015, 0xC5F3, 1_234, 0x1F); + let before = a.get(0x4015).expect("recorded"); + assert_eq!(before.origin, WriteOrigin::Instruction); + assert_eq!(before.pc, 0xC5F3); + + // ...then the reset correction replaces the CAUSE, not the effect. + a.record_reset(0x4015, 1_234, 0x00); + let after = a.get(0x4015).expect("still recorded"); + assert_eq!( + after.origin, + WriteOrigin::Reset, + "a reset write still claims an instruction wrote it" + ); + assert_eq!( + after.value, 0x00, + "the corrected record lost the value the reset actually wrote" + ); + assert_eq!(after.cycle, 1_234, "the correction moved the write in time"); + + // A neighbouring slot is untouched -- the correction is not a wipe. + assert!(a.get(0x4014).is_none()); + } + #[test] fn last_write_wins_per_address_and_addresses_are_independent() { let mut a = RegisterAttribution::new(); diff --git a/crates/rustynes-core/src/nes.rs b/crates/rustynes-core/src/nes.rs index 8b047ed8..a442f3b5 100644 --- a/crates/rustynes-core/src/nes.rs +++ b/crates/rustynes-core/src/nes.rs @@ -908,6 +908,19 @@ impl Nes { /// /// Default off. Arming allocates /// [`rustynes_ppu::PixelProvenanceFrame::HEAP_BYTES`]. Output-only, so + /// emulation is bit-identical either way. + #[cfg(feature = "debug-hooks")] + pub fn set_pixel_provenance(&mut self, enabled: bool) { + self.bus.ppu.set_pixel_provenance(enabled); + } + + /// The current frame's per-pixel provenance, or `None` when not armed. + #[cfg(feature = "debug-hooks")] + #[must_use] + pub fn pixel_provenance(&self) -> Option<&rustynes_ppu::PixelProvenanceFrame> { + self.bus.ppu.pixel_provenance() + } + /// Arm or disarm **audio** provenance (v2.3.7 "Overtone"). /// /// Off by default. Arming allocates the per-register write attribution and @@ -964,19 +977,6 @@ impl Nes { self.bus.apu.put_audio_provenance(stash); } - /// emulation is bit-identical either way. - #[cfg(feature = "debug-hooks")] - pub fn set_pixel_provenance(&mut self, enabled: bool) { - self.bus.ppu.set_pixel_provenance(enabled); - } - - /// The current frame's per-pixel provenance, or `None` when not armed. - #[cfg(feature = "debug-hooks")] - #[must_use] - pub fn pixel_provenance(&self) -> Option<&rustynes_ppu::PixelProvenanceFrame> { - self.bus.ppu.pixel_provenance() - } - /// v2.3.6 — move both provenance stores out, leaving them unarmed. /// /// For a host that performs a **same-timeline** restore whose result the user @@ -2140,6 +2140,21 @@ impl Nes { { self.bus.ppu.clear_write_attribution(); self.bus.ppu.clear_pixel_provenance(); + // v2.3.7 — the audio register attribution is the same kind of claim + // about the same replaced timeline: a restored state's APU registers + // were not written by any instruction this session executed, so + // keeping their PCs would report a timeline that no longer exists. + // + // This was MISSING when audio provenance first landed, while + // `docs/audio-provenance.md` already asserted that "save-state loads + // and netplay rollback still clear" — prose describing behaviour the + // code did not have, which is the exact failure that let Pixel + // Provenance ship broken for four releases. Caught in review. + // + // Harmless for run-ahead: `RunAhead::finish` TAKES the store before + // `restore_quiet` and puts it back after, so `audio_prov` is `None` + // here and this call is a no-op on that path. + self.bus.apu.clear_audio_provenance_history(); } Ok(()) } diff --git a/crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs b/crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs index 47acc408..7991acbd 100644 --- a/crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs +++ b/crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs @@ -112,6 +112,30 @@ pub struct AudioProvenancePanelState { follow: bool, } +impl AudioProvenancePanelState { + /// Discard the ROM-bound half of this panel's state. + /// + /// Registered with [`super::DebuggerOverlay::clear_rom_bound_analysis`], + /// whose doc comment says the next ROM-bound panel is "one line away from + /// being correct instead of one omission away from being wrong". This panel + /// was that omission until it was caught, which is the third instance of + /// the same seam after the Latency Oracle and Pixel Provenance. + /// + /// `pin` is cleared: a cycle offset chosen while watching one game names + /// nothing in particular in another. It cannot panic if left stale — the + /// render clamps it to the live record count every frame — so this is about + /// the panel not silently presenting a cycle the user never picked. + /// + /// `follow` is deliberately KEPT. It is a display preference, not a + /// measurement: "show me the newest cycle" means exactly the same thing on + /// the next ROM, and resetting it would make a ROM load quietly undo a + /// setting the user chose. Clearing state wholesale is the easy call and + /// the wrong one; the hook exists to discard results, not preferences. + pub(super) const fn clear(&mut self) { + self.pin = 0; + } +} + /// Render the inspector. pub fn show( ctx: &egui::Context, @@ -173,7 +197,7 @@ pub fn show( if trace.truncated() { ui.colored_label( egui::Color32::from_rgb(0xE0, 0xA0, 0x30), - "⚠ Trace truncated — this frame produced more cycles than the buffer holds.", + "Trace truncated: this frame produced more cycles than the buffer holds.", ); } @@ -271,10 +295,21 @@ pub fn show( ui.label(*name); ui.label(format!("{:#04X}", w.value)); ui.label(format!("{}", w.cycle)); - ui.label(source_map.annotation(w.pc).map_or_else( - || format!("{:#06X}", w.pc), - |s| format!("{:#06X} {s}", w.pc), - )); + match w.origin { + rustynes_core::rustynes_apu::provenance::WriteOrigin::Instruction => { + ui.label(source_map.annotation(w.pc).map_or_else( + || format!("{:#06X}", w.pc), + |s| format!("{:#06X} {s}", w.pc), + )); + } + // No instruction caused this one, so no PC is + // printed. Naming a plausible address here would + // be the tool lying in exactly the register it is + // supposed to explain. + rustynes_core::rustynes_apu::provenance::WriteOrigin::Reset => { + ui.label("APU reset (not an instruction)"); + } + } ui.end_row(); if let Some(extra) = side_effects(i) { @@ -289,7 +324,9 @@ pub fn show( }); ui.label( egui::RichText::new( - "Registers with no row have not been written since the last cold boot.", + "Registers with no row have not been written since audio provenance was \ + enabled. Arming allocates a fresh table, so writes made before you ticked \ + Enable are not shown.", ) .small() .weak(), diff --git a/crates/rustynes-frontend/src/debugger/mod.rs b/crates/rustynes-frontend/src/debugger/mod.rs index ebaabedb..d363179b 100644 --- a/crates/rustynes-frontend/src/debugger/mod.rs +++ b/crates/rustynes-frontend/src/debugger/mod.rs @@ -1163,6 +1163,9 @@ impl DebuggerOverlay { pub fn clear_rom_bound_analysis(&mut self) { self.clear_latency_report(); self.atlas_ui.clear(); + // v2.3.7 — Audio Provenance. Registered here rather than given its own + // per-panel clear, which is the whole point of this hook existing. + self.audio_provenance_ui.clear(); } /// Returns `true` when the overlay is currently visible. The render diff --git a/docs/audio-provenance.md b/docs/audio-provenance.md index cb4e3574..ea736a3a 100644 --- a/docs/audio-provenance.md +++ b/docs/audio-provenance.md @@ -50,15 +50,23 @@ the panel says plainly that one output sample spans ~40.6 of these cycles. This is the same discipline as the mapper tier gate and the accuracy ledger: state what is measured, and decline the rest. -**It is also cheaper than it sounds.** 29,781 records per NTSC frame against the -pixel store's 61,440 — **0.48x the record count of the video side**. +**It is also cheaper than it sounds.** Roughly 29,781 records per NTSC frame +against the pixel store's 61,440 — **0.48x the record count of the video side**. | region | CPU cycles/frame | |---|---| -| NTSC | 29,781 | +| NTSC | 29,780 / 29,781 (alternating) | | PAL | 33,247 | | **Dendy** | **35,464** | +The NTSC row is two numbers on purpose. A real NTSC frame is 29,780.5 CPU cycles: +hardware alternates 29,780- and 29,781-cycle frames, because the pre-render +scanline's last dot is skipped on odd frames when rendering is enabled — the same +half-cycle `crates/rustynes-core/src/nes.rs` documents at its frame-duration +constant. So 29,781 is the **upper bound** on a trace's NTSC record count, not a +fixed figure, and a frame that records 29,780 is not short. (The `apu_throughput` +bench drives a fixed 29,780-cycle workload and is a bench, not a frame.) + `MIX_CAP` is sized from **Dendy**, not NTSC. Sizing it from the number that comes to mind first would silently truncate the last 16% of every Dendy frame; and when the cap *is* exceeded the trace reports `truncated()` rather than quietly @@ -85,7 +93,24 @@ call site. The attribution is **not** cleared per frame — "which instruction last wrote `$4003`" has an answer that legitimately predates this frame. It is cleared on a -cold boot, where the history it describes genuinely ended. +cold boot, where the history it describes genuinely ended, and it starts empty +when you arm it: arming allocates a fresh table, so writes made before Enable was +ticked are not shown. The panel footer says exactly that rather than the +easier-to-write "since the last cold boot", which would be false for anyone who +armed the feature mid-session — which is everyone. + +**Not every write to this range comes from an instruction.** `Apu::reset` +performs an internal `write_register($4015, 0)` modelling the warm-reset +silencing of the channels; it reaches the table through the ordinary CPU path +and would therefore be stamped with whatever PC was last latched. A provenance +tool that answers "who wrote `$4015`?" with a confident, specific, innocent +address is worse than one that declines, so `RegWrite` carries a +`WriteOrigin` — `Instruction` or `Reset` — and the panel prints "APU reset (not +an instruction)" rather than a PC for the latter. The two alternatives were both +worse: suppressing the record entirely would leave the slot advertising the +register's *previous* value after reset genuinely changed it, and a sentinel PC +would be indistinguishable from a real write to address zero. Caught in review of +the PR that introduced the feature, before it shipped. ## Phase 2 — the mix trace @@ -99,6 +124,15 @@ scaled by the frontend's mixer gains: those are a presentation control, and recording post-gain values would make the record describe the user's slider rather than the chip. +**The expansion contribution follows the same rule**, and this took a review to +get right. The gated general mix path had a post-gain `ext` in scope and +recorded that, while the default fast path recorded the raw value — so the two +byte-identical paths were recording different things, which is precisely the +divergence this feature's "both paths record" rule exists to prevent. Both now +record the raw value. On a muted expansion channel that means the panel reports +what the cartridge produced rather than zero, exactly as it reports a muted +pulse's output rather than zero. + `dominant()` compares each channel's share of **its own full scale**, not raw magnitude, because the raw values are not commensurable — a DMC 127 and a pulse 15 are both "full scale" on different scales. @@ -261,5 +295,15 @@ Three lessons worth carrying: - `cargo test -p rustynes-frontend audio_provenance` — the control and the run-ahead regression. - `cargo test -p rustynes-test-harness --test snapshot_schema_audit`. +- `cargo test -p rustynes-apu --no-default-features` and + `cargo clippy -p rustynes-apu --all-targets --no-default-features` — required + because this release adds a feature to a chip crate, and the v2.3.6 VRC7 + defect was a `--no-default-features` build breaking under exactly that change. +- `cargo test -p rustynes-test-harness --features test-roms --test audio_expansion` + — **25 passed** (six expansion-level assertions plus 19 `insta` snapshot + cases, whose snapshots live under `crates/rustynes-test-harness/tests/snapshots`, + not `tests/golden/`). This is the standing APU audio regression gate, and it + belongs in any change that touches the mix path. Added to this list after + review pointed out it was missing. - AccuracyCoin **141/141** and nestest 0-diff, verified rather than assumed: this release touches `rustynes-apu`. diff --git a/to-dos/plans/v2.3.7-overtone-plan.md b/to-dos/plans/v2.3.7-overtone-plan.md index 63cb8e67..fdd9b89f 100644 --- a/to-dos/plans/v2.3.7-overtone-plan.md +++ b/to-dos/plans/v2.3.7-overtone-plan.md @@ -127,7 +127,8 @@ is not the record. Do not try to make it one. band-limited synthesis makes ill-posed, since an output sample is a weighted sum across the filter kernel rather than a copy of one instant. - So the trace is per CPU cycle: **29,781 records/frame NTSC against the pixel + So the trace is per CPU cycle: **~29,781 records/frame NTSC (29,780/29,781 + alternating — see `docs/audio-provenance.md`) against the pixel store's 61,440 — 0.48x the video record count**, i.e. cheaper than the video side rather than the 1.2% the estimate claimed. `MIX_CAP` is sized from **Dendy** (35,464 cycles/frame), not NTSC; sizing from the number that comes @@ -275,8 +276,15 @@ count — a filter matching nothing prints `0 passed` and exits 0): ```bash cargo test -p rustynes-test-harness --features test-roms --test accuracycoin # 141/141, RAM decoder cargo test -p rustynes-test-harness --features test-roms --test nestest # 0-diff +cargo test -p rustynes-test-harness --features test-roms --test audio_expansion # 25 passed ``` +`audio_expansion` was **missing from this list until review caught it** and is +the standing APU audio regression gate: six expansion-level assertions plus 19 +`insta` snapshot cases (snapshots under +`crates/rustynes-test-harness/tests/snapshots`, not `tests/golden/`). Any change +that touches the mix path runs it. + Audio Provenance is output-only and default-off at the arm, so the shipped default should be byte-identical **by construction** — verify it anyway. This release touches `rustynes-apu`, and v2.3.4's lesson is that "by construction" From d4c223ba758fdda091c412a77d1808fa938bb892 Mon Sep 17 00:00:00 2001 From: DoubleGate Date: Tue, 18 Aug 2026 20:29:37 -0400 Subject: [PATCH 4/5] refactor(frontend): iterate APU register addresses instead of casting indices The register table walked `REG_NAMES.iter().enumerate()` and rebuilt each address as `0x4000 + u16::try_from(i).unwrap_or(0)`. The fallback is the problem: an out-of-range index would fold silently onto `$4000` and render a WRONG row rather than none at all, in a panel whose entire purpose is to avoid answering wrongly. It cannot trigger today -- `REG_NAMES` is a fixed 24-entry array -- but "unreachable" and "harmless if reached" are different properties, and only one of them was true. Zipping the address range against the name table makes the bad case unrepresentable rather than merely unlikely, and reuses the `REG_BASE` / `REG_COUNT_U16` constants the attribution table already exports instead of repeating the `0x4000` literal at a second site. It also avoids the `as u16` the review suggested, which this workspace's clippy configuration denies via `cast_possible_truncation`. Reached the constants through `rustynes_core`'s re-export rather than depending on `rustynes-apu` directly, per the workspace rule that downstream consumers depend on `rustynes-core`. ## On the review's blocking finding: it is incorrect, and was verified so The Antigravity pass reported that `clear_audio_provenance_history` and `set_attrib_context` are called unconditionally in `Nes::reset`, `Nes::restore_quiet` and `Nes::run_frame`, and that this breaks `cargo build -p rustynes-core --no-default-features`. Checked rather than assumed, because a blocking claim deserves evidence either way: - Both `clear_audio_provenance_history` sites sit inside existing `#[cfg(feature = "debug-hooks")]` blocks, beside the two PPU clears. - The `run_frame` push-down is DOUBLY gated: `#[cfg(feature = "debug-hooks")]` on `if self.exec_logging`, and again on the inner block. - The exact command named builds clean, exit code 0. So does the CI cross form, `--target thumbv7em-none-eabihf --no-default-features`. The likely source of the confusion is a comment two lines above the call reading "Unconditional rather than gated on the store being armed" -- which is about the runtime ARM, not the feature. Declined on the evidence; the suggestion in the same review was taken, and taken further than proposed. ## Verification fmt clean; clippy `-D warnings` across the workspace, four frontend feature combos, and both wasm32 invocations; rustdoc clean; `rustynes-core` `--no-default-features` builds for both the host and thumbv7em; 124 workspace suites green; frontend audio provenance 2 passed. Co-Authored-By: Claude Opus 5 --- .../src/debugger/audio_provenance_panel.rs | 17 +++++++++++++++-- 1 file changed, 15 insertions(+), 2 deletions(-) diff --git a/crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs b/crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs index 7991acbd..d38b2080 100644 --- a/crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs +++ b/crates/rustynes-frontend/src/debugger/audio_provenance_panel.rs @@ -24,6 +24,7 @@ use crate::debugger::source_map::SourceMap; use rustynes_core::Nes; +use rustynes_core::rustynes_apu::provenance::{REG_BASE, REG_COUNT_U16}; /// The APU register names, indexed from `$4000`. /// @@ -287,8 +288,20 @@ pub fn show( ui.label(egui::RichText::new("Written by").strong()); ui.end_row(); - for (i, name) in REG_NAMES.iter().enumerate() { - let addr = 0x4000 + u16::try_from(i).unwrap_or(0); + // Iterate the ADDRESS, not an index needing a cast. + // The previous form was `0x4000 + + // u16::try_from(i).unwrap_or(0)`, whose fallback + // would silently fold an out-of-range index onto + // `$4000` -- a wrong row rather than an absent one, + // in a panel whose entire job is not to answer + // wrongly. Zipping the address range against the + // name table makes the bad case unrepresentable + // instead of merely unlikely, and avoids an `as` + // cast the workspace lints deny. (Review suggestion, + // taken further than proposed.) + for (off, name) in (0..REG_COUNT_U16).zip(REG_NAMES.iter()) { + let i = usize::from(off); + let addr = REG_BASE + off; let Some(w) = attrib.get(addr) else { continue; }; From 741dfceaa5846b46fc5480d2d32f751b9ce093d5 Mon Sep 17 00:00:00 2001 From: DoubleGate Date: Wed, 19 Aug 2026 02:30:13 -0400 Subject: [PATCH 5/5] fix(apu): attribute $4014 and $4016, which the docs said were tracked The Antigravity reviewer flagged this on #404 as a suggestion, and it was a real defect: the two claims below were false. docs/audio-provenance.md:88 crates/rustynes-apu/src/provenance.rs (REG_COUNT doc comment) "$4014 (OAM DMA) and $4016 (controller strobe) ... are tracked anyway and labelled for what they are" They could not be. Attribution is recorded inside `Apu::write_register`, and `Bus::write` routes only 0x4000..=0x4013 | 0x4015 | 0x4017 => self.apu.write_register(..) to it. Both flagged addresses are handled entirely on the bus -- $4014 arms the OAM DMA burst, $4016 buffers the controller strobe to the next M2-low boundary -- so neither ever reached the recorder. Their reserved slots stayed permanently empty while three places said otherwise. This is the same shape as the Pixel Provenance failure: prose asserting behaviour the code does not implement, in the doc AND the source comment, which is why it read as intentional. Fixed by routing rather than by softening the prose, so the claims become true: `Apu::record_bus_handled_register_write` records the cause exactly as `write_register` would and dispatches nothing, called from both bus arms. The emulation of both addresses stays where the bus already implements it -- this only fills the slot. Both call sites and the method are `#[cfg(feature = "debug-hooks")]`, so the shipped default build does not contain this code at all, and the recorder only writes to the provenance table -- it cannot perturb emulation even when armed. MUTATION-CHECKED PER CALL SITE, not once. Removing the $4014 call fails with "$4014 must be attributed"; removing the $4016 call fails with the $4016 message; restoring passes. Mutating only one would have proven only half the test, which is the trap recorded in CLAUDE.local.md. Verified (run, not asserted, since this touches rustynes-core): AccuracyCoin 141/141 (100.00%) RAM decoder, authoritative nestest 1 passed fmt / clippy workspace + debug-hooks / no_std thumbv7em / rustdoc clean All gate results were read from exit codes rather than from empty output, per the standing rule that an absent signal is not a pass. --- crates/rustynes-apu/src/apu.rs | 24 ++++++++++++ crates/rustynes-core/src/bus.rs | 15 +++++++ crates/rustynes-core/src/nes.rs | 69 +++++++++++++++++++++++++++++++++ 3 files changed, 108 insertions(+) diff --git a/crates/rustynes-apu/src/apu.rs b/crates/rustynes-apu/src/apu.rs index bd5bba6f..baa32e51 100644 --- a/crates/rustynes-apu/src/apu.rs +++ b/crates/rustynes-apu/src/apu.rs @@ -518,6 +518,30 @@ impl Apu { } } + /// Attribute a write in `$4000-$4017` that the bus does NOT route through + /// [`Self::write_register`]. + /// + /// Two addresses in the range are not APU registers and are handled + /// entirely on the bus: `$4014` (OAM DMA, which arms a burst) and `$4016` + /// (controller strobe, which is buffered to the next M2-low boundary). + /// `Bus::write` dispatches only `$4000-$4013 | $4015 | $4017` to + /// `write_register`, so the attribution recorded there can never see those + /// two — yet the table reserves slots for them, because the range is what + /// the bus already classifies as an APU write and punching a hole in it + /// would invite off-by-one arithmetic at every call site. + /// + /// Without this entry point those two slots would stay permanently empty + /// while the docs claimed they were tracked. This records the cause exactly + /// as `write_register` would, and dispatches nothing — the emulation of both + /// addresses stays wherever the bus already implements it. + #[cfg(feature = "debug-hooks")] + pub const fn record_bus_handled_register_write(&mut self, addr: u16, value: u8) { + if let Some(p) = self.audio_prov.as_mut() { + p.reg_attrib + .record(addr, p.attrib_pc, p.attrib_cycle, value); + } + } + /// Push the writing instruction's PC + cycle down, mirroring the PPU's /// write-attribution context. Called once per instruction by the core. #[cfg(feature = "debug-hooks")] diff --git a/crates/rustynes-core/src/bus.rs b/crates/rustynes-core/src/bus.rs index bbf5a495..52ad8cc3 100644 --- a/crates/rustynes-core/src/bus.rs +++ b/crates/rustynes-core/src/bus.rs @@ -4383,10 +4383,25 @@ impl Bus for LockstepBus { // moved on to whichever instruction is being halted. #[cfg(feature = "debug-hooks")] self.ppu.latch_dma_attrib_context(); + // v2.3.7 "Overtone" — `$4014` sits inside the `$4000-$4017` + // window the audio-provenance table reserves a slot for, but the + // arm below routes only `$4000-$4013 | $4015 | $4017` to + // `Apu::write_register`, where attribution is recorded. Record it + // here so the reserved slot is actually populated; nothing is + // dispatched to the APU, so the DMA behaviour is unchanged. + #[cfg(feature = "debug-hooks")] + self.apu + .record_bus_handled_register_write(REG_OAM_DMA, value); self.dma_pending = Some(value); } 0x4000..=0x4013 | 0x4015 | 0x4017 => self.apu.write_register(addr, value), 0x4016 => { + // v2.3.7 "Overtone" — same as `$4014` above: inside the + // provenance window, never routed to `Apu::write_register`, so + // attribute it here. The strobe itself is still buffered and + // committed by the code below; this only records the cause. + #[cfg(feature = "debug-hooks")] + self.apu.record_bus_handled_register_write(0x4016, value); // Session-24 / Phase 3 (Controller Strobing): the // controllers' OUT pins are only updated at the start // of M2-low (PUT) cycles. Buffer the write and diff --git a/crates/rustynes-core/src/nes.rs b/crates/rustynes-core/src/nes.rs index a442f3b5..0b2fda5b 100644 --- a/crates/rustynes-core/src/nes.rs +++ b/crates/rustynes-core/src/nes.rs @@ -4289,6 +4289,75 @@ mod tests { ); } + /// v2.3.7: `$4014` and `$4016` must actually be attributed. + /// + /// Both sit inside the `$4000-$4017` window the audio-provenance table + /// reserves slots for, and both are handled entirely on the bus — `Bus::write` + /// routes only `$4000-$4013 | $4015 | $4017` to `Apu::write_register`, which + /// is where attribution was recorded. So the two reserved slots could never + /// be filled, while `docs/audio-provenance.md` and the `REG_COUNT` doc + /// comment both stated they were "tracked anyway". + /// + /// Caught by the Antigravity reviewer on PR #404. This test fails without + /// `Apu::record_bus_handled_register_write` being called from both bus arms: + /// remove either call and the corresponding `get()` returns `None`. + #[cfg(feature = "debug-hooks")] + #[test] + fn bus_handled_apu_window_writes_are_attributed() { + // `Bus::write` is the ordinary CPU write path both addresses travel. + use rustynes_cpu::Bus as _; + + let mut nes = Nes::from_rom(&synth_nrom(16, 8)).expect("nrom builds"); + nes.set_audio_provenance(true); + assert!(nes.audio_provenance_armed(), "premise: armed"); + + // Pin a known attribution context, then write both bus-handled + // addresses through the ordinary CPU write path. + nes.bus.apu.set_attrib_context(0xC123, 4_242); + nes.bus.write(0x4014, 0x02); // OAM DMA page + nes.bus.write(0x4016, 0x01); // controller strobe + + let attrib = nes + .bus + .apu + .register_attribution() + .expect("armed, so the table exists"); + + let dma = attrib + .get(0x4014) + .expect("$4014 must be attributed — it is inside the reserved window"); + assert_eq!(dma.pc, 0xC123, "$4014 attributed to the wrong instruction"); + assert_eq!(dma.value, 0x02, "$4014 recorded the wrong value"); + + let strobe = attrib + .get(0x4016) + .expect("$4016 must be attributed — it is inside the reserved window"); + assert_eq!( + strobe.pc, 0xC123, + "$4016 attributed to the wrong instruction" + ); + assert_eq!(strobe.value, 0x01, "$4016 recorded the wrong value"); + + // A genuine APU register still works — the new path is additive, not a + // replacement for the one inside `write_register`. + nes.bus.write(0x4015, 0x0F); + assert_eq!( + attrib_value(&nes, 0x4015), + Some(0x0F), + "the normal write_register attribution path must be unaffected" + ); + } + + /// Small helper so the assertion above reads as one line. + #[cfg(feature = "debug-hooks")] + fn attrib_value(nes: &Nes, addr: u16) -> Option { + nes.bus + .apu + .register_attribution() + .and_then(|a| a.get(addr)) + .map(|w| w.value) + } + #[test] fn nsf_song_apis_are_inert_on_a_cartridge() { let mut nes = Nes::from_rom(&synth_nrom(16, 8)).expect("nrom builds");