diff --git a/PROGRESS.md b/PROGRESS.md index f9a6cd5..407796c 100644 --- a/PROGRESS.md +++ b/PROGRESS.md @@ -10,6 +10,28 @@ up instantly. Newest status at the top. ## ▶ Where we left off / next action +- **Done:** **Fixed a *second* silent-playback bug — the playout clock free-ran and drifted off + the stream** (2026-06-17, reported live: both `vccli` and the Windows client showed `talking=1/0` + correctly on VAD/PTT, mic + screen-share were recognized by peers, but nothing was audible). + Root cause: `RemoteStream::playout_ts` was only ever seeded to `0` and then advanced one Opus + frame per playback callback **via the PLC path too** (`core/src/audio/audio_engine.cpp` + `on_playback`), so it free-ran at ~1× wall-clock regardless of whether the sender was + transmitting. The sender's frame timestamps only advance while it actually sends (the VAD/PTT + gate in `core/src/core/client.cpp` returns before `ls.timestamp += samples`). Across a late join + or any VAD/PTT silence gap the two clocks diverged without bound; once past the jitter buffer's + 500 ms late-drop window, every real frame was dropped-as-late (clock ahead) or never-due (clock + behind) → permanent silence, while the talk indicator (driven by `push_recv_frame`, independent + of the jitter buffer) stayed lit. The M3 E2E test missed it because clients there talked + continuously right after joining, keeping the clocks aligned. **Fix:** `JitterBuffer` gained + `peek_front_ts()` (try-lock, RT-safe); `on_playback` now seeds/re-syncs `playout_ts` to the + earliest buffered frame on the first frame and whenever it has drifted past ±200/500 ms + (`kResyncAheadSamples`/`kResyncBehindSamples`), which both seeds startup and recovers after every + silence gap. New regression test `test_playout_resync` (`tests/test_vad_ptt_devices.cpp`): + free-runs the clock ~2 s past the drop window, pushes a `ts=0` frame, asserts audible output — + verified to fail (energy=0) with the fix disabled, pass (energy≈15M) with it. `ctest --test-dir + build/m1-dev` — **14/14 green** (run via PowerShell; Git Bash exec gotcha for these binaries, see + `docs/building.md`). **Not yet confirmed audible by ear** — pending the user re-running their + live test. - **Done:** **Fixed silent-playback bug in `AudioEngine::on_playback`** (2026-06-16, found via live manual test: two `vccli --voice` clients, control-plane events and VAD all correct, but zero audible output). Root cause: `opus_decode()`'s `max_samples` was being passed the diff --git a/core/src/audio/audio_engine.cpp b/core/src/audio/audio_engine.cpp index a4b9323..07053be 100644 --- a/core/src/audio/audio_engine.cpp +++ b/core/src/audio/audio_engine.cpp @@ -18,6 +18,14 @@ int64_t now_ms() { .count(); } +// Playout-clock re-sync thresholds (samples @ 48 kHz). The playout clock advances every callback +// via the PLC path in on_playback, while the sender's frame timestamps only advance while it is +// actually transmitting — so they drift across VAD/PTT silence gaps and late joins. Both are kept +// under JitterBuffer::kLateDropSamples (500 ms) so the clock is snapped back before frames would +// begin to be dropped-as-late, which is what produced the "talk indicator lit, no audio" silence. +constexpr int32_t kResyncAheadSamples = 48000 * 200 / 1000; // clock 200 ms ahead → re-seed +constexpr int32_t kResyncBehindSamples = 48000 * 500 / 1000; // clock 500 ms behind → re-seed + #ifdef VOICECAT_HAS_AUDIO // device_id encoding (DeviceInfo::id / AudioParams::*_device_id): a hex string of the raw // ma_device_id bytes. Opaque on purpose — names aren't guaranteed unique, and this is the only @@ -103,6 +111,12 @@ std::optional JitterBuffer::pop(uint32_t playout_ts) { return f; } +std::optional JitterBuffer::peek_front_ts() const { + std::unique_lock lk(mu_, std::try_to_lock); + if (!lk || buf_.empty()) return std::nullopt; + return buf_.begin()->first; +} + void JitterBuffer::reset() { std::lock_guard lk(mu_); buf_.clear(); @@ -413,6 +427,24 @@ void AudioEngine::on_playback(int16_t* out, ma_uint32 frames) { const int dec_channels = std::max(1, stream.decoder.channels()); const int frame_samples = stream.decoder.frame_samples(); + // Seed / re-sync the playout clock to the arriving stream. playout_ts advances every + // callback (via the PLC path below) independently of whether the sender is transmitting, + // so across a late join or any VAD/PTT silence gap it drifts away from the sender's frame + // timestamps without bound. Left uncorrected, the divergence eventually exceeds the jitter + // buffer's late-drop window and every real frame is dropped-as-late (clock ahead) or + // never-due (clock behind) — permanent silence even though frames keep arriving (the talk + // indicator, driven by push_recv_frame, stays lit). Snap to the earliest buffered frame on + // the first frame and whenever the clock has drifted too far; this both seeds startup and + // recovers after every silence gap. u32 subtraction via int32_t handles timestamp wrap. + if (auto front_ts = stream.jitter.peek_front_ts()) { + int32_t drift = static_cast(stream.playout_ts - *front_ts); + if (!stream.playout_started || drift > kResyncAheadSamples || + drift < -kResyncBehindSamples) { + stream.playout_ts = *front_ts; + stream.playout_started = true; + } + } + while (stream.ring_count < frames && frame_samples > 0) { auto maybe_frame = stream.jitter.pop(stream.playout_ts); int n; diff --git a/core/src/audio/audio_engine.h b/core/src/audio/audio_engine.h index 28087eb..2d05ff3 100644 --- a/core/src/audio/audio_engine.h +++ b/core/src/audio/audio_engine.h @@ -55,6 +55,11 @@ class JitterBuffer { // Drops frames that are too old (more than kLateDropSamples late). std::optional pop(uint32_t playout_ts); + // Timestamp of the earliest buffered frame, or nullopt if empty/contended. Lets the playout + // clock seed/re-sync itself to the arriving stream rather than free-running (see + // AudioEngine::on_playback). Uses try_lock — never blocks the real-time callback. + std::optional peek_front_ts() const; + uint32_t target_depth_ms()const { return target_depth_ms_.load(); } uint32_t packets_lost() const { return lost_.load(); } void reset(); @@ -259,6 +264,11 @@ class AudioEngine { float gain = 1.0f; bool mute = false; uint32_t playout_ts = 0; + // playout_ts free-runs (advances every callback via PLC), so it must be seeded from, and + // periodically re-synced to, the actual stream timeline — otherwise it drifts past the + // jitter buffer's drop window across VAD/PTT gaps and late joins and every frame is + // dropped/never-due (silent playback). false until the first frame seeds it (on_playback). + bool playout_started = false; // M3: listener-chosen, local-only noise reduction (docs/voice.md §10). Lazily // created only when enabled — bounded by how many remote streams this listener diff --git a/tests/test_vad_ptt_devices.cpp b/tests/test_vad_ptt_devices.cpp index eae635d..bf1ca2a 100644 --- a/tests/test_vad_ptt_devices.cpp +++ b/tests/test_vad_ptt_devices.cpp @@ -229,6 +229,68 @@ static void test_stereo_mix() { engine.stop(); std::printf("test_stereo_mix: ok (total_diff=%lld)\n", static_cast(total_diff)); } + +// ── 4b. Playout-clock re-sync after a late join / silence gap ──────────────────── +// Regression for the "talk indicator lit, no audio" bug: the playout clock free-runs (it +// advances every callback via PLC), while the sender's frame timestamps only advance while it +// is actually transmitting. After a silence gap or a late join the clock drifts past the jitter +// buffer's 500 ms late-drop window, so every real frame is dropped-as-late and the stream is +// permanently silent. on_playback must re-seed the clock to the earliest buffered frame. +static void test_playout_resync() { + voicecat::audio::AudioEngine engine; + voicecat::audio::AudioParams p; + p.sample_rate = 48000; + p.capture_channels = 1; + p.playback_channels = 2; + p.frame_ms = 20; + CHECK(engine.start(p)); + + voicecat::codec::OpusParams mono_params; // mono = the mic path + mono_params.stereo = false; + int frame_samples = voicecat::codec::opus_frame_samples(mono_params); + + voicecat::codec::OpusEncoder enc; + CHECK(enc.init(mono_params)); + + std::vector sine(static_cast(frame_samples)); + for (int i = 0; i < frame_samples; ++i) { + float t = static_cast(i) / 48000.0f; + sine[i] = static_cast(std::sin(2.0f * 3.14159265f * 440.0f * t) * 20000.0f); + } + uint8_t opus_buf[1500]; + int opus_len = enc.encode(sine.data(), frame_samples, opus_buf, sizeof(opus_buf)); + CHECK(opus_len > 0); + + engine.init_recv_stream(/*ssrc=*/2, mono_params); + + std::vector out(static_cast(frame_samples) * 2, 0); + + // Free-run the playout clock with an empty jitter buffer (PLC every callback) far past the + // 500 ms late-drop window — this is what a silence gap / late join does in the field. + for (int i = 0; i < 100; ++i) // ~100 frames @ 20 ms = ~2 s, well past 500 ms + engine.mix_for_test(out.data(), static_cast(frame_samples)); + + // Now a real frame arrives carrying a timestamp far behind the free-run clock. Without the + // re-sync it is dropped-as-late and playback stays silent; with it the clock snaps back and + // the frame is decoded and mixed. + voicecat::audio::JitterBuffer::Frame f; + f.seq = 0; + f.timestamp = 0; // stream-relative start, now far behind the drifted playout clock + f.fec_present = false; + f.payload.assign(opus_buf, opus_buf + opus_len); + engine.push_recv_frame(2, std::move(f)); + + std::fill(out.begin(), out.end(), 0); + engine.mix_for_test(out.data(), static_cast(frame_samples)); + + int64_t energy = 0; + for (int16_t s : out) energy += std::abs(static_cast(s)); + CHECK(energy > static_cast(frame_samples) * 1000); // audible, not PLC silence + + engine.remove_stream(2); + engine.stop(); + std::printf("test_playout_resync: ok (energy=%lld)\n", static_cast(energy)); +} #endif // VOICECAT_HAS_AUDIO && VOICECAT_HAS_OPUS // ── 5. Capture-frame accumulation (white-box, no audio hardware needed) ────────── @@ -439,6 +501,7 @@ int main() { test_device_enumeration(); #if defined(VOICECAT_HAS_AUDIO) && defined(VOICECAT_HAS_OPUS) test_stereo_mix(); + test_playout_resync(); #endif #ifdef VOICECAT_HAS_AUDIO test_capture_frame_accumulation();