Merge pull request #5246 from jherico/inter_idle_timing

Instrument the inter-idle time and tweaking the timeout setting

interface/src/Application.cpp

@@ -91,6 +91,7 @@
 #include <SceneScriptingInterface.h>
 #include <ScriptCache.h>
 #include <SettingHandle.h>
+#include <SimpleAverage.h>
 #include <SoundCache.h>
 #include <TextRenderer.h>
 #include <Tooltip.h>
@@ -178,6 +179,7 @@ using namespace std;
 //  Starfield information
 static unsigned STARFIELD_NUM_STARS = 50000;
 static unsigned STARFIELD_SEED = 1;
+static uint8_t THROTTLED_IDLE_TIMER_DELAY = 10;
 
 const qint64 MAXIMUM_CACHE_SIZE = 10 * BYTES_PER_GIGABYTES;  // 10GB
 
@@ -1785,8 +1787,22 @@ void Application::checkFPS() {
 }
 
 void Application::idle() {
-    PerformanceTimer perfTimer("idle");
+    static SimpleAverage<float> interIdleDurations;
+    static uint64_t lastIdleEnd{ 0 };
 
+    if (lastIdleEnd != 0) {
+        uint64_t now = usecTimestampNow();
+        interIdleDurations.update(now - lastIdleEnd);
+        static uint64_t lastReportTime = now;
+        if ((now - lastReportTime) >= (USECS_PER_SECOND)) {
+            static QString LOGLINE("Average inter-idle time: %1 us for %2 samples");
+            qCDebug(interfaceapp_timing) << LOGLINE.arg((int)interIdleDurations.getAverage()).arg(interIdleDurations.getCount());
+            interIdleDurations.reset();
+            lastReportTime = now;
+        }
+    }
+
+    PerformanceTimer perfTimer("idle");
     if (_aboutToQuit) {
         return; // bail early, nothing to do here.
     }
@@ -1829,13 +1845,15 @@ void Application::idle() {
                 _idleLoopStdev.reset();
             }
 
-            // After finishing all of the above work, restart the idle timer, allowing 2ms to process events.
-            idleTimer->start(2);
         }
-    }
+        // After finishing all of the above work, ensure the idle timer is set to the proper interval,
+        // depending on whether we're throttling or not
+        idleTimer->start(_glWidget->isThrottleRendering() ? THROTTLED_IDLE_TIMER_DELAY : 0);
+    } 
 
     // check for any requested background downloads.
     emit checkBackgroundDownloads();
+    lastIdleEnd = usecTimestampNow();
 }
 
 void Application::setFullscreen(bool fullscreen) {

interface/src/InterfaceLogging.cpp

@@ -12,3 +12,4 @@
 #include "InterfaceLogging.h"
 
 Q_LOGGING_CATEGORY(interfaceapp, "hifi.interface")
+Q_LOGGING_CATEGORY(interfaceapp_timing, "hifi.interface.timing")

interface/src/InterfaceLogging.h

@@ -15,5 +15,6 @@
 #include <QLoggingCategory>
 
 Q_DECLARE_LOGGING_CATEGORY(interfaceapp)
+Q_DECLARE_LOGGING_CATEGORY(interfaceapp_timing)
 
 #endif // hifi_InterfaceLogging_h

libraries/shared/src/SimpleAverage.h

@@ -0,0 +1,33 @@
+//
+//  Created by Bradley Austin Davis on 2015/07/01.
+//  Copyright 2013 High Fidelity, Inc.
+//
+//  Distributed under the Apache License, Version 2.0.
+//  See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
+//
+
+#pragma once
+#ifndef hifi_SimpleAverage_h
+#define hifi_SimpleAverage_h
+
+template<typename T>
+class SimpleAverage {
+public:
+    void update(T sample) {
+        _sum += sample;
+        ++_count;
+    }
+    void reset() {
+        _sum = 0;
+        _count = 0;
+    }
+
+    int getCount() const { return _count; };
+    T getAverage() const { return _sum / (T)_count; };
+
+private:
+    int _count;
+    T _sum;
+};
+
+#endif