From b464969cd1f5dd4dceb996ad8410e2695ab477c4 Mon Sep 17 00:00:00 2001 From: skal Date: Sun, 15 Feb 2026 14:45:15 +0100 Subject: docs: document audio WAV drift bug investigation Root cause: audio_render_ahead() over-renders by 366ms per 10s, causing progressive timing drift in WAV files. Events appear early in viewer. Findings: - Renders 11,733 extra frames over 40s (331,533 vs 319,800 expected) - Ring buffer accumulates excess audio (~19 frames/iteration) - WAV dump reads exact 533 frames but renders ~552 frames per call - Results in -180ms drift at 60 beats visible in timeline viewer Debug changes: - Added render tracking to audio.cc to measure actual vs expected - Added drift printf to tracker.cc for kick/snare timing analysis - Added WAV sample rate detection to timeline viewer See doc/AUDIO_WAV_DRIFT_BUG.md for complete analysis and proposed fixes. Co-Authored-By: Claude Sonnet 4.5 --- src/audio/audio.cc | 17 +++++++++++++++++ src/audio/tracker.cc | 8 ++++++++ 2 files changed, 25 insertions(+) (limited to 'src') diff --git a/src/audio/audio.cc b/src/audio/audio.cc index ba76a28..f5bc4ab 100644 --- a/src/audio/audio.cc +++ b/src/audio/audio.cc @@ -108,6 +108,10 @@ void audio_render_ahead(float music_time, float dt, float target_fill) { if (chunk_frames <= 0) return; + static int64_t g_total_render_calls = 0; + static int64_t g_total_frames_rendered = 0; + const int64_t frames_before = g_ring_buffer.get_total_written() / RING_BUFFER_CHANNELS; + // Keep rendering small chunks until buffer is full enough while (true) { // First, try to flush any pending samples from previous partial writes @@ -224,6 +228,19 @@ void audio_render_ahead(float music_time, float dt, float target_fill) { } } } + + // DEBUG: Track actual frames rendered vs expected + const int64_t frames_after = g_ring_buffer.get_total_written() / RING_BUFFER_CHANNELS; + const int64_t actual_rendered = frames_after - frames_before; + g_total_render_calls++; + g_total_frames_rendered += actual_rendered; + + if (g_total_render_calls % 600 == 0) { // Every 10 seconds at 60fps + const float expected_frames = g_total_render_calls * (float)(chunk_frames); + const float drift_ms = (expected_frames - g_total_frames_rendered) / RING_BUFFER_SAMPLE_RATE * 1000.0f; + printf("[RENDER_DRIFT] calls=%lld expect=%.1f actual=%lld drift=%.2fms\n", + g_total_render_calls, expected_frames, g_total_frames_rendered, drift_ms); + } } float audio_get_playback_time() { diff --git a/src/audio/tracker.cc b/src/audio/tracker.cc index 37f0683..00c31e9 100644 --- a/src/audio/tracker.cc +++ b/src/audio/tracker.cc @@ -324,6 +324,14 @@ void tracker_update(float music_time_sec, float dt_music_sec) { } } + // DEBUG: Track kick/snare timing for drift investigation + if (event.sample_id == 0 || event.sample_id == 1) { // Assuming kick=0, snare=1 + const char* name = (event.sample_id == 0) ? "KICK " : "SNARE"; + const float delta_ms = (event_music_time - music_time_sec) * 1000.0f; + printf("[DRIFT] %s: music=%.4f expect=%.4f delta=%.2fms offset=%d\n", + name, music_time_sec, event_music_time, delta_ms, sample_offset); + } + trigger_note_event(event, sample_offset, volume_mult); active.next_event_idx++; } -- cgit v1.2.3