diff --git a/apps/chanora_flutter/pubspec.yaml b/apps/chanora_flutter/pubspec.yaml index ab5d739..6c1b6af 100644 --- a/apps/chanora_flutter/pubspec.yaml +++ b/apps/chanora_flutter/pubspec.yaml @@ -16,7 +16,7 @@ publish_to: 'none' # Remove this line if you wish to publish to pub.dev # https://developer.apple.com/library/archive/documentation/General/Reference/InfoPlistKeyReference/Articles/CoreFoundationKeys.html # In Windows, build-name is used as the major, minor, and patch parts # of the product and file versions while build-number is used as the build suffix. -version: 1.0.0-rc.8+73 +version: 1.0.0-rc.8+74 environment: sdk: ^3.11.5 diff --git a/crates/chanora_audio/src/ios_voice_unit.rs b/crates/chanora_audio/src/ios_voice_unit.rs index afb78bd..4f42075 100644 --- a/crates/chanora_audio/src/ios_voice_unit.rs +++ b/crates/chanora_audio/src/ios_voice_unit.rs @@ -578,24 +578,71 @@ impl IosVoiceUnit { let handler_for_producer = handler.clone(); let (producer_shutdown_tx, mut producer_shutdown_rx) = tokio::sync::oneshot::channel::<()>(); + // Use the consumer's `slots()` (= free slots = unwritten) + // to compute current ring fill level (= RING_BUFFER_SAMPLES + // - free). But the consumer end is in the render closure, + // not accessible here. rtrb exposes `Producer::slots()` + // which returns the FREE count, same arithmetic: + // fill_samples = RING_BUFFER_SAMPLES - producer.slots() + // fill_ms = fill_samples * 1000 / 48000 + // No locks needed; slots() is a relaxed atomic read. tokio::spawn(async move { let mut scratch_stereo = vec![0.0_f32; FRAME_SAMPLES_MONO * 2]; let mut interval = tokio::time::interval(Duration::from_millis(PRODUCER_TICK_MS)); interval.set_missed_tick_behavior(tokio::time::MissedTickBehavior::Skip); + // Per-tick counters (rolled up every PRODUCER_LOG_TICKS + // ticks = ~5 s of wall time). All u64 to avoid overflow + // across hours of session. + let mut producer_ticks: u64 = 0; let mut produced_chunks: u64 = 0; + let mut fill_buffer_calls: u64 = 0; + let mut fill_buffer_zero_returns: u64 = 0; let mut ring_full_drops: u64 = 0; + // Min/max ring level WITHIN the current logging + // window. Reset to extremes at each log emission so + // each window's report describes that window's + // behaviour. + let mut ring_min_samples: usize = usize::MAX; + let mut ring_max_samples: usize = 0; + // Accumulated scratch envelope across the window so + // we can emit window-average peak + RMS without + // doing a O(n) scan in the hot path \u2014 only an + // O(n) scan per producer tick (already affordable). + let mut window_peak_f32: f32 = 0.0; + let mut window_sumsq_f64: f64 = 0.0; + let mut window_sample_count: u64 = 0; + const PRODUCER_LOG_TICKS: u64 = 250; // 250 * 20 ms = 5 s loop { tokio::select! { _ = &mut producer_shutdown_rx => { debug!( target: "chanora_audio", produced_chunks, + fill_buffer_calls, + fill_buffer_zero_returns, ring_full_drops, "ios VPIO producer task shutting down" ); break; } _ = interval.tick() => { + producer_ticks = producer_ticks.wrapping_add(1); + // Measure ring level BEFORE the push so + // the diagnostic shows whether the + // consumer is keeping up. Slots = free + // slots; fill = capacity - free. + let free_before = ring_producer.slots(); + let fill_before = RING_BUFFER_SAMPLES.saturating_sub(free_before); + if fill_before < ring_min_samples { + ring_min_samples = fill_before; + } + if fill_before > ring_max_samples { + ring_max_samples = fill_before; + } + + // Zero scratch first (fill_buffer is + // additive over per-talker streams; it + // does NOT clear). for s in scratch_stereo.iter_mut() { *s = 0.0; } @@ -603,28 +650,117 @@ impl IosVoiceUnit { let mut h = handler_for_producer.lock().unwrap(); let _removed = h.fill_buffer(&mut scratch_stereo); } - let free = ring_producer.slots(); - if free < FRAME_SAMPLES_MONO { - ring_full_drops = ring_full_drops.wrapping_add(1); - if ring_full_drops.is_multiple_of(50) { - warn!( - target: "chanora_audio", - ring_full_drops, - free_slots = free, - "ios VPIO ring buffer overflow (consumer slow)" - ); + fill_buffer_calls = fill_buffer_calls.wrapping_add(1); + + // Measure scratch envelope. fill_buffer + // either filled with real content or + // left it at zero (we pre-zeroed). A + // zero-peak scratch means the handler + // had nothing to play \u2014 either no + // talker active, no packets in queue, or + // queue stuck in buffering_samples + // state. + let mut tick_peak: f32 = 0.0; + let mut tick_sumsq: f64 = 0.0; + for &s in scratch_stereo.iter() { + let a = s.abs(); + if a > tick_peak { + tick_peak = a; } - continue; + tick_sumsq += (s as f64) * (s as f64); } - for i in 0..FRAME_SAMPLES_MONO { - let l = scratch_stereo[i * 2]; - let r = scratch_stereo[i * 2 + 1]; - let mono_f32 = (l + r) * 0.5; - let clamped = mono_f32.clamp(-1.0, 1.0); - let sample = (clamped * i16::MAX as f32) as i16; - let _ = ring_producer.push(sample); + if tick_peak == 0.0 { + fill_buffer_zero_returns = + fill_buffer_zero_returns.wrapping_add(1); + } + if tick_peak > window_peak_f32 { + window_peak_f32 = tick_peak; + } + window_sumsq_f64 += tick_sumsq; + window_sample_count = + window_sample_count.wrapping_add(scratch_stereo.len() as u64); + + // Check ring has room then push. + if free_before < FRAME_SAMPLES_MONO { + ring_full_drops = ring_full_drops.wrapping_add(1); + // Don't push; ring would block / wrap. + } else { + for i in 0..FRAME_SAMPLES_MONO { + let l = scratch_stereo[i * 2]; + let r = scratch_stereo[i * 2 + 1]; + let mono_f32 = (l + r) * 0.5; + let clamped = mono_f32.clamp(-1.0, 1.0); + let sample = (clamped * i16::MAX as f32) as i16; + let _ = ring_producer.push(sample); + } + produced_chunks = produced_chunks.wrapping_add(1); + } + + // Emit rolled-up window diagnostic every + // ~5 s. All fields together let us tell + // exactly where audio is being lost: + // + // producer_ticks : how many times we + // ticked (should be + // ~250 per 5 s window; + // fewer = tokio + // scheduler stalled). + // produced_chunks : pushes into ring + // (= ticks - drops). + // fill_buffer_calls : AudioHandler queries + // (= ticks; always + // equal unless tokio + // panicked mid-loop). + // fill_buffer_zero_returns + // : ticks where fill_buffer + // left scratch at all + // zeros. High value = + // AudioHandler has no + // content to play. + // ring_full_drops : pushes skipped because + // ring was full (consumer + // slow). + // ring_min/max_samples : depth envelope across + // window. Should sit + // stable around the + // target_level + // (FRAME_SAMPLES_MONO). + // window_peak_f32 : max scratch sample + // across window. + // window_rms_f32 : RMS across all scratch + // samples in window. + if producer_ticks.is_multiple_of(PRODUCER_LOG_TICKS) { + let window_rms = if window_sample_count > 0 { + (window_sumsq_f64 / window_sample_count as f64).sqrt() as f32 + } else { + 0.0 + }; + let ring_min_ms = + (ring_min_samples * 1000) as f64 / 48000.0; + let ring_max_ms = + (ring_max_samples * 1000) as f64 / 48000.0; + info!( + target: "chanora_audio", + producer_ticks, + produced_chunks, + fill_buffer_calls, + fill_buffer_zero_returns, + ring_full_drops, + ring_min_samples, + ring_max_samples, + ring_min_ms = format!("{:.1}", ring_min_ms), + ring_max_ms = format!("{:.1}", ring_max_ms), + window_peak_f32, + window_rms_f32 = window_rms, + "ios VPIO producer task diagnostic sample" + ); + // Reset window-scope counters. + ring_min_samples = usize::MAX; + ring_max_samples = 0; + window_peak_f32 = 0.0; + window_sumsq_f64 = 0.0; + window_sample_count = 0; } - produced_chunks = produced_chunks.wrapping_add(1); } } } @@ -643,6 +779,13 @@ impl IosVoiceUnit { let out: &mut [i16] = args.data.buffer; let num_frames = out.len(); + // Measure ring buffer fill level BEFORE the read so + // the diagnostic shows whether the producer is keeping + // up. Consumer::slots() returns the number of + // AVAILABLE (= readable) samples; the inverse + // (free space) lives on the Producer end. + let ring_avail_before = ring_consumer.slots(); + // Pop up to num_frames samples from the ring buffer // into the output. Anything not filled stays at // whatever was there (we zero-fill the tail @@ -670,6 +813,7 @@ impl IosVoiceUnit { } } } + let zero_filled_this_call = num_frames - filled; // Post-process: mute then gain. Gain is applied // CONSUMER-SIDE (not producer-side) so user-driven @@ -713,6 +857,9 @@ impl IosVoiceUnit { cb = cb_count, num_frames, frames_changes = num_frames_changes, + ring_avail_before, + read_frames = filled, + zero_filled = zero_filled_this_call, underruns, underrun_samples, peak_out_i16 = peak_out,