From a9b91145a69ab0b0bb771dcf98cece0186bf7f0d Mon Sep 17 00:00:00 2001 From: evgeny Date: Mon, 19 Oct 2026 17:39:54 +0200 Subject: [PATCH] Document sequential presentation diagnostics and simplify GUI frame ownership --- doc/chat_call_arch.md | 18 ++-- tools/chatgui/src/call_video_engine.cpp | 47 ++++------ tools/chatgui/src/live_video_encoder.cpp | 108 +++++++++++------------ 3 files changed, 81 insertions(+), 92 deletions(-) diff --git a/doc/chat_call_arch.md b/doc/chat_call_arch.md index 9f326284..389916b1 100644 --- a/doc/chat_call_arch.md +++ b/doc/chat_call_arch.md @@ -226,20 +226,18 @@ Backend публикует только числовой снимок в огр `AudioDiag: audio timing` для стадий `callback`/`write` при `call=debug` показывает интервалы callback и время блокирующей передачи в WASAPI. HRESULT ошибок и потери диагностической очереди логируются. Снимки только наблюдают: Windows-аудиочасы остаются `callback-estimate` (`measured=0`). -- `video late drop`: первый пропущенный за секунду кадр, его PTS, audio PTS, отставание, - возраст от приёма до решения и абсолютные сроки. `video playout` агрегирует `late_av_us` - и `late_rx_age_us` всех поздних кадров; порог пропуска остаётся 50мс. +- `video playout`: показанные кадры, `speed_ppm`, диапазон A/V-фазы, интервалы показа, + опоздание worker и ожидания аудиочасов. Опоздание кадра не вызывает пропуск; догон до 1.6x. - Desktop `video RX worker`: число декодированных кадров, максимальное время декодирования, возраст кадра после декодирования и опоздание пробуждения worker после sleep. Снимок аудио содержит `audio_measured`, PTS и позиции played/written. Все эти строки относятся к `call=debug`; `video=trace` для этой диагностики не требуется. -- `video GUI delivery`: выбранные изображения, доставленные в GUI, число замен до исполнения - уведомления и максимальные ожидание уведомления/промежуток доставки. В `stage=publish` - `ui_wait_us` считается от постановки уведомления, `selected_age_us` — от последней замены кадра. - Малый возраст последнего кадра сам по себе не исключает паузу GUI и замену предыдущих кадров. -- `video port TX frames released` и `TX mailbox busy` показывают фактическую потерю готовых - encoded кадров при отказе отправки. Это отдельный путь от пропуска уже декодированного показа; - диагностика сохраняет действующее поведение отказа и запроса KEY. +- `video GUI delivery`: доставленные изображения, ожидание уведомления, промежуток доставки, + `paint_wait_max_us` до подтверждения рисования. В GUI один ожидающий кадр, замены нет. +- `video port TX paused/resumed`: сохранённый хвост пачки, первый ID, длительность ожидания + и число повторов. Busy сохраняет encoded-кадры и не запрашивает KEY. +- `video port RX full/drained`: заполнение и полная разгрузка encoded FIFO перед возобновлением + приёма. Hysteresis переносит ограничение до новых входов sender encoder, освобождая запас для догона. - `call audio TX timing`: ожидание g_mtx, обработка/кодирование под ним, ожидание posted task; post включает ожидание lock при выполнении задачи, его разрешение 100мкс. На Android этот же замер обработки включает программный AEC, на desktop AEC уже выполнен в capture worker. diff --git a/tools/chatgui/src/call_video_engine.cpp b/tools/chatgui/src/call_video_engine.cpp index 34d31311..9891e19e 100644 --- a/tools/chatgui/src/call_video_engine.cpp +++ b/tools/chatgui/src/call_video_engine.cpp @@ -32,17 +32,14 @@ struct CallVideoEngine::Impl { QByteArray cameraId; bool captureActive = false; uint64_t captured = 0; - QImage shown; - int64_t shownPts = -1; uint64_t publicationEpoch = 0; bool publicationPending = false; bool presentationDriven = false; uint64_t publicationSerial = 0; - unsigned publicationOverwritten = 0; // Только под lock: выбранные кадры, заменённые до GUI callback. int64_t publicationQueuedAt = 0; - int64_t shownAt = 0; + int64_t paintWaitMax = 0; // Только под lock: время до подтверждения рисования. int64_t uiReportAt = 0, uiLastAt = 0, uiWaitMax = 0, uiGapMax = 0; // Только GUI-поток. - unsigned uiPublished = 0, uiOverwritten = 0; + unsigned uiPublished = 0; int64_t previewReportAt = 0, previewMaxUs = 0; unsigned previewFrames = 0; QString status; @@ -95,56 +92,50 @@ void CallVideoEngine::setPresentationDriven(bool enabled) { } void CallVideoEngine::imagePresented(quint64 serial) { { std::lock_guard guard(m->lock); - if (serial != m->publicationSerial) return; + if (!m->publicationPending || serial != m->publicationSerial) return; + m->paintWaitMax = std::max(m->paintWaitMax, nowUs() - m->publicationQueuedAt); m->publicationPending = false; } m->wake.notify_all(); } // Только один кадр до подтверждения рисования: GUI не заменяет ещё не показанное изображение. void CallVideoEngine::publishImage(const QImage& image, int64_t pts) { - uint64_t epoch, serial; + uint64_t epoch, serial; int64_t queued; { std::unique_lock guard(m->lock); m->wake.wait(guard, [this] { return !m->running || !m->publicationPending; }); if (!m->running) return; - m->shown = image; m->shownPts = pts; m->shownAt = nowUs(); - m->publicationPending = true; m->publicationQueuedAt = m->shownAt; epoch = m->publicationEpoch; + m->publicationPending = true; queued = m->publicationQueuedAt = nowUs(); epoch = m->publicationEpoch; serial = ++m->publicationSerial; } - QMetaObject::invokeMethod(this, [this, epoch, serial] { - QImage image; int64_t pts, selected, queued; unsigned overwritten; + QMetaObject::invokeMethod(this, [this, epoch, serial, image, pts, queued] { { std::lock_guard guard(m->lock); if (epoch != m->publicationEpoch) return; - image = m->shown; pts = m->shownPts; selected = m->shownAt; queued = m->publicationQueuedAt; - overwritten = m->publicationOverwritten; m->publicationOverwritten = 0; } + } const int64_t now = nowUs(), wait = now - queued; ++m->uiPublished; m->uiWaitMax = std::max(m->uiWaitMax, wait); if (m->uiLastAt) m->uiGapMax = std::max(m->uiGapMax, now - m->uiLastAt); m->uiLastAt = now; - if (overwritten && !m->uiOverwritten) - DEBUG_WARN(DEBUG_CATEGORY_CALL, "video GUI coalesced call=%llu overwritten=%u notification_wait_us=%lld " - "selected_age_us=%lld pts=%lld mono_us=%lld", (unsigned long long)m->id, overwritten, - (long long)wait, (long long)(now - selected), (long long)pts, (long long)now); - m->uiOverwritten += overwritten; emit imageChanged(image, serial); bool driven; { std::lock_guard guard(m->lock); driven = m->presentationDriven; } if (!driven || image.isNull()) imagePresented(serial); if (!m->uiReportAt) m->uiReportAt = now; if (now - m->uiReportAt >= 1000000) { - DEBUG_DEBUG(DEBUG_CATEGORY_CALL, "video GUI delivery call=%llu interval_us=%lld published=%u overwritten=%u " - "notification_wait_max_us=%lld delivery_gap_max_us=%lld mono_us=%lld", - (unsigned long long)m->id, (long long)(now - m->uiReportAt), m->uiPublished, m->uiOverwritten, - (long long)m->uiWaitMax, (long long)m->uiGapMax, (long long)now); - m->uiReportAt = now; m->uiPublished = m->uiOverwritten = 0; m->uiWaitMax = m->uiGapMax = 0; + int64_t paintWait; + { std::lock_guard guard(m->lock); paintWait = m->paintWaitMax; m->paintWaitMax = 0; } + DEBUG_DEBUG(DEBUG_CATEGORY_CALL, "video GUI delivery call=%llu interval_us=%lld published=%u " + "notification_wait_max_us=%lld delivery_gap_max_us=%lld paint_wait_max_us=%lld mono_us=%lld", + (unsigned long long)m->id, (long long)(now - m->uiReportAt), m->uiPublished, + (long long)m->uiWaitMax, (long long)m->uiGapMax, (long long)paintWait, (long long)now); + m->uiReportAt = now; m->uiPublished = 0; m->uiWaitMax = m->uiGapMax = 0; } if (!image.isNull() && pts >= 0 && pts % 1000000 < 34000) - DEBUG_DEBUG(DEBUG_CATEGORY_CALL, "video timing stage=publish call=%llu pts=%lld mono_us=%lld ui_wait_us=%lld " - "selected_age_us=%lld overwritten=%u", (unsigned long long)m->id, (long long)pts, - (long long)now, (long long)wait, (long long)(now - selected), overwritten); + DEBUG_DEBUG(DEBUG_CATEGORY_CALL, "video timing stage=publish call=%llu pts=%lld mono_us=%lld ui_wait_us=%lld", + (unsigned long long)m->id, (long long)pts, (long long)now, (long long)wait); }, Qt::QueuedConnection); } void CallVideoEngine::start(quint64 id) { if (m->running && m->id == id) return; stop(); m->id = id; m->running = true; m_timer.start(); - m->uiReportAt = m->uiLastAt = m->uiWaitMax = m->uiGapMax = 0; m->uiPublished = m->uiOverwritten = 0; + m->uiReportAt = m->uiLastAt = m->uiWaitMax = m->uiGapMax = 0; m->uiPublished = 0; try { m->tx = std::thread(&CallVideoEngine::transmit, this); m->rx = std::thread(&CallVideoEngine::receive, this); } catch (const std::exception& error) { DEBUG_ERROR(DEBUG_CATEGORY_CALL, "video worker start: %s", error.what()); stop(); emit statusChanged(error.what()); } } @@ -163,7 +154,7 @@ void CallVideoEngine::stop() { if (m->rx.joinable()) m->rx.join(); if (m->id) call_video_port_close(m->id); { std::lock_guard guard(m->lock); - ++m->publicationEpoch; m->publicationPending = false; m->publicationOverwritten = 0; m->shown = {}; m->shownPts = -1; } + ++m->publicationEpoch; m->publicationPending = false; m->paintWaitMax = 0; } m->id = 0; m->enabled = false; emit imageChanged({}, 0); } void CallVideoEngine::setVideo(bool enabled, const QByteArray& cameraId, int width, int height, int codec) { diff --git a/tools/chatgui/src/live_video_encoder.cpp b/tools/chatgui/src/live_video_encoder.cpp index f9f90af4..00cbcd01 100644 --- a/tools/chatgui/src/live_video_encoder.cpp +++ b/tools/chatgui/src/live_video_encoder.cpp @@ -386,61 +386,61 @@ bool LiveVideoEncoder::encode(const QImage& image, uint64_t pts, bool key, QList const bool constrained = m->config.profile != LiveVideoProfile::Automatic; qint64 preparedUs = 0, submittedUs = 0; if (!image.isNull()) { - QImage canvas(m->config.width, m->config.height, QImage::Format_RGB32); canvas.fill(Qt::black); - QSize fitted = image.size().scaled(canvas.size(), Qt::KeepAspectRatio); - { QPainter painter(&canvas); painter.drawImage(QRect(QPoint((canvas.width() - fitted.width()) / 2, - (canvas.height() - fitted.height()) / 2), fitted), image); } - result = av_frame_make_writable(m->frame); - m->scale = sws_getCachedContext(m->scale, canvas.width(), canvas.height(), AV_PIX_FMT_RGB32, - m->frame->width, m->frame->height, static_cast(m->frame->format), SWS_FAST_BILINEAR, nullptr, nullptr, nullptr); - if (!m->scale) result = AVERROR(ENOMEM); - if (result >= 0) { - const int* coefficients = sws_getCoefficients(SWS_CS_ITU709); - sws_setColorspaceDetails(m->scale, coefficients, 1, coefficients, 0, 0, 1 << 16, 1 << 16); - const uint8_t* input[4] = {canvas.constBits(), nullptr, nullptr, nullptr}; - int stride[4] = {static_cast(canvas.bytesPerLine()), 0, 0, 0}; - result = sws_scale(m->scale, input, stride, 0, canvas.height(), m->frame->data, m->frame->linesize); - } - if (result >= 0 && m->reportTimer.elapsed() >= 1000 && debug_should_output(DEBUG_LEVEL_TRACE, DEBUG_CATEGORY_DEBUG) - && (m->frame->format == AV_PIX_FMT_NV12 || m->frame->format == AV_PIX_FMT_YUV420P)) { - uint64_t edges = 0, samples = 0; - int minimum = 255, maximum = 0; - for (int y = 0; y + 1 < m->frame->height; y += 16) { - const uint8_t* row = m->frame->data[0] + y * m->frame->linesize[0]; - for (int x = 0; x + 1 < m->frame->width; x += 16) { - int value = row[x]; minimum = std::min(minimum, value); maximum = std::max(maximum, value); - edges += std::abs(value - row[x + 1]) + std::abs(value - row[x + m->frame->linesize[0]]); samples += 2; - } + QImage canvas(m->config.width, m->config.height, QImage::Format_RGB32); canvas.fill(Qt::black); + QSize fitted = image.size().scaled(canvas.size(), Qt::KeepAspectRatio); + { QPainter painter(&canvas); painter.drawImage(QRect(QPoint((canvas.width() - fitted.width()) / 2, + (canvas.height() - fitted.height()) / 2), fitted), image); } + result = av_frame_make_writable(m->frame); + m->scale = sws_getCachedContext(m->scale, canvas.width(), canvas.height(), AV_PIX_FMT_RGB32, + m->frame->width, m->frame->height, static_cast(m->frame->format), SWS_FAST_BILINEAR, nullptr, nullptr, nullptr); + if (!m->scale) result = AVERROR(ENOMEM); + if (result >= 0) { + const int* coefficients = sws_getCoefficients(SWS_CS_ITU709); + sws_setColorspaceDetails(m->scale, coefficients, 1, coefficients, 0, 0, 1 << 16, 1 << 16); + const uint8_t* input[4] = {canvas.constBits(), nullptr, nullptr, nullptr}; + int stride[4] = {static_cast(canvas.bytesPerLine()), 0, 0, 0}; + result = sws_scale(m->scale, input, stride, 0, canvas.height(), m->frame->data, m->frame->linesize); } - DEBUG_TRACE(DEBUG_CATEGORY_DEBUG, - "video encoder input name=%s pts=%llu source=%dx%d encoded=%dx%d pixel=%d luma_min=%d luma_max=%d edge_x1000=%llu", - qPrintable(m->name), (unsigned long long)pts, image.width(), image.height(), m->frame->width, m->frame->height, - m->frame->format, minimum, maximum, (unsigned long long)(samples ? edges * 1000 / samples : 0)); - } - if (constrained && m->timestamps.size() >= 8) { - m->error = "GPU encoder exceeded the bounded input pipeline"; - DEBUG_ERROR(DEBUG_CATEGORY_VIDEO, "call encoder stalled name=%s pending=%zu pts=%llu", - qPrintable(m->name), m->timestamps.size(), (unsigned long long)pts); return false; - } - bool forceKey = key && (m->forcedKeys || m->submittedFrames == 0); - m->frame->pts = av_rescale_q(static_cast(pts), AVRational{1, 1000000}, m->codec->time_base); - m->frame->pict_type = forceKey ? AV_PICTURE_TYPE_I : AV_PICTURE_TYPE_NONE; - if (forceKey) m->frame->flags |= AV_FRAME_FLAG_KEY; else m->frame->flags &= ~AV_FRAME_FLAG_KEY; - AVFrame* hardware = nullptr; - if (result >= 0 && m->codec->hw_frames_ctx) { - hardware = av_frame_alloc(); - result = hardware ? av_hwframe_get_buffer(m->codec->hw_frames_ctx, hardware, 0) : AVERROR(ENOMEM); - if (result >= 0) result = av_hwframe_transfer_data(hardware, m->frame, 0); - if (result >= 0) result = av_frame_copy_props(hardware, m->frame); - } - preparedUs = timer.nsecsElapsed() / 1000; - if (result >= 0) result = avcodec_send_frame(m->codec, hardware ? hardware : m->frame); - submittedUs = timer.nsecsElapsed() / 1000; - if (result >= 0) { - m->submittedFrames++; - if (constrained) m->timestamps.emplace_back(m->frame->pts, pts); - } - av_frame_free(&hardware); + if (result >= 0 && m->reportTimer.elapsed() >= 1000 && debug_should_output(DEBUG_LEVEL_TRACE, DEBUG_CATEGORY_DEBUG) + && (m->frame->format == AV_PIX_FMT_NV12 || m->frame->format == AV_PIX_FMT_YUV420P)) { + uint64_t edges = 0, samples = 0; + int minimum = 255, maximum = 0; + for (int y = 0; y + 1 < m->frame->height; y += 16) { + const uint8_t* row = m->frame->data[0] + y * m->frame->linesize[0]; + for (int x = 0; x + 1 < m->frame->width; x += 16) { + int value = row[x]; minimum = std::min(minimum, value); maximum = std::max(maximum, value); + edges += std::abs(value - row[x + 1]) + std::abs(value - row[x + m->frame->linesize[0]]); samples += 2; + } + } + DEBUG_TRACE(DEBUG_CATEGORY_DEBUG, + "video encoder input name=%s pts=%llu source=%dx%d encoded=%dx%d pixel=%d luma_min=%d luma_max=%d edge_x1000=%llu", + qPrintable(m->name), (unsigned long long)pts, image.width(), image.height(), m->frame->width, m->frame->height, + m->frame->format, minimum, maximum, (unsigned long long)(samples ? edges * 1000 / samples : 0)); + } + if (constrained && m->timestamps.size() >= 8) { + m->error = "GPU encoder exceeded the bounded input pipeline"; + DEBUG_ERROR(DEBUG_CATEGORY_VIDEO, "call encoder stalled name=%s pending=%zu pts=%llu", + qPrintable(m->name), m->timestamps.size(), (unsigned long long)pts); return false; + } + bool forceKey = key && (m->forcedKeys || m->submittedFrames == 0); + m->frame->pts = av_rescale_q(static_cast(pts), AVRational{1, 1000000}, m->codec->time_base); + m->frame->pict_type = forceKey ? AV_PICTURE_TYPE_I : AV_PICTURE_TYPE_NONE; + if (forceKey) m->frame->flags |= AV_FRAME_FLAG_KEY; else m->frame->flags &= ~AV_FRAME_FLAG_KEY; + AVFrame* hardware = nullptr; + if (result >= 0 && m->codec->hw_frames_ctx) { + hardware = av_frame_alloc(); + result = hardware ? av_hwframe_get_buffer(m->codec->hw_frames_ctx, hardware, 0) : AVERROR(ENOMEM); + if (result >= 0) result = av_hwframe_transfer_data(hardware, m->frame, 0); + if (result >= 0) result = av_frame_copy_props(hardware, m->frame); + } + preparedUs = timer.nsecsElapsed() / 1000; + if (result >= 0) result = avcodec_send_frame(m->codec, hardware ? hardware : m->frame); + submittedUs = timer.nsecsElapsed() / 1000; + if (result >= 0) { + m->submittedFrames++; + if (constrained) m->timestamps.emplace_back(m->frame->pts, pts); + } + av_frame_free(&hardware); } else if (finish) result = avcodec_send_frame(m->codec, nullptr); AVPacket* packet = av_packet_alloc(); if (!packet) result = AVERROR(ENOMEM);