From 0c88972f090abde0b2b91460aa4da37311445c9f Mon Sep 17 00:00:00 2001 From: Brad Davis Date: Wed, 1 Jul 2015 14:37:23 -0700 Subject: [PATCH 1/4] Instrument the inter-idle time and tweaking the timeout setting --- interface/src/Application.cpp | 23 +++++++++++++++++++---- 1 file changed, 19 insertions(+), 4 deletions(-) diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index a08ac61cf2..1f22b31c64 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -1784,9 +1784,23 @@ void Application::checkFPS() { DependencyManager::get()->sendDomainServerCheckIn(); } -void Application::idle() { - PerformanceTimer perfTimer("idle"); +static SimpleMovingAverage interIdleDurations; +static uint64_t lastIdleEnd{ 0 }; +void Application::idle() { + if (lastIdleEnd != 0) { + uint64_t now = usecTimestampNow(); + interIdleDurations.updateAverage(now - lastIdleEnd); + static uint64_t lastReportTime = now; + if ((now - lastReportTime) >= (1000 * 1000)) { + int avgIdleDuration = (int)interIdleDurations.getAverage(); + qDebug() << "Average inter-idle time: " << avgIdleDuration << "s for " << interIdleDurations.getSampleCount() << " samples"; + interIdleDurations.reset(); + lastReportTime = now; + } + } + + PerformanceTimer perfTimer("idle"); if (_aboutToQuit) { return; // bail early, nothing to do here. } @@ -1830,12 +1844,13 @@ void Application::idle() { } // After finishing all of the above work, restart the idle timer, allowing 2ms to process events. - idleTimer->start(2); } - } + idleTimer->start(_glWidget->isThrottleRendering() ? 10 : 0); + } // check for any requested background downloads. emit checkBackgroundDownloads(); + lastIdleEnd = usecTimestampNow(); } void Application::setFullscreen(bool fullscreen) { From 59027959b8d3a8d7cd4e414f5d049e87b7ef1a85 Mon Sep 17 00:00:00 2001 From: Brad Davis Date: Wed, 1 Jul 2015 16:30:42 -0700 Subject: [PATCH 2/4] CR comments and fixing the average calculation --- interface/src/Application.cpp | 16 ++++++++------ interface/src/InterfaceLogging.cpp | 1 + interface/src/InterfaceLogging.h | 1 + libraries/shared/src/SimpleAverage.h | 33 ++++++++++++++++++++++++++++ 4 files changed, 44 insertions(+), 7 deletions(-) create mode 100644 libraries/shared/src/SimpleAverage.h diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index 1f22b31c64..5241864100 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -91,6 +91,7 @@ #include #include #include +#include #include #include #include @@ -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 = 2; const qint64 MAXIMUM_CACHE_SIZE = 10 * BYTES_PER_GIGABYTES; // 10GB @@ -1784,17 +1786,17 @@ void Application::checkFPS() { DependencyManager::get()->sendDomainServerCheckIn(); } -static SimpleMovingAverage interIdleDurations; -static uint64_t lastIdleEnd{ 0 }; - void Application::idle() { + static SimpleAverage interIdleDurations; + static uint64_t lastIdleEnd{ 0 }; + if (lastIdleEnd != 0) { uint64_t now = usecTimestampNow(); - interIdleDurations.updateAverage(now - lastIdleEnd); + interIdleDurations.update(now - lastIdleEnd); static uint64_t lastReportTime = now; - if ((now - lastReportTime) >= (1000 * 1000)) { + if ((now - lastReportTime) >= (USECS_PER_SECOND)) { int avgIdleDuration = (int)interIdleDurations.getAverage(); - qDebug() << "Average inter-idle time: " << avgIdleDuration << "s for " << interIdleDurations.getSampleCount() << " samples"; + qCDebug(interfaceapp_timing) << "Average inter-idle time: " << avgIdleDuration << "s for " << interIdleDurations.getCount() << " samples"; interIdleDurations.reset(); lastReportTime = now; } @@ -1845,7 +1847,7 @@ void Application::idle() { // After finishing all of the above work, restart the idle timer, allowing 2ms to process events. } - idleTimer->start(_glWidget->isThrottleRendering() ? 10 : 0); + idleTimer->start(_glWidget->isThrottleRendering() ? THROTTLED_IDLE_TIMER_DELAY : 0); } // check for any requested background downloads. diff --git a/interface/src/InterfaceLogging.cpp b/interface/src/InterfaceLogging.cpp index 18bc4e58e8..0afcb30c27 100644 --- a/interface/src/InterfaceLogging.cpp +++ b/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") diff --git a/interface/src/InterfaceLogging.h b/interface/src/InterfaceLogging.h index d1d92aa93d..be2ee73fba 100644 --- a/interface/src/InterfaceLogging.h +++ b/interface/src/InterfaceLogging.h @@ -15,5 +15,6 @@ #include Q_DECLARE_LOGGING_CATEGORY(interfaceapp) +Q_DECLARE_LOGGING_CATEGORY(interfaceapp_timing) #endif // hifi_InterfaceLogging_h diff --git a/libraries/shared/src/SimpleAverage.h b/libraries/shared/src/SimpleAverage.h new file mode 100644 index 0000000000..33ed9d84cc --- /dev/null +++ b/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 +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 From 4cffa26c01ca8bd7b5978ea2100d6da0945a32a6 Mon Sep 17 00:00:00 2001 From: Brad Davis Date: Wed, 1 Jul 2015 16:53:12 -0700 Subject: [PATCH 3/4] CR comments and fixing the microsecond display --- interface/src/Application.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index 5241864100..261055dc60 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -179,7 +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 = 2; +static uint8_t THROTTLED_IDLE_TIMER_DELAY = 10; const qint64 MAXIMUM_CACHE_SIZE = 10 * BYTES_PER_GIGABYTES; // 10GB @@ -1795,8 +1795,8 @@ void Application::idle() { interIdleDurations.update(now - lastIdleEnd); static uint64_t lastReportTime = now; if ((now - lastReportTime) >= (USECS_PER_SECOND)) { - int avgIdleDuration = (int)interIdleDurations.getAverage(); - qCDebug(interfaceapp_timing) << "Average inter-idle time: " << avgIdleDuration << "s for " << interIdleDurations.getCount() << " samples"; + 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; } From 88a733181e73573dcd684dd0ed6a8690e1cad31a Mon Sep 17 00:00:00 2001 From: Brad Davis Date: Wed, 1 Jul 2015 16:54:59 -0700 Subject: [PATCH 4/4] Fixing comment to reflect code --- interface/src/Application.cpp | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index 261055dc60..9db6188404 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -1845,8 +1845,9 @@ void Application::idle() { _idleLoopStdev.reset(); } - // After finishing all of the above work, restart the idle timer, allowing 2ms to process events. } + // 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); }