From 208b594ef82f1fe66baab4b8c1f5e9ea61e2c60c Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Thu, 24 Mar 2016 12:37:07 -0700 Subject: [PATCH 01/12] make the deadlock watchdog more generous and add some logging so we can see heatbeats on slow machines --- interface/src/Application.cpp | 39 +++++++++++++++++++--- libraries/shared/src/SimpleMovingAverage.h | 5 +-- 2 files changed, 37 insertions(+), 7 deletions(-) diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index e7bccae892..850fd844bf 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -240,14 +240,17 @@ class DeadlockWatchdogThread : public QThread { public: static const unsigned long HEARTBEAT_CHECK_INTERVAL_SECS = 1; static const unsigned long HEARTBEAT_UPDATE_INTERVAL_SECS = 1; - static const unsigned long MAX_HEARTBEAT_AGE_USECS = 15 * USECS_PER_SECOND; - + static const unsigned long HEARTBEAT_REPORT_INTERVAL_USECS = 5 * USECS_PER_SECOND; + static const unsigned long MAX_HEARTBEAT_AGE_USECS = 30 * USECS_PER_SECOND; + static const uint64_t WARNING_ELAPSED_HEARTBEAT = 500 * USECS_PER_MSEC; // warn if elapsed heartbeat average is large + static const int HEARTBEAT_SAMPLES = 100000; // ~5 seconds worth of samples + // Set the heartbeat on launch DeadlockWatchdogThread() { setObjectName("Deadlock Watchdog"); QTimer* heartbeatTimer = new QTimer(); // Give the heartbeat an initial value - updateHeartbeat(); + _heartbeat = usecTimestampNow(); connect(heartbeatTimer, &QTimer::timeout, [this] { updateHeartbeat(); }); @@ -258,7 +261,10 @@ public: } void updateHeartbeat() { - _heartbeat = usecTimestampNow(); + auto now = usecTimestampNow(); + auto elapsed = now - _heartbeat; + _movingAverage.addSample(elapsed); + _heartbeat = now; } void deadlockDetectionCrash() { @@ -269,10 +275,24 @@ public: void run() override { while (!_quit) { QThread::sleep(HEARTBEAT_UPDATE_INTERVAL_SECS); -#ifdef NDEBUG auto now = usecTimestampNow(); auto lastHeartbeatAge = now - _heartbeat; + auto sinceLastReport = now - _lastReport; + int elapsedMovingAverage = _movingAverage.average; + + if (elapsedMovingAverage > _maxElapsed) { + _maxElapsed = elapsedMovingAverage; + } + if ((sinceLastReport > HEARTBEAT_REPORT_INTERVAL_USECS) || (elapsedMovingAverage > WARNING_ELAPSED_HEARTBEAT)) { + qDebug() << "updateHeartbeat.elapsedMovingAverage:" << elapsedMovingAverage + << " maxElapsed:" << _maxElapsed << "numSamples:" << _movingAverage.numSamples; + _lastReport = now; + } + +#ifdef NDEBUG if (lastHeartbeatAge > MAX_HEARTBEAT_AGE_USECS) { + qDebug() << "DEADLOCK DETECTED -- updateHeartbeat.elapsedMovingAverage:" << elapsedMovingAverage + << " maxElapsed:" << _maxElapsed << "numSamples:" << _movingAverage.numSamples; deadlockDetectionCrash(); } #endif @@ -280,10 +300,15 @@ public: } static std::atomic _heartbeat; + static std::atomic _lastReport; + static std::atomic _maxElapsed; bool _quit { false }; + MovingAverage _movingAverage; }; std::atomic DeadlockWatchdogThread::_heartbeat; +std::atomic DeadlockWatchdogThread::_lastReport; +std::atomic DeadlockWatchdogThread::_maxElapsed; #ifdef Q_OS_WIN class MyNativeEventFilter : public QAbstractNativeEventFilter { @@ -1381,6 +1406,8 @@ void Application::initializeUi() { void Application::paintGL() { + updateHeartbeat(); + // Some plugins process message events, potentially leading to // re-entering a paint event. don't allow further processing if this // happens @@ -2502,6 +2529,8 @@ static uint32_t _renderedFrameIndex { INVALID_FRAME }; void Application::idle(uint64_t now) { + updateHeartbeat(); + if (_aboutToQuit || _inPaint) { return; // bail early, nothing to do here. } diff --git a/libraries/shared/src/SimpleMovingAverage.h b/libraries/shared/src/SimpleMovingAverage.h index 53754ae241..91c2809dc2 100644 --- a/libraries/shared/src/SimpleMovingAverage.h +++ b/libraries/shared/src/SimpleMovingAverage.h @@ -14,6 +14,7 @@ #ifndef hifi_SimpleMovingAverage_h #define hifi_SimpleMovingAverage_h +#include #include class SimpleMovingAverage { @@ -45,8 +46,8 @@ template class MovingAverage { public: const float WEIGHTING = 1.0f / (float)MAX_NUM_SAMPLES; const float ONE_MINUS_WEIGHTING = 1.0f - WEIGHTING; - int numSamples{ 0 }; - T average; + std::atomic numSamples { 0 }; + std::atomic average; void clear() { numSamples = 0; From 6eed8fb429e281c7e88d7e8b5e0af34304fb6c8b Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Thu, 24 Mar 2016 13:30:20 -0700 Subject: [PATCH 02/12] fix unix build --- libraries/shared/src/SimpleMovingAverage.h | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/libraries/shared/src/SimpleMovingAverage.h b/libraries/shared/src/SimpleMovingAverage.h index 91c2809dc2..09e2a6489d 100644 --- a/libraries/shared/src/SimpleMovingAverage.h +++ b/libraries/shared/src/SimpleMovingAverage.h @@ -57,7 +57,8 @@ public: void addSample(T sample) { if (numSamples > 0) { - average = (sample * WEIGHTING) + (average * ONE_MINUS_WEIGHTING); + T lastAverage = average; + average = (sample * WEIGHTING) + (lastAverage * ONE_MINUS_WEIGHTING); } else { average = sample; } From deed643ca7541d8a90e5562fd8c0b7bb9c211cd8 Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Thu, 24 Mar 2016 13:30:39 -0700 Subject: [PATCH 03/12] add additional tracking of max elapsed --- interface/src/Application.cpp | 37 +++++++++++++++++++++++++++++------ 1 file changed, 31 insertions(+), 6 deletions(-) diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index 850fd844bf..b9484de2b6 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -280,19 +280,42 @@ public: auto sinceLastReport = now - _lastReport; int elapsedMovingAverage = _movingAverage.average; - if (elapsedMovingAverage > _maxElapsed) { - _maxElapsed = elapsedMovingAverage; + if (elapsedMovingAverage > _maxElapsedAverage) { + qDebug() << "DEADLOCK WATCHDOG NEW maxElapsedAverage:" + << "lastHeartbeatAge:" << lastHeartbeatAge + << "elapsedMovingAverage:" << elapsedMovingAverage + << "maxElapsed:" << _maxElapsed + << "PREVIOUS maxElapsedAverage:" << _maxElapsedAverage + << "NEW maxElapsedAverage:" << elapsedMovingAverage + << "numSamples:" << _movingAverage.numSamples; + _maxElapsedAverage = elapsedMovingAverage; + } + if (lastHeartbeatAge > _maxElapsed) { + qDebug() << "DEADLOCK WATCHDOG NEW maxElapsed:" + << "lastHeartbeatAge:" << lastHeartbeatAge + << "elapsedMovingAverage:" << elapsedMovingAverage + << "PREVIOUS maxElapsed:" << _maxElapsed + << "NEW maxElapsed:" << lastHeartbeatAge + << "maxElapsedAverage:" << _maxElapsedAverage + << "numSamples:" << _movingAverage.numSamples; + _maxElapsed = lastHeartbeatAge; } if ((sinceLastReport > HEARTBEAT_REPORT_INTERVAL_USECS) || (elapsedMovingAverage > WARNING_ELAPSED_HEARTBEAT)) { - qDebug() << "updateHeartbeat.elapsedMovingAverage:" << elapsedMovingAverage - << " maxElapsed:" << _maxElapsed << "numSamples:" << _movingAverage.numSamples; + qDebug() << "DEADLOCK WATCHDOG STATUS -- lastHeartbeatAge:" << lastHeartbeatAge + << "elapsedMovingAverage:" << elapsedMovingAverage + << "maxElapsed:" << _maxElapsed + << "maxElapsedAverage:" << _maxElapsedAverage + << "numSamples:" << _movingAverage.numSamples; _lastReport = now; } #ifdef NDEBUG if (lastHeartbeatAge > MAX_HEARTBEAT_AGE_USECS) { - qDebug() << "DEADLOCK DETECTED -- updateHeartbeat.elapsedMovingAverage:" << elapsedMovingAverage - << " maxElapsed:" << _maxElapsed << "numSamples:" << _movingAverage.numSamples; + qDebug() << "DEADLOCK DETECTED -- lastHeartbeatAge:" << lastHeartbeatAge + << "elapsedMovingAverage:" << elapsedMovingAverage + << "maxElapsed:" << _maxElapsed + << "maxElapsedAverage:" << _maxElapsedAverage + << "numSamples:" << _movingAverage.numSamples; deadlockDetectionCrash(); } #endif @@ -302,6 +325,7 @@ public: static std::atomic _heartbeat; static std::atomic _lastReport; static std::atomic _maxElapsed; + static std::atomic _maxElapsedAverage; bool _quit { false }; MovingAverage _movingAverage; }; @@ -309,6 +333,7 @@ public: std::atomic DeadlockWatchdogThread::_heartbeat; std::atomic DeadlockWatchdogThread::_lastReport; std::atomic DeadlockWatchdogThread::_maxElapsed; +std::atomic DeadlockWatchdogThread::_maxElapsedAverage; #ifdef Q_OS_WIN class MyNativeEventFilter : public QAbstractNativeEventFilter { From 8691aa69054403eee8741aeffa5749862f944aac Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Thu, 24 Mar 2016 15:45:44 -0700 Subject: [PATCH 04/12] fix unix build and CR feedback --- interface/src/Application.cpp | 15 +++++---------- libraries/gpu/src/gpu/Query.cpp | 2 +- libraries/shared/src/SimpleMovingAverage.h | 14 +++++++++----- 3 files changed, 15 insertions(+), 16 deletions(-) diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index b9484de2b6..57fbe22577 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -248,13 +248,8 @@ public: // Set the heartbeat on launch DeadlockWatchdogThread() { setObjectName("Deadlock Watchdog"); - QTimer* heartbeatTimer = new QTimer(); // Give the heartbeat an initial value _heartbeat = usecTimestampNow(); - connect(heartbeatTimer, &QTimer::timeout, [this] { - updateHeartbeat(); - }); - heartbeatTimer->start(HEARTBEAT_UPDATE_INTERVAL_SECS * MSECS_PER_SECOND); connect(qApp, &QCoreApplication::aboutToQuit, [this] { _quit = true; }); @@ -278,7 +273,7 @@ public: auto now = usecTimestampNow(); auto lastHeartbeatAge = now - _heartbeat; auto sinceLastReport = now - _lastReport; - int elapsedMovingAverage = _movingAverage.average; + auto elapsedMovingAverage = _movingAverage.getAverage(); if (elapsedMovingAverage > _maxElapsedAverage) { qDebug() << "DEADLOCK WATCHDOG NEW maxElapsedAverage:" @@ -287,7 +282,7 @@ public: << "maxElapsed:" << _maxElapsed << "PREVIOUS maxElapsedAverage:" << _maxElapsedAverage << "NEW maxElapsedAverage:" << elapsedMovingAverage - << "numSamples:" << _movingAverage.numSamples; + << "numSamples:" << _movingAverage.getNumSamples(); _maxElapsedAverage = elapsedMovingAverage; } if (lastHeartbeatAge > _maxElapsed) { @@ -297,7 +292,7 @@ public: << "PREVIOUS maxElapsed:" << _maxElapsed << "NEW maxElapsed:" << lastHeartbeatAge << "maxElapsedAverage:" << _maxElapsedAverage - << "numSamples:" << _movingAverage.numSamples; + << "numSamples:" << _movingAverage.getNumSamples(); _maxElapsed = lastHeartbeatAge; } if ((sinceLastReport > HEARTBEAT_REPORT_INTERVAL_USECS) || (elapsedMovingAverage > WARNING_ELAPSED_HEARTBEAT)) { @@ -305,7 +300,7 @@ public: << "elapsedMovingAverage:" << elapsedMovingAverage << "maxElapsed:" << _maxElapsed << "maxElapsedAverage:" << _maxElapsedAverage - << "numSamples:" << _movingAverage.numSamples; + << "numSamples:" << _movingAverage.getNumSamples(); _lastReport = now; } @@ -315,7 +310,7 @@ public: << "elapsedMovingAverage:" << elapsedMovingAverage << "maxElapsed:" << _maxElapsed << "maxElapsedAverage:" << _maxElapsedAverage - << "numSamples:" << _movingAverage.numSamples; + << "numSamples:" << _movingAverage.getNumSamples(); deadlockDetectionCrash(); } #endif diff --git a/libraries/gpu/src/gpu/Query.cpp b/libraries/gpu/src/gpu/Query.cpp index 2e28dcd061..51bd16a979 100644 --- a/libraries/gpu/src/gpu/Query.cpp +++ b/libraries/gpu/src/gpu/Query.cpp @@ -67,5 +67,5 @@ void RangeTimer::end(gpu::Batch& batch) { } double RangeTimer::getAverage() const { - return _movingAverage.average; + return _movingAverage.getAverage(); } \ No newline at end of file diff --git a/libraries/shared/src/SimpleMovingAverage.h b/libraries/shared/src/SimpleMovingAverage.h index 09e2a6489d..44b1daa2e1 100644 --- a/libraries/shared/src/SimpleMovingAverage.h +++ b/libraries/shared/src/SimpleMovingAverage.h @@ -44,11 +44,6 @@ private: template class MovingAverage { public: - const float WEIGHTING = 1.0f / (float)MAX_NUM_SAMPLES; - const float ONE_MINUS_WEIGHTING = 1.0f - WEIGHTING; - std::atomic numSamples { 0 }; - std::atomic average; - void clear() { numSamples = 0; } @@ -64,6 +59,15 @@ public: } numSamples++; } + + T getAverage() const { return average; } + T getNumSamples() const { return numSamples; } + +private: + const float WEIGHTING = 1.0f / (float)MAX_NUM_SAMPLES; + const float ONE_MINUS_WEIGHTING = 1.0f - WEIGHTING; + std::atomic numSamples{ 0 }; + std::atomic average; }; #endif // hifi_SimpleMovingAverage_h From 2b595fb329df6cc4cda6b420f545e4b2249f86b3 Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Thu, 24 Mar 2016 16:26:28 -0700 Subject: [PATCH 05/12] break out thread safe moving average to get around unix build hell --- interface/src/Application.cpp | 2 +- libraries/gpu/src/gpu/Query.cpp | 2 +- libraries/shared/src/SimpleMovingAverage.h | 29 ++++++++++++++++++++++ 3 files changed, 31 insertions(+), 2 deletions(-) diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index 57fbe22577..4a815e453b 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -322,7 +322,7 @@ public: static std::atomic _maxElapsed; static std::atomic _maxElapsedAverage; bool _quit { false }; - MovingAverage _movingAverage; + ThreadSafeMovingAverage _movingAverage; }; std::atomic DeadlockWatchdogThread::_heartbeat; diff --git a/libraries/gpu/src/gpu/Query.cpp b/libraries/gpu/src/gpu/Query.cpp index 51bd16a979..2e28dcd061 100644 --- a/libraries/gpu/src/gpu/Query.cpp +++ b/libraries/gpu/src/gpu/Query.cpp @@ -67,5 +67,5 @@ void RangeTimer::end(gpu::Batch& batch) { } double RangeTimer::getAverage() const { - return _movingAverage.getAverage(); + return _movingAverage.average; } \ No newline at end of file diff --git a/libraries/shared/src/SimpleMovingAverage.h b/libraries/shared/src/SimpleMovingAverage.h index 44b1daa2e1..debe58da52 100644 --- a/libraries/shared/src/SimpleMovingAverage.h +++ b/libraries/shared/src/SimpleMovingAverage.h @@ -44,6 +44,11 @@ private: template class MovingAverage { public: + const float WEIGHTING = 1.0f / (float)MAX_NUM_SAMPLES; + const float ONE_MINUS_WEIGHTING = 1.0f - WEIGHTING; + int numSamples{ 0 }; + T average; + void clear() { numSamples = 0; } @@ -60,6 +65,29 @@ public: numSamples++; } + T getAverage() const { return average; } + T getNumSamples() const { return numSamples; } +}; + +template class ThreadSafeMovingAverage { +public: + void clear() { + numSamples = 0; + } + + bool isAverageValid() const { return (numSamples > 0); } + + void addSample(T sample) { + if (numSamples > 0) { + T lastAverage = average; + average = (sample * WEIGHTING) + (lastAverage * ONE_MINUS_WEIGHTING); + } + else { + average = sample; + } + numSamples++; + } + T getAverage() const { return average; } T getNumSamples() const { return numSamples; } @@ -70,4 +98,5 @@ private: std::atomic average; }; + #endif // hifi_SimpleMovingAverage_h From 06a6a8462ff83fc3be4f7c3e975deb4c3468ab80 Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Thu, 24 Mar 2016 16:34:09 -0700 Subject: [PATCH 06/12] more cleanup --- libraries/shared/src/SimpleMovingAverage.h | 6 +----- 1 file changed, 1 insertion(+), 5 deletions(-) diff --git a/libraries/shared/src/SimpleMovingAverage.h b/libraries/shared/src/SimpleMovingAverage.h index debe58da52..67efa296f6 100644 --- a/libraries/shared/src/SimpleMovingAverage.h +++ b/libraries/shared/src/SimpleMovingAverage.h @@ -57,16 +57,12 @@ public: void addSample(T sample) { if (numSamples > 0) { - T lastAverage = average; - average = (sample * WEIGHTING) + (lastAverage * ONE_MINUS_WEIGHTING); + average = (sample * WEIGHTING) + (average * ONE_MINUS_WEIGHTING); } else { average = sample; } numSamples++; } - - T getAverage() const { return average; } - T getNumSamples() const { return numSamples; } }; template class ThreadSafeMovingAverage { From 5b13ebf72b0792d175c5874ed23ecbf447ee35c5 Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Thu, 24 Mar 2016 17:19:11 -0700 Subject: [PATCH 07/12] more mac build busters --- 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 4a815e453b..7c0189da04 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -242,7 +242,7 @@ public: static const unsigned long HEARTBEAT_UPDATE_INTERVAL_SECS = 1; static const unsigned long HEARTBEAT_REPORT_INTERVAL_USECS = 5 * USECS_PER_SECOND; static const unsigned long MAX_HEARTBEAT_AGE_USECS = 30 * USECS_PER_SECOND; - static const uint64_t WARNING_ELAPSED_HEARTBEAT = 500 * USECS_PER_MSEC; // warn if elapsed heartbeat average is large + static const int WARNING_ELAPSED_HEARTBEAT = 500 * USECS_PER_MSEC; // warn if elapsed heartbeat average is large static const int HEARTBEAT_SAMPLES = 100000; // ~5 seconds worth of samples // Set the heartbeat on launch @@ -319,7 +319,7 @@ public: static std::atomic _heartbeat; static std::atomic _lastReport; - static std::atomic _maxElapsed; + static std::atomic _maxElapsed; static std::atomic _maxElapsedAverage; bool _quit { false }; ThreadSafeMovingAverage _movingAverage; @@ -327,7 +327,7 @@ public: std::atomic DeadlockWatchdogThread::_heartbeat; std::atomic DeadlockWatchdogThread::_lastReport; -std::atomic DeadlockWatchdogThread::_maxElapsed; +std::atomic DeadlockWatchdogThread::_maxElapsed; std::atomic DeadlockWatchdogThread::_maxElapsedAverage; #ifdef Q_OS_WIN From cfaa97d8f3a6404ed780b833939cd258af384533 Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Thu, 24 Mar 2016 17:39:23 -0700 Subject: [PATCH 08/12] one more try --- 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 7c0189da04..5e01bcbe88 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -322,13 +322,14 @@ public: static std::atomic _maxElapsed; static std::atomic _maxElapsedAverage; bool _quit { false }; - ThreadSafeMovingAverage _movingAverage; + static ThreadSafeMovingAverage _movingAverage; }; std::atomic DeadlockWatchdogThread::_heartbeat; std::atomic DeadlockWatchdogThread::_lastReport; std::atomic DeadlockWatchdogThread::_maxElapsed; std::atomic DeadlockWatchdogThread::_maxElapsedAverage; +ThreadSafeMovingAverage DeadlockWatchdogThread::_movingAverage; #ifdef Q_OS_WIN class MyNativeEventFilter : public QAbstractNativeEventFilter { From 7de8a2267f3e96392dce43136801a51d8b457903 Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Thu, 24 Mar 2016 18:09:14 -0700 Subject: [PATCH 09/12] one more try --- interface/src/Application.cpp | 3 ++- libraries/shared/src/SimpleMovingAverage.h | 25 ++++++++++++++++------ 2 files changed, 21 insertions(+), 7 deletions(-) diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index 5e01bcbe88..22bc272921 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -321,8 +321,9 @@ public: static std::atomic _lastReport; static std::atomic _maxElapsed; static std::atomic _maxElapsedAverage; - bool _quit { false }; static ThreadSafeMovingAverage _movingAverage; + + bool _quit { false }; }; std::atomic DeadlockWatchdogThread::_heartbeat; diff --git a/libraries/shared/src/SimpleMovingAverage.h b/libraries/shared/src/SimpleMovingAverage.h index 67efa296f6..a35199a97c 100644 --- a/libraries/shared/src/SimpleMovingAverage.h +++ b/libraries/shared/src/SimpleMovingAverage.h @@ -14,7 +14,7 @@ #ifndef hifi_SimpleMovingAverage_h #define hifi_SimpleMovingAverage_h -#include +#include #include class SimpleMovingAverage { @@ -68,12 +68,17 @@ public: template class ThreadSafeMovingAverage { public: void clear() { + std::unique_lock lock(_lock); numSamples = 0; } - bool isAverageValid() const { return (numSamples > 0); } + bool isAverageValid() const { + std::unique_lock lock(_lock); + return (numSamples > 0); + } void addSample(T sample) { + std::unique_lock lock(_lock); if (numSamples > 0) { T lastAverage = average; average = (sample * WEIGHTING) + (lastAverage * ONE_MINUS_WEIGHTING); @@ -84,14 +89,22 @@ public: numSamples++; } - T getAverage() const { return average; } - T getNumSamples() const { return numSamples; } + T getAverage() const { + std::unique_lock lock(_lock); + return average; + } + + T getNumSamples() const { + std::unique_lock lock(_lock); + return numSamples; + } private: const float WEIGHTING = 1.0f / (float)MAX_NUM_SAMPLES; const float ONE_MINUS_WEIGHTING = 1.0f - WEIGHTING; - std::atomic numSamples{ 0 }; - std::atomic average; + int numSamples { 0 }; + T average; + mutable std::mutex _lock; }; From fb09ad51b3ee9f3a1cefb51ca67e8c50f3c0d601 Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Thu, 24 Mar 2016 21:14:07 -0700 Subject: [PATCH 10/12] CR feedback --- interface/src/Application.cpp | 8 +++---- libraries/shared/src/SimpleMovingAverage.h | 26 ++++++++++------------ 2 files changed, 16 insertions(+), 18 deletions(-) diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index 22bc272921..c37d010395 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -282,7 +282,7 @@ public: << "maxElapsed:" << _maxElapsed << "PREVIOUS maxElapsedAverage:" << _maxElapsedAverage << "NEW maxElapsedAverage:" << elapsedMovingAverage - << "numSamples:" << _movingAverage.getNumSamples(); + << "samples:" << _movingAverage.getSamples(); _maxElapsedAverage = elapsedMovingAverage; } if (lastHeartbeatAge > _maxElapsed) { @@ -292,7 +292,7 @@ public: << "PREVIOUS maxElapsed:" << _maxElapsed << "NEW maxElapsed:" << lastHeartbeatAge << "maxElapsedAverage:" << _maxElapsedAverage - << "numSamples:" << _movingAverage.getNumSamples(); + << "samples:" << _movingAverage.getSamples(); _maxElapsed = lastHeartbeatAge; } if ((sinceLastReport > HEARTBEAT_REPORT_INTERVAL_USECS) || (elapsedMovingAverage > WARNING_ELAPSED_HEARTBEAT)) { @@ -300,7 +300,7 @@ public: << "elapsedMovingAverage:" << elapsedMovingAverage << "maxElapsed:" << _maxElapsed << "maxElapsedAverage:" << _maxElapsedAverage - << "numSamples:" << _movingAverage.getNumSamples(); + << "samples:" << _movingAverage.getSamples(); _lastReport = now; } @@ -310,7 +310,7 @@ public: << "elapsedMovingAverage:" << elapsedMovingAverage << "maxElapsed:" << _maxElapsed << "maxElapsedAverage:" << _maxElapsedAverage - << "numSamples:" << _movingAverage.getNumSamples(); + << "samples:" << _movingAverage.getSamples(); deadlockDetectionCrash(); } #endif diff --git a/libraries/shared/src/SimpleMovingAverage.h b/libraries/shared/src/SimpleMovingAverage.h index a35199a97c..296911ae3e 100644 --- a/libraries/shared/src/SimpleMovingAverage.h +++ b/libraries/shared/src/SimpleMovingAverage.h @@ -69,41 +69,39 @@ template class ThreadSafeMovingAverage { public: void clear() { std::unique_lock lock(_lock); - numSamples = 0; + _samples = 0; } bool isAverageValid() const { std::unique_lock lock(_lock); - return (numSamples > 0); + return (_samples > 0); } void addSample(T sample) { std::unique_lock lock(_lock); - if (numSamples > 0) { - T lastAverage = average; - average = (sample * WEIGHTING) + (lastAverage * ONE_MINUS_WEIGHTING); + if (_samples > 0) { + _average = (sample * WEIGHTING) + (_average * ONE_MINUS_WEIGHTING); + } else { + _average = sample; } - else { - average = sample; - } - numSamples++; + _samples++; } T getAverage() const { std::unique_lock lock(_lock); - return average; + return _average; } - T getNumSamples() const { + size_t getSamples() const { std::unique_lock lock(_lock); - return numSamples; + return _samples; } private: const float WEIGHTING = 1.0f / (float)MAX_NUM_SAMPLES; const float ONE_MINUS_WEIGHTING = 1.0f - WEIGHTING; - int numSamples { 0 }; - T average; + size_t _samples { 0 }; + T _average; mutable std::mutex _lock; }; From 941821e2c761e759ac9020de96ee9bbbce9e4e8b Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Fri, 25 Mar 2016 12:17:24 -0700 Subject: [PATCH 11/12] add some extra debugging at deadlock detection to explain unreasonable numbers --- interface/src/Application.cpp | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index c37d010395..89bddf7a90 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -306,7 +306,10 @@ public: #ifdef NDEBUG if (lastHeartbeatAge > MAX_HEARTBEAT_AGE_USECS) { - qDebug() << "DEADLOCK DETECTED -- lastHeartbeatAge:" << lastHeartbeatAge + qDebug() << "DEADLOCK DETECTED -- " + << "lastHeartbeatAge:" << lastHeartbeatAge + << "[ _heartbeat:" << _heartbeat + << "now:" << now << " ]" << "elapsedMovingAverage:" << elapsedMovingAverage << "maxElapsed:" << _maxElapsed << "maxElapsedAverage:" << _maxElapsedAverage From fe31be71eb85608319d39ea3037672a4df31bb20 Mon Sep 17 00:00:00 2001 From: Brad Hefta-Gaub Date: Fri, 25 Mar 2016 14:59:43 -0700 Subject: [PATCH 12/12] protect against unexpected rollover --- interface/src/Application.cpp | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index c3e2b8284b..381816e81f 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -271,8 +271,10 @@ public: while (!_quit) { QThread::sleep(HEARTBEAT_UPDATE_INTERVAL_SECS); auto now = usecTimestampNow(); - auto lastHeartbeatAge = now - _heartbeat; - auto sinceLastReport = now - _lastReport; + + // in the unlikely event that now is less than _heartbeat, don't rollover and confuse ourselves + auto lastHeartbeatAge = (now > _heartbeat) ? now - _heartbeat : 0; + auto sinceLastReport = (now > _lastReport) ? now - _lastReport : 0; auto elapsedMovingAverage = _movingAverage.getAverage(); if (elapsedMovingAverage > _maxElapsedAverage) {