From 91933ce05ba157dc549d52ed6c00c71c457fca05 Mon Sep 17 00:00:00 2001 From: skal Date: Wed, 4 Feb 2026 19:40:40 +0100 Subject: feat: Audio playback stability, NOTE_ parsing fix, sample caching, and debug logging infrastructure MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit MILESTONE: Audio System Robustness & Debugging Core Audio Backend Optimization: - Fixed stop-and-go audio glitches caused by timing mismatch - Core Audio optimized for 44.1kHz (10ms periods), but 32kHz expected ~13.78ms - Added allowNominalSampleRateChange=TRUE to force OS-level 32kHz native - Added performanceProfile=conservative for 4096-frame buffers (128ms) - Result: Stable ~128ms callbacks, <1ms jitter, zero underruns Ring Buffer Improvements: - Increased capacity from 200ms to 400ms for tempo scaling headroom - Added comprehensive bounds checking with abort() on violations - Fixed tempo-scaled buffer fill: dt * g_tempo_scale - Buffer maintains 400ms fullness during 2.0x acceleration NOTE_ Parsing Fix & Sample Caching: - Fixed is_note_name() checking only first letter (A-G) - ASSET_KICK_1 was misidentified as A0 (27.5 Hz) - Required "NOTE_" prefix to distinguish notes from assets - Updated music.track to use NOTE_E2, NOTE_G4 format - Discovered resource exhaustion: 14 unique samples → 228 registrations - Implemented comprehensive caching in tracker_init() - Assets: loaded once from AssetManager, cached synth_id - Generated notes: created once, stored in persistent pool - Result: MAX_SPECTROGRAMS 256 → 32 (88% memory reduction) Debug Logging Infrastructure: - Created src/util/debug.h with 7 category macros (AUDIO, RING_BUFFER, TRACKER, SYNTH, 3D, ASSETS, GPU) - Added DEMO_ENABLE_DEBUG_LOGS CMake option (defines DEBUG_LOG_ALL) - Converted all diagnostic code to use category macros - Default build: macros compile to ((void)0) for zero runtime cost - Debug build: comprehensive logging for troubleshooting - Updated CONTRIBUTING.md with pre-commit policy Resource Analysis Tool: - Enhanced tracker_compiler to report pool sizes and cache potential - Analysis: 152/228 spectrograms without caching, 14 with caching - Tool generates optimization recommendations during compilation Files Changed: - CMakeLists.txt: Add DEBUG_LOG option - src/util/debug.h: New debug logging header (7 categories) - src/audio/miniaudio_backend.cc: Use DEBUG_AUDIO/DEBUG_RING_BUFFER - src/audio/ring_buffer.cc: Use DEBUG_RING_BUFFER for underruns - src/audio/tracker.cc: Implement sample caching, use DEBUG_TRACKER - src/audio/synth.cc: Use DEBUG_SYNTH for validation - src/audio/synth.h: Update MAX_SPECTROGRAMS (256→32), document caching - tools/tracker_compiler.cc: Fix is_note_name(), add resource analysis - assets/music.track: Update to use NOTE_ prefix format - doc/CONTRIBUTING.md: Add debug logging pre-commit policy - PROJECT_CONTEXT.md: Document milestone - TODO.md: Mark tasks completed Verification: - Default build: No debug output, audio plays correctly - Debug build: Comprehensive logging, audio plays correctly - Caching working: 14 unique samples cached at init - All tests passing (17/17) handoff(Claude): Audio system now stable with robust diagnostic infrastructure. Co-Authored-By: Claude Sonnet 4.5 --- src/audio/tracker.cc | 155 ++++++++++++++++++++++++++++++++++++--------------- 1 file changed, 109 insertions(+), 46 deletions(-) (limited to 'src/audio/tracker.cc') diff --git a/src/audio/tracker.cc b/src/audio/tracker.cc index cb97f23..5358e50 100644 --- a/src/audio/tracker.cc +++ b/src/audio/tracker.cc @@ -2,6 +2,7 @@ #include "audio.h" #include "audio/synth.h" #include "util/asset_manager.h" +#include "util/debug.h" #include #include @@ -27,6 +28,14 @@ struct ManagedSpectrogram { static ManagedSpectrogram g_spec_pool[MAX_SPECTROGRAMS]; static int g_next_pool_slot = 0; // Round-robin allocation +// CACHE: Pre-registered synth_ids for all samples (indexed by sample_id) +// This eliminates redundant spectrogram generation and registration +static int g_sample_synth_cache[256]; // Max 256 unique samples +static bool g_cache_initialized = false; + +// Forward declarations +static int get_free_pool_slot(); + void tracker_init() { g_last_trigger_idx = 0; g_next_pool_slot = 0; @@ -36,6 +45,78 @@ void tracker_init() { g_spec_pool[i].active = false; g_active_patterns[i].active = false; } + + // Initialize sample cache + if (!g_cache_initialized) { + for (int i = 0; i < 256; ++i) { + g_sample_synth_cache[i] = -1; + } + + // Pre-register all unique samples (assets + generated notes) + for (uint32_t sid = 0; sid < g_tracker_samples_count; ++sid) { + AssetId aid = g_tracker_sample_assets[sid]; + + if (aid != AssetId::ASSET_LAST_ID) { + // ASSET sample: Load once and cache + size_t size; + const uint8_t* data = GetAsset(aid, &size); + if (data && size >= sizeof(SpecHeader)) { + const SpecHeader* header = (const SpecHeader*)data; + const int note_frames = header->num_frames; + const float* spectral_data = (const float*)(data + sizeof(SpecHeader)); + + Spectrogram spec; + spec.spectral_data_a = spectral_data; + spec.spectral_data_b = spectral_data; + spec.num_frames = note_frames; + + g_sample_synth_cache[sid] = synth_register_spectrogram(&spec); + +#if defined(DEBUG_LOG_TRACKER) + if (g_sample_synth_cache[sid] == -1) { + DEBUG_TRACKER( "[TRACKER INIT] Failed to cache asset sample_id=%d (aid=%d)\n", + sid, (int)aid); + } +#endif /* defined(DEBUG_LOG_TRACKER) */ + } + } else { + // GENERATED note: Generate once and cache + const NoteParams& params = g_tracker_samples[sid]; + int note_frames = 0; + std::vector note_data = generate_note_spectrogram(params, ¬e_frames); + + if (note_frames > 0) { + // Allocate persistent storage for this note + const int slot = get_free_pool_slot(); + g_spec_pool[slot].data = new float[note_data.size()]; + memcpy(g_spec_pool[slot].data, note_data.data(), + note_data.size() * sizeof(float)); + + Spectrogram spec; + spec.spectral_data_a = g_spec_pool[slot].data; + spec.spectral_data_b = g_spec_pool[slot].data; + spec.num_frames = note_frames; + + g_sample_synth_cache[sid] = synth_register_spectrogram(&spec); + g_spec_pool[slot].synth_id = g_sample_synth_cache[sid]; + g_spec_pool[slot].active = true; // Mark as permanently allocated + +#if defined(DEBUG_LOG_TRACKER) + if (g_sample_synth_cache[sid] == -1) { + DEBUG_TRACKER( "[TRACKER INIT] Failed to cache generated sample_id=%d (freq=%.2f)\n", + sid, params.base_freq); + } +#endif /* defined(DEBUG_LOG_TRACKER) */ + } + } + } + + g_cache_initialized = true; + +#if defined(DEBUG_LOG_TRACKER) + DEBUG_TRACKER( "[TRACKER INIT] Cached %d unique samples\n", g_tracker_samples_count); +#endif /* defined(DEBUG_LOG_TRACKER) */ + } } void tracker_reset() { @@ -67,57 +148,39 @@ static int get_free_pattern_slot() { return -1; // No free slots } -// Helper to trigger a single note event +// Helper to trigger a single note event (OPTIMIZED with caching) static void trigger_note_event(const TrackerEvent& event) { - std::vector note_data; - int note_frames = 0; - - // Load or generate the note spectrogram - AssetId aid = g_tracker_sample_assets[event.sample_id]; - if (aid != AssetId::ASSET_LAST_ID) { - size_t size; - const uint8_t* data = GetAsset(aid, &size); - if (data && size >= sizeof(SpecHeader)) { - const SpecHeader* header = (const SpecHeader*)data; - note_frames = header->num_frames; - const float* src_spectral_data = - (const float*)(data + sizeof(SpecHeader)); - note_data.assign(src_spectral_data, - src_spectral_data + (size_t)note_frames * DCT_SIZE); - } - } else { - const NoteParams& params = g_tracker_samples[event.sample_id]; - note_data = generate_note_spectrogram(params, ¬e_frames); +#if defined(DEBUG_LOG_TRACKER) + // VALIDATION: Check sample_id bounds + if (event.sample_id >= g_tracker_samples_count) { + DEBUG_TRACKER( "[TRACKER ERROR] Invalid sample_id=%d (max=%d)\n", + event.sample_id, g_tracker_samples_count - 1); + return; } + // VALIDATION: Check volume and pan ranges + if (event.volume < 0.0f || event.volume > 2.0f) { + DEBUG_TRACKER( "[TRACKER WARNING] Unusual volume=%.2f for sample_id=%d\n", + event.volume, event.sample_id); + } + if (event.pan < -1.0f || event.pan > 1.0f) { + DEBUG_TRACKER( "[TRACKER WARNING] Invalid pan=%.2f for sample_id=%d\n", + event.pan, event.sample_id); + } +#endif /* defined(DEBUG_LOG_TRACKER) */ - if (note_frames > 0) { - const int slot = get_free_pool_slot(); - - // Clean up old data in this slot if reusing - if (g_spec_pool[slot].synth_id != -1) { - synth_unregister_spectrogram(g_spec_pool[slot].synth_id); - g_spec_pool[slot].synth_id = -1; - } - if (g_spec_pool[slot].data != nullptr) { - delete[] g_spec_pool[slot].data; - g_spec_pool[slot].data = nullptr; - } - - // Allocate and register new note - g_spec_pool[slot].data = new float[note_data.size()]; - memcpy(g_spec_pool[slot].data, note_data.data(), - note_data.size() * sizeof(float)); - - Spectrogram spec; - spec.spectral_data_a = g_spec_pool[slot].data; - spec.spectral_data_b = g_spec_pool[slot].data; - spec.num_frames = note_frames; - - g_spec_pool[slot].synth_id = synth_register_spectrogram(&spec); - g_spec_pool[slot].active = true; + // OPTIMIZED: Use cached synth_id instead of regenerating spectrogram + const int cached_synth_id = g_sample_synth_cache[event.sample_id]; - synth_trigger_voice(g_spec_pool[slot].synth_id, event.volume, event.pan); +#if defined(DEBUG_LOG_TRACKER) + if (cached_synth_id == -1) { + DEBUG_TRACKER( "[TRACKER ERROR] No cached synth_id for sample_id=%d (init failed?)\n", + event.sample_id); + return; } +#endif /* defined(DEBUG_LOG_TRACKER) */ + + // Trigger voice directly with cached spectrogram + synth_trigger_voice(cached_synth_id, event.volume, event.pan); } void tracker_update(float music_time_sec) { -- cgit v1.2.3