Diagnose decoder work crossing video presentation deadlines

doc/call_video.txt

@@ -1116,3 +1116,31 @@ Qt bothOrientations кодирует и декодирует H.264/H.265 при
 проверяя поколения и PTS. Аппаратный probe на SM и Q8 проходит с INSTRUMENTATION_CODE: 0;
 дополнительно выбирает реальные проверенные режимы в обеих ориентациях через общий C CAPS/JNI.
 Это локальные codec-проверки, живой межплатформенный звонок новой пары сборок ещё не проверен.
+
+Windows 2.log, неравномерность показа, 19.10.2026
+На 136 стабильных секундных интервалах shown/interval даёт 30.09fps; drop_order=0,
+обычный общий запас — 2-3 кадра. В живом потоке выбран D3D11VA, а threads=1 относится
+к аппаратному backend. Это не однопоточный программный decoder.
+
+Сравнение устойчивых участков 21:40:51-21:41:37 (480x640) и 21:41:55-21:42:31 (720x1280):
+медиана секундных decode_max_us растёт 4450 -> 10111, convert_max_us — 2229 -> 6744,
+dispatch_max_us — 3079 -> 7311. При этом wake_late_max_us — 1076 -> 1045,
+GUI paint_max_us — 3505 -> 2947, notification_wait_max_us — 434 -> 422.
+Это медианы максимумов окон, а не средние длительности отдельных кадров.
+
+RX worker выполняет decoder.submit/receive (включая GPU transfer/RGB/rotation) в том же
+потоке, что и playout.poll/publishImage. Готовая голова может пропустить назначенный срок
+во время подготовки следующего кадра. Для прямой проверки добавлена секундная диагностика:
+decode_deadline_misses — число операций decoder, начавшихся до срока готовой головы и
+завершившихся после него; decode_deadline_max_us — наибольшее такое опоздание;
+decode_deadline_stage=input/output, work_us и margin_us описывают именно эту операцию.
+Ожидание аудио, GUI ACK и отсутствие назначенной готовой головы исключены из счётчика.
+Фильтр — call=debug; алгоритм, лимиты очередей и порядок кадров не менялись.
+
+Есть отдельная граница достоверности: desktop ACK отправляется в конце paintEvent,
+до подтверждённой презентации окна. По этим метрикам нельзя измерить scanout или признать
+доказанной потерю кадров композитором. Текущая формула срока следующего кадра использует
+предыдущий ACK плюс шаг минус сглаженный dispatch lead; индивидуальные задержки рисования
+тем самым влияют на расписание. Для устранения зависимости нужны независимое исполнение
+decoder/планировщика и синхронизация presentation с обновлением дисплея; обычный таймер
+и ранний ACK из QPainter не дают такой гарантии.

tools/chatgui/src/call_video_engine.cpp

@@ -394,6 +394,22 @@ void CallVideoEngine::receive() {
     call_video_frame input{};
     bool wakeBound = false, waitingKey = false;
     int64_t decoderProgressAt = nowUs();
+    unsigned decodeDeadlineMisses = 0;
+    int64_t decodeDeadlineMax = 0, decodeDeadlineWork = 0, decodeDeadlineMargin = 0;
+    const char* decodeDeadlineStage = "none";
+    auto recordDeadlineWork = [&](const char* stage, int64_t started, int64_t finished) {
+        // Только уже назначенный показ: ожидание аудио и отсутствие готовой головы сюда не относятся.
+        if (pictures.empty() || playout.awaiting || !playout.audio_valid
+            || playout.head_pts != pictures.front().timing.pts_us || playout.deadline_us != playout.head_due_us
+            || started >= playout.head_due_us || finished <= playout.head_due_us) return;
+        ++decodeDeadlineMisses;
+        if (finished - playout.head_due_us > decodeDeadlineMax) {
+            decodeDeadlineMax = finished - playout.head_due_us; decodeDeadlineWork = finished - started;
+            decodeDeadlineMargin = playout.head_due_us - started; decodeDeadlineStage = stage;
+        }
+    };
+    DEBUG_INFO(DEBUG_CATEGORY_CALL, "video RX scheduling call=%llu decoder_and_playout_shared=1 ready_capacity=3 "
+        "deadline_overlap_diagnostics=1", (unsigned long long)m->id);
     while (m->running) {
         const uint64_t ticket = m->rxWake.ticket();
         if (requestedWake) wakeLateMax = std::max(wakeLateMax, nowUs() - requestedWake);
@@ -422,7 +438,8 @@ void CallVideoEngine::receive() {
         while (pictures.size() + playout.awaiting < 3 && m->running) {
             call_video_frame packet{}; QImage image;
             const int64_t started = nowUs(); int result = decoder.receive(packet, image);
-            decodeMax = std::max(decodeMax, nowUs() - started);
+            const int64_t finished = nowUs();
+            decodeMax = std::max(decodeMax, finished - started); recordDeadlineWork("output", started, finished);
             if (!result && !playout.awaiting && pictures.empty() && decoder.pendingFrames() > decoder.pipelineFrames()
                 && nowUs() - decoderProgressAt > 2000000) {
                 DEBUG_ERROR(DEBUG_CATEGORY_CALL, "video decoder stalled call=%llu pending=%u pipeline=%u progress_age_us=%lld",
@@ -452,7 +469,8 @@ void CallVideoEngine::receive() {
                 }
                 const int64_t started = nowUs();
                 int result = decoder.submit(input);
-                decodeMax = std::max(decodeMax, nowUs() - started);
+                const int64_t finished = nowUs();
+                decodeMax = std::max(decodeMax, finished - started); recordDeadlineWork("input", started, finished);
                 if (result) {
                     worked = true;
                     if (result > 0) {
@@ -479,13 +497,17 @@ void CallVideoEngine::receive() {
         if (now - reportAt >= 1000000) {
             DEBUG_DEBUG(DEBUG_CATEGORY_CALL, "video RX worker call=%llu interval_us=%lld decoded=%u decode_max_us=%lld "
                 "rx_to_decode_max_us=%lld wake_late_max_us=%lld ready=%zu audio_valid=%d audio_measured=%d "
-                "audio_pts=%lld played=%llu written=%llu mono_us=%lld submitted=%u presented=%u encoded=%u inflight=%u total=%u",
+                "audio_pts=%lld played=%llu written=%llu mono_us=%lld submitted=%u presented=%u encoded=%u inflight=%u total=%u "
+                "decode_deadline_misses=%u decode_deadline_max_us=%lld decode_deadline_stage=%s "
+                "decode_deadline_work_us=%lld decode_deadline_margin_us=%lld",
                 (unsigned long long)m->id, (long long)(now - reportAt), decoded, (long long)decodeMax, (long long)rxAgeMax,
                 (long long)wakeLateMax, pictures.size(), clock.valid, clock.measured, (long long)clock.pts_us,
                 (unsigned long long)clock.played_samples, (unsigned long long)clock.written_samples, (long long)now,
-                submitted, acknowledged, status.rx_frames, decoder.pendingFrames(), total);
+                submitted, acknowledged, status.rx_frames, decoder.pendingFrames(), total, decodeDeadlineMisses,
+                (long long)decodeDeadlineMax, decodeDeadlineStage, (long long)decodeDeadlineWork, (long long)decodeDeadlineMargin);
             reportAt = now; decoded = 0; decodeMax = rxAgeMax = wakeLateMax = 0;
             submitted = acknowledged = 0;
+            decodeDeadlineMisses = 0; decodeDeadlineMax = decodeDeadlineWork = decodeDeadlineMargin = 0; decodeDeadlineStage = "none";
         }
         if (worked) { requestedWake = 0; continue; }
         // VIDEO_OFF пока отсутствует в протоколе: убираем застывшую картинку после прекращения показа.