Prototype/Demo: add IO timing measurement

- use a helper class with a series of timer variables
- these can be addressed like the buffer ring »slots«
- commit each individual measurement into an EMA

FrOSCon26/FrOSCon.26.mm

@@ -2433,6 +2433,49 @@
 </html></richcontent>
 </node>
 </node>
+<node COLOR="#435e98" CREATED="1784335264402" ID="ID_494036485" MODIFIED="1784337690200" TEXT="IO-Laufzeiten messen">
+<arrowlink COLOR="#a6fdfd" DESTINATION="ID_1315195836" ENDARROW="Default" ENDINCLINATION="-1219;90;" ID="Arrow_ID_462277871" STARTARROW="None" STARTINCLINATION="-89;575;"/>
+<node CREATED="1784335284745" ID="ID_1701920818" MODIFIED="1784337685187" TEXT="es geht nur um eine diagnostische Ausgabe">
+<icon BUILTIN="yes"/>
+<node CREATED="1784335310132" ID="ID_74981723" MODIFIED="1784335319627" TEXT="hier wird eine Zeitreihe beobachtet">
+<icon BUILTIN="idea"/>
+</node>
+<node CREATED="1784335320658" ID="ID_1702163307" MODIFIED="1784335336932" TEXT="man kann aber nur jeden k-ten-Wert ausgeben (weil sonst zu schnell)"/>
+<node CREATED="1784335337812" ID="ID_1692924948" MODIFIED="1784335361432" TEXT="&#x27f9; klassicher Fall f&#xfc;r einen exponentiellen-moving-average">
+<node CREATED="1784335368476" ID="ID_77716704" MODIFIED="1784335539730" TEXT="siehe hauZu.mm">
+<richcontent TYPE="NOTE"><html>
+  <head/>
+  <body>
+    <p>
+      der &#187;alte Wert&#171; wird jeweils mit (N-1)/N multipliziert
+    </p>
+    <p>
+      n meiner Rationalisierung w&#228;re dann &#945; &#8788; 1/N&#160;&#160;&#10233; 1-&#945; = (N-1)/N
+    </p>
+    <p>
+      <font face="SansSerif, sans-serif"><b>D&#228;mpfungsfaktor &#945;</b></font>
+    </p>
+    <p>
+      EMA(i) = &#945; &#183; value(i) + (1- &#945;) &#183; EMA(i-1)
+    </p>
+  </body>
+</html></richcontent>
+</node>
+<node CREATED="1784335588727" ID="ID_1900875309" MODIFIED="1784335609726" TEXT="kann Mittelungs-Periode als Template-Parameter definieren"/>
+</node>
+</node>
+<node CREATED="1784335615306" ID="ID_639063024" MODIFIED="1784335631453" TEXT="Code-Lesbarkeit: sollte Timer komplett &#xbb;daneben&#xab; stellen">
+<node COLOR="#338800" CREATED="1784335636544" ID="ID_267882121" MODIFIED="1784337678294" TEXT="definiere eine ma&#xdf;geschneiderte Timer-Klasse in den &#xbb;commons&#xab;">
+<icon BUILTIN="button_ok"/>
+<node CREATED="1784335697343" ID="ID_1157691393" MODIFIED="1784335705962" TEXT="verwendet ein Array von Einzel-Timern"/>
+<node CREATED="1784335706628" ID="ID_848237208" MODIFIED="1784335719033" TEXT="Zeitmessugs-Code mit std::chrono"/>
+<node CREATED="1784335719545" ID="ID_1863925346" MODIFIED="1784335733140" TEXT="siehe microbenchmark.hpp"/>
+</node>
+<node COLOR="#435e98" CREATED="1784335673422" ID="ID_1048715353" MODIFIED="1784337675374" TEXT="die wird dann in eine globale Variable gepackt und gut is">
+<icon BUILTIN="yes"/>
+</node>
+</node>
+</node>
 <node CREATED="1784229335474" ID="ID_476891533" MODIFIED="1784229337398" TEXT="Fragen">
 <node BACKGROUND_COLOR="#f0d5c5" COLOR="#990033" CREATED="1784229339746" ID="ID_655619575" MODIFIED="1784229414327" TEXT="bisher habe ich in addNext... die mem_order_seq_cst">
 <richcontent TYPE="NOTE"><html>
@@ -2550,8 +2593,7 @@
       Das war ein ganz selten herausragendes Feuerwerk, und ich erinnere mich da&#223; mir einige sehr gut abgeschlossene Sequenzen gelungen sind
     </p>
   </body>
-</html>
-</richcontent>
+</html></richcontent>
 <node CREATED="1784298243470" ID="ID_396338130" MODIFIED="1784298274562" TEXT="Lumix/vidzzz/"/>
 <node CREATED="1784298326663" ID="ID_125254865" MODIFIED="1784298916848" TEXT="00535.mts">
 <node CREATED="1784299006300" ID="ID_539210641" MODIFIED="1784299124443" TEXT="ab 0:15">
@@ -2572,8 +2614,7 @@
       ...das w&#228;re dann aber eine l&#228;ngere Sequenz, beginnend mit den goldgelben Garben am untern Bildrand, und dann ein Bouquet aus gro&#223;en Kugeln, die ihre Farbe von Blau &#252;ber Rot entfalten. Klassisches Feuerwerk
     </p>
   </body>
-</html>
-</richcontent>
+</html></richcontent>
 </node>
 </node>
 <node CREATED="1784298340820" ID="ID_1114649715" MODIFIED="1784298919194" TEXT="00536.mts">
@@ -2595,8 +2636,7 @@
       auch das eine ehr langsame und zeitlose Sequenz; besonders im Zusammenspiel mit den Pulverwolken und Spuren am Ende
     </p>
   </body>
-</html>
-</richcontent>
+</html></richcontent>
 </node>
 </node>
 </node>
@@ -2613,8 +2653,7 @@
       Wegen dem Recht am Bild. Zwar ist die Rechtslage in Deutschland eindeutig (Panoramafreiheit sowie Geschehen der relativen Zeitgeschichte), jedoch k&#246;nnte es &#196;rger geben, wenn jemand erkennbar prominent im Bild ist. Bei der bezeichneten Szene w&#228;re das vor 1:15 der Fall, wo mehrere Leute direkt im Vordergrund Gruppen-Selfies machen; das k&#246;nnte man m.E. unbesorgt einsetzen, wenn man die Gesamt-Szene zeigt, aber f&#252;r einen kurzen Ausschnitt sollte ich besser vorsichtig sein. Daher w&#228;hle ich die n&#228;chste Sequenz, in der selbst in der Gruppe mit den Wunderkerzen keine Gesichter prominent erkennbar sind
     </p>
   </body>
-</html>
-</richcontent>
+</html></richcontent>
 <icon BUILTIN="messagebox_warning"/>
 </node>
 <node BACKGROUND_COLOR="#ccb59b" COLOR="#6e2a38" CREATED="1784298493000" ID="ID_403555231" MODIFIED="1784298588968" TEXT="da ist mir eine zetlose Szene gelungen">
@@ -2625,8 +2664,7 @@
       Die Kamera bewegt sich fl&#252;ssig nach links durch eine gut gelaunte Menschenmenge, eine Gruppe mit Wunderkerzen, eine Steinskulptur, dahinter die Flu&#223;br&#252;cke randvoll mit einer Menschenmasse und ein irres Feuerwerk dar&#252;ber, schon halb im Pulverdampf
     </p>
   </body>
-</html>
-</richcontent>
+</html></richcontent>
 <font ITALIC="true" NAME="SansSerif" SIZE="14"/>
 <icon BUILTIN="yes"/>
 </node>
@@ -2654,8 +2692,7 @@
       bitrate=972000.0kbits/s video:2373047KiB&#160;&#160;&#8793; <b><font color="#890707">2.3</font></b><font color="#890707">&#160; GiB</font>
     </p>
   </body>
-</html>
-</richcontent>
+</html></richcontent>
 <linktarget COLOR="#5bfe3a" DESTINATION="ID_1648226456" ENDARROW="Default" ENDINCLINATION="-269;14;" ID="Arrow_ID_1321145390" SOURCE="ID_1577242171" STARTARROW="None" STARTINCLINATION="238;17;"/>
 </node>
 <node CREATED="1784304034683" ID="ID_428549034" MODIFIED="1784304887052" TEXT="anzeigen mit...">
@@ -2789,6 +2826,10 @@
 <font NAME="SansSerif" SIZE="11"/>
 <icon BUILTIN="back"/>
 </node>
+<node COLOR="#054262" CREATED="1784239826448" ID="ID_1315195836" MODIFIED="1784337690200" STYLE="fork" TEXT="Beobachtung: &#x2205; IO ~ 1.2ms (mag HD)">
+<linktarget COLOR="#a6fdfd" DESTINATION="ID_1315195836" ENDARROW="Default" ENDINCLINATION="-1219;90;" ID="Arrow_ID_462277871" SOURCE="ID_494036485" STARTARROW="None" STARTINCLINATION="-89;575;"/>
+<font NAME="SansSerif" SIZE="11"/>
+</node>
 </node>
 </node>
 </node>

FrOSCon26/examples/commons.hpp

@@ -17,6 +17,7 @@
 #include <iostream>
 #include <chrono>
 #include <string>
+#include <array>
 
 #include <linux/time_types.h>   // for struct __kernel_timespec
 
@@ -61,4 +62,45 @@ asKernelTimespec (std::chrono::duration<REP, SCALE> dur)
                           };
 }
 
+
+/**
+ * A series of timers for performance measurement, that can be used in interleaved.
+ * When marking the end of each timed interval, the resulting duration is committed
+ * into an exponential moving average of all observed timings.
+ * @note not threadsafe, only to be used from within a single thread.
+ */
+template<uint cnt, uint ema_period>
+class OverlappingTimers
+  {
+    using Scale = std::micro;  // timings in µs
+    using Clock = std::chrono::steady_clock;
+    using Time  = decltype(Clock::now());
+    using Dur   = std::chrono::duration<double, Scale>;
+
+    std::array<Time, cnt> timer_{Time{}};
+
+    /** damping factor to compute exponential moving average
+        EMA(i) = value(i)/N + (N-1)/N · EMA(i-1) */
+    static constexpr double ALPHA = 1.0 / ema_period;
+    double expMA_{1};
+
+  public:
+    double expMA() { return expMA_; }
+
+    void
+    markStart (uint timerID)
+      {
+        timer_[timerID % cnt] = Clock::now();
+      }
+
+    double
+    markStop (uint timerID)
+      {
+        Dur duration = Clock::now () - timer_[timerID % cnt];
+        double runTime = duration.count();
+        expMA_ = ALPHA * runTime + (1-ALPHA) * expMA_;
+        return runTime;
+      }
+  };
+
 #endif /*COMMONS_H*/

FrOSCon26/examples/demo-uring.cpp

@@ -37,9 +37,18 @@ const size_t MAX_LOOP_FRAME = 960;
 
 auto calcSrcFrame = [](size_t runningNr){ return START_FRAME + runningNr % MAX_LOOP_FRAME; };
 
+const uint EMA_PERIOD = 20;
 //-----------------hard-coded-config--
 
 
+namespace {
+  /** a set of timers, one for each buffer »slot«
+   *  to observe average IO times */
+  OverlappingTimers<RING_SIZ, EMA_PERIOD> timings;
+}
+
+
+
 /**
  * Read video frames from a raw video file and pass them to OpenGL display.
  * Using a »Proactor« thread to coordinate reading via IO_URING.
@@ -204,6 +213,7 @@ UringVideoPlayer::addNextReadSubmissions (io_uring& uRing, int inputFD)
                          );
       io_uring_sqe_set_data64 (readSubmission, nextRead_);
       buffState_[nextRead_ % RING_SIZ].store (READ, std::memory_order_relaxed);
+      timings.markStart (nextRead_);
       ++nextRead_;
     }
 }
@@ -219,6 +229,8 @@ UringVideoPlayer::handleCompletedRead (io_uring_cqe& completion)
   size_t frameNr = completion.user_data;              // Note: completion was marked with the frameNr as »user data«
   auto& state = buffState_[frameNr % RING_SIZ];       // Can thus pick buffer slot based on frame number, cycling through the ring
 
+  timings.markStop(frameNr);
+
   if (completion.res != sizeof(Buffer))
     state.store(STOP, std::memory_order_relaxed);     // Insufficient read, possibly end-of-file => signal stop of playback (to ourselves)
   else
@@ -249,6 +261,9 @@ UringVideoPlayer::maybeDisplayFrame()
       buffState_[currShow_ % RING_SIZ].store (SHOW, std::memory_order_release);
       // Notify GUI thread via Glib::Dispatcher
       dispatchFrame_();
+
+      if (0 == currShow_ % EMA_PERIOD)
+        std::cout << "Frame #"<<currShow_<<" IO ∅ "<<timings.expMA()<<"µs"<< std::endl;
     }
   else
   if (nextState == STOP)