diff --git a/tools/chatgui/src/call_video_engine.cpp b/tools/chatgui/src/call_video_engine.cpp index 44eae027..ac0c101b 100644 --- a/tools/chatgui/src/call_video_engine.cpp +++ b/tools/chatgui/src/call_video_engine.cpp @@ -39,6 +39,8 @@ struct CallVideoEngine::Impl { int64_t publicationQueuedAt = 0; int64_t paintWaitMax = 0; // Только под lock: время до подтверждения рисования. int64_t uiReportAt = 0, uiLastAt = 0, uiWaitMax = 0, uiGapMax = 0; // Только GUI-поток. + int64_t uiTickAt = 0, uiTickReportAt = 0, uiTickGapMax = 0, uiImageSlotMax = 0; + unsigned uiTicks = 0; unsigned uiPublished = 0; int64_t previewReportAt = 0, previewMaxUs = 0; unsigned previewFrames = 0; @@ -56,6 +58,18 @@ CallVideoEngine::CallVideoEngine(QObject* parent) : QObject(parent), m(std::make m_timer.setInterval(20); m_timer.setTimerType(Qt::PreciseTimer); connect(&m_timer, &QTimer::timeout, this, [this] { + const int64_t now = nowUs(), gap = m->uiTickAt ? now - m->uiTickAt : 0; + if (gap > 50000 && m->uiTickGapMax <= 50000) + DEBUG_WARN(DEBUG_CATEGORY_CALL, "video GUI loop delayed call=%llu tick_gap_us=%lld expected_us=20000 mono_us=%lld", + (unsigned long long)m->id, (long long)gap, (long long)now); + m->uiTickAt = now; m->uiTickGapMax = std::max(m->uiTickGapMax, gap); ++m->uiTicks; + if (!m->uiTickReportAt) m->uiTickReportAt = now; + if (now - m->uiTickReportAt >= 1000000) { + DEBUG_DEBUG(DEBUG_CATEGORY_CALL, "video GUI loop call=%llu interval_us=%lld ticks=%u tick_gap_max_us=%lld mono_us=%lld", + (unsigned long long)m->id, (long long)(now - m->uiTickReportAt), m->uiTicks, + (long long)m->uiTickGapMax, (long long)now); + m->uiTickReportAt = now; m->uiTicks = 0; m->uiTickGapMax = 0; + } QString status; bool report = false; { std::lock_guard guard(m->lock); if (m->statusDirty) { status = m->status; m->statusDirty = false; report = true; } } @@ -114,6 +128,11 @@ void CallVideoEngine::publishImage(const QImage& image, int64_t pts) { if (m->uiLastAt) m->uiGapMax = std::max(m->uiGapMax, now - m->uiLastAt); m->uiLastAt = now; emit imageChanged(image, serial); + const int64_t slotUs = nowUs() - now; + if (slotUs > 20000 && m->uiImageSlotMax <= 20000) + DEBUG_WARN(DEBUG_CATEGORY_CALL, "video GUI image slot slow call=%llu serial=%llu work_us=%lld mono_us=%lld", + (unsigned long long)m->id, (unsigned long long)serial, (long long)slotUs, (long long)now); + m->uiImageSlotMax = std::max(m->uiImageSlotMax, slotUs); bool driven; { std::lock_guard guard(m->lock); driven = m->presentationDriven; } if (!driven || image.isNull()) imagePresented(serial); @@ -122,10 +141,11 @@ void CallVideoEngine::publishImage(const QImage& image, int64_t pts) { 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", + "notification_wait_max_us=%lld delivery_gap_max_us=%lld paint_wait_max_us=%lld image_slot_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); + (long long)m->uiWaitMax, (long long)m->uiGapMax, (long long)paintWait, (long long)m->uiImageSlotMax, (long long)now); m->uiReportAt = now; m->uiPublished = 0; m->uiWaitMax = m->uiGapMax = 0; + m->uiImageSlotMax = 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", @@ -136,6 +156,7 @@ 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 = 0; + m->uiTickAt = m->uiTickReportAt = m->uiTickGapMax = m->uiImageSlotMax = 0; m->uiTicks = 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()); } } diff --git a/tools/chatgui/src/callwindow.cpp b/tools/chatgui/src/callwindow.cpp index 4d8ab95a..997e359a 100644 --- a/tools/chatgui/src/callwindow.cpp +++ b/tools/chatgui/src/callwindow.cpp @@ -4,6 +4,7 @@ #include "call_audio_engine.h" #include "call_video_engine.h" #include "../../../src/call/call_video_port.h" +#include "../../../src/call/call_video_playout.h" #include "sound_manager.h" #include @@ -46,7 +47,11 @@ public: QImage remote, local; CallVideoEngine* engine = nullptr; quint64 serial = 0; + quint64 callId = 0; + int64_t requestedAt = 0; // GUI-получение кадра -> начало paintEvent, отдельно от самой работы painter. protected: + void moveEvent(QMoveEvent* event) override { ++m_moves; QWidget::moveEvent(event); } + void resizeEvent(QResizeEvent* event) override { ++m_resizes; QWidget::resizeEvent(event); } void hideEvent(QHideEvent* event) override { presented(); QWidget::hideEvent(event); } void changeEvent(QEvent* event) override { QWidget::changeEvent(event); @@ -66,17 +71,47 @@ protected: QWidget::mouseDoubleClickEvent(event); } void paintEvent(QPaintEvent*) override { + const int64_t started = call_video_playout_now_us(), requestWait = serial && requestedAt ? started - requestedAt : 0; + const bool selected = serial != 0; QPainter painter(this); painter.fillRect(rect(), Qt::black); painter.setRenderHint(QPainter::SmoothPixmapTransform); if (remote.isNull()) return; QSize fitted = remote.size().scaled(size(), Qt::KeepAspectRatio); QRect videoRect(QPoint((width() - fitted.width()) / 2, (height() - fitted.height()) / 2), fitted); + const int64_t prepared = call_video_playout_now_us(); painter.drawImage(videoRect, remote); + const int64_t drawn = call_video_playout_now_us(); if (!local.isNull()) { QSize preview = local.size().scaled(qMin(200, fitted.width() / 4), qMin(150, fitted.height() / 4), Qt::KeepAspectRatio); QRect target(QPoint(videoRect.right() - preview.width() - 12, videoRect.top() + 12), preview); painter.setPen(QPen(Qt::white, 2)); painter.drawRect(target.adjusted(-1, -1, 1, 1)); painter.drawImage(target, local); } - painter.end(); presented(); + const int64_t overlay = call_video_playout_now_us(); + painter.end(); + const int64_t finished = call_video_playout_now_us(); + presented(); + ++m_paints; if (selected) ++m_selectedPaints; + m_requestMax = std::max(m_requestMax, requestWait); m_paintMax = std::max(m_paintMax, finished - started); + m_prepareMax = std::max(m_prepareMax, prepared - started); m_drawMax = std::max(m_drawMax, drawn - prepared); + m_overlayMax = std::max(m_overlayMax, overlay - drawn); m_finishMax = std::max(m_finishMax, finished - overlay); + if (!m_slowReported && (requestWait > 50000 || finished - started > 20000)) { + DEBUG_WARN(DEBUG_CATEGORY_CALL, "video GUI paint delayed call=%llu request_wait_us=%lld paint_us=%lld " + "prepare_us=%lld draw_us=%lld overlay_us=%lld finish_us=%lld window=%dx%d image=%dx%d dpr_x1000=%d mono_us=%lld", + (unsigned long long)callId, (long long)requestWait, (long long)(finished - started), + (long long)(prepared - started), (long long)(drawn - prepared), (long long)(overlay - drawn), + (long long)(finished - overlay), width(), height(), remote.width(), remote.height(), + int(devicePixelRatioF() * 1000), (long long)finished); + m_slowReported = true; + } + if (!m_reportAt) m_reportAt = started; + if (finished - m_reportAt >= 1000000) { + DEBUG_DEBUG(DEBUG_CATEGORY_CALL, "video GUI paint call=%llu interval_us=%lld paints=%u selected=%u moves=%u resizes=%u " + "request_wait_max_us=%lld paint_max_us=%lld prepare_max_us=%lld draw_max_us=%lld overlay_max_us=%lld finish_max_us=%lld", + (unsigned long long)callId, (long long)(finished - m_reportAt), m_paints, m_selectedPaints, m_moves, m_resizes, + (long long)m_requestMax, (long long)m_paintMax, (long long)m_prepareMax, (long long)m_drawMax, + (long long)m_overlayMax, (long long)m_finishMax); + m_reportAt = finished; m_paints = m_selectedPaints = m_moves = m_resizes = 0; + m_requestMax = m_paintMax = m_prepareMax = m_drawMax = m_overlayMax = m_finishMax = 0; m_slowReported = false; + } } private: void presented() { @@ -87,6 +122,9 @@ private: else { m_geometry = saveGeometry(); showFullScreen(); } } QByteArray m_geometry; + int64_t m_reportAt = 0, m_requestMax = 0, m_paintMax = 0, m_prepareMax = 0, m_drawMax = 0, m_overlayMax = 0, m_finishMax = 0; + unsigned m_paints = 0, m_selectedPaints = 0, m_moves = 0, m_resizes = 0; + bool m_slowReported = false; }; static QColor colorForName(const QString& name) { @@ -331,7 +369,8 @@ CallWindow::CallWindow(QWidget* parent) }); connect(m_video, &CallVideoEngine::imageChanged, this, [this](const QImage& image, quint64 serial) { bool changed = m_remoteImage.isNull() != image.isNull(); m_remoteImage = image; - m_videoWindow->remote = image; m_videoWindow->serial = serial; m_videoWindow->update(); + m_videoWindow->remote = image; m_videoWindow->serial = serial; m_videoWindow->callId = m_videoCall; + m_videoWindow->requestedAt = call_video_playout_now_us(); m_videoWindow->update(); if (changed) updateVideoPresentation(); // Скрытое окно продолжает принимать поток, не ждёт невозможного paintEvent. if (!m_videoWindow->isVisible() || m_videoWindow->isMinimized()) m_video->imagePresented(serial);