From 0d65c5bb742a7adc6bd3ed64c2eeb9b41abcfdee Mon Sep 17 00:00:00 2001 From: evgeny Date: Thu, 15 Oct 2026 16:14:51 +0200 Subject: [PATCH] Exercise delayed receive workers UI stalls and call restart with real video decoding --- tests/test_call_video_playout.c | 6 ++- tools/chatgui/tests/test_call_video_clock.cpp | 39 ++++++++++++++----- 2 files changed, 34 insertions(+), 11 deletions(-) diff --git a/tests/test_call_video_playout.c b/tests/test_call_video_playout.c index 99e9896c..e200c79f 100644 --- a/tests/test_call_video_playout.c +++ b/tests/test_call_video_playout.c @@ -95,7 +95,8 @@ static void test_combined(void) { int head = 0, shown = 0, dropped = 0; int64_t last = -1, audio = origin - 1000; for (int64_t now = origin; now < origin + 10000000 && head < 400; now += 1000) { - audio += now >= origin + 4000000 && now < origin + 4200000 ? 1600 : 1000; + if (now < origin + 4200000 || now >= origin + 4320000) + audio += now >= origin + 4000000 && now < origin + 4200000 ? 1600 : 1000; if (now >= origin + 2000000 && now < origin + 2080000) continue; int valid = now < origin + 3000000 || now >= origin + 3100000; for (;;) { @@ -114,8 +115,9 @@ static void test_combined(void) { if (action == SHOW) break; } } + DEBUG_INFO(DEBUG_CATEGORY_CALL, "playout combined simulation consumed=%d shown=%d dropped=%d", head, shown, dropped); CHECK(head == 400 && shown > 300 && dropped > 0); - DEBUG_INFO(DEBUG_CATEGORY_CALL, "PASS playout: combined jitter/CPU/FPS/audio tempo simulation shown=%d dropped=%d", shown, dropped); + DEBUG_INFO(DEBUG_CATEGORY_CALL, "PASS playout: combined jitter/CPU/FPS/audio tempo simulation"); } int main(void) { diff --git a/tools/chatgui/tests/test_call_video_clock.cpp b/tools/chatgui/tests/test_call_video_clock.cpp index c89062de..c6d92162 100644 --- a/tools/chatgui/tests/test_call_video_clock.cpp +++ b/tools/chatgui/tests/test_call_video_clock.cpp @@ -9,6 +9,7 @@ #include #include #include +#include extern "C" { #include "../../../lib/mem.h" #include "../../../lib/debug_config.h" @@ -18,6 +19,7 @@ static call_video_format format{1, 640, 360, 30, 0, 1, 31, 4000000, 2}; static std::atomic requests{0}, rejects{0}; static int cursor = 0; static int64_t start; +static bool disturbed = false; static int64_t nowUs() { return std::chrono::duration_cast(std::chrono::steady_clock::now().time_since_epoch()).count(); } extern "C" int __wrap_call_audio_get_clock(uint64_t, int64_t now, call_clock_snapshot* out) { *out = {}; out->valid = out->measured = 1; out->pts_us = 1000000 + now - start; @@ -29,10 +31,13 @@ extern "C" int __wrap_call_video_port_status(uint64_t, struct call_video_port_st extern "C" void __wrap_call_video_port_request_key(uint64_t) { ++requests; } extern "C" int __wrap_call_video_port_decoded(uint64_t, uint64_t, int accepted) { if (!accepted) ++rejects; return 0; } extern "C" int __wrap_call_video_port_pull(uint64_t id, call_video_frame* out) { - if (cursor >= (int)frames.size() || nowUs() - start < cursor * 33333ll) return 0; + const int64_t received = start + cursor * 33333ll + (disturbed && cursor == 30 ? 20000 : 0); + if (cursor >= (int)frames.size() || nowUs() < received) return 0; + // Кадр уже пришёл: остановка RX worker не должна подменить время доступности данных. + if (disturbed && cursor == 60) QThread::msleep(80); const auto& f = frames[cursor]; *out = {}; out->call_id = id; out->format = format; out->pts_us = f.pts; out->frame_id = ++cursor; out->flags = f.key ? CALL_VIDEO_KEY : 0; - out->received_us = start + (cursor - 1) * 33333ll; + out->received_us = received; out->size = out->length = f.data.size(); auto* data = static_cast(u_malloc(out->size)); memcpy(data, f.data.constData(), out->size); out->data = data; return 1; } @@ -46,11 +51,27 @@ int main(int argc, char** argv) { if (!encoder.encode(image, 1000000 + i * 33333ll, i == 0, frame, completion)) return 3; frames.push_back(frame); } - int shown = 0; CallVideoEngine engine; - QObject::connect(&engine, &CallVideoEngine::imageChanged, [&](const QImage& frame) { if (!frame.isNull()) ++shown; }); - start = nowUs(); engine.start(7); QElapsedTimer timer; timer.start(); - while (timer.elapsed() < 3200) { app.processEvents(); QThread::msleep(2); } - engine.stop(); - fprintf(stderr, "CLOCK PROBE shown=%d/90 key_requests=%d decoder_rejections=%d audio_epochs=32\n", shown, requests.load(), rejects.load()); - return shown >= 85 && requests == 0 && rejects == 0 ? 0 : 1; + CallVideoEngine engine; std::vector published; + QObject::connect(&engine, &CallVideoEngine::imageChanged, [&](const QImage& frame) { + if (!frame.isNull()) published.push_back(nowUs()); + }); + for (int scenario = 0; scenario < 2; ++scenario) { + disturbed = scenario != 0; cursor = 0; published.clear(); + start = nowUs(); engine.start(7); QElapsedTimer timer; timer.start(); bool uiPaused = false; + while (timer.elapsed() < 3200) { + if (disturbed && !uiPaused && timer.elapsed() >= 1500) { QThread::msleep(60); uiPaused = true; } + app.processEvents(); QThread::msleep(2); + } + engine.stop(); const auto stoppedCount = published.size(); app.processEvents(); + if (published.size() != stoppedCount) { DEBUG_ERROR(DEBUG_CATEGORY_CALL, "stale video publication after stop"); return 1; } + std::vector gaps; + for (size_t i = 1; i < published.size(); ++i) gaps.push_back(published[i] - published[i - 1]); + std::sort(gaps.begin(), gaps.end()); + DEBUG_INFO(DEBUG_CATEGORY_CALL, "CLOCK PROBE disturbed=%d shown=%zu/90 key_requests=%d decoder_rejections=%d " + "gap_p50_us=%lld gap_p95_us=%lld gap_max_us=%lld audio_epochs=32", disturbed, published.size(), requests.load(), rejects.load(), + (long long)(gaps.empty() ? 0 : gaps[gaps.size() / 2]), (long long)(gaps.empty() ? 0 : gaps[gaps.size() * 95 / 100]), + (long long)(gaps.empty() ? 0 : gaps.back())); + if (published.size() < (disturbed ? 82u : 85u) || requests || rejects) return 1; + } + return 0; }