Support high-resolution stats; add audio stats framework

.gitignore

@@ -2,6 +2,7 @@
 
 
 **/.vs/
+.vscode/
 build/
 config.tests/*/.qmake.stash
 config.tests/*/Makefile

app/app.pro

@@ -201,6 +201,7 @@ SOURCES += \
     streaming/input/reltouch.cpp \
     streaming/session.cpp \
     streaming/audio/audio.cpp \
+    streaming/audio/renderers/renderer.cpp \
     streaming/audio/renderers/sdlaud.cpp \
     gui/computermodel.cpp \
     gui/appmodel.cpp \

app/streaming/audio/audio.cpp

@@ -157,6 +157,8 @@ int Session::arInit(int /* audioConfiguration */,
 
 void Session::arCleanup()
 {
+    s_ActiveSession->m_AudioRenderer->logGlobalAudioStats();
+
     delete s_ActiveSession->m_AudioRenderer;
     s_ActiveSession->m_AudioRenderer = nullptr;
 
@@ -205,6 +207,8 @@ void Session::arDecodeAndPlaySample(char* sampleData, int sampleLength)
     }
 
     if (s_ActiveSession->m_AudioRenderer != nullptr) {
+        uint64_t startTimeUs = LiGetMicroseconds();
+
         int sampleSize = s_ActiveSession->m_AudioRenderer->getAudioBufferSampleSize();
         int frameSize = sampleSize * s_ActiveSession->m_ActiveAudioConfig.channelCount;
         int desiredBufferSize = frameSize * s_ActiveSession->m_ActiveAudioConfig.samplesPerFrame;
@@ -239,6 +243,24 @@ void Session::arDecodeAndPlaySample(char* sampleData, int sampleLength)
             desiredBufferSize = 0;
         }
 
+        // used to display the raw audio bitrate
+        s_ActiveSession->m_AudioRenderer->statsAddOpusBytesReceived(sampleLength);
+
+        // Once a second, maybe grab stats from the last two windows for display, then shift to the next stats window
+        if (LiGetMicroseconds() > s_ActiveSession->m_AudioRenderer->getActiveWndAudioStats().measurementStartUs + 1000000) {
+            if (s_ActiveSession->getOverlayManager().isOverlayEnabled(Overlay::OverlayDebugAudio)) {
+                AUDIO_STATS lastTwoWndAudioStats = {};
+                s_ActiveSession->m_AudioRenderer->snapshotAudioStats(lastTwoWndAudioStats);
+
+                s_ActiveSession->m_AudioRenderer->stringifyAudioStats(lastTwoWndAudioStats,
+                                                                      s_ActiveSession->getOverlayManager().getOverlayText(Overlay::OverlayDebugAudio),
+                                                                      s_ActiveSession->getOverlayManager().getOverlayMaxTextLength());
+                s_ActiveSession->getOverlayManager().setOverlayTextUpdated(Overlay::OverlayDebugAudio);
+            }
+
+            s_ActiveSession->m_AudioRenderer->flipAudioStatsWindows();
+        }
+
         if (!s_ActiveSession->m_AudioRenderer->submitAudio(desiredBufferSize)) {
             SDL_LogWarn(SDL_LOG_CATEGORY_APPLICATION,
                         "Reinitializing audio renderer after failure");
@@ -249,6 +271,9 @@ void Session::arDecodeAndPlaySample(char* sampleData, int sampleLength)
             delete s_ActiveSession->m_AudioRenderer;
             s_ActiveSession->m_AudioRenderer = nullptr;
         }
+
+        // keep stats on how long the audio pipline took to execute
+        s_ActiveSession->m_AudioRenderer->statsTrackDecodeTime(startTimeUs);
     }
 
     // Only try to recreate the audio renderer every 200 samples (1 second)

app/streaming/audio/renderers/renderer.cpp

@@ -0,0 +1,158 @@
+#include "renderer.h"
+
+#include <Limelight.h>
+
+IAudioRenderer::IAudioRenderer()
+{
+    SDL_zero(m_ActiveWndAudioStats);
+    SDL_zero(m_LastWndAudioStats);
+    SDL_zero(m_GlobalAudioStats);
+
+    m_ActiveWndAudioStats.measurementStartUs = LiGetMicroseconds();
+}
+
+int IAudioRenderer::getAudioBufferSampleSize()
+{
+    switch (getAudioBufferFormat()) {
+    case IAudioRenderer::AudioFormat::Sint16NE:
+        return sizeof(short);
+    case IAudioRenderer::AudioFormat::Float32NE:
+        return sizeof(float);
+    default:
+        Q_UNREACHABLE();
+    }
+}
+
+void IAudioRenderer::addAudioStats(AUDIO_STATS& src, AUDIO_STATS& dst)
+{
+    dst.opusBytesReceived     += src.opusBytesReceived;
+    dst.decodedPackets        += src.decodedPackets;
+    dst.renderedPackets       += src.renderedPackets;
+    dst.droppedNetwork        += src.droppedNetwork;
+    dst.droppedOverload       += src.droppedOverload;
+    dst.decodeDurationUs      += src.decodeDurationUs;
+
+    if (!LiGetEstimatedRttInfo(&dst.lastRtt, NULL)) {
+        dst.lastRtt = 0;
+    }
+    else {
+        // Our logic to determine if RTT is valid depends on us never
+        // getting an RTT of 0. ENet currently ensures RTTs are >= 1.
+        SDL_assert(dst.lastRtt > 0);
+    }
+
+    // Initialize the measurement start point if this is the first video stat window
+    if (!dst.measurementStartUs) {
+        dst.measurementStartUs = src.measurementStartUs;
+    }
+
+    // The following code assumes the global measure was already started first
+    SDL_assert(dst.measurementStartUs <= src.measurementStartUs);
+
+    double timeDiffSecs = (double)(LiGetMicroseconds() - dst.measurementStartUs) / 1000000.0;
+    dst.opusKbitsPerSec = (double)(dst.opusBytesReceived * 8) / 1000.0 / timeDiffSecs;
+}
+
+void IAudioRenderer::flipAudioStatsWindows()
+{
+    // Called once a second, adds stats to the running global total,
+    // copies the active window to the last window, and initializes
+    // a fresh active window.
+
+    // Accumulate these values into the global stats
+    addAudioStats(m_ActiveWndAudioStats, m_GlobalAudioStats);
+
+    // Move this window into the last window slot and clear it for next window
+    SDL_memcpy(&m_LastWndAudioStats, &m_ActiveWndAudioStats, sizeof(m_ActiveWndAudioStats));
+    SDL_zero(m_ActiveWndAudioStats);
+    m_ActiveWndAudioStats.measurementStartUs = LiGetMicroseconds();
+}
+
+void IAudioRenderer::logGlobalAudioStats()
+{
+    if (m_GlobalAudioStats.decodedPackets > 0) {
+        char audioStatsStr[1024];
+        stringifyAudioStats(m_GlobalAudioStats, audioStatsStr, sizeof(audioStatsStr));
+
+        SDL_LogInfo(SDL_LOG_CATEGORY_APPLICATION,
+                    "\nCurrent session audio stats\n---------------------------\n%s",
+                    audioStatsStr);
+    }
+}
+
+void IAudioRenderer::snapshotAudioStats(AUDIO_STATS &snapshot)
+{
+    addAudioStats(m_LastWndAudioStats, snapshot);
+    addAudioStats(m_ActiveWndAudioStats, snapshot);
+}
+
+void IAudioRenderer::statsAddOpusBytesReceived(int size)
+{
+    m_ActiveWndAudioStats.opusBytesReceived += size;
+
+    if (size) {
+        m_ActiveWndAudioStats.decodedPackets++;
+    }
+    else {
+        // if called with size=0 it indicates a packet that is presumed lost by the network
+        m_ActiveWndAudioStats.droppedNetwork++;
+    }
+}
+
+void IAudioRenderer::statsTrackDecodeTime(uint64_t startTimeUs)
+{
+    uint64_t decodeTimeUs = LiGetMicroseconds() - startTimeUs;
+    m_ActiveWndAudioStats.decodeDurationUs += decodeTimeUs;
+}
+
+// Provide audio stats common to all renderer backends. Child classes can then add additional lines
+// at the returned offset length into output.
+int IAudioRenderer::stringifyAudioStats(AUDIO_STATS& stats, char *output, int length)
+{
+    int offset = 0;
+
+    // Start with an empty string
+    output[offset] = 0;
+
+    double opusFrameSize = (double)m_opusConfig->samplesPerFrame / 48.0;
+    const RTP_AUDIO_STATS* rtpAudioStats = LiGetRTPAudioStats();
+    double fecOverhead = (double)rtpAudioStats->packetCountFec * 1.0 / (rtpAudioStats->packetCountAudio + rtpAudioStats->packetCountFec);
+
+    int ret = snprintf(
+        &output[offset],
+        length - offset,
+        "Audio stream: %s-channel Opus low-delay @ 48 kHz (%s)\n"
+        "Bitrate: %.1f kbps, +%.0f%% forward error-correction\n"
+        "Opus config: %s, frame size: %.1f ms\n"
+        "Packet loss from network: %.2f%%, loss from CPU overload: %.2f%%\n"
+        "Average decoding time: %0.2f ms\n",
+
+        // "Audio stream: %s-channel Opus low-delay @ 48 kHz (%s)\n"
+        m_opusConfig->channelCount == 6 ? "5.1" : m_opusConfig->channelCount == 8 ? "7.1" : "2",
+        getRendererName(),
+
+        // "Bitrate: %.1f %s, +%.0f%% forward error-correction\n"
+        stats.opusKbitsPerSec,
+        fecOverhead * 100.0,
+
+        // "Opus config: %s, frame size: %.1fms\n"
+        // Work out if we're getting high or low quality from Sunshine. coupled surround is designed for physical speakers
+        ((m_opusConfig->channelCount == 2 && stats.opusKbitsPerSec > 128) || !m_opusConfig->coupledStreams)
+            ? "high quality (LAN)" // 512k stereo coupled, 1.5mbps 5.1 uncoupled, 2mbps 7.1 uncoupled
+            : "normal quality",    // 96k stereo coupled, 256k 5.1 coupled, 450k 7.1 coupled
+        opusFrameSize,
+
+        // "Packet loss from network: %.2f%%, loss from CPU overload: %.2f%%\n"
+        stats.decodedPackets ? ((double)stats.droppedNetwork / stats.decodedPackets) * 100.0 : 0.0,
+        stats.decodedPackets ? ((double)stats.droppedOverload / stats.decodedPackets) * 100.0 : 0.0,
+
+        // "Average decoding time: %0.2f ms\n"
+        (double)(stats.decodeDurationUs / 1000.0) / stats.decodedPackets
+    );
+    if (ret < 0 || ret >= length - offset) {
+        SDL_assert(false);
+        return -1;
+    }
+
+    return offset + ret;
+}

app/streaming/audio/renderers/renderer.h

@@ -2,14 +2,37 @@
 
 #include <Limelight.h>
 #include <QtGlobal>
+#include <SDL.h>
+
+typedef struct _AUDIO_STATS {
+    uint32_t opusBytesReceived;
+    uint32_t decodedPackets;                    // total packets decoded (if less than renderedPackets it indicates droppedOverload)
+    uint32_t renderedPackets;                   // total audio packets rendered (only for certain backends)
+
+    uint32_t droppedNetwork;                    // total packets lost to the network
+    uint32_t droppedOverload;                   // total times we dropped a packet due to being unable to run in time
+    uint32_t totalGlitches;                     // total times the audio was interrupted
+
+    uint64_t decodeDurationUs;                  // cumulative render time, microseconds
+    uint64_t decodeDurationUsMax;               // slowest render time, microseconds
+    uint32_t lastRtt;                           // network latency from enet, milliseconds
+    uint64_t measurementStartUs;                // timestamp stats were started, microseconds
+    double opusKbitsPerSec;                     // current Opus bitrate in kbps, not including FEC overhead
+} AUDIO_STATS, *PAUDIO_STATS;
 
 class IAudioRenderer
 {
 public:
+    IAudioRenderer();
+
     virtual ~IAudioRenderer() {}
 
     virtual bool prepareForPlayback(const OPUS_MULTISTREAM_CONFIGURATION* opusConfig) = 0;
 
+    virtual void setOpusConfig(const OPUS_MULTISTREAM_CONFIGURATION* opusConfig) {
+        m_opusConfig = opusConfig;
+    }
+
     virtual void* getAudioBuffer(int* size) = 0;
 
     // Return false if an unrecoverable error has occurred and the renderer must be reinitialized
@@ -33,14 +56,28 @@ class IAudioRenderer
     };
     virtual AudioFormat getAudioBufferFormat() = 0;
 
-    int getAudioBufferSampleSize() {
-        switch (getAudioBufferFormat()) {
-        case IAudioRenderer::AudioFormat::Sint16NE:
-            return sizeof(short);
-        case IAudioRenderer::AudioFormat::Float32NE:
-            return sizeof(float);
-        default:
-            Q_UNREACHABLE();
-        }
+    virtual int getAudioBufferSampleSize();
+
+    AUDIO_STATS & getActiveWndAudioStats() {
+        return m_ActiveWndAudioStats;
     }
+
+    virtual const char * getRendererName() { return "IAudioRenderer"; };
+
+    // generic stats handling for all child classes
+    virtual void addAudioStats(AUDIO_STATS &, AUDIO_STATS &);
+    virtual void flipAudioStatsWindows();
+    virtual void logGlobalAudioStats();
+    virtual void snapshotAudioStats(AUDIO_STATS &);
+    virtual void statsAddOpusBytesReceived(int);
+    virtual void statsTrackDecodeTime(uint64_t);
+    virtual int stringifyAudioStats(AUDIO_STATS &, char *, int);
+
+protected:
+    AUDIO_STATS m_ActiveWndAudioStats;
+    AUDIO_STATS m_LastWndAudioStats;
+    AUDIO_STATS m_GlobalAudioStats;
+
+    // input stream metadata
+    const OPUS_MULTISTREAM_CONFIGURATION* m_opusConfig;
 };

app/streaming/audio/renderers/sdl.h

@@ -20,8 +20,11 @@ class SdlAudioRenderer : public IAudioRenderer
 
     virtual AudioFormat getAudioBufferFormat();
 
+    const char * getRendererName() { return m_Name; }
+
 private:
     SDL_AudioDeviceID m_AudioDevice;
     void* m_AudioBuffer;
     int m_FrameSize;
+    char m_Name[24];
 };

app/streaming/audio/renderers/sdlaud.cpp

@@ -5,7 +5,8 @@
 
 SdlAudioRenderer::SdlAudioRenderer()
     : m_AudioDevice(0),
-      m_AudioBuffer(nullptr)
+      m_AudioBuffer(nullptr),
+      m_Name("SDL")
 {
     SDL_assert(!SDL_WasInit(SDL_INIT_AUDIO));
 
@@ -59,6 +60,8 @@ bool SdlAudioRenderer::prepareForPlayback(const OPUS_MULTISTREAM_CONFIGURATION*
         return false;
     }
 
+    setOpusConfig(opusConfig);
+
     SDL_LogInfo(SDL_LOG_CATEGORY_APPLICATION,
                 "Desired audio buffer: %u samples (%u bytes)",
                 want.samples,
@@ -69,9 +72,10 @@ bool SdlAudioRenderer::prepareForPlayback(const OPUS_MULTISTREAM_CONFIGURATION*
                 have.samples,
                 have.size);
 
+    const char *driver = SDL_GetCurrentAudioDriver();
+    snprintf(m_Name, 5 + strlen(driver), "SDL/%s", driver);
     SDL_LogInfo(SDL_LOG_CATEGORY_APPLICATION,
-                "SDL audio driver: %s",
-                SDL_GetCurrentAudioDriver());
+                "SDL audio driver: %s", driver);
 
     // Start playback
     SDL_PauseAudioDevice(m_AudioDevice, 0);
@@ -110,6 +114,8 @@ bool SdlAudioRenderer::submitAudio(int bytesWritten)
     // Don't queue if there's already more than 30 ms of audio data waiting
     // in Moonlight's audio queue.
     if (LiGetPendingAudioDuration() > 30) {
+        m_ActiveWndAudioStats.totalGlitches++;
+        m_ActiveWndAudioStats.droppedOverload++;
         return true;
     }
 

app/streaming/audio/renderers/slaud.cpp

@@ -19,6 +19,8 @@ bool SLAudioRenderer::prepareForPlayback(const OPUS_MULTISTREAM_CONFIGURATION* o
         return false;
     }
 
+    setOpusConfig(opusConfig);
+
     // This number is pretty conservative (especially for surround), but
     // it's hard to avoid since we get crushed by CPU limitations.
     m_MaxQueuedAudioMs = 40 * opusConfig->channelCount / 2;
@@ -109,6 +111,8 @@ bool SLAudioRenderer::submitAudio(int bytesWritten)
         SDL_LogInfo(SDL_LOG_CATEGORY_APPLICATION,
                     "Too many queued audio frames: %d",
                     LiGetPendingAudioFrames());
+        m_ActiveWndAudioStats.totalGlitches++;
+        m_ActiveWndAudioStats.droppedOverload++;
     }
 
     return true;

app/streaming/audio/renderers/slaud.h

@@ -20,6 +20,8 @@ class SLAudioRenderer : public IAudioRenderer
 
     virtual AudioFormat getAudioBufferFormat();
 
+    const char * getRendererName() { return "Steam Link"; }
+
     virtual void remapChannels(POPUS_MULTISTREAM_CONFIGURATION opusConfig);
 
 private: