From 2c42bb0aa8efc1dca6c307eaa44fd099680f5558 Mon Sep 17 00:00:00 2001
From: Zach Pomerantz <zmp@umich.edu>
Date: Wed, 30 Nov 2016 18:18:36 -0500
Subject: [PATCH] time audio mixing frames

---
 assignment-client/src/audio/AudioMixer.cpp | 16 ++++++++++++++++
 assignment-client/src/audio/AudioMixer.h   |  6 ++++++
 2 files changed, 22 insertions(+)

diff --git a/assignment-client/src/audio/AudioMixer.cpp b/assignment-client/src/audio/AudioMixer.cpp
index a2c4402cb0..b2257d4ba8 100644
--- a/assignment-client/src/audio/AudioMixer.cpp
+++ b/assignment-client/src/audio/AudioMixer.cpp
@@ -267,6 +267,15 @@ void AudioMixer::sendStatsPacket() {
     statsObject["avg_streams_per_frame"] = (float)_stats.sumStreams / (float)_numStatFrames;
     statsObject["avg_listeners_per_frame"] = (float)_stats.sumListeners / (float)_numStatFrames;
 
+    _sumMixTimesIndex = (_sumMixTimesIndex + 1) % MIX_TIMES_TRAILING_SECONDS;
+    _sumMixTimesTrailing -= _sumMixTimesHistory[_sumMixTimesIndex];
+    _sumMixTimesHistory[_sumMixTimesIndex] = _sumMixTimes.count();
+    _sumMixTimesTrailing += _sumMixTimesHistory[_sumMixTimesIndex];
+
+    statsObject["avg_us_per_frame"] = (qint64)(_sumMixTimes.count() / _numStatFrames);
+    statsObject["avg_us_per_frames_trailing"] =
+        (qint64)((_sumMixTimesTrailing / MIX_TIMES_TRAILING_SECONDS) / _numStatFrames);
+
     QJsonObject mixStats;
     mixStats["%_hrtf_mixes"] = percentageForMixStats(_stats.hrtfRenders);
     mixStats["%_hrtf_silent_mixes"] = percentageForMixStats(_stats.hrtfSilentRenders);
@@ -280,6 +289,7 @@ void AudioMixer::sendStatsPacket() {
     statsObject["mix_stats"] = mixStats;
 
     _numStatFrames = 0;
+    _sumMixTimes = std::chrono::microseconds(0);
     _stats.reset();
 
     // add stats for each listerner
@@ -356,6 +366,9 @@ void AudioMixer::start() {
     while (!_isFinished) {
         manageLoad(frameTimestamp, framesSinceManagement);
 
+        // start timing the frame
+        auto startTime = p_high_resolution_clock::now();
+
         // aquire the read-lock in a single thread, to avoid canonical rwlock undefined behaviors
         //   node removal will acquire a write lock;
         //   read locks (in slave threads) while a write lock is pending have undefined order in pthread
@@ -375,6 +388,9 @@ void AudioMixer::start() {
             slave.stats.reset();
         });
 
+        // stop timing the frame
+        _sumMixTimes += std::chrono::duration_cast<std::chrono::microseconds>(p_high_resolution_clock::now() - startTime);
+
         ++frame;
         ++_numStatFrames;
 
diff --git a/assignment-client/src/audio/AudioMixer.h b/assignment-client/src/audio/AudioMixer.h
index 7a4a84e61f..77bc9ad1fb 100644
--- a/assignment-client/src/audio/AudioMixer.h
+++ b/assignment-client/src/audio/AudioMixer.h
@@ -90,6 +90,12 @@ private:
 
     AudioMixerSlavePool _slavePool;
 
+    static const int MIX_TIMES_TRAILING_SECONDS = 10;
+    std::chrono::microseconds _sumMixTimes { 0 };
+    uint64_t _sumMixTimesTrailing { 0 };
+    uint64_t _sumMixTimesHistory[MIX_TIMES_TRAILING_SECONDS] { 0 };
+    int _sumMixTimesIndex { 0 };
+
     static int _numStaticJitterFrames; // -1 denotes dynamic jitter buffering
     static float _noiseMutingThreshold;
     static float _attenuationPerDoublingInDistance;