calculate unplayed ms on all streams/buffers as max

assignment-client/src/audio/AudioMixerClientData.cpp

@@ -270,6 +270,7 @@ QJsonObject AudioMixerClientData::getAudioStreamStats() {
     downstreamStats["desired"] = streamStats._desiredJitterBufferFrames;
     downstreamStats["available_avg_10s"] = streamStats._framesAvailableAverage;
     downstreamStats["available"] = (double) streamStats._framesAvailable;
+    downstreamStats["unplayed"] = (double) streamStats._unplayedMs;
     downstreamStats["starves"] = (double) streamStats._starveCount;
     downstreamStats["not_mixed"] = (double) streamStats._consecutiveNotMixedCount;
     downstreamStats["overflows"] = (double) streamStats._overflowCount;
@@ -294,6 +295,7 @@ QJsonObject AudioMixerClientData::getAudioStreamStats() {
         upstreamStats["desired_calc"] = avatarAudioStream->getCalculatedJitterBufferFrames();
         upstreamStats["available_avg_10s"] = streamStats._framesAvailableAverage;
         upstreamStats["available"] = (double) streamStats._framesAvailable;
+        upstreamStats["unplayed"] = (double) streamStats._unplayedMs;
         upstreamStats["starves"] = (double) streamStats._starveCount;
         upstreamStats["not_mixed"] = (double) streamStats._consecutiveNotMixedCount;
         upstreamStats["overflows"] = (double) streamStats._overflowCount;
@@ -323,6 +325,7 @@ QJsonObject AudioMixerClientData::getAudioStreamStats() {
             upstreamStats["desired_calc"] = injectorPair.second->getCalculatedJitterBufferFrames();
             upstreamStats["available_avg_10s"] = streamStats._framesAvailableAverage;
             upstreamStats["available"] = (double) streamStats._framesAvailable;
+            upstreamStats["unplayed"] = (double) streamStats._unplayedMs;
             upstreamStats["starves"] = (double) streamStats._starveCount;
             upstreamStats["not_mixed"] = (double) streamStats._consecutiveNotMixedCount;
             upstreamStats["overflows"] = (double) streamStats._overflowCount;

interface/src/ui/AudioStatsDialog.cpp

@@ -120,17 +120,14 @@ void AudioStatsDialog::renderStats() {
         audioOutputBufferLatency = 0.0;
         
     if (SharedNodePointer audioMixerNodePointer = DependencyManager::get<NodeList>()->soloNodeOfType(NodeType::AudioMixer)) {
-        mixerRingBufferFrames = (double)_stats->getMixerAvatarStreamStats()._framesAvailableAverage;
+        audioInputBufferLatency = (double)_stats->getInputMsRead().getWindowMax();
-        outputRingBufferFrames = (double)_stats->getMixerDownstreamStats()._framesAvailableAverage;
+        inputRingBufferLatency =  (double)_stats->getInputMsUnplayed().getWindowMax();
-
+        networkRoundtripLatency = (double)audioMixerNodePointer->getPingMs();
-        audioInputBufferLatency = (double)_stats->getAudioInputMsecsReadStats().getWindowAverage();
+        mixerRingBufferLatency = (double)_stats->getMixerAvatarStreamStats()._unplayedMs;
-        inputRingBufferLatency =  (double)_stats->getInputRungBufferMsecsAvailableStats().getWindowAverage();
+        outputRingBufferLatency = (double)_stats->getMixerDownstreamStats()._unplayedMs;
-        networkRoundtripLatency = (double) audioMixerNodePointer->getPingMs();
+        audioOutputBufferLatency = (double)_stats->getOutputMsUnplayed().getWindowMax();
-        mixerRingBufferLatency = mixerRingBufferFrames * (double)AudioConstants::NETWORK_FRAME_MSECS;
-        outputRingBufferLatency = outputRingBufferFrames * (double)AudioConstants::NETWORK_FRAME_MSECS;
-        audioOutputBufferLatency = (double)_stats->getAudioOutputMsecsUnplayedStats().getWindowAverage();
     }
-        
+
     double totalLatency = audioInputBufferLatency + inputRingBufferLatency + mixerRingBufferLatency
         + outputRingBufferLatency + audioOutputBufferLatency + networkRoundtripLatency;
 
@@ -142,20 +139,18 @@ void AudioStatsDialog::renderStats() {
     _audioMixerStats.push_back(stats.arg(QString::number(inputRingBufferLatency, 'f', 0)));
     stats = "Network (client->mixer):\t%1 ms";
     _audioMixerStats.push_back(stats.arg(QString::number(networkRoundtripLatency / 2, 'f', 0)));
-    stats = "Mixer Ring:\t%1 ms (%2 frames)";
+    stats = "Mixer Ring:\t%1 ms";
-    _audioMixerStats.push_back(stats.arg(QString::number(mixerRingBufferLatency, 'f', 0),
+    _audioMixerStats.push_back(stats.arg(QString::number(mixerRingBufferLatency, 'f', 0)));
-        QString::number(mixerRingBufferFrames, 'f', 0)));
     stats = "Network (mixer->client):\t%1 ms";
     _audioMixerStats.push_back(stats.arg(QString::number(networkRoundtripLatency / 2, 'f', 0)));
-    stats = "Output Ring:\t%1 ms (%2 frames)";
+    stats = "Output Ring:\t%1 ms";
-    _audioMixerStats.push_back(stats.arg(QString::number(outputRingBufferLatency, 'f', 0),
+    _audioMixerStats.push_back(stats.arg(QString::number(outputRingBufferLatency, 'f', 0)));
-        QString::number(outputRingBufferFrames, 'f', 0)));
     stats = "Output Read:\t%1 ms";
     _audioMixerStats.push_back(stats.arg(QString::number(audioOutputBufferLatency, 'f', 0)));
     stats = "TOTAL:\t%1 ms";
     _audioMixerStats.push_back(stats.arg(QString::number(totalLatency, 'f', 0)));
 
-    const MovingMinMaxAvg<quint64>& packetSentTimeGaps = _stats->getPacketSentTimeGaps();
+    const MovingMinMaxAvg<quint64>& packetSentTimeGaps = _stats->getPacketTimegaps();
 
     _upstreamClientStats.push_back("\nUpstream Mic Audio Packets Sent Gaps (by client):");
 

libraries/audio-client/src/AudioClient.cpp

@@ -123,12 +123,11 @@ AudioClient::AudioClient() :
     _outputBufferSizeFrames("audioOutputBufferSizeFrames", DEFAULT_AUDIO_OUTPUT_BUFFER_SIZE_FRAMES),
     _sessionOutputBufferSizeFrames(_outputBufferSizeFrames.get()),
     _outputStarveDetectionEnabled("audioOutputBufferStarveDetectionEnabled",
-                                  DEFAULT_AUDIO_OUTPUT_STARVE_DETECTION_ENABLED),
+        DEFAULT_AUDIO_OUTPUT_STARVE_DETECTION_ENABLED),
     _outputStarveDetectionPeriodMsec("audioOutputStarveDetectionPeriod",
-                                     DEFAULT_AUDIO_OUTPUT_STARVE_DETECTION_PERIOD),
+        DEFAULT_AUDIO_OUTPUT_STARVE_DETECTION_PERIOD),
     _outputStarveDetectionThreshold("audioOutputStarveDetectionThreshold",
-                                    DEFAULT_AUDIO_OUTPUT_STARVE_DETECTION_THRESHOLD),
+        DEFAULT_AUDIO_OUTPUT_STARVE_DETECTION_THRESHOLD),
-    _averagedLatency(0.0f),
     _lastInputLoudness(0.0f),
     _timeSinceLastClip(-1.0f),
     _muted(false),
@@ -854,7 +853,7 @@ void AudioClient::handleAudioInput() {
     _inputRingBuffer.writeData(inputByteArray.data(), inputByteArray.size());
 
     float audioInputMsecsRead = inputByteArray.size() / (float)(_inputFormat.bytesForDuration(USECS_PER_MSEC));
-    _stats.updateInputMsecsRead(audioInputMsecsRead);
+    _stats.updateInputMsRead(audioInputMsecsRead);
 
     const int numNetworkBytes = _isStereoInput
         ? AudioConstants::NETWORK_FRAME_BYTES_STEREO
@@ -942,6 +941,10 @@ void AudioClient::handleAudioInput() {
 
         emitAudioPacket(encodedBuffer.constData(), encodedBuffer.size(), _outgoingAvatarAudioSequenceNumber, audioTransform, packetType, _selectedCodecName);
         _stats.sentPacket();
+
+        int bytesInInputRingBuffer = _inputRingBuffer.samplesAvailable() * sizeof(int16_t);
+        float msecsInInputRingBuffer = bytesInInputRingBuffer / (float)(_inputFormat.bytesForDuration(USECS_PER_MSEC));
+        _stats.updateInputMsUnplayed(msecsInInputRingBuffer);
     }
 }
 
@@ -1358,22 +1361,6 @@ int AudioClient::calculateNumberOfFrameSamples(int numBytes) const {
     return frameSamples;
 }
 
-float AudioClient::getInputRingBufferMsecsAvailable() const {
-    int bytesInInputRingBuffer = _inputRingBuffer.samplesAvailable() * sizeof(int16_t);
-    float msecsInInputRingBuffer = bytesInInputRingBuffer / (float)(_inputFormat.bytesForDuration(USECS_PER_MSEC));
-    return  msecsInInputRingBuffer;
-}
-
-float AudioClient::getAudioOutputMsecsUnplayed() const {
-    if (!_audioOutput) {
-        return 0.0f;
-    }
-    int bytesAudioOutputUnplayed = _audioOutput->bufferSize() - _audioOutput->bytesFree();
-    float msecsAudioOutputUnplayed = bytesAudioOutputUnplayed / (float)_outputFormat.bytesForDuration(USECS_PER_MSEC);
-    return msecsAudioOutputUnplayed;
-}
-
-
 float AudioClient::azimuthForSource(const glm::vec3& relativePosition) {
     // copied from AudioMixer, more or less
     glm::quat inverseOrientation = glm::inverse(_orientationGetter());
@@ -1430,8 +1417,11 @@ qint64 AudioClient::AudioOutputIODevice::readData(char * data, qint64 maxSize) {
         bytesWritten = maxSize;
     }
 
-    bool wasBufferStarved = _audio->_audioOutput->bufferSize() == _audio->_audioOutput->bytesFree();
+    int bytesAudioOutputUnplayed = _audio->_audioOutput->bufferSize() - _audio->_audioOutput->bytesFree();
-    if (wasBufferStarved) {
+    float msecsAudioOutputUnplayed = bytesAudioOutputUnplayed / (float)_audio->_outputFormat.bytesForDuration(USECS_PER_MSEC);
+    _audio->_stats.updateOutputMsUnplayed(msecsAudioOutputUnplayed);
+
+    if (bytesAudioOutputUnplayed == 0) {
         _unfulfilledReads++;
     }
 

libraries/audio-client/src/AudioClient.h

@@ -121,9 +121,6 @@ public:
 
     const AudioIOStats& getStats() const { return _stats; }
 
-    float getInputRingBufferMsecsAvailable() const;
-    float getAudioOutputMsecsUnplayed() const;
-
     int getOutputBufferSize() { return _outputBufferSizeFrames.get(); }
 
     bool getOutputStarveDetectionEnabled() { return _outputStarveDetectionEnabled.get(); }
@@ -284,7 +281,6 @@ private:
 
     StDev _stdev;
     QElapsedTimer _timeSinceLastReceived;
-    float _averagedLatency;
     float _lastInputLoudness;
     float _timeSinceLastClip;
     int _totalInputAudioSamples;

libraries/audio-client/src/AudioIOStats.cpp

@@ -18,54 +18,73 @@
 
 #include "AudioIOStats.h"
 
-const int FRAMES_AVAILABLE_STATS_WINDOW_SECONDS = 10;
+// This is called 5x/sec (see AudioStatsDialog), and we want it to log the last 5s
+static const int INPUT_READS_WINDOW = 25;
+static const int INPUT_UNPLAYED_WINDOW = 25;
+static const int OUTPUT_UNPLAYED_WINDOW = 25;
 
-const int APPROXIMATELY_30_SECONDS_OF_AUDIO_PACKETS = (int)(30.0f * 1000.0f / AudioConstants::NETWORK_FRAME_MSECS);
+static const int APPROXIMATELY_30_SECONDS_OF_AUDIO_PACKETS = (int)(30.0f * 1000.0f / AudioConstants::NETWORK_FRAME_MSECS);
 
 
 AudioIOStats::AudioIOStats(MixedProcessedAudioStream* receivedAudioStream) :
     _receivedAudioStream(receivedAudioStream),
-    _audioInputMsecsReadStats(MSECS_PER_SECOND / (float)AudioConstants::NETWORK_FRAME_MSECS * AudioClient::CALLBACK_ACCELERATOR_RATIO, FRAMES_AVAILABLE_STATS_WINDOW_SECONDS),
+    _inputMsRead(0, INPUT_READS_WINDOW),
-    _inputRingBufferMsecsAvailableStats(1, FRAMES_AVAILABLE_STATS_WINDOW_SECONDS),
+    _inputMsUnplayed(0, INPUT_UNPLAYED_WINDOW),
-    _audioOutputMsecsUnplayedStats(1, FRAMES_AVAILABLE_STATS_WINDOW_SECONDS),
+    _outputMsUnplayed(0, OUTPUT_UNPLAYED_WINDOW),
-    _lastSentAudioPacket(0),
+    _lastSentPacketTime(0),
-    _packetSentTimeGaps(1, APPROXIMATELY_30_SECONDS_OF_AUDIO_PACKETS)
+    _packetTimegaps(0, APPROXIMATELY_30_SECONDS_OF_AUDIO_PACKETS)
 {
-
-}
-
-AudioStreamStats AudioIOStats::getMixerDownstreamStats() const {
-    return _receivedAudioStream->getAudioStreamStats();
 }
 
 void AudioIOStats::reset() {
     _receivedAudioStream->resetStats();
 
+    _inputMsRead.reset();
+    _inputMsUnplayed.reset();
+    _outputMsUnplayed.reset();
+    _packetTimegaps.reset();
+
     _mixerAvatarStreamStats = AudioStreamStats();
     _mixerInjectedStreamStatsMap.clear();
-
-    _audioInputMsecsReadStats.reset();
-    _inputRingBufferMsecsAvailableStats.reset();
-
-    _audioOutputMsecsUnplayedStats.reset();
-    _packetSentTimeGaps.reset();
 }
 
 void AudioIOStats::sentPacket() {
     // first time this is 0
-    if (_lastSentAudioPacket == 0) {
+    if (_lastSentPacketTime == 0) {
-        _lastSentAudioPacket = usecTimestampNow();
+        _lastSentPacketTime = usecTimestampNow();
     } else {
         quint64 now = usecTimestampNow();
-        quint64 gap = now - _lastSentAudioPacket;
+        quint64 gap = now - _lastSentPacketTime;
-        _packetSentTimeGaps.update(gap);
+        _lastSentPacketTime = now;
-
+        _packetTimegaps.update(gap);
-        _lastSentAudioPacket = now;
     }
 }
 
-void AudioIOStats::processStreamStatsPacket(QSharedPointer<ReceivedMessage> message, SharedNodePointer sendingNode) {
+const MovingMinMaxAvg<float>& AudioIOStats::getInputMsRead() const {
+    _inputMsRead.currentIntervalComplete();
+    return _inputMsRead;
+}
 
+const MovingMinMaxAvg<float>& AudioIOStats::getInputMsUnplayed() const {
+    _inputMsUnplayed.currentIntervalComplete();
+    return _inputMsUnplayed;
+}
+
+const MovingMinMaxAvg<float>& AudioIOStats::getOutputMsUnplayed() const {
+    _outputMsUnplayed.currentIntervalComplete();
+    return _outputMsUnplayed;
+}
+
+const MovingMinMaxAvg<quint64>& AudioIOStats::getPacketTimegaps() const {
+    _packetTimegaps.currentIntervalComplete();
+    return _packetTimegaps;
+}
+
+const AudioStreamStats AudioIOStats::getMixerDownstreamStats() const {
+    return _receivedAudioStream->getAudioStreamStats();
+}
+
+void AudioIOStats::processStreamStatsPacket(QSharedPointer<ReceivedMessage> message, SharedNodePointer sendingNode) {
     // parse the appendFlag, clear injected audio stream stats if 0
     quint8 appendFlag;
     message->readPrimitive(&appendFlag);
@@ -92,14 +111,9 @@ void AudioIOStats::processStreamStatsPacket(QSharedPointer<ReceivedMessage> mess
 }
 
 void AudioIOStats::sendDownstreamAudioStatsPacket() {
-
     auto audioIO = DependencyManager::get<AudioClient>();
 
-    // since this function is called every second, we'll sample for some of our stats here
+    // call _receivedAudioStream's per-second callback
-    _inputRingBufferMsecsAvailableStats.update(audioIO->getInputRingBufferMsecsAvailable());
-    _audioOutputMsecsUnplayedStats.update(audioIO->getAudioOutputMsecsUnplayed());
-
-    // also, call _receivedAudioStream's per-second callback
     _receivedAudioStream->perSecondCallbackForUpdatingStats();
 
     auto nodeList = DependencyManager::get<NodeList>();

libraries/audio-client/src/AudioIOStats.h

@@ -29,19 +29,20 @@ public:
                
     void reset();
     
-    void updateInputMsecsRead(float msecsRead) { _audioInputMsecsReadStats.update(msecsRead); }
+    void updateInputMsRead(float ms) { _inputMsRead.update(ms); }
+    void updateInputMsUnplayed(float ms) { _inputMsUnplayed.update(ms); }
+    void updateOutputMsUnplayed(float ms) { _outputMsUnplayed.update(ms); }
     void sentPacket();
     
-    AudioStreamStats getMixerDownstreamStats() const;
+    const MovingMinMaxAvg<float>& getInputMsRead() const;
+    const MovingMinMaxAvg<float>& getInputMsUnplayed() const;
+    const MovingMinMaxAvg<float>& getOutputMsUnplayed() const;
+    const MovingMinMaxAvg<quint64>& getPacketTimegaps() const;
+
+    const AudioStreamStats getMixerDownstreamStats() const;
     const AudioStreamStats& getMixerAvatarStreamStats() const {  return _mixerAvatarStreamStats; }
     const QHash<QUuid, AudioStreamStats>& getMixerInjectedStreamStatsMap() const { return _mixerInjectedStreamStatsMap; }
     
-    const MovingMinMaxAvg<float>& getAudioInputMsecsReadStats() const { return _audioInputMsecsReadStats; }
-    const MovingMinMaxAvg<float>& getInputRungBufferMsecsAvailableStats() const { return _inputRingBufferMsecsAvailableStats; }
-    const MovingMinMaxAvg<float>& getAudioOutputMsecsUnplayedStats() const { return _audioOutputMsecsUnplayedStats; }
-    
-    const MovingMinMaxAvg<quint64>& getPacketSentTimeGaps() const { return _packetSentTimeGaps; }
-    
     void sendDownstreamAudioStatsPacket();
 
 public slots:
@@ -49,17 +50,16 @@ public slots:
 
 private:
     MixedProcessedAudioStream* _receivedAudioStream;
-    
+
-    MovingMinMaxAvg<float> _audioInputMsecsReadStats;
+    mutable MovingMinMaxAvg<float> _inputMsRead;
-    MovingMinMaxAvg<float> _inputRingBufferMsecsAvailableStats;
+    mutable MovingMinMaxAvg<float> _inputMsUnplayed;
-    
+    mutable MovingMinMaxAvg<float> _outputMsUnplayed;
-    MovingMinMaxAvg<float> _audioOutputMsecsUnplayedStats;
+
+    quint64 _lastSentPacketTime;
+    mutable MovingMinMaxAvg<quint64> _packetTimegaps;
     
     AudioStreamStats _mixerAvatarStreamStats;
     QHash<QUuid, AudioStreamStats> _mixerInjectedStreamStatsMap;
-    
-    quint64 _lastSentAudioPacket;
-    MovingMinMaxAvg<quint64> _packetSentTimeGaps;
 };
 
 #endif // hifi_AudioIOStats_h

libraries/audio/src/AudioStreamStats.h

@@ -48,6 +48,7 @@ public:
 
     quint32 _framesAvailable;
     quint16 _framesAvailableAverage;
+    quint16 _unplayedMs;
     quint16 _desiredJitterBufferFrames;
     quint32 _starveCount;
     quint32 _consecutiveNotMixedCount;

libraries/audio/src/InboundAudioStream.cpp

@@ -18,7 +18,10 @@
 #include "InboundAudioStream.h"
 #include "AudioLogging.h"
 
-const int STARVE_HISTORY_CAPACITY = 50;
+static const int STARVE_HISTORY_CAPACITY = 50;
+
+// This is called 1x/s, and we want it to log the last 5s
+static const int UNPLAYED_MS_WINDOW_SECS = 5;
 
 InboundAudioStream::InboundAudioStream(int numFrameSamples, int numFramesCapacity, const Settings& settings) :
     _ringBuffer(numFrameSamples, numFramesCapacity),
@@ -46,6 +49,7 @@ InboundAudioStream::InboundAudioStream(int numFrameSamples, int numFramesCapacit
     _starveHistory(STARVE_HISTORY_CAPACITY),
     _starveThreshold(settings._windowStarveThreshold),
     _framesAvailableStat(),
+    _unplayedMs(0, UNPLAYED_MS_WINDOW_SECS),
     _currentJitterBufferFrames(0),
     _timeGapStatsForStatsPacket(0, STATS_FOR_STATS_PACKET_WINDOW_SECONDS),
     _repetitionWithFade(settings._repetitionWithFade),
@@ -82,6 +86,7 @@ void InboundAudioStream::resetStats() {
     _framesAvailableStat.reset();
     _currentJitterBufferFrames = 0;
     _timeGapStatsForStatsPacket.reset();
+    _unplayedMs.reset();
 }
 
 void InboundAudioStream::clearBuffer() {
@@ -101,6 +106,7 @@ void InboundAudioStream::perSecondCallbackForUpdatingStats() {
     _timeGapStatsForDesiredCalcOnTooManyStarves.currentIntervalComplete();
     _timeGapStatsForDesiredReduction.currentIntervalComplete();
     _timeGapStatsForStatsPacket.currentIntervalComplete();
+    _unplayedMs.currentIntervalComplete();
 }
 
 int InboundAudioStream::parseData(ReceivedMessage& message) {
@@ -303,6 +309,9 @@ int InboundAudioStream::popFrames(int maxFrames, bool allOrNothing, bool starveI
 }
 
 void InboundAudioStream::popSamplesNoCheck(int samples) {
+    float unplayedMs = (_ringBuffer.samplesAvailable() / (float)_ringBuffer.getNumFrameSamples()) * AudioConstants::NETWORK_FRAME_MSECS;
+    _unplayedMs.update(unplayedMs);
+
     _lastPopOutput = _ringBuffer.nextOutput();
     _ringBuffer.shiftReadPosition(samples);
     framesAvailableChanged();
@@ -507,6 +516,7 @@ AudioStreamStats InboundAudioStream::getAudioStreamStats() const {
 
     streamStats._framesAvailable = _ringBuffer.framesAvailable();
     streamStats._framesAvailableAverage = _framesAvailableStat.getAverage();
+    streamStats._unplayedMs = (quint16)_unplayedMs.getWindowMax();
     streamStats._desiredJitterBufferFrames = _desiredJitterBufferFrames;
     streamStats._starveCount = _starveCount;
     streamStats._consecutiveNotMixedCount = _consecutiveNotMixedCount;

libraries/audio/src/InboundAudioStream.h

@@ -265,6 +265,7 @@ protected:
     int _starveThreshold;
 
     TimeWeightedAvg<int> _framesAvailableStat;
+    MovingMinMaxAvg<float> _unplayedMs;
 
     // this value is periodically updated with the time-weighted avg from _framesAvailableStat. it is only used for
     // dropping silent frames right now.