fix: SG-43367: eliminate EXR+WAV playback stuttering

docs/rv-manuals/rv-user-manual/rv-user-manual-chapter-fourteen.md

@@ -150,7 +150,26 @@ When decoding EXR files, you have the option of setting both the number of reade
 
 If you want to stream EXR files you may want to reserve some of your cores for decoding. The number of EXR decoding threads can be changed from the Preferences > Formats > OpenEXR. Always check performances with **Automatic Threads** activated.
 
-If this doesn't work, deselect **Automatic Threads** and increase the number in Reader/Decoder Threads by 1. Check performances, and increase by thread count by 1. Repeat until performances are acceptable, but don't go over the number of logical cores of your workstation minus 1 (if you have 16 logical cores, don't go over 15) or your system will become unstable. If performances are still degraded, you need to look elsewhere, such as upgrading your hardware.
+When **Automatic Threads** is enabled, RV chooses the OpenEXR decoder thread count from the number of logical processors on your system:
+
+* On systems with **16 or fewer logical processors**, RV uses all but one logical processor.
+* On systems with **more than 16 logical processors**, RV uses 15 threads plus one more for every 4 additional logical processors. All EXR decodes share a single OpenEXR thread pool, and the decoding work needed for playback depends on the media (resolution, frame rate, compression), not on the number of cores. Dedicating too many cores to decoding can starve RV's playback/UI, audio, and caching threads and cause dropped frames.
+
+The thread count never decreases as the number of logical processors grows:
+
+| Logical processors | EXR decoder threads |
+| ------------------ | ------------------- |
+| 8                  | 7                   |
+| 16                 | 15                  |
+| 24                 | 17                  |
+| 32                 | 19                  |
+| 48                 | 23                  |
+| 64                 | 27                  |
+| 128                | 43                  |
+
+Advanced: you can override the Automatic value without changing the preference by setting the `RV_EXR_AUTO_MAX_THREADS` environment variable to the desired thread count.
+
+If this doesn't work, deselect **Automatic Threads** and increase the number in Reader/Decoder Threads by 1. Check performances, and increase the thread count by 1. Repeat until performance is acceptable. Note that on systems with many logical cores, using close to the maximum (logical cores minus 1) can make playback *worse*, not better: the decoder threads compete with RV's playback/UI threads, so the system may drop frames or become unstable. On high-core machines, start from the Automatic value rather than from the maximum. If performance is still degraded, you need to look elsewhere, such as upgrading your hardware.
 
 ### About File I/O and Decoding Latency
 

docs/rv-manuals/rv-user-manual/rv-user-manual-chapter-sixteen.md

@@ -68,7 +68,7 @@ RVIO supports all of the same movie, image, and audio formats that RV does inclu
 | -copyright *string*       | Output copyright (movie files, default="")                                                                                                                   |
 | -debug *string*           | Debug category                                                                                                                                               |
 | -version                  | Show RVIO version number                                                                                                                                     |
-| -exrcpus *int*            | EXR thread count (default=*platform dependant*)                                                                                                              |
+| -exrcpus *int*            | EXR decoder thread count (default = number of logical cores)                                                                                                 |
 | -exrRGBA                  | EXR use basic RGBA interface (default=false)                                                                                                                 |
 | -exrInherit               | EXR guesses channel inheritance (default=false)                                                                                                              |
 | -exrIOMethod int [int]    | EXR I/O Method (0=standard, 1=buffered, 2=unbuffered, 3=MemoryMap, 4=AsyncBuffered, 5=AsyncUnbuffered, default=0) and optional chunk size (default=61440)    |

docs/rv-manuals/rv-user-manual/rv-user-manual-chapter-three.md

@@ -168,7 +168,7 @@ You can control the size and number of log files kept by RV with the following e
 | -cmsTypes                         | Show all available Color Management Systems                                                                                                                                                                               |
 | -debug *string*                   | Debug category (events, threads, gpu, audio, audioverbose, dumpaudio, shaders, shadercode, profile, playback, playbackverbose, cache, mu, muc, compile, dtree, passes, imagefbo, nogpucache, imagefbolog, nodes, plugins) |
 | -cinalt                           | Use alternate Cineon/DPX readers                                                                                                                                                                                          |
-| -exrcpus *int*                    | EXR thread count (default=2)                                                                                                                                                                                              |
+| -exrcpus *int*                    | EXR decoder thread count (0 = automatic: logical cores minus 1 up to 16, then 15 plus one per 4 extra logical cores; default=0)                                                                                           |
 | -exrRGBA                          | EXR use basic RGBA interface (default=false)                                                                                                                                                                              |
 | -exrInherit                       | EXR guesses channel inheritance (default=false)                                                                                                                                                                           |
 | -exrIOMethod int [int]            | EXR I/O Method (0=standard, 1=buffered, 2=unbuffered, 3=MemoryMap, 4=AsyncBuffered, 5=AsyncUnbuffered, default=0) and optional chunk size (default=61440)                                                                 |

src/bin/apps/rv/main.cpp

@@ -627,7 +627,7 @@ int utf8Main(int argc, char* argv[])
     }
     else
     {
-        Imf::setGlobalThreadCount(TwkUtil::SystemInfo::numCPUs() > 1 ? (TwkUtil::SystemInfo::numCPUs() - 1) : 1);
+        Imf::setGlobalThreadCount(Rv::automaticExrThreadCount());
     }
 
     //

src/bin/nsapps/RV/main.cpp

@@ -567,7 +567,7 @@ int main(int argc, char* argv[])
     }
     else
     {
-        Imf::setGlobalThreadCount(TwkUtil::SystemInfo::numCPUs() > 1 ? (TwkUtil::SystemInfo::numCPUs() - 1) : 1);
+        Imf::setGlobalThreadCount(Rv::automaticExrThreadCount());
     }
 
     //

src/lib/app/RvApp/Options.cpp

@@ -39,6 +39,8 @@
 #include <TwkUtil/Timer.h>
 #include <TwkAudio/Audio.h>
 #include <algorithm>
+#include <climits>
+#include <cstdlib>
 #include <fstream>
 #include <iostream>
 #include <stl_ext/string_algo.h>
@@ -164,6 +166,45 @@ namespace Rv
                "plugins";
     }
 
+    int automaticExrThreadCount()
+    {
+        //  Explicit override wins (for tuning without a rebuild).
+        if (const char* v = getenv("RV_EXR_AUTO_MAX_THREADS"))
+        {
+            constexpr int kDecimalBase = 10;
+            char* end = nullptr;
+            const long n = strtol(v, &end, kDecimalBase);
+            if (end != v && *end == '\0' && n > 0 && n <= INT_MAX)
+            {
+                return static_cast<int>(n);
+            }
+        }
+
+        const int cores = static_cast<int>(TwkUtil::SystemInfo::numCPUs());
+        if (cores <= 1)
+        {
+            return 1;
+        }
+
+        //  Up to 16 logical cores keep the previous behavior (all but one).
+        //  Above that, add one thread per four extra cores. The decode work
+        //  needed for playback is bounded by the media, not the core count, so
+        //  a large pool (which all readers share) only adds contention with the
+        //  main/UI, audio, caching and compositor threads and drops frames.
+        //  The curve is continuous and monotonic so moving to a machine with
+        //  more cores never lowers the count (e.g. 16 -> 15, 24 -> 17,
+        //  64 -> 27, 128 -> 43). On a 64-logical-core system, 12-32 threads
+        //  played back best and 40+ degraded.
+        constexpr int kAllButOneMaxCores = 16;
+        constexpr int kExtraCoresPerThread = 4;
+        if (cores <= kAllButOneMaxCores)
+        {
+            return cores - 1;
+        }
+
+        return (kAllButOneMaxCores - 1) + (cores - kAllButOneMaxCores) / kExtraCoresPerThread;
+    }
+
     int collectParams(Options::Params& p, const Options::Files& inputFiles, int index)
     {
         int count = -1;

src/lib/app/RvApp/RvApp/Options.h

@@ -360,6 +360,17 @@ namespace Rv
     int parseSendEvents(int, char**);
     const char* getDebugCategories();
 
+    //
+    //  The OpenEXR global thread-pool size to use when the "Automatic" EXR
+    //  thread count is selected (opts.exrcpus == 0). All but one logical core
+    //  up to 16 cores, then growing by one thread per four extra cores, so
+    //  decode threads cannot starve the main/UI, audio and caching threads
+    //  (which caused dropped frames, especially with slow DWA/DWAB frames).
+    //  Overridable via the RV_EXR_AUTO_MAX_THREADS environment variable.
+    //
+
+    int automaticExrThreadCount();
+
 } // namespace Rv
 
 //

src/lib/app/RvCommon/GLWindow.cpp

@@ -23,13 +23,16 @@
 #include <TwkApp/Event.h>
 #include <TwkApp/VideoDevice.h>
 #include <TwkGLF/GLVideoDevice.h>
+#include <TwkUtil/PlaybackDiagnostics.h>
+#include <TwkUtil/Clock.h>
 #include <QOpenGLContext>
 #include <QtGui/QGuiApplication>
 #include <QtGui/QScreen>
 #include <QKeyEvent>
 #include <QResizeEvent>
 #include <QtWidgets/QMenu>
 #include <cmath>
+#include <cstdlib>
 #include <iostream>
 #include <sstream>
 #include <cstdlib>
@@ -145,7 +148,27 @@ namespace Rv
         }
     }
 
-    void GLWindow::eventProcessingTimeout() { m_doc->session()->userGenericEvent("per-render-event-processing", ""); }
+    void GLWindow::eventProcessingTimeout()
+    {
+        IPCore::Session* session = (m_doc != nullptr) ? m_doc->session() : nullptr;
+        if (session == nullptr)
+        {
+            return;
+        }
+
+        //  Time the synchronous per-render event processing (Mu/Python handlers)
+        //  that runs on the GUI thread after each paint.
+        const bool diagOn = session->isPlaying() && TwkUtil::PlaybackDiagnostics::enabled();
+        const double startTime = diagOn ? TwkUtil::SystemClock().now() : 0.0;
+
+        session->userGenericEvent("per-render-event-processing", "");
+
+        if (diagOn)
+        {
+            const double perRenderMs = (TwkUtil::SystemClock().now() - startTime) * TwkUtil::kMillisecondsPerSecond;
+            TwkUtil::PlaybackDiagnostics::instance().record("perrender", -1, session->currentFrame(), perRenderMs);
+        }
+    }
 
     float GLWindow::devicePixelRatioF() const { return static_cast<float>(devicePixelRatio()); }
 
@@ -318,6 +341,41 @@ namespace Rv
         IPCore::Session* session = m_doc->session();
         const bool debug = IPCore::debugProfile && session != nullptr;
 
+        //  Playback present-path diagnostics. The Session-side "outsideGap"
+        //  measures render_v2-end -> next render_v2-start, which lumps together
+        //  the present and the event-loop work (notably the
+        //  per-render-event-processing handler). Here we time the whole paintGL
+        //  and the gap between successive paints so the analyzer can split that
+        //  bucket into present vs event-loop handlers.
+        //
+        //  m_videoDevice is null until the hosting GLView assigns it after
+        //  construction, and the window is created during that construction, so
+        //  a paint can land before the device is wired up. Require it here so we
+        //  never record a paint that did no rendering.
+        static double s_diagPaintEntry = 0.0;
+        static double s_diagPrevPaintExit = 0.0;
+        double diagPaintGap = 0.0;
+        const bool diagOn =
+            (session != nullptr) && (m_videoDevice != nullptr) && session->isPlaying() && TwkUtil::PlaybackDiagnostics::enabled();
+        if (diagOn)
+        {
+            s_diagPaintEntry = TwkUtil::SystemClock().now();
+            if (s_diagPrevPaintExit > 0.0)
+            {
+                diagPaintGap = (s_diagPaintEntry - s_diagPrevPaintExit) * TwkUtil::kMillisecondsPerSecond;
+            }
+        }
+
+        //  Optional GPU-completion probe (RV_DIAG_GLFINISH). session->render()
+        //  only submits GL commands (texture upload + shaders); the GPU runs
+        //  them asynchronously and the present later blocks until they finish.
+        static int s_diagGlFinish = -1;
+        if (s_diagGlFinish < 0)
+        {
+            s_diagGlFinish = (getenv("RV_DIAG_GLFINISH") != nullptr) ? 1 : 0;
+        }
+        double diagGpuMs = -1.0;
+
         if (!m_postFirstNonEmptyRender && session && session->postFirstNonEmptyRender())
         {
             m_postFirstNonEmptyRender = true;
@@ -363,6 +421,13 @@ namespace Rv
             session->render();
             TWK_GLDEBUG;
 
+            if (diagOn && (s_diagGlFinish != 0))
+            {
+                const double t0 = TwkUtil::SystemClock().now();
+                glFinish();
+                diagGpuMs = (TwkUtil::SystemClock().now() - t0) * TwkUtil::kMillisecondsPerSecond;
+            }
+
             m_firstPaintCompleted = true;
 
             // Force the resulting alpha channel to 1 so the surface is fully
@@ -385,6 +450,10 @@ namespace Rv
 
         if (m_stopProcessingEvents || session == nullptr)
         {
+            //  This path skips the "paint" record below, so drop the exit
+            //  timestamp too. Leaving it stale would make the next computed
+            //  gap span everything that happened in between.
+            s_diagPrevPaintExit = 0.0;
             return;
         }
 
@@ -417,6 +486,24 @@ namespace Rv
         session->addSyncSample();
         session->postRender();
 
+        if (diagOn)
+        {
+            const double nowSecs = TwkUtil::SystemClock().now();
+            const double paintMs = (nowSecs - s_diagPaintEntry) * TwkUtil::kMillisecondsPerSecond;
+            s_diagPrevPaintExit = nowSecs;
+            std::ostringstream extra;
+            //  paint = whole paintGL (render_v2 + glClear tail + postRender)
+            //  gap   = previous paint-exit -> this paint-entry. The viewport is a
+            //          QOpenGLWindow, which swaps after paintGL returns, so this
+            //          covers swapBuffers/vsync + platform update-request
+            //          delivery + the event loop between paints. It does NOT
+            //          include a full-window widget composite: the viewport has
+            //          its own native surface and no longer serializes with the
+            //          rest of the window.
+            extra << "paint=" << paintMs << ";gap=" << diagPaintGap << ";gpuFinish=" << diagGpuMs;
+            TwkUtil::PlaybackDiagnostics::instance().record("paint", -1, session->currentFrame(), paintMs, extra.str());
+        }
+
         m_eventProcessingTimer.start();
 
         TWK_GLDEBUG;

src/lib/app/RvCommon/RvPreferences.cpp

@@ -38,6 +38,7 @@
 #include <QtWidgets/QMessageBox>
 #include <QtWidgets/QFileDialog>
 #include <TwkQtCoreUtil/QtConvert.h>
+#include <RvApp/Options.h>
 #include <RvApp/RvSession.h>
 #include <TwkApp/Bundle.h>
 #include <TwkApp/VideoDevice.h>
@@ -1870,7 +1871,7 @@ namespace Rv
     {
         if (m_ui.exrNumThreadsEdit->text() == "0")
         {
-            Imf::setGlobalThreadCount(TwkUtil::SystemInfo::numCPUs() > 1 ? (TwkUtil::SystemInfo::numCPUs() - 1) : 1);
+            Imf::setGlobalThreadCount(Rv::automaticExrThreadCount());
         }
         else
         {
@@ -1885,7 +1886,7 @@ namespace Rv
             m_ui.exrNumThreadsEdit->setText("0");
             m_ui.exrNumThreadsEdit->setEnabled(false);
             m_ui.exrThreadsLabel->setEnabled(false);
-            Imf::setGlobalThreadCount(TwkUtil::SystemInfo::numCPUs() > 1 ? (TwkUtil::SystemInfo::numCPUs() - 1) : 1);
+            Imf::setGlobalThreadCount(Rv::automaticExrThreadCount());
         }
         else
         {

src/lib/audio/ALSASafeAudioModule/ALSASafeAudioRenderer.cpp

@@ -15,6 +15,7 @@
 #include <TwkAudio/Audio.h>
 #include <TwkAudio/AudioFormats.h>
 #include <TwkMovie/Movie.h>
+#include <TwkUtil/PlaybackDiagnostics.h>
 #include <iostream>
 #include <sstream>
 
@@ -1091,6 +1092,16 @@ namespace IPCore
                         cerr << endl;
                     }
 
+                    //  Record ALSA-level audio underruns independently of the
+                    //  -debug audio flag so they show up in the consolidated
+                    //  diagnostic log. -EPIPE is the classic hardware underrun.
+                    if (TwkUtil::PlaybackDiagnostics::enabled())
+                    {
+                        std::ostringstream extra;
+                        extra << "err=" << snd_strerror((int)frames);
+                        TwkUtil::PlaybackDiagnostics::instance().record("underrun", -1, -1, 0.0, extra.str());
+                    }
+
                     if (!m_pcm)
                         return;
 #ifdef USE_SAFE_ALSA
@@ -1115,6 +1126,11 @@ namespace IPCore
 
             if (pcmState == SND_PCM_STATE_XRUN)
             {
+                if (TwkUtil::PlaybackDiagnostics::enabled())
+                {
+                    TwkUtil::PlaybackDiagnostics::instance().record("underrun", -1, -1, 0.0, "state=xrun");
+                }
+
                 if (!m_pcm)
                     return;
                 if (snd_pcm_prepare(m_pcm) < 0)

src/lib/audio/ALSASafeAudioModule/CMakeLists.txt

@@ -24,7 +24,7 @@ ADD_LIBRARY(
 TARGET_INCLUDE_DIRECTORIES(
   ${_target}
   PUBLIC ${CMAKE_CURRENT_SOURCE_DIR} "$<TARGET_PROPERTY:IPCore,INTERFACE_INCLUDE_DIRECTORIES>" "$<TARGET_PROPERTY:IPBaseNodes,INTERFACE_INCLUDE_DIRECTORIES>"
-         "$<TARGET_PROPERTY:RvApp,INTERFACE_INCLUDE_DIRECTORIES>"
+         "$<TARGET_PROPERTY:RvApp,INTERFACE_INCLUDE_DIRECTORIES>" "$<TARGET_PROPERTY:TwkUtil,INTERFACE_INCLUDE_DIRECTORIES>"
 )
 
 TARGET_LINK_LIBRARIES(

src/lib/base/TwkUtil/CMakeLists.txt

@@ -41,6 +41,7 @@ SET(_sources
     MemPool.cpp
     FNV1a.cpp
     Log.cpp
+    PlaybackDiagnostics.cpp
     Clock.cpp
     sgcHopImplementation.cpp
     sgcHopTools.cpp