1 files changed, 162 insertions, 2 deletions

diff --git a/src/audio/miniaudio_backend.cc b/src/audio/miniaudio_backend.cc
index 9dd2b50..c2db268 100644
--- a/src/audio/miniaudio_backend.cc
+++ b/src/audio/miniaudio_backend.cc
@@ -5,22 +5,140 @@
 #include "miniaudio_backend.h"
 #include "audio.h"
 #include "ring_buffer.h"
+#include "util/debug.h"
 #include <stdio.h>
+#include <stdlib.h>  // for abort()
 
 // Static callback for miniaudio (C API requirement)
 void MiniaudioBackend::audio_callback(ma_device* pDevice, void* pOutput,
                                        const void* pInput,
                                        ma_uint32 frameCount) {
-  (void)pDevice;
   (void)pInput;
+
+#if defined(DEBUG_LOG_AUDIO)
+  // Validate callback parameters
+  static ma_uint32 last_frameCount = 0;
+  static int callback_reentry = 0;
+  static double last_time = 0.0;
+  static int timing_initialized = 0;
+  static uint64_t total_frames_requested = 0;
+  static uint64_t callback_number = 0;
+
+  callback_number++;
+  total_frames_requested += frameCount;
+
+  // Track timing
+  struct timespec ts;
+  clock_gettime(CLOCK_MONOTONIC, &ts);
+  double now = ts.tv_sec + ts.tv_nsec / 1000000000.0;
+
+  if (timing_initialized) {
+    double delta = (now - last_time) * 1000.0;  // ms
+    double expected = ((double)frameCount / pDevice->sampleRate) * 1000.0;
+    double jitter = delta - expected;
+
+    // Enhanced logging: Log first 20 callbacks in detail, then periodic summary
+    if (callback_number <= 20 || callback_number % 50 == 0) {
+      const double elapsed_by_frames = (double)total_frames_requested / pDevice->sampleRate * 1000.0;
+      const double elapsed_by_time = now * 1000.0;  // Convert to ms
+      DEBUG_AUDIO("[CB#%llu] frameCount=%u, Delta=%.2fms, Expected=%.2fms, Jitter=%.2fms, "
+                  "TotalFrames=%llu (%.1fms), TotalTime=%.1fms, Drift=%.2fms\n",
+                  callback_number, frameCount, delta, expected, jitter,
+                  total_frames_requested, elapsed_by_frames, elapsed_by_time,
+                  elapsed_by_time - elapsed_by_frames);
+    }
+
+    // Detect large timing anomalies (>5ms off from expected)
+    if (fabs(jitter) > 5.0) {
+      DEBUG_AUDIO("[TIMING ANOMALY] CB#%llu Delta=%.2fms, Expected=%.2fms, Jitter=%.2fms\n",
+                  callback_number, delta, expected, jitter);
+    }
+  }
+  last_time = now;
+  timing_initialized = 1;
+
+  // Check for re-entrant calls
+  if (callback_reentry > 0) {
+    DEBUG_AUDIO("FATAL: Callback re-entered! depth=%d\n", callback_reentry);
+    abort();
+  }
+  callback_reentry++;
+
+  // Check if frameCount changed unexpectedly
+  if (last_frameCount != 0 && frameCount != last_frameCount) {
+    DEBUG_AUDIO("WARNING: frameCount changed! was=%u, now=%u\n",
+                last_frameCount, frameCount);
+  }
+  last_frameCount = frameCount;
+
+  // Validate device state
+  if (!pDevice || pDevice->sampleRate == 0) {
+    DEBUG_AUDIO("FATAL: Invalid device in callback!\n");
+    abort();
+  }
+
+  // Check actual sample rate matches our expectation
+  if (pDevice->sampleRate != 32000) {
+    static int rate_warning = 0;
+    if (rate_warning++ == 0) {
+      DEBUG_AUDIO("WARNING: Device sample rate is %u, not 32000! Resampling may occur.\n",
+                  pDevice->sampleRate);
+    }
+  }
+#endif /* defined(DEBUG_LOG_AUDIO) */
+
   float* fOutput = (float*)pOutput;
 
+  // BOUNDS CHECK: Sanity check on frameCount
+  if (frameCount > 8192 || frameCount == 0) {
+    fprintf(stderr, "AUDIO CALLBACK ERROR: frameCount=%u (unreasonable!)\n", frameCount);
+    abort();
+  }
+
   // Read from ring buffer instead of calling synth directly
   AudioRingBuffer* ring_buffer = audio_get_ring_buffer();
   if (ring_buffer != nullptr) {
     const int samples_to_read = (int)frameCount * 2;  // Stereo
-    ring_buffer->read(fOutput, samples_to_read);
+
+#if defined(DEBUG_LOG_RING_BUFFER)
+    // Track buffer level and detect drops
+    static int min_available = 99999;
+    const int available = ring_buffer->available_read();
+
+    if (available < min_available) {
+      min_available = available;
+      DEBUG_RING_BUFFER("[BUFFER] CB#%llu NEW MIN: available=%d (%.1fms)\n",
+                        callback_number, available, (float)available / (32000.0f * 2.0f) * 1000.0f);
+    }
+
+    // Log buffer state for first 20 callbacks and periodically
+    if (callback_number <= 20 || callback_number % 50 == 0) {
+      DEBUG_RING_BUFFER("[BUFFER] CB#%llu requested=%d, available=%d (%.1fms), min=%d\n",
+                        callback_number, samples_to_read, available,
+                        (float)available / (32000.0f * 2.0f) * 1000.0f, min_available);
+    }
+
+    // CRITICAL: Verify we have enough samples
+    if (available < samples_to_read) {
+      DEBUG_RING_BUFFER("[BUFFER UNDERRUN] CB#%llu requested=%d, available=%d, SHORT=%d\n",
+                        callback_number, samples_to_read, available, samples_to_read - available);
+    }
+#endif /* defined(DEBUG_LOG_RING_BUFFER) */
+
+    const int actually_read = ring_buffer->read(fOutput, samples_to_read);
+
+#if defined(DEBUG_LOG_RING_BUFFER)
+    if (actually_read < samples_to_read) {
+      DEBUG_RING_BUFFER("[PARTIAL READ] CB#%llu requested=%d, got=%d, padded=%d with silence\n",
+                        callback_number, samples_to_read, actually_read, samples_to_read - actually_read);
+    }
+#endif /* defined(DEBUG_LOG_RING_BUFFER) */
   }
+
+#if defined(DEBUG_LOG_AUDIO)
+  // Clear reentry flag
+  callback_reentry--;
+#endif /* defined(DEBUG_LOG_AUDIO) */
 }
 
 MiniaudioBackend::MiniaudioBackend() : initialized_(false) {
@@ -41,6 +159,21 @@ void MiniaudioBackend::init() {
   config.playback.format = ma_format_f32;
   config.playback.channels = 2;
   config.sampleRate = 32000;
+
+  // Core Audio Backend-Specific Configuration
+  // Problem: Core Audio uses 10ms periods optimized for 44.1kHz, causing
+  // uneven callback timing (10ms/10ms/20ms) when resampling to 32kHz
+  //
+  // Solution 1: Force OS-level sample rate to 32kHz to avoid resampling
+  config.coreaudio.allowNominalSampleRateChange = MA_TRUE;
+
+  // Solution 2: Use conservative performance profile for larger buffers
+  config.performanceProfile = ma_performance_profile_conservative;
+
+  // Let Core Audio choose the period size based on conservative profile
+  config.periodSizeInFrames = 0;  // 0 = let backend decide
+  config.periods = 0;  // 0 = let backend decide based on performance profile
+
   config.dataCallback = MiniaudioBackend::audio_callback;
   config.pUserData = this;
 
@@ -49,6 +182,33 @@ void MiniaudioBackend::init() {
     return;
   }
 
+#if defined(DEBUG_LOG_AUDIO)
+  // Log actual device configuration (to stderr for visibility)
+  DEBUG_AUDIO("\n=== MINIAUDIO DEVICE CONFIGURATION ===\n");
+  DEBUG_AUDIO("  Sample rate: %u (requested: 32000)\n", device_.sampleRate);
+  DEBUG_AUDIO("  Channels: %u (requested: 2)\n", device_.playback.channels);
+  DEBUG_AUDIO("  Format: %d (requested: %d, f32=%d)\n",
+              device_.playback.format, config.playback.format, ma_format_f32);
+  DEBUG_AUDIO("  Period size: %u frames (%.1fms at %uHz)\n",
+              device_.playback.internalPeriodSizeInFrames,
+              (float)device_.playback.internalPeriodSizeInFrames / device_.sampleRate * 1000.0f,
+              device_.sampleRate);
+  DEBUG_AUDIO("  Periods: %u (buffer multiplier)\n", device_.playback.internalPeriods);
+  DEBUG_AUDIO("  Backend: %s\n", ma_get_backend_name(device_.pContext->backend));
+  DEBUG_AUDIO("  Total buffer size: %u frames (%.2fms) [period * periods]\n",
+              device_.playback.internalPeriodSizeInFrames * device_.playback.internalPeriods,
+              (float)(device_.playback.internalPeriodSizeInFrames * device_.playback.internalPeriods) / device_.sampleRate * 1000.0f);
+
+  // Calculate expected callback interval
+  if (device_.playback.internalPeriodSizeInFrames > 0) {
+    const float expected_callback_ms = (float)device_.playback.internalPeriodSizeInFrames / device_.sampleRate * 1000.0f;
+    DEBUG_AUDIO("  Expected callback interval: %.2fms (based on period size)\n", expected_callback_ms);
+    DEBUG_AUDIO("  WARNING: If actual callback interval differs, audio corruption may occur!\n");
+  }
+  DEBUG_AUDIO("======================================\n\n");
+  fflush(stderr);
+#endif /* defined(DEBUG_LOG_AUDIO) */
+
   initialized_ = true;
 }