Add PAINT_DELAY_DEBUG log

interface/src/Application.cpp

@@ -2624,6 +2624,20 @@ void Application::idle(uint64_t now) {
         return; // bail early, we're throttled and not enough time has elapsed
     }
 
+#ifdef DEBUG_PAINT_DELAY
+    static uint64_t paintDelaySamples{ 0 };
+    static uint64_t paintDelayUsecs{ 0 };
+
+    paintDelayUsecs += displayPlugin->getPaintDelayUsecs();
+
+    static const int PAINT_DELAY_THROTTLE = 1000;
+    if (++paintDelaySamples % PAINT_DELAY_THROTTLE == 0) {
+        qCDebug(interfaceapp).nospace() <<
+            "Paint delay (" << paintDelaySamples << " samples): " <<
+            (float)paintDelaySamples / paintDelayUsecs << "us";
+    }
+#endif
+
     auto presentCount = displayPlugin->presentCount();
     if (presentCount < _renderedFrameIndex) {
         _renderedFrameIndex = INVALID_FRAME;

libraries/plugins/src/plugins/DisplayPlugin.cpp

@@ -1,5 +1,6 @@
 #include "DisplayPlugin.h"
 
+#include <NumericalConstants.h>
 #include <ui/Menu.h>
 
 #include "PluginContainer.h"
@@ -23,4 +24,15 @@ void DisplayPlugin::deactivate() {
     Parent::deactivate();
 }
 
+int64_t DisplayPlugin::getPaintDelayUsecs() const {
+    return _paintDelayTimer.isValid() ? _paintDelayTimer.nsecsElapsed() / NSECS_PER_USEC : 0;
+}
 
+void DisplayPlugin::incrementPresentCount() {
+#ifdef DEBUG_PAINT_DELAY
+    // Avoid overhead if we are not debugging
+    _paintDelayTimer.start();
+#endif
+
+    ++_presentedFrameIndex;
+}

libraries/plugins/src/plugins/DisplayPlugin.h

@@ -15,6 +15,7 @@
 
 #include <QtCore/QSize>
 #include <QtCore/QPoint>
+#include <QtCore/QElapsedTimer>
 class QImage;
 
 #include <GLMHelpers.h>
@@ -156,6 +157,8 @@ public:
     // Rate at which rendered frames are being skipped
     virtual float droppedFrameRate() const { return -1.0f; }
     uint32_t presentCount() const { return _presentedFrameIndex; }
+    // Time since last call to incrementPresentCount. Only valid if DEBUG_PAINT_DELAY is defined
+    int64_t getPaintDelayUsecs() const;
 
     virtual void cycleDebugOutput() {}
 
@@ -165,9 +168,10 @@ signals:
     void recommendedFramebufferSizeChanged(const QSize & size);
 
 protected:
-    void incrementPresentCount() { ++_presentedFrameIndex; }
+    void incrementPresentCount();
 
 private:
     std::atomic<uint32_t> _presentedFrameIndex;
+    QElapsedTimer _paintDelayTimer;
 };