Misc. profiling to help debug poor UI perf with 4 videos.

Author: Mysticial

SerialPrograms/Source/CommonFramework/VideoPipeline/Backends/CameraWidgetQt6.5.cpp

@@ -91,8 +91,9 @@ CameraVideoSource::CameraVideoSource(
     const CameraInfo& info,
     Resolution desired_resolution
 )
-    : VideoSource(true)
+    : VideoSource(logger, true)
     , m_logger(logger)
+    , m_last_frame(logger)
     , m_snapshot_manager(logger, m_last_frame)
 {
     if (!info){

SerialPrograms/Source/CommonFramework/VideoPipeline/Backends/CameraWidgetQt6.cpp

@@ -84,8 +84,9 @@ CameraVideoSource::CameraVideoSource(
     const CameraInfo& info,
     Resolution desired_resolution
 )
-    : VideoSource(true)
+    : VideoSource(logger, true)
     , m_logger(logger)
+    , m_last_frame(logger)
     , m_snapshot_manager(logger, m_last_frame)
 {
     if (!info){

SerialPrograms/Source/CommonFramework/VideoPipeline/Backends/QVideoFrameCache.h

@@ -12,52 +12,93 @@
 #include <QVideoFrame>
 #include "Common/Cpp/Time.h"
 #include "Common/Cpp/Concurrency/SpinLock.h"
+#include "CommonFramework/Tools/StatAccumulator.h"
+
+//#define PA_PROFILE_QVideoFrameCache
 
 namespace PokemonAutomation{
 
 
 
 class QVideoFrameCache{
 public:
-    QVideoFrameCache()
+    QVideoFrameCache(Logger& logger)
+#ifdef PA_PROFILE_QVideoFrameCache
+        : m_logger(logger)
+        , m_last_frame_timestamp(WallClock::min())
+#else
         : m_last_frame_timestamp(WallClock::min())
+#endif
         , m_last_frame_seqnum(0)
+#ifdef PA_PROFILE_QVideoFrameCache
+        , m_stats_lock("QVideoFrameCache::push_frame()-Lock", "ms", 1000, std::chrono::seconds(10))
+        , m_stats_push_frame("QVideoFrameCache::push_frame()-All", "ms", 1000, std::chrono::seconds(10))
+#endif
     {}
 
     uint64_t seqnum() const{
         return m_last_frame_seqnum.load(std::memory_order_relaxed);
     }
     uint64_t get_latest(QVideoFrame& frame, WallClock& timestamp) const{
-        WriteSpinLock lg(m_frame_lock);
+        WriteSpinLock lg(m_frame_lock, "QVideoFrameCache::get_latest()");
         frame = m_last_frame;
         timestamp = m_last_frame_timestamp;
         return seqnum();
     }
 
     bool push_frame(QVideoFrame frame, WallClock timestamp){
-        WriteSpinLock lg(m_frame_lock);
+#ifdef PA_PROFILE_QVideoFrameCache
+        WallClock time0 = current_time();
+#endif
+
+        WriteSpinLock lg(m_frame_lock, "QVideoFrameCache::push_frame()");
+
+#ifdef PA_PROFILE_QVideoFrameCache
+        {
+            WallClock time1 = current_time();
+            uint32_t microseconds = (uint32_t)std::chrono::duration_cast<std::chrono::microseconds>(time1 - time0).count();
+            m_stats_lock.report_data(m_logger, microseconds);
+        }
+#endif
 
         //  Skip duplicate frames.
         if (frame.startTime() != -1 && frame.startTime() <= m_last_frame.startTime()){
             return false;
         }
 
-        m_last_frame = frame;
+        m_last_frame = std::move(frame);
         m_last_frame_timestamp = timestamp;
         uint64_t seqnum = m_last_frame_seqnum.load(std::memory_order_relaxed);
         seqnum++;
         m_last_frame_seqnum.store(seqnum, std::memory_order_relaxed);
 
+#ifdef PA_PROFILE_QVideoFrameCache
+        {
+            WallClock time1 = current_time();
+            uint32_t microseconds = (uint32_t)std::chrono::duration_cast<std::chrono::microseconds>(time1 - time0).count();
+            m_stats_push_frame.report_data(m_logger, microseconds);
+        }
+#endif
+
         return true;
     }
 
 
 private:
+#ifdef PA_PROFILE_QVideoFrameCache
+    Logger& m_logger;
+#endif
+
     mutable SpinLock m_frame_lock;
 
     QVideoFrame m_last_frame;
     WallClock m_last_frame_timestamp;
     std::atomic<uint64_t> m_last_frame_seqnum;
+
+#ifdef PA_PROFILE_QVideoFrameCache
+    PeriodicStatsReporterI32 m_stats_lock;
+    PeriodicStatsReporterI32 m_stats_push_frame;
+#endif
 };
 
 

SerialPrograms/Source/CommonFramework/VideoPipeline/VideoSource.cpp

@@ -9,4 +9,33 @@
 namespace PokemonAutomation{
 
 
+
+VideoSource::VideoSource(Logger& m_logger, bool allow_watchdog_reset)
+    : m_logger(m_logger)
+    , m_allow_watchdog_reset(allow_watchdog_reset)
+    , m_stats_report_source_frame("VideoSource::report_source_frame()", "ms", 1000, std::chrono::seconds(60))
+    , m_stats_report_rendered_frame("VideoSource::report_rendered_frame()", "ms", 1000, std::chrono::seconds(60))
+    , m_sanitizer("VideoSource")
+{}
+
+
+void VideoSource::report_source_frame(std::shared_ptr<const VideoFrame> frame){
+    auto scope_check = m_sanitizer.check_scope();
+    WallClock time0 = current_time();
+    m_source_frame_listeners.run_method_unique(&VideoFrameListener::on_frame, frame);
+    WallClock time1 = current_time();
+    auto microseconds = (uint32_t)std::chrono::duration_cast<std::chrono::microseconds>(time1 - time0).count();
+    m_stats_report_source_frame.report_data(m_logger, microseconds);
+}
+void VideoSource::report_rendered_frame(WallClock timestamp){
+    auto scope_check = m_sanitizer.check_scope();
+    WallClock time0 = current_time();
+    m_rendered_frame_listeners.run_method_unique(&RenderedFrameListener::on_rendered_frame, timestamp);
+    WallClock time1 = current_time();
+    auto microseconds = (uint32_t)std::chrono::duration_cast<std::chrono::microseconds>(time1 - time0).count();
+    m_stats_report_rendered_frame.report_data(m_logger, microseconds);
+}
+
+
+
 }

SerialPrograms/Source/CommonFramework/VideoPipeline/VideoSource.h

@@ -12,6 +12,7 @@
 #include "Common/Cpp/ImageResolution.h"
 #include "Common/Cpp/ListenerSet.h"
 #include "CommonFramework/VideoPipeline/VideoFeed.h"
+#include "CommonFramework/Tools/StatAccumulator.h"
 
 class QWidget;
 
@@ -45,10 +46,7 @@ class VideoSource{
 
 
 public:
-    VideoSource(bool allow_watchdog_reset)
-        : m_allow_watchdog_reset(allow_watchdog_reset)
-        , m_sanitizer("VideoSource")
-    {}
+    VideoSource(Logger& m_logger, bool allow_watchdog_reset);
     virtual ~VideoSource() = default;
 
 
@@ -65,27 +63,29 @@ class VideoSource{
 
 
 protected:
-    void report_source_frame(std::shared_ptr<const VideoFrame> frame){
-        auto scope_check = m_sanitizer.check_scope();
-        m_source_frame_listeners.run_method_unique(&VideoFrameListener::on_frame, frame);
-    }
+    //  These are not thread-safe.
+
+    void report_source_frame(std::shared_ptr<const VideoFrame> frame);
+
     // Called by UI to report a frame is rendered
-    void report_rendered_frame(WallClock timestamp){
-        auto scope_check = m_sanitizer.check_scope();
-        m_rendered_frame_listeners.run_method_unique(&RenderedFrameListener::on_rendered_frame, timestamp);
-    }
+    void report_rendered_frame(WallClock timestamp);
 
 
 public:
     virtual QWidget* make_display_QtWidget(QWidget* parent) = 0;
 
 
 private:
+    Logger& m_logger;
+
     ListenerSet<VideoFrameListener> m_source_frame_listeners;
     ListenerSet<RenderedFrameListener> m_rendered_frame_listeners;
 
     const bool m_allow_watchdog_reset;
 
+    PeriodicStatsReporterI32 m_stats_report_source_frame;
+    PeriodicStatsReporterI32 m_stats_report_rendered_frame;
+
     LifetimeSanitizer m_sanitizer;
 };
 

SerialPrograms/Source/CommonFramework/VideoPipeline/VideoSources/VideoSource_StillImage.cpp

@@ -61,15 +61,15 @@ JsonValue VideoSourceDescriptor_StillImage::to_json() const{
 
 std::unique_ptr<VideoSource> VideoSourceDescriptor_StillImage::make_VideoSource(Logger& logger, Resolution resolution) const{
 //    cout << "make_VideoSource: " << m_path << endl;
-    return std::make_unique<VideoSource_StillImage>(path(), resolution);
+    return std::make_unique<VideoSource_StillImage>(logger, path(), resolution);
 }
 
 
 
 
 
-VideoSource_StillImage::VideoSource_StillImage(const std::string& path, Resolution resolution)
-    : VideoSource(false)
+VideoSource_StillImage::VideoSource_StillImage(Logger& logger, const std::string& path, Resolution resolution)
+    : VideoSource(logger, false)
     , m_original_image(QString::fromStdString(path))
 {
     m_snapshot = VideoSnapshot(

SerialPrograms/Source/CommonFramework/VideoPipeline/VideoSources/VideoSource_StillImage.h

@@ -52,7 +52,7 @@ class VideoSourceDescriptor_StillImage : public VideoSourceDescriptor{
 
 class VideoSource_StillImage : public VideoSource{
 public:
-    VideoSource_StillImage(const std::string& path, Resolution resolution);
+    VideoSource_StillImage(Logger& logger, const std::string& path, Resolution resolution);
 
     const std::string path() const{
         return m_path;