fix(audio): stretch each frame's audio over the time the frame took - #257
fix(audio): stretch each frame's audio over the time the frame took#257doublegate wants to merge 3 commits into
Conversation
…ting it audio.rs already named the cause -- supply is fps/60 -- and had never measured it. It also repeated the user's "~1 s on / ~1 s off" as fact and guessed that the period was the ring's 0.25 s capacity. Two probes now settle all three claims, and only the first survives. examples/audio_probe.rs (core side, before the ring): the emulated AI stream is CONTINUOUS -- 108/120 frames audible, the 12 silent ones contiguous at the start, 3 underruns -- staging exactly rate/60 samples per frame, supply 26.1% against fps/60 = 26.1%. This refutes the competing hypothesis that the game's audio DMA starves inside the machine, which would have been an emulation defect rather than a speed consequence. measure_audio_gaps_at_the_device_boundary (device side, after the ring): 0/469 callbacks fully fed, 14.2% of samples delivered, silent runs mean 95 ms and max 128 ms. So the chop is ~10 Hz, an ORDER OF MAGNITUDE off the reported ~1 s, and its period is one emulated frame plus the pacer's yield -- not the ring capacity. Both halves of the recorded guess were wrong and neither had been checked. Also records a tempting fix that MUST NOT be taken. The pacer sleeps a full frame period after every frame while ~85 ms behind (99.955 ms unpaced via frame_bench, 117.6 ms paced). Shrinking it to 2 ms measures A-B-A at 1.14x with audio 14.2% -> 16.2% -- and takes the UI's median emu-mutex wait from 664 ns to 76.5 ms. The yield is load-bearing, not vestigial: it is the only window in which anything else can take the emu mutex, because the pacer holds it for the whole frame. Reverted. No production code changes. The fix is a policy choice (slow-running audio) plus an architectural one (stop app.rs taking the emu mutex in six places, which emu_thread's own header already claims it does not).
|
Warning Review limit reached
Next review available in: 2 minutes Enable usage-based reviews in Billing to review now. Otherwise, wait until the next included review is available. How can I continue?After more reviews become available, a review can be triggered using the To avoid repeated limits, reduce automatic review volume by pausing incremental auto-reviews earlier, using label-based review opt-in, excluding WIP or generated PR titles, or requesting reviews manually when the PR is ready. If your team needs uninterrupted high-volume reviews, an organization admin can enable usage-based reviews. How do review limits work?CodeRabbit enforces per-developer PR review limits for each organization. Most developers receive the normal plan review availability. For paid Pro and Pro+ PR reviews, CodeRabbit uses adaptive limits for sustained high-volume activity. When a developer's recent PR review activity reaches the 95th percentile or higher among CodeRabbit users, additional reviews become available more gradually as earlier reviews age out of the rolling window. Please refer docs for additional details. Review details⚙️ Run configurationConfiguration used: Path: .coderabbit.yaml Review profile: ASSERTIVE Plan: Pro Plus Run ID: 📒 Files selected for processing (6)
📝 WalkthroughSummary by CodeRabbit
WalkthroughThe PR adds standalone and end-to-end audio probes. It measures emulator production, device delivery, underruns, pacing, mutex waits, and silent gaps. It updates frontend and user documentation with the measured results. ChangesAudio measurement
Estimated code review effort: 3 (Moderate) | ~25 minutes Possibly related PRs
Suggested reviewers: 🚥 Pre-merge checks | ✅ 8 | ❌ 2❌ Failed checks (2 warnings)
✅ Passed checks (8 passed)
Comment |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 5
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@crates/rustyn64-frontend/examples/audio_probe.rs`:
- Around line 79-80: Update main and the audio probe error flow so
load_rom(&raw) propagates a typed error instead of calling panic! on invalid ROM
data. Preserve the existing path context in the returned error, and ensure
main’s return type supports propagation of the load failure.
- Line 122: Update the underrun calculation in the audio probe to capture
audio_underruns() before the timed-frame loop and subtract that baseline from
the final underrun count, rather than subtracting the first frame’s underruns
via log.first(). Preserve the existing log.last() final-count behavior and
include underruns from the first timed frame.
In `@crates/rustyn64-frontend/src/emu_thread.rs`:
- Around line 407-415: Update the documentation around EmuThread and OBSERVE to
report approximately 10 Hz chopping with mean silent runs of 95 ms and a maximum
of 128 ms, while separately describing the measured gap period rather than
claiming a “~1 s on / ~1 s off” cycle. Replace the assertion that audio supply
is exactly fps / 60 with wording that identifies it as a measured ratio and
preserves uncertainty.
- Around line 431-433: Update the documentation above the BUF constant to
describe 1024 frames as a representative callback size and remove the claim that
it is cpal’s usual default, while preserving the existing cadence context.
In `@docs/audio.md`:
- Around line 246-252: Update the measurement documentation around the audio
probes to record each probe’s absolute or differential observation, ROM revision
and hash, host platform, and complete build configuration. Preserve both
existing commands, adding the provenance needed to reproduce their reported
values before presenting the measurements.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Path: .coderabbit.yaml
Review profile: ASSERTIVE
Plan: Pro Plus
Run ID: 574a852e-1e37-450b-abe0-0a1efc3ccc6d
📒 Files selected for processing (4)
crates/rustyn64-frontend/examples/audio_probe.rscrates/rustyn64-frontend/src/audio.rscrates/rustyn64-frontend/src/emu_thread.rsdocs/audio.md
There was a problem hiding this comment.
Pull request overview
This PR documents and codifies a re-runnable investigation of the frontend audio “chopping” symptom by adding two measurement probes (core-side and device-boundary) and updating the audio documentation/comments to reflect measured behavior rather than inferred claims.
Changes:
- Add a committed probe example (
audio_probe.rs) to measure whether gaps originate in the emulated AI stream (pre-ring). - Add an ignored measurement test in
emu_thread.rsto quantify underrun/chopping at the simulated device callback boundary (post-ring), including UI mutex-wait impact context. - Update
docs/audio.mdand theaudio.rsmodule docs to record the measured results and correct the previously repeated (but non-reproducing) ~1s period claim.
Reviewed changes
Copilot reviewed 4 out of 4 changed files in this pull request and generated 1 comment.
| File | Description |
|---|---|
| docs/audio.md | Adds a “measured at both boundaries” section with run instructions and summarized probe results. |
| crates/rustyn64-frontend/src/emu_thread.rs | Introduces an ignored measurement test to observe device-boundary gap period and prints summary stats. |
| crates/rustyn64-frontend/src/audio.rs | Updates module-level documentation to cite the new measurements and correct prior asserted claims. |
| crates/rustyn64-frontend/examples/audio_probe.rs | Adds a runnable probe example that measures emulated-AI continuity and supply ratio pre-ring. |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| // tail on underrun, so trailing silence IS the underrun — but a | ||
| // genuinely quiet passage also reads as zero, which is why the core | ||
| // probe establishes separately that the stream is not silent. | ||
| let real = buf.iter().rposition(|s| *s != 0.0).map_or(0, |i| i + 1); |
The device was offered fps/60 of what it consumes and silence for the rest -- 14.2% measured, with 0 of 469 callbacks fully fed. produce_audio stages exactly one emulated frame of audio per emulated frame, so no buffering strategy can make up the difference. AudioServo stretches that frame's audio across the wall-clock interval the frame actually took: feed-forward from an EMA of the measured interval, trimmed by ring occupancy toward half-full, clamped to [1.0, MAX_AUDIO_STRETCH]. The samples are the same samples, spent over the whole frame rather than a sixtieth of it, so a slow core sounds like a slow tape instead of a stutter. The maintainer chose continuity over pitch when given the three options. 14.2% -> 90.9% delivered, 100.0% in steady state; the shortfall is the startup ramp from an empty ring, which the harness now reports separately because a single figure charges a one-off transient to steady quality. Frames per second (85) and UI emu-lock latency (p50 590 ns) are both unchanged -- this trades no throughput. TRIM_GAIN is measured, not tuned: 0.2/0.4/0.6 all reach 100% steady state and all reach their first fully-fed callback at #15, differing only in the ramp-dominated whole-window figure. The lowest ships, because a larger gain makes the pitch hunt and bought nothing. The wiring test seeds the core's stretch with a value outside the servo's clamp range, because a ROM-less core legitimately asks for 1.0 -- which is also the default, so asserting the value alone cannot tell "applied" from "never written". Both mutations verified red: deleting set_audio_stretch, and never consulting the servo. Determinism untouched: the stretch applies in the frontend resampler, which ADR 0004 already designates as the non-deterministic host-timing stage. The core's emitted stream is unchanged, so audio_play_rom and mixer_microcode are unaffected, and with no ring the servo never runs.
doublegate
changed the title
Four review findings, three of which are real defects in the measurement rather than in the code it measures. `rposition(|s| *s != 0.0)` treated an exact zero at the tail of a callback as the start of underrun silence. Real audio crosses zero, so some fully-fed callbacks were scored as partial. It biases DOWNWARD and applied to both legs equally, so the 14.2% -> 90.9% comparison held, but both absolute figures were pessimistic. Now thresholded at the same 1e-4 floor audio_probe.rs uses, and the numbers move to 14.2% -> 90.1%. The underrun baseline was taken from the FIRST TIMED FRAME rather than from before the loop, so any underrun that frame recorded was silently dropped. Captured before the loop now. The documented value is still 3 for this ROM -- the method was wrong and the number happened not to be, which is worth stating rather than quietly correcting. "1024 frames -- cpal's usual default" is an undocumented claim about cpal 0.18, which defers BufferSize::Default to the host and device. It is a representative callback size and the comment now says so; the delivered percentage is a ratio and does not depend on it. docs/audio.md gains the provenance block its own rules require: ROM SHA-256, host, toolchain, build configuration, tree, and the fact that every figure is differential. It also states outright that the two harnesses run different builds (fast-exec vs default) and must not be cross-read -- the mistake the table exists to prevent. Not adopted: making the env-var and file-read failures typed errors. Those are harness misconfiguration, not untrusted input, and a probe that cannot start must stop loudly. The ROM CONTENTS are parsed data and now do return a typed error, which is where the rule actually bites.
Adjudication — CodeRabbit + CopilotFour adopted, one rejected with reasoning, all in
|
| before | after | |
|---|---|---|
| delivered, servo on | 90.9% | 90.1% |
| callbacks fully fed | 412/469 | 404/469 |
The bias is downward and applied to both legs equally, so the 14.2% → 90% comparison was never in question — but both absolute figures were pessimistic and are now honest.
Underrun baseline off by one frame — adopted (CodeRabbit)
Right: log.first() is the first timed frame's count, taken after that frame ran, so any underrun it recorded was dropped. Captured before the loop now.
The number is unchanged — still 3 for this ROM. Worth saying plainly rather than quietly correcting: the method was wrong and the value happened not to be. Had a ROM underrun during that one frame, the documented figure would have been silently low.
"cpal's usual default" — adopted (CodeRabbit)
Also right, and it is this repo's own recorded failure mode: "undocumented is a claim about a document, and it decays." cpal::BufferSize::Default defers to the host and device in 0.18, so there is no single figure to call the default. The comment now says representative, and notes that the delivered percentage is a ratio and does not depend on the buffer size at all.
Provenance for the measurements — adopted (CodeRabbit)
docs/audio.md gains the block its own rules require: ROM SHA-256 17ce0773…, host (i9-10850K), toolchain (rustc 1.96.0), build configuration, tree, and that every figure is differential over a post-warm-up window.
It also states something the reviewer did not ask for but that the two tables made possible: the two harnesses run different builds — audio_probe under fast-exec,fast-scheduler at ~15.7 FPS, the device test under default features at ~8.5 FPS. Reading a supply ratio from one against a frame rate from the other is a mistake the table now heads off.
Typed error for the ROM load — adopted in part, rejected in part
Adopted where the rule actually bites: load_rom parses ROM contents, and that now returns a typed error through main() -> Result<…>.
Rejected for the env var and the file read. Those are harness misconfiguration — "you did not set RUSTYN64_PROBE_ROM" — not untrusted input, and a probe that cannot start must stop loudly rather than return a value nobody will read. The distinction is now a comment in the file so the next reviewer does not have to re-derive it.
Gates
fmt / clippy -D warnings / cargo test --workspace / rustdoc -D warnings / check_en_us / markdownlint, one conditional: ALL-GATES-OK. Both harnesses re-run after the change; figures above are from that run.
Antigravity review (Gemini via Ultra)This PR introduces a host-side resampler servo ( Blocking issues
Suggestions
Nitpicks
Automated first-pass review by |
Motivation
Task #56: "audio plays ~1s, then ~1s silence, repeating forever."
audio.rsalready named the cause — supply isfps / 60— and had never measured it. It also repeated the ~1 s period as fact and guessed the period was the ring's 0.25 s capacity. This measures all three, fixes the one that is real, and ships the policy the maintainer chose.The fix: stretch, don't chop
emu_thread::AudioServostretches each emulated frame's audio across the wall-clock interval that frame actually took. The samples are the same samples — nothing can manufacture the missing 86% — they are spent over the whole frame instead of a sixtieth of it followed by silence. A slow core now sounds like a slow tape rather than a stutter, which was the explicit choice between the three available failure modes.Clamped
[1.0, 12.0]. Never compresses below real time — a core faster than 60 FPS already oversupplies, and drop-oldest is the right answer there.Measured, same harness as the defect
Steady state is 100%; the whole-window 90.9% is the startup ramp from an empty ring, which the harness now reports separately because one figure charges a transient to continuous quality. Throughput and UI latency are unchanged — this trades nothing.
What the investigation refuted
Two recorded claims did not survive, both of which had been written down as fact:
rate / 60per frame. That mattered — it would have been an emulation defect with a different fix.One tempting fix, built and rejected
The pacer sleeps a full frame period after every frame while ~85 ms behind (
frame_bench99.955 ms unpaced vs 117.6 ms paced). Shrinking it to 2 ms measures 1.14x A-B-A — larger than the entire declined optimization backlog — and takes the UI's median emu-mutex wait from 664 ns to 76.5 ms. The yield is load-bearing, not vestigial. Reverted;docs/audio.mdrecords it so it is not rediscovered.The architectural unlock stays open:
emu_thread's header claims "the winit thread never takes the emu mutex", andapp.rstakes it in six places.Discipline notes
TRIM_GAINis measured, not tuned. 0.2 / 0.4 / 0.6 all reach 100% steady state and all reach their first fully-fed callback at feat(cpu): the COP0 register file (T-12-001) #15; they differ only in the ramp-dominated whole-window figure. The lowest ships — picking 0.6 for a 1.3-point edge on a transient would be tuning.1.0, which is also the default, so asserting the value cannot distinguish "applied" from "never written". It seeds the core with a value outside the clamp range instead. Both mutations verified red: deletingset_audio_stretch, and never consulting the servo.audio_play_romandmixer_microcodeare unaffected; withring: Nonethe servo never runs and behavior is byte-identical.Gates
cargo fmt --check,clippy --workspace --all-targets -D warnings,cargo test --workspace(855 pass),rustdoc -D warnings,check_en_us.sh,markdownlint— one conditional,ALL-GATES-OK.