diff --git a/doc/tasks.md b/doc/tasks.md index 09099c9b..b8f5571c 100644 --- a/doc/tasks.md +++ b/doc/tasks.md @@ -43,6 +43,15 @@ причина редких аудиоколлбэков пока не установлена. Добавить измерения интервалов и длительности callback, кадров capture/playback и сводку CALL_STATS; сравнить сетевые задержки после подключения ПК к 5ГГц или кабелю. + Повторный звонок `b2a423ed2d36ed83` (01:25:31–01:27:39): DIRECT сохраняется, + RTT 2–3мс; в начале на SM gap tone длится 1.8–2.0с примерно каждые 6с. + На Qt частота callback падает вплоть до 4/с, входящий PCM продолжает приходить: + буфер 65→465→1465→2079мс за 3с, затем растёт до нескольких секунд, dropped=0. + Локализовано прекращение обслуживания duplex-аудио Qt; ожидание backend и + задержка обработки PCM пока не разделены. Часы SM отстают от Qt примерно на 1.24с. + Добавлена диагностика backend/устройств, времени между callback и длительности + capture/playback, фактической частоты callback и PCM кадров за интервал. + Счётчики сбрасываются до старта устройства; нужна повторная запись с новой сборкой. [ ] **Гонка invite-файла в test_chat_join_e2e** — `wait_file()` проверяет только существование файла, а `wf()` создаёт его до записи. Читатель иногда получает diff --git a/tools/chatgui/src/call_audio_engine.cpp b/tools/chatgui/src/call_audio_engine.cpp index f4441520..655fa528 100644 --- a/tools/chatgui/src/call_audio_engine.cpp +++ b/tools/chatgui/src/call_audio_engine.cpp @@ -11,6 +11,7 @@ extern "C" { } #include +#include #include static CallAudioEngine* g_callAudioEngine = nullptr; @@ -102,6 +103,12 @@ int CallAudioEngine::initDevice() { return -1; } } + DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "CallAudio: device backend=%s rate=%u capture='%s' rate=%u period=%u playback='%s' rate=%u period=%u", + ma_get_backend_name(ctx->backend), m_device->sampleRate, + m_device->capture.name, m_device->capture.internalSampleRate, m_device->capture.internalPeriodSizeInFrames, + m_device->playback.name, m_device->playback.internalSampleRate, m_device->playback.internalPeriodSizeInFrames); + m_capturePos = 0; + m_dbg = {}; if (ma_device_start(m_device) != MA_SUCCESS) { DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "CallAudio: device start failed"); ma_device_uninit(m_device); @@ -109,7 +116,6 @@ int CallAudioEngine::initDevice() { return -1; } m_deviceStarted = true; - m_capturePos = 0; return 0; } @@ -164,25 +170,19 @@ void CallAudioEngine::teardownDevice() { void CallAudioEngine::dataCallback(const void* in, void* out, unsigned int frames) { const int16_t* in16 = (const int16_t*)in; int16_t* out16 = (int16_t*)out; + uint64_t startTb = get_time_tb(); + uint64_t idleTb = m_dbg.lastEndTb ? startTb - m_dbg.lastEndTb : 0; + if (!m_dbg.lastReportTb) m_dbg.lastReportTb = startTb; /* диагностика (DEBUG_CATEGORY_DEBUG): фактические параметры miniaudio-коллбэка */ - if (m_dbgFrames == 0) { - m_dbgFrames = frames; + if (m_dbg.frames != frames) { + m_dbg.frames = frames; DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "CallAudio: callback frames=%u in=%s out=%s", frames, in16 ? "yes" : "no", out16 ? "yes" : "no"); } - m_dbgCbCount++; - { - uint64_t now = get_time_tb(); - if (m_dbgLastTb == 0) m_dbgLastTb = now; - else if (now - m_dbgLastTb >= 10000) { - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "CallAudio: cb=%u/s frames=%u", m_dbgCbCount, frames); - m_dbgCbCount = 0; - m_dbgLastTb = now; - } - } /* захват: копим 960 samples → encode+send (сервисный слой). mute → тишина. */ + uint64_t captureStartTb = get_time_tb(); if (in16) { bool muted = m_muted.load(); for (unsigned int i = 0; i < frames; i++) { @@ -193,9 +193,40 @@ void CallAudioEngine::dataCallback(const void* in, void* out, unsigned int frame } } } + uint64_t captureEndTb = get_time_tb(); /* воспроизведение: финальный PCM из сервисного слоя (jitter+stretch+тоны) */ int n = call_audio_pull_pcm(m_callId.load(), out16, (int)frames); if (n < (int)frames) std::memset(out16 + n, 0, (size_t)(frames - n) * sizeof(int16_t)); + uint64_t endTb = get_time_tb(); + uint64_t captureTb = captureEndTb - captureStartTb; + uint64_t playbackTb = endTb - captureEndTb; + m_dbg.callbacks++; + m_dbg.captureFrames += in16 ? frames : 0; + m_dbg.playbackFrames += out16 ? frames : 0; + m_dbg.maxIdleTb = std::max(m_dbg.maxIdleTb, idleTb); + m_dbg.maxCaptureTb = std::max(m_dbg.maxCaptureTb, captureTb); + m_dbg.maxPlaybackTb = std::max(m_dbg.maxPlaybackTb, playbackTb); + if (idleTb > 500 || endTb - startTb > 200) { + DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "CallAudio: stall call=%016llx idle=%.1fms work=%.1fms capture=%.1fms playback=%.1fms frames=%u", + (unsigned long long)m_callId.load(), idleTb / 10.0, (endTb - startTb) / 10.0, + captureTb / 10.0, playbackTb / 10.0, frames); + } + uint64_t elapsedTb = endTb - m_dbg.lastReportTb; + if (elapsedTb >= 10000) { + DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, + "CallAudio: interval=%.1fms cb=%.1f/s capture=%.0f/s playback=%.0f/s max_idle=%.1fms max_capture=%.1fms max_playback=%.1fms", + elapsedTb / 10.0, m_dbg.callbacks * 10000.0 / elapsedTb, + m_dbg.captureFrames * 10000.0 / elapsedTb, m_dbg.playbackFrames * 10000.0 / elapsedTb, + m_dbg.maxIdleTb / 10.0, m_dbg.maxCaptureTb / 10.0, m_dbg.maxPlaybackTb / 10.0); + m_dbg.callbacks = 0; + m_dbg.captureFrames = 0; + m_dbg.playbackFrames = 0; + m_dbg.maxIdleTb = 0; + m_dbg.maxCaptureTb = 0; + m_dbg.maxPlaybackTb = 0; + m_dbg.lastReportTb = endTb; + } + m_dbg.lastEndTb = get_time_tb(); } diff --git a/tools/chatgui/src/call_audio_engine.h b/tools/chatgui/src/call_audio_engine.h index d5fb2c17..6236b9e5 100644 --- a/tools/chatgui/src/call_audio_engine.h +++ b/tools/chatgui/src/call_audio_engine.h @@ -60,8 +60,16 @@ private: std::vector m_captureBuf; /* 960 samples, аудио-поток */ int m_capturePos = 0; - /* диагностика (DEBUG_CATEGORY_DEBUG): фактические параметры miniaudio-коллбэка */ - unsigned int m_dbgFrames = 0; - uint32_t m_dbgCbCount = 0; - uint64_t m_dbgLastTb = 0; + /* Только аудио-поток; сброс до ma_device_start. Время в 0.1мс. */ + struct { + unsigned int frames = 0; + uint32_t callbacks = 0; + uint64_t captureFrames = 0; + uint64_t playbackFrames = 0; + uint64_t lastReportTb = 0; + uint64_t lastEndTb = 0; + uint64_t maxIdleTb = 0; + uint64_t maxCaptureTb = 0; + uint64_t maxPlaybackTb = 0; + } m_dbg; };