From 6f542bfae9fee2e2ea00651919cbb2505305840f Mon Sep 17 00:00:00 2001 From: evgeny Date: Mon, 19 Oct 2026 21:13:21 +0200 Subject: [PATCH] Test video timing with slow decoder and missing presentation ACK --- tools/chatgui/CMakeLists.txt | 6 +-- tools/chatgui/tests/test_call_video_clock.cpp | 49 ++++++++++++++++--- 2 files changed, 45 insertions(+), 10 deletions(-) diff --git a/tools/chatgui/CMakeLists.txt b/tools/chatgui/CMakeLists.txt index ec71ee6e..108c40d0 100644 --- a/tools/chatgui/CMakeLists.txt +++ b/tools/chatgui/CMakeLists.txt @@ -167,12 +167,12 @@ if(FFMPEG_FOUND) set_tests_properties(test_call_video_gpu PROPERTIES TIMEOUT 60) add_executable(test_call_video_clock tests/test_call_video_clock.cpp src/call_video_engine.cpp) target_link_libraries(test_call_video_clock PRIVATE chatgui_live_video) - foreach(symbol call_audio_get_clock call_video_port_open call_video_port_close call_video_port_status - call_video_port_pull call_video_port_request_key call_video_port_decoded) + foreach(symbol call_audio_try_clock call_video_port_received call_video_port_open call_video_port_close call_video_port_status + call_video_port_pull call_video_port_request_key call_video_port_decoded avcodec_receive_frame) target_link_options(test_call_video_clock PRIVATE "-Wl,--wrap=${symbol}") endforeach() add_test(NAME test_call_video_clock COMMAND test_call_video_clock) - set_tests_properties(test_call_video_clock PROPERTIES TIMEOUT 15) + set_tests_properties(test_call_video_clock PROPERTIES TIMEOUT 30) endif() endif() add_library(chatgui_camera STATIC src/call_camera_capture.cpp src/call_camera_worker.cpp src/call_camera_source.h) diff --git a/tools/chatgui/tests/test_call_video_clock.cpp b/tools/chatgui/tests/test_call_video_clock.cpp index c4eca25d..88f856ab 100644 --- a/tools/chatgui/tests/test_call_video_clock.cpp +++ b/tools/chatgui/tests/test_call_video_clock.cpp @@ -10,9 +10,11 @@ #include #include #include +#include extern "C" { #include "../../../lib/mem.h" #include "../../../lib/debug_config.h" +#include } static std::vector frames; static call_video_format format{1, 640, 360, 30, 0, 1, 31, 4000000, 2}; @@ -20,14 +22,35 @@ static std::atomic requests{0}, rejects{0}; static std::atomic cursor{0}; static int64_t start; static bool disturbed = false; +static bool slowDecoder = false, holdAck = false; +static std::atomic displayThread{0}; +static std::atomic unsafeTimer{false}; +static size_t threadId() { return std::hash{}(std::this_thread::get_id()); } 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) { +extern "C" int __real_avcodec_receive_frame(AVCodecContext*, AVFrame*); +extern "C" int __wrap_avcodec_receive_frame(AVCodecContext* codec, AVFrame* frame) { + if (threadId() == displayThread.load()) unsafeTimer = true; + int result = __real_avcodec_receive_frame(codec, frame); + if (!result && slowDecoder && frame->pts >= 1000000 && (frame->pts - 1000000) / 33333 % 3 == 0) QThread::msleep(12); + return result; +} +extern "C" int __wrap_call_audio_try_clock(uint64_t, int64_t now, call_clock_snapshot* out) { + displayThread = threadId(); + if (disturbed && (now - start) % 20000 < 1500) return 0; *out = {}; out->valid = out->measured = 1; out->pts_us = 1000000 + now - start; - out->source_epoch = (now - start) / 100000 + 1; return 0; + out->source_epoch = (now - start) / 100000 + 1; return 1; +} +extern "C" uint64_t __wrap_call_video_port_received(uint64_t) { + unsigned count = 0; + for (; count < frames.size(); ++count) { + if (start + count * 33333ll + (disturbed && count == 30 ? 20000 : 0) > nowUs()) break; + } + return count; } extern "C" int __wrap_call_video_port_open(uint64_t, const call_video_caps*) { return 0; } extern "C" void __wrap_call_video_port_close(uint64_t) {} extern "C" int __wrap_call_video_port_status(uint64_t, struct call_video_port_status* out) { + if (threadId() == displayThread.load()) unsafeTimer = true; *out = {}; unsigned available = 0; for (unsigned i = cursor.load(); i < frames.size(); ++i) { @@ -40,6 +63,7 @@ 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 (threadId() == displayThread.load()) unsafeTimer = true; const int64_t received = start + cursor * 33333ll + (disturbed && cursor == 30 ? 20000 : 0); if (cursor >= (int)frames.size() || nowUs() < received) return 0; // Кадр уже пришёл: остановка RX worker не должна подменить время доступности данных. @@ -63,14 +87,15 @@ int main(int argc, char** argv) { CallVideoEngine engine; engine.setPresentationDriven(true); std::vector published, presented; QObject::connect(&engine, &CallVideoEngine::imageChanged, [&](const QImage& frame, quint64 serial) { if (!frame.isNull()) published.push_back(nowUs()); + if (holdAck) return; // Подтверждение потребления отдельно от доставки signal, как paintEvent окна. QTimer::singleShot(5, &engine, [&, serial, video = !frame.isNull()] { if (video) presented.push_back(nowUs()); engine.imagePresented(serial); }); }); - for (int scenario = 0; scenario < 2; ++scenario) { - disturbed = scenario != 0; cursor = 0; published.clear(); presented.clear(); + for (int scenario = 0; scenario < 3; ++scenario) { + disturbed = scenario == 1; slowDecoder = scenario == 2; cursor = 0; published.clear(); presented.clear(); displayThread = 0; start = nowUs(); engine.start(7); QElapsedTimer timer; timer.start(); bool uiPaused = false; while (timer.elapsed() < 4000) { if (disturbed && !uiPaused && timer.elapsed() >= 1500) { QThread::msleep(60); uiPaused = true; } @@ -82,14 +107,24 @@ int main(int argc, char** argv) { std::vector gaps; for (size_t i = 1; i < presented.size(); ++i) gaps.push_back(presented[i] - presented[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 stop_us=%lld", disturbed, presented.size(), requests.load(), rejects.load(), + DEBUG_INFO(DEBUG_CATEGORY_CALL, "CLOCK PROBE disturbed=%d slow_decoder=%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 stop_us=%lld", disturbed, slowDecoder, presented.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()), (long long)stopUs); - if (published.size() != frames.size() || presented.size() != frames.size() || requests || rejects || stopUs > 250000) return 1; + if (published.size() != frames.size() || presented.size() != frames.size() || requests || rejects || unsafeTimer || stopUs > 250000) return 1; if (!disturbed && (gaps.empty() || gaps[gaps.size() * 95 / 100] > 45000)) { DEBUG_ERROR(DEBUG_CATEGORY_CALL, "steady video presentation jitter exceeds 45ms at 30fps"); return 1; } } + // Без ACK первый слот остаётся занятым; producer может заполнить только два следующих. + slowDecoder = disturbed = false; holdAck = true; cursor = 0; published.clear(); presented.clear(); displayThread = 0; + start = nowUs(); engine.start(7); QElapsedTimer stalled; stalled.start(); + while (stalled.elapsed() < 250) { app.processEvents(); QThread::msleep(1); } + if (published.size() != 1 || cursor != 3) { + DEBUG_ERROR(DEBUG_CATEGORY_CALL, "video ACK capacity failed published=%zu decoder_inputs=%d", published.size(), cursor.load()); return 1; + } + const int64_t stopAt = nowUs(); engine.stop(); app.processEvents(); + if (nowUs() - stopAt > 250000 || unsafeTimer) return 1; + DEBUG_INFO(DEBUG_CATEGORY_CALL, "PASS stop without GUI ACK: one selected + two ready, decoder and port never run on display thread"); return 0; }