Changeset 88259 in vbox

Timestamp:

Mar 23, 2021 12:10:36 PM (4 years ago)

Author:

vboxsync

svn:sync-xref-src-repo-rev:

143462

Message:

DrvAudio: Hacked the underruns detection so it won't falsely trigger when there is still enough bytes buffered in the host driver. bugref:9890

Location:

trunk

Files:

• include/VBox/vmm/pdmaudioifs.h (modified) (2 diffs)
• src/VBox/Devices/Audio/DrvAudio.cpp (modified) (10 diffs)

trunk/include/VBox/vmm/pdmaudioifs.h

@@ -1228 +1228 @@
         STAMCOUNTER     TotalTimesWritten;
     } Stats;
+    /** Hack alert: Max writable amount reported by the backend.
+     * This is used to aid buffer underrun detection in DrvAudio while playing.
+     * Ideally, the backend should have a method for querying number of buffered
+     * bytes instead.  However this will do for now. */
+    uint32_t            cbBackendMaxWritable;
 } PDMAUDIOSTREAMOUT;
 /** Pointer to the specifics for an audio output stream. */
@@ -1319 +1324 @@
 
 /** Magic value for PDMAUDIOSTREAM. */
-#define PDMAUDIOSTREAM_MAGIC    PDM_VERSION_MAKE(0xa0d3, 1, 0)
+#define PDMAUDIOSTREAM_MAGIC    PDM_VERSION_MAKE(0xa0d3, 1, 1)
 
 

trunk/src/VBox/Devices/Audio/DrvAudio.cpp

@@ -183 +183 @@
         /** The driver's output confguration (tweakable via CFGM). */
         DRVAUDIOCFG         Cfg;
+        /** Number of times underruns triggered re-(pre-)buffering. */
+        STAMCOUNTER         StatsReBuffering;
     } Out;
 #ifdef VBOX_WITH_STATISTICS
@@ -1611 +1613 @@
         return VERR_AUDIO_STREAM_NOT_READY;
 
-
-    /*
-     *
-     */
-    const uint32_t cFramesLive             = AudioMixBufLive(&pStream->Host.MixBuf);
-    const uint64_t tsDeltaPlayedCapturedNs = RTTimeNanoTS() - pStream->tsLastPlayedCapturedNs;
-    const uint32_t cFramesPassedReal       = PDMAudioPropsNanoToFrames(&pStream->Host.Cfg.Props, tsDeltaPlayedCapturedNs);
-
-    Log3Func(("[%s] Last played %'RU64 ns ago; filled with %u frm / %RU64 ms / %RU8%% total%s\n",
-              pStream->szName, tsDeltaPlayedCapturedNs, cFramesLive,
+    /*
+     * Get number of frames in the mix buffer and do some logging.
+     */
+    uint32_t const cFramesLive = AudioMixBufLive(&pStream->Host.MixBuf);
+    Log3Func(("[%s] Last played %'RI64 ns ago; filled with %u frm / %RU64 ms / %RU8%% total%s\n",
+              pStream->szName, pStream->fThresholdReached ? RTTimeNanoTS() - pStream->tsLastPlayedCapturedNs : -1, cFramesLive,
               PDMAudioPropsFramesToMilli(&pStream->Host.Cfg.Props, cFramesLive),
               (100 * cFramesLive) / AudioMixBufSize(&pStream->Host.MixBuf), pStream->fThresholdReached ? "" : ", pre-buffering"));
@@ -1632 +1630 @@
     else
     {
-        LogRel2(("Audio: Buffer underrun for stream '%s' occurred (%RU64ms passed)\n",
-                 pStream->szName, PDMAudioPropsFramesToMilli(&pStream->Host.Cfg.Props, cFramesPassedReal)));
-
-        if (pStream->Host.Cfg.Backend.cFramesPreBuffering) /* Any pre-buffering configured? */
-        {
-            /* Enter pre-buffering stage again. */
-            pStream->fThresholdReached = false;
+        /* It's not an underrun if the host audio driver still has an reasonable amount
+           buffered.  We don't have a direct way of querying that, so instead we'll use
+           some heuristics based on number of writable bytes now compared to when
+           prebuffering ended the first time around. */
+        uint32_t cbBuffered = pThis->pHostDrvAudio->pfnStreamGetWritable(pThis->pHostDrvAudio, pStream->pvBackend);
+        if (cbBuffered < pStream->Out.cbBackendMaxWritable)
+            cbBuffered = pStream->Out.cbBackendMaxWritable - cbBuffered;
+        else
+            cbBuffered = 0;
+        uint32_t cbMinBuf = PDMAudioPropsMilliToBytes(&pStream->Host.Cfg.Props, pStream->Guest.Cfg.Device.cMsSchedulingHint * 2);
+        Log3Func(("Potential underrun: cbBuffered=%#x vs cbMinBuf=%#x\n", cbBuffered, cbMinBuf));
+        if (cbBuffered < cbMinBuf)
+        {
+            LogRel2(("Audio: Buffer underrun for stream '%s' (%RI64 ms since last call, %u buffered)\n",
+                     pStream->szName, RTTimeNanoTS() - pStream->tsLastPlayedCapturedNs, cbBuffered));
+
+            /* Re-enter the pre-buffering stage again if enabled. */
+            if (pStream->Host.Cfg.Backend.cFramesPreBuffering > 0)
+            {
+                pStream->fThresholdReached = false;
+                STAM_REL_COUNTER_INC(&pThis->Out.StatsReBuffering);
+            }
         }
     }
@@ -1647 +1660 @@
      * This is straight forward, the backend
      */
+    uint32_t cbWritable;
     bool fJustStarted = false;
     if (pStream->fThresholdReached)
-    { /* not-prebuffering, likely after a while at least */ }
+    {
+        /* not-prebuffering, likely after a while at least */
+        cbWritable = pThis->pHostDrvAudio->pfnStreamGetWritable(pThis->pHostDrvAudio, pStream->pvBackend);
+    }
     else
     {
@@ -1659 +1676 @@
         {
             LogRel2(("Audio: Stream '%s' buffering complete\n", pStream->szName));
-            Log3Func(("[%s] Dbg: Buffering complete\n", pStream->szName));
+            Log3Func(("[%s] Dbg: Buffering complete!\n", pStream->szName));
             pStream->fThresholdReached = fJustStarted = true;
         }
@@ -1674 +1691 @@
         {
             LogRel2(("Audio: Stream '%s' buffering complete (short sound)\n", pStream->szName));
-            Log3Func(("[%s] Dbg: Buffering complete (short)\n", pStream->szName));
+            Log3Func(("[%s] Dbg: Buffering complete (short)!\n", pStream->szName));
             pStream->fThresholdReached = fJustStarted = true;
         }
@@ -1686 +1703 @@
             return VINF_SUCCESS;
         }
+
+        /* Hack alert! This is for the underrun detection.  */
+        cbWritable = pThis->pHostDrvAudio->pfnStreamGetWritable(pThis->pHostDrvAudio, pStream->pvBackend);
+        if (cbWritable > pStream->Out.cbBackendMaxWritable)
+            pStream->Out.cbBackendMaxWritable = cbWritable;
     }
 
@@ -1692 +1714 @@
      * Easy, as much as the host audio backend will allow us to.
      */
-    uint32_t cbWritable      = pThis->pHostDrvAudio->pfnStreamGetWritable(pThis->pHostDrvAudio, pStream->pvBackend);
     uint32_t cFramesWritable = PDMAUDIOPCMPROPS_B2F(&pStream->Host.Cfg.Props, cbWritable);
     uint32_t cFramesToPlay   = cFramesWritable;
@@ -1748 +1769 @@
     }
 
-    Log3Func(("[%s] Passed=%RU64 ms (%RU32 fr) Live=%RU32 fr (%RU64 ms) Period=%RU32 fr (%RU64 ms) Writable=%RU32 fr (%RU64 ms) -> ToPlay=%RU32 fr (%RU64 ms) Played=%RU32 fr (%RU64 ms)%s\n",
+    Log3Func(("[%s] Live=%RU32 fr (%RU64 ms) Period=%RU32 fr (%RU64 ms) Writable=%RU32 fr (%RU64 ms) -> ToPlay=%RU32 fr (%RU64 ms) Played=%RU32 fr (%RU64 ms)%s\n",
               pStream->szName,
-              PDMAudioPropsFramesToMilli(&pStream->Host.Cfg.Props, cFramesPassedReal), cFramesPassedReal,
               cFramesLive, PDMAudioPropsFramesToMilli(&pStream->Host.Cfg.Props, cFramesLive),
               pStream->Host.Cfg.Backend.cFramesPeriod,
@@ -3839 +3859 @@
      * Statistics.
      */
+    PDMDrvHlpSTAMRegCounterEx(pDrvIns, &pThis->Out.StatsReBuffering, "OutputReBuffering",
+                              STAMUNIT_COUNT, "Number of times the output stream was re-buffered after starting.");
+
 #ifdef VBOX_WITH_STATISTICS
     PDMDrvHlpSTAMRegCounterEx(pDrvIns, &pThis->Stats.TotalStreamsActive,   "TotalStreamsActive",