[JayBeest]

Goal

Closes #82: crackle/pop and slow music on 1.0.2b, reported on Windows 11 with a
USB DAC, present continuously from the intro onward.

The reporter's "from the intro on" detail is what makes this diagnosable. It
rules out anything event-driven (gunfire cadence, sound pools) and anything in
the mixing path (a wrong ADPCM decode sounds wrong, not choppy). It leaves the
delivery path: the pump that feeds SDL.

While chasing it I found the same root cause behind an older complaint — audio
arriving ~100 ms late, noticed when comparing weapon-reload timing against real
hardware. Both are one design problem, so this PR fixes both.

Description

The problem with 1.0.2b's pump

The pump in 1.0.2b (port/src/audio_pc.c) takes its render count from the
simulation's field counter (src/game/frametiming.c, currentFrameCounter) and
corrects an over-full queue by skipping whole rendered field frames. Two
consequences, both audible:

1. alAudioFrame() is the only thing that advances the game's audio clock. The
   SFX player's event queue and the three music sequencers all move in rendered
   samples (src/libultra/audio/synthesizer.c:143-227). So the render count is
   simultaneously "how much audio" and "how fast audio time runs". Tying it to
   the game loop means every stalled frame — stage load, the intro swirl, a
   window drag, alt-tab — delivers no audio, the device drains, plays silence,
   and resumes with a discontinuity. That is a click. Often enough, it is
   continuous crackle and music running behind real time.

   It also made audio behaviour depend on the maxfps setting: at uncapped
   rates the field delta is usually 0, so only the queue-low branch rendered at
   all — which is Gen 1 behaviour again.

2. Dropping a rendered frame throws away ~16.7 ms of synthesised audio
   mid-stream. That is a step discontinuity by construction, and the N64 never
   did it: src/audi.c:529 sized each frame from the AI's remaining buffer
   ((g_FrameSize - (osAiGetLength() >> 2)) + 16 + EXTRA_SAMPLES) — a
   sample-level servo whose correction was inaudible. The port lost that because
   portAudioPump() calls alAudioFrame() directly and the shim stubs
   osAiGetLength() to 0.

The fix: split one decision into the two it always was

• A live device sets the rate. Refill toward a target depth. The render rate
  then equals the DAC's consumption rate: the queue is stable, device clock
  drift is absorbed, and audio time is the hardware's own time. This is exactly
  what amHandleFrameMessage did. The correction is a few samples of frame
  length, so nothing is ever dropped or duplicated.
• The wall clock sets the rate only when there is no usable device, and
  those samples are discarded. Game audio time still advances, so a missing or
  wedged sink cannot freeze the sequencers or saturate the SFX queue.

Also in this PR

• Target 40 ms, ratcheting up on an underrun and easing back only in a clean
  10 s window (10.2 KB ceiling).
• The target is floored at one pump interval + a device period. A target
  shallower than the interval between pumps starves by construction: between two
  pumps the device drains that interval and refill stops at the target. This is
  what makes 40 ms safe at 60 fps (interval 16.7 ms, floor never binds).
• Single-digit frame rates are supported (classic and demo modes). At N fps
  the pump runs N times a second and must bridge 1000/N ms, so the queue cap now
  scales with the interval — a fixed 16 KB holds 185 ms, which is less than one
  interval at 5 fps, so starvation was guaranteed. The per-pump render budget
  scales too. Down to 1 fps.
• portAudioPumpForce() no longer floods the queue. music.c's track-stop
  spins (portCSPWaitStopped, portMusicKillAll) can force up to 512 frames in
  a few ms; that used to push seconds of audio into a 186 ms buffer, with the
  excess dropped and the trim left to clean up — the intro's crackle. A forced
  frame now advances the sequencer and is queued only when the queue is
  genuinely shallow.
• The queue cap is checked before alAudioFrame, not after. Rendering a
  frame that cannot be queued is not free: it advances the audio clock and burns
  CPU. (A reviewer caught this one after an earlier revision of this branch had
  it backwards.)
• The pacing rules are pure functions with tests:
  port/src/audio_pace.c + port/include/audio_pace.h — no SDL, no engine
  headers, no globals, no clock reads — driven by port/tests/audio_pace.c
  under GE_PORT_TESTS=ON (ctest -R audio_pace).
• GE_AUDIODBG=1 prints a one-second trace (pumps, samples rendered vs
  needed, queue open→close vs target, clock credit, stalled, forced) so the next
  audio report can be read instead of guessed at. The existing 10 s health line
  is unchanged and only prints when a counter is non-zero.

Fixes #82.

Type of Change

• Bug fix (non-breaking change which fixes an issue)

How Has This Been Tested?

Unit / policy tests

cmake -B build -DGE_PORT_TESTS=ON -DGE_NATIVE_64=ON
cmake --build build --target audio_pace_test
ctest --test-dir build -R audio_pace

or standalone, since the unit has no dependencies:

cc -std=c99 -Iport/include port/tests/audio_pace.c port/src/audio_pace.c -o ap && ./ap

16 cases, all pure-function or closed-loop simulation:

• test_refill_is_aligned_and_clamped,
  test_refill_does_not_drain_when_pumping_fast — alignment, one-frame cap,
  and the rounding-down trap below, isolated.
• test_clock_holds_wall_time, test_clock_at_field_rate_is_exact — rate
  tracks wall time with no device (1 ms and 16.67 ms intervals, 60 s).
• test_clock_catchup_is_bounded, test_clock_rests_while_a_device_paces
  — stall not replayed; phantom backlog discarded when a device takes over.
• test_simulation_holds_the_queue,
  test_simulation_refills_a_dry_start — the constant-of-integration bug,
  and recovery from a device that opens empty.
• test_simulation_absorbs_device_drift — ±100 ppm and ±2000 ppm crystal
  error absorbed by the queue, sink never starves.
• test_simulation_at_low_frame_rate,
  test_simulation_at_single_digit_frame_rate,
  test_simulation_at_high_frame_rate — 1, 2, 5, 8, 20, 60 and 300 fps.
• test_interval_floor_and_cap_scale_together — the invariant a fixed cap
  broke at 5 fps, for every rate 1–120 fps; a 60 s hitch is clamped.
• test_target_ratchets_and_eases — ratchet bounded, easing returns to the
  floor and never below.
• test_drain_watchdog, test_simulation_survives_a_stall_between_pumps —
  "consuming" vs "frozen backlog" vs "pinned empty", and bounded recovery.

ctest: 8/8 (the 7 existing native suites plus audio_pace).

Real-binary verification (macOS/CoreAudio, 22050 Hz, 256-sample period)

Ran the built game on the title screen (stage 90, the attract loop) for 24 s
with GE_AUDIODBG=1. This is deliberately where the reporter's crackle starts.

Before (this branch's first revision, and 1.0.2b behaves worse):

ge: audio: last 10 s: queue ran dry 24 times, 0 frames over the cap dropped,
  0 frames skipped as invalid | longest gap between pumps 17 ms | queue target 116 ms

queue cycling 1216→3584 B against a 10240 target it had ratcheted to.

After:

ge: audio dbg: 60 pumps in 1000 ms, rendered 22016 samples (need 22050),
  queue 1508 -> 3556 of 3520, clock 0, stalled 0, forced 0

Queue steady at 3556 B against a 3520 target, render rate tracking what wall
time needs, and no ge: audio: last N s: line at all — zero dry pumps, zero
over-cap drops, zero skipped frames for the whole run.

Two bugs found by running it, not by reasoning

Both now have tests named after them. Recording them because they are the kind
of mistake that passes review:

1. The first revision paced on the wall clock and steered the queue from the
   same budget (credit time, add a bounded bias, charge it back). It compiled and
   passed 15 cases including a closed-loop simulated device, and starved on
   hardware: if total rendered must equal wall time while the device also
   consumes wall time, the queue depth is a constant of integration. A bounded
   bias changes when samples arrive, never the running total.
2. Rounding the refill down to the 16-sample alignment loses a few samples on
   every pump — ~11 % short at 300 fps, draining the queue whatever the target.

Not verified

• Windows, which is the reporter's platform. The most likely environmental
  cause there is unfixed by this PR and is deliberately left to its own change:
  the device is still opened at an exact 22050 Hz with allowed_changes = 0, so
  Windows shared mode (48000) puts an OS resampler and possibly a fallback
  driver between us and the DAC. See below.
• Single-digit fps on a real build: covered by simulation only, not by a live
  classic/demo-mode session at 1–8 fps.

Ways I tried to break it

• Device vanishing mid-run, then failing to open, then recovering.
• Device that opens and never consumes (stall → clock takeover → reopen).
• maxfps uncapped / 120 / 60 (tickhz derived changes the pump rate).
• Music track stop/start storms at the title screen (the force path).
• Window focus loss (mute_unfocused zeroes the frame downstream of pacing).
• Long stalls: the pump-interval floor is clamped at 1 s so a hitch cannot
  demand an absurd backlog.
• Over-cap: nothing is synthesised that cannot be queued.

Known limits, left for their own changes

1. Rate-agnostic device open. want.freq = 22050, allowed_changes = 0. On
   Windows this likely lands on the OS resampler or DirectSound/WinMM with mixer
   quanta near our 11.6 ms device period. The fix is
   SDL_AUDIO_ALLOW_FREQUENCY_CHANGE + an SDL_AudioStream (22050 → device
   rate). Kept separate on purpose: bundled together, a "still crackling" report
   would be ambiguous. Full briefing in docs/port/rate_prompt.md.
   Before spending time there: ask for the log line
   ge: audio: opened the default device on driver 'X': N Hz, .... If N is
   22050 the OS accepted the exact rate and that change is not the fix.
2. Forced frames can push track time slightly ahead during a stop burst,
   because they advance the sequencer without being delivered when the queue is
   not shallow. Bounded by the stop. The real fix is wall-clock pacing
   music.c's spins rather than iteration-counting them.
3. Low frame rates trade latency for continuity. At 2 fps the backlog is
   500 ms, because the pump runs twice a second. Inherent to pumping from the
   render loop; escaping it needs a separate audio thread, which the AL
   library's shared state makes a much larger change. Continuous audio at high
   latency beats crackle at low latency.

Checklist

• My code has been thoroughly tested and is free of bugs
  (policy; real-binary verified on macOS at 60 fps — Windows untested)
• I have performed a self-review of my code
• I have commented my code, particularly in hard-to-understand areas
  (each non-obvious decision says what was tried and why it failed)
• The commits I've made are clean, small and easy to understand
  (single commit; docs/ notes excluded by .gitignore — forced in, sorry)
• My changes generate no compiler warnings
  (clean -Wall -Wextra on the new files; the macOS ld section-alignment
  warning is pre-existing and unrelated)
• My Code is AI-Generated or AI-assisted — AI-assisted: Codewhale v0.10.1 <> DeepSeek V4.1-Flash-1017
• My PR contains no AI-generated images, textures, models, sound or music
• I am an AI — no, a human maintainer is submitting this
• I have reviewed my PR to make sure the above is truthful and accurate

Reviewer's guide — where to look

1. port/include/audio_pace.h — the whole design rationale in one comment
   block, including the constant-of-integration trap.
2. port/src/audio_pace.c — ~220 lines, three functions. portAudioPaceRefill
   (device-paced) and portAudioPaceFrame (both paths) are the core.
3. port/tests/audio_pace.c — the cases named
   test_simulation_holds_the_queue and
   test_simulation_at_single_digit_frame_rate are the two bugs from above.
4. port/src/audio_pc.c — portAudioPump() only. Everything else in the file
   (the aspMain interpreter) is untouched.

[JayBeest]

My latest commit added initial debug/log functionality to the audio-pump. (needs proper review/testing)

PROJECT MIDAS - CONSOLE HELP
============================

The in-game console opens with ` (the key left of 1, also called tilde/~).
Type a command and press Enter. Up/Down recall earlier lines, PgUp/PgDn/Home/
End scroll, and `help` lists every command.

Most settings are also in the menus. The commands here are the ones with no
menu row: diagnostics that answer "why is it doing that?" when something
misbehaves. None of them change how the game plays, and none are saved to
midas.ini - a restart puts them back to off.


==============================================================================
Audio pump diagnostics:  cl_audio_pump  and  cl_audio_log
==============================================================================

WHAT THE AUDIO PUMP IS

  The game's audio is synthesised on the CPU by the N64 sound library and
  handed to your sound card. The code that does this once per frame is
  called "the pump". It decides how much audio to make each time it runs,
  and the queue is the backlog of audio waiting to be played.

  Two things can go wrong, and they sound different:

    crackling, popping   the backlog ran out, so the card played silence in
                         the middle of a sound. The queue was too shallow or
                         the pump delivered too little.

    delayed sound        the backlog grew too large, so what you hear is old.
                         The queue was too deep or the card is not draining.

  These two commands show the numbers behind either symptom.


CL_AUDIO_PUMP - the on-screen block

  cl_audio_pump 0|1     turn it off or on
  cl_audio_pump         report the current state without changing it

  On, a block of six lines appears in the top-left corner, where the FPS
  number normally sits. Player 1's view only, in split-screen.

  THE BLOCK REPLACES THE FPS COUNTER. It shows FPS and TPS itself, so if you
  also have cl_showfps 1 set, the plain FPS digits are hidden while the block
  is on and come back when you turn it off. Showing both would print the same
  two numbers twice.

  It is not saved. It is off after every restart.


CL_AUDIO_LOG - the same numbers, to a file

  cl_audio_log 0|1      start or stop writing the log
  cl_audio_log          report whether it is running

  On, the same figures are written once a second to

      Data/Logs/audio_pump.log

  beside your saves. The file starts fresh each time you turn it on, begins
  with a legend naming every field, and is written out immediately, so if the
  game crashes the last line before the crash is still there.

  Roughly 8 KB a minute. The log and the on-screen block are independent: you
  can run either without the other.

  Use the log for a bug report. One line a second for the length of the
  problem is far more useful than a description, and it can be compared
  against the log line the game already prints every 10 seconds.


WHY THE LOG CARRIES MORE THAN THE SCREEN

  The screen is for glancing, so each value gets exactly one unit - whichever
  one makes the question "is this healthy?" answerable without arithmetic.
  The log is read by someone chasing a specific defect, so it keeps the exact
  figures too. Two fields differ:

    que    the screen prints bytes; the log prints bytes AND the ms of audio
           they represent. 3556B is 40ms, and 40ms is what you actually hear
           as delay. Bytes alone answer "is the pump right?"; ms answers
           "why does the sound lag?".

    snd    the screen prints ms; the log prints the raw sample counts AND the
           ms. One sample at 22050 Hz is 0.045 ms, so millisecond figures
           round away anything smaller than about 22 samples. A slow leak of a
           few samples per pump is invisible on the screen and obvious in the
           counts, which is exactly the kind of fault a log exists to catch.

  Both forms are in the line, so a log line can still be read side by side
  with a screenshot: the ms figures match what the block shows.


TIMESTAMPS

  Each line starts with t=, milliseconds since logging began. That is the
  measure to use for intervals: it is monotonic, so it can never jump
  backwards, and it is unaffected by the system clock being corrected mid-run.

  The header also records the wall-clock instant logging started:

      # started 2026-10-25 00:29:24 (local); t= below is ms since this instant

  Add t= to that instant to date any line. This matters because nothing else
  the game logs carries a wall clock: it is what lets you line a line up with
  a crash.log timestamp, with a ge: stats line in the run log, or with a
  user's "it went wrong around 21:40". Wall clock on every line was avoided on
  purpose - it would only add repetition, and a clock correction mid-run would
  make the file look out of order.


READING THE BLOCK

  Example, on a healthy machine at 60 tps with the frame limiter off:

      FPS 533fps TPS 60tps
      PMP 131k/s RND 130/s
      QUE 3556/3520B CAP 16384B
      SND 499ms/500ms
      DRY 0 OVER 0 SKIP 0 FRC 0
      STALL 0 CLK 0ms DEV 22050Hz

  The log file has the same figures plus a few more units - see WHY THE LOG
  CARRIES MORE THAN THE SCREEN below.

  UNITS. Every value carries its own: fps and tps for rates per second, /s for
  pump counts, B for bytes, ms for milliseconds of audio, Hz for the device
  rate. DRY, OVER, SKIP and FRC are counts of events and have no unit.

  Field by field. Everything except QUE, CAP, STALL, CLK and DEV is measured
  over the last half second, so it settles rather than flickering; those five
  describe the most recent pump only.

  FPS       Frames drawn per second.
  TPS       Simulation steps per second. Normally 60, whatever FPS is: that is
            the tick rate, set by Max FPS in the menus. FPS well above TPS just
            means frames are cheap enough to draw more often than the game
            updates, which is normal and harmless.
  PMP       Pump calls per second. This is large because the pump runs many
            times for each drawn frame. On its own it says nothing about sound.
  RND       Of those calls, how many actually produced audio. This is the
            useful half of PMP: around 60 a second is the mixer keeping up.
  QUE a/b   Bytes of audio waiting to play (a), against the depth the pump is
            aiming for (b). a slightly above b is normal. a far below b means
            the card is outrunning the pump.
  CAP       The ceiling for QUE, in bytes. It grows when the target grows, so a
            low frame rate can still queue enough audio.
  SND a/b   Milliseconds of audio produced in the last half second (a), against
            the half second of real time it was worth (b). THESE SHOULD MATCH.
            This is the single most important line: matching means audio is
            keeping pace with real time. a persistently short means the sound
            is starving, and you will hear it.
  DRY       Pumps that found the queue empty: the card played silence. Every
            one is an audible gap. Should be 0. When it happens, the pump
            automatically keeps more audio queued afterwards, so a few DRY
            during a stage load are expected and self-correcting.
  OVER      Frames refused because they would not fit under CAP: the backlog
            was full. Should be 0. Nonzero means audio is being made faster
            than the card is playing it.
  SKIP      Frames the audio validator rejected, played as silence instead.
            Should be 0. Nonzero is a bug in the sound output, not a pacing
            problem - worth reporting with the log.
  FRC       "Forced" frames, used to keep the music sequencer moving during
            track changes. A few at a track change is normal. A large number
            that keeps climbing is not.
  STALL     1 = the sound device has played nothing for 2 seconds. Should be
            0. At 1 the pump stops trusting the device and runs the game's
            audio clock on wall time, and after 2 more seconds it closes and
            reopens the device to retry.
  CLK       Wall-clock credit in milliseconds of audio. Only nonzero when no
            device is pacing (no card, or a stalled one) and the samples are
            being discarded. 0ms means the device is setting the pace, which
            is what you want.
  DEV       The rate the device was opened at, in Hz, or 0Hz if no device is
            open.


WHAT TO REPORT

  For any sound problem, include:

    - Data/Logs/audio_pump.log, captured with cl_audio_log 1 running while the
      problem happens
    - the rough time you saw the problem, or the t= value from the line where
      it started - the header's started stamp plus t= dates it exactly
    - whether the sound was crackling, lagging, or absent
    - your platform (Windows / Linux / macOS) and your stage or menu

  The useful details are: SND a running below SND b, DRY above zero, OVER above
  zero, STALL at 1, or DEV at 0. If all of those look healthy while the sound
  is still wrong, the fault is below the pump - in the device or the driver -
  and the log says so, which is worth knowing.


A NOTE ON HIGH LATENCY AT LOW FRAME RATES

  The pump runs from the frame loop, so at a low frame rate each pump has to
  queue enough audio to cover the gap until the next one. That backlog is
  latency: continuous sound a fraction of a second behind beats crackling.
  At single-digit frame rates QUE and CAP grow accordingly, and that is by
  design, not a fault.