Skip to content

audio: move callback diagnostics to the watchdog - #731

Closed
thehobbit85 wants to merge 1 commit into
seedds:mainfrom
thehobbit85:codex/fix-audio-callback-logging
Closed

thehobbit85 wants to merge 1 commit into
seedds:mainfrom
thehobbit85:codex/fix-audio-callback-logging

Conversation

@thehobbit85

@thehobbit85 thehobbit85 commented Oct 30, 2026 •

Copy link
Copy Markdown
Contributor

Moves AudioUnit callback diagnostics to the watchdog so stdio locking cannot delay PCM rendering or guest release-event delivery. Related to the callback-logging finding in #313; this addresses that finding, while the broader roadmap remains open.

At each statistics checkpoint, au_render publishes a bounded snapshot. The watchdog copies ready reports under the output-registry lock and logs after releasing it; the release-event notifier remains independent. An unread mailbox is preserved and later windows accumulate under backpressure. Reports retain output ID, call count, frame range, queue depth, underrun/zero-padding counts and actual window length. Close and the watchdog serialize snapshot consumption, and copied reports own all arguments needed after an output is freed.

Maintenance refresh — 2026-10-31 13:20 UTC: rebased d63c850a268e3e6e34d579ad45f44cecce64e665 onto main ec9c3aa6784ee85ca7a166455296d26a37474ef6, producing 90515a68b164e46b77f5465b8ab2779e08243b61. No conflicts; the complete patch is identical by range-diff. Main adds iOS DLC lookup/replacement, the scheduling-independent polling fixture from #779, and Vorbis movie-audio Flush handling (#787). These do not remove logging from au_render, so this callback fix remains relevant. The #779 correction is inherited through main, with no prerequisite cherry-pick. The AudioOut implementation, callback-statistics fixture, fullscreen frontend and graphics sources are unchanged from this PR’s previous head. Existing hle_bigstack.c fixture integration and production HLE_FORCE_BIG / dm_bigstack_caller provenance remain intact. There are no new comments, reviews or inline threads.

Fresh validation on 90515a68: all 11 documentation tests and git diff --check passed. The shared upstream movie fixture passed centrally on final main ec9c3aa6 (Vorbis after Flush, repeated flush, VP8/VP9 NV12/RGBA and signal checks); its production and test sources are byte-identical in this candidate. New-head CI is pending and centrally monitored. No native frontend or callback-statistics test was repeated for unchanged source inputs.

Historical evidence: previous head d63c850a passed a freshly rebuilt callback-statistics fixture (22 checks) and 11 documentation tests. Earlier head 6c719618 passed all seven applicable CI checks. Head 2d8f0187 passed the full host suite and audio/HID TSan; its callback fixture separately passed all 22 checks under ASan/UBSan and TSan, including blocked logging, 8,000 guest release events, merged windows and copied reports after close. Its Mac host built with 52 existing graphics warnings, and Python lint reported 392 baseline findings with zero new or stale findings. These are historical results, not new-head runtime claims.

The preceding impact and five-game harness attempt covered Hades, Breath of the Wild, Pokémon Scarlet and Tears of the Kingdom, plus Pokémon Legends: Z-A for the shared host. The harness exited 2 before execution because no selected game had a local Mac build. No game or extract rebuild was attempted in this refresh; no new gameplay, real-game audio-quality, screenshot, frame-time/memory, shader/interface or iOS-device result is claimed.

The prior all-state au_render search found this PR alone. Open #384 changes PCM dumping and #193 changes run lifecycle; their inspected audio diffs do not replace the callback logging fix. The older exact 635e8008 → bc372f24 Z-A static comparison passed with 28,603/28,603 shaders and no differences or new failures; it remains historical, before compiled shared host shaders were introduced.

@thehobbit85
thehobbit85 force-pushed the codex/fix-audio-callback-logging branch 2 times, most recently from cb1e0df to 99db440 Compare October 31, 2026 01:18
@thehobbit85
thehobbit85 force-pushed the codex/fix-audio-callback-logging branch 4 times, most recently from 6c71961 to d63c850 Compare October 31, 2026 12:43
@thehobbit85
thehobbit85 force-pushed the codex/fix-audio-callback-logging branch from d63c850 to 90515a6 Compare October 31, 2026 13:26
seedds added a commit that referenced this pull request Oct 31, 2026
Publish bounded callback-statistics snapshots for the existing watchdog so
stdio locking cannot block PCM delivery or guest buffer-release events.
Preserve unread reports and merged-window counts, and copy log arguments
before releasing the output-registry lock or freeing an output.

Cover blocked diagnostic output, independent release events, backlog
accounting and reports that outlive their audio output.

Co-authored-by: Eliran Zach <4012041+thehobbit85@users.noreply.github.com>
@seedds seedds closed this Oct 31, 2026
@thehobbit85
thehobbit85 deleted the codex/fix-audio-callback-logging branch November 1, 2026 04:43
@cowwithoutleg

cowwithoutleg commented Nov 5, 2026 •

Copy link
Copy Markdown

A field case for this change, on Super Mario Galaxy 1.3.1 (010099C022B96000) on an M3 iPad Air (iPad15,3), iPadOS 26, sideloaded IPA, thermal state 0:

Before the change (a build from f11018a): twice in a 25-minute session the game froze for a moment while jumping, with the last audio buffer repeating loudly, then caught up. Both freezes are in the log as the watchdog firing, and each sits directly after the 2,000-callback statistics line:

[dm] audio #0 device callbacks 118000: 256–256 frames each, 2.0 blocks queued on average at callback; in these 2000, 0 underruns, 0.0 ms zero-padded
[dm] [RED] audio #0: the device has not called back for 211 ms while playing: the silent sink stands in, retrying the AudioUnit
[dm] audio #0: AudioUnit restarted
...
[dm] audio #0 device callbacks 120000: 256–256 frames each, 2.0 blocks queued on average at callback; in these 2000, 0 underruns, 0.0 ms zero-padded
[dm] [RED] audio #0: the device has not called back for 209 ms while playing: the silent sink stands in, retrying the AudioUnit
[dm] audio #0: AudioUnit restarted

2 of 71 statistics boundaries in that session; no [longframe], 0 underruns otherwise, 4,535 pipelines all built at start. Hagi paces the game on its audio output, so the blocked callback shows as a whole-game stall, not only as a sound glitch.

After cherry-picking 63ef327 onto the same base (nothing else changed): a 30-minute session, 53,700 frames, 168,000 callbacks and 84 statistics boundaries with no watchdog line and no underrun; no freeze felt. The entry's "no particular game's audible failure is attributed to this finding" now has one.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants