From a71bcaae4368a08d9f323f6841176e56ebd818b3 Mon Sep 17 00:00:00 2001
From: Ichthyostega <prg@ichthyostega.de>
Date: Wed, 25 Oct 2023 23:43:19 +0200
Subject: [PATCH] Scheduler: shorthand notation for work-Function test

To cover the visible behaviour of the work-Function,
we have to check an amalgam of timing delays and time differences.

This kind of test tends to be problematic, since timings are always
random and also machine dependent, and thus we need to produce pronounced effects
---
 src/lib/test/microbenchmark.hpp             |  2 +-
 src/vault/gear/scheduler.hpp                |  6 +++
 tests/vault/gear/scheduler-service-test.cpp | 54 ++++++++++++++++-----
 wiki/thinkPad.ichthyo.mm                    | 23 +++++++++
 4 files changed, 72 insertions(+), 13 deletions(-)

diff --git a/src/lib/test/microbenchmark.hpp b/src/lib/test/microbenchmark.hpp
index 28b904fec..d733f93d7 100644
--- a/src/lib/test/microbenchmark.hpp
+++ b/src/lib/test/microbenchmark.hpp
@@ -88,7 +88,7 @@ namespace test{
     auto start = system_clock::now();
     invokeTestLoop();
     Dur duration = system_clock::now () - start;
-    return duration.count()/(repeatCnt);
+    return duration.count() / repeatCnt;
   };
   
   
diff --git a/src/vault/gear/scheduler.hpp b/src/vault/gear/scheduler.hpp
index 10acbf42e..a861578fa 100644
--- a/src/vault/gear/scheduler.hpp
+++ b/src/vault/gear/scheduler.hpp
@@ -123,6 +123,12 @@ namespace gear {
         { }
       
       
+      bool
+      empty()  const
+        {
+          return layer1_.empty();
+        }
+      
       /**
        * 
        */
diff --git a/tests/vault/gear/scheduler-service-test.cpp b/tests/vault/gear/scheduler-service-test.cpp
index 43e3a484b..b2b89ca41 100644
--- a/tests/vault/gear/scheduler-service-test.cpp
+++ b/tests/vault/gear/scheduler-service-test.cpp
@@ -30,6 +30,7 @@
 #include "vault/gear/scheduler.hpp"
 #include "lib/time/timevalue.hpp"
 #include "lib/format-cout.hpp"
+#include "lib/test/microbenchmark.hpp"
 #include "lib/test/diagnostic-output.hpp"///////////////TODO
 //#include "lib/util.hpp"
 
@@ -99,22 +100,51 @@ namespace test {
           
           // this test class is declared friend to get a backdoor to Scheduler internals...
           auto& schedCtx = Scheduler::ExecutionCtx::from(scheduler);
-          Time now = schedCtx.getSchedTime();
-          schedCtx.post (now, &probe, schedCtx);
           
-          CHECK (activity::WAIT == scheduler.getWork());
           
-          cout << detector.showLog()<<endl; // HINT: use this for investigation...
-          CHECK (detector.verifyInvocation("testProbe"));
-          ////////////////////////////////////////////////////////////////////////////////////TODO need a way to get the actual time passed to the Probe
-SHOW_EXPR(now)
-SHOW_EXPR(detector.invokeTime(probe))
 
           auto wasClose = [](TimeValue a, TimeValue b)
-                            {
-                              return Duration{Offset{a,b}} < Duration{FSecs{1,2000}}; // 500µs are considered "close"
-                            };
-          CHECK (wasClose (now, detector.invokeTime (probe)));
+                              {                                // 500µs are considered "close"
+                                return Duration{Offset{a,b}} < Duration{FSecs{1,2000}};
+                              };
+          auto wasInvoked = [&](Time start)
+                              {
+                                Time invoked = detector.invokeTime (probe);
+                                return invoked >= start
+                                   and wasClose (invoked, start);
+                              };
+          
+          TimeVar start = RealClock::now();
+          schedCtx.post (start, &probe, schedCtx);
+SHOW_EXPR(_raw(start))
+SHOW_EXPR(_raw(detector.invokeTime(probe)))
+          
+          CHECK (wasInvoked(start));
+          CHECK (scheduler.empty());
+          
+          activity::Proc res;
+          double delay_us;
+          int64_t slip_us;
+          
+          
+          auto pullWork = [&] {
+                                uint REPETITIONS = 1;
+                                delay_us = lib::test::benchmarkTime([&]{ res = scheduler.getWork(); }, REPETITIONS);
+                                slip_us = _raw(detector.invokeTime(probe)) - _raw(start);
+                              };
+
+//          start = RealClock::now();
+          pullWork();
+          
+SHOW_EXPR(_raw(start))
+SHOW_EXPR(_raw(detector.invokeTime(probe)))
+SHOW_EXPR(res);
+SHOW_EXPR(delay_us)
+SHOW_EXPR(slip_us)
+SHOW_EXPR(wasInvoked(start))
+          CHECK (activity::WAIT == res);
+          
+          cout << detector.showLog()<<endl; // HINT: use this for investigation...
         }
       
       
diff --git a/wiki/thinkPad.ichthyo.mm b/wiki/thinkPad.ichthyo.mm
index dabec0da9..05f9647bf 100644
--- a/wiki/thinkPad.ichthyo.mm
+++ b/wiki/thinkPad.ichthyo.mm
@@ -88196,6 +88196,12 @@ Date:&#160;&#160;&#160;Thu Apr 20 18:53:17 2023 +0200<br/>
 <node CREATED="1698246275186" ID="ID_389803917" MODIFIED="1698246286348" TEXT="bei jedem Aufruf im Objekt speichern"/>
 <node CREATED="1698246286912" ID="ID_1611070007" MODIFIED="1698246292046" TEXT="Zugriffs-Funktion schaffen"/>
 </node>
+<node BACKGROUND_COLOR="#eef0c5" COLOR="#990000" CREATED="1698273941216" ID="ID_206667469" MODIFIED="1698273954614" TEXT="Kurznotation entwickeln zum Formulieren der Testf&#xe4;lle">
+<icon BUILTIN="pencil"/>
+<node CREATED="1698273959952" ID="ID_1633573295" MODIFIED="1698273977867" TEXT="lokale Abk&#xfc;rzungs-&#x3bb;"/>
+<node CREATED="1698273979493" ID="ID_1574422283" MODIFIED="1698273987600" TEXT="Zeitmessung fest einbauen"/>
+<node CREATED="1698273988136" ID="ID_1921986548" MODIFIED="1698274003262" TEXT="Werte in immer gleiche Variable &#x201e;abwerfen&#x201c;"/>
+</node>
 </node>
 </node>
 <node BACKGROUND_COLOR="#eee5c3" COLOR="#990000" CREATED="1697473158929" ID="ID_1723058065" MODIFIED="1697484548083" TEXT="vollst&#xe4;ndiger Ende-zu-Ende Test incl. WorkForce">
@@ -88208,6 +88214,19 @@ Date:&#160;&#160;&#160;Thu Apr 20 18:53:17 2023 +0200<br/>
 <icon BUILTIN="pencil"/>
 </node>
 </node>
+<node BACKGROUND_COLOR="#fafe99" COLOR="#fa002a" CREATED="1698275299501" ID="ID_1052614531" MODIFIED="1698275445662" TEXT="DAS DING ZUCKT">
+<arrowlink COLOR="#e9fea5" DESTINATION="ID_353022740" ENDARROW="Default" ENDINCLINATION="-90;-5;" ID="Arrow_ID_187000480" STARTARROW="None" STARTINCLINATION="51;7;"/>
+<font NAME="SansSerif" SIZE="16"/>
+<icon BUILTIN="launch"/>
+<node COLOR="#435e98" CREATED="1698275461079" HGAP="31" ID="ID_1605227309" MODIFIED="1698275499061" TEXT="erste Timings sehen doch ganz ordentlich aus..." VSHIFT="-2">
+<edge COLOR="#a8fe8d"/>
+<icon BUILTIN="clock"/>
+<node CREATED="1698275564705" ID="ID_181492806" MODIFIED="1698275568734" TEXT="-O3">
+<node CREATED="1698275570360" ID="ID_1639263149" MODIFIED="1698275580859" TEXT="leere work-Function: 2&#xb5;s"/>
+<node CREATED="1698275583014" ID="ID_1884559465" MODIFIED="1698275618806" TEXT="post() einstellen &#x27f6; Dispatch: 5&#xb5;s"/>
+</node>
+</node>
+</node>
 <node CREATED="1697758391611" ID="ID_124711923" MODIFIED="1697758397083" TEXT="F&#xe4;lle">
 <node CREATED="1697758425500" ID="ID_1450418166" MODIFIED="1697758430911" TEXT="simpleUsage">
 <node CREATED="1697758440737" ID="ID_1211803424" MODIFIED="1697758454084" TEXT="zeigt hier vor allem was man braucht"/>
@@ -88220,6 +88239,10 @@ Date:&#160;&#160;&#160;Thu Apr 20 18:53:17 2023 +0200<br/>
 <node COLOR="#338800" CREATED="1698247394051" ID="ID_198829622" MODIFIED="1698247420009" TEXT="kann einfachen Aufruf einer vorher eingespielten Activity belegen">
 <icon BUILTIN="button_ok"/>
 </node>
+<node COLOR="#338800" CREATED="1698275364348" ID="ID_353022740" MODIFIED="1698275448819" TEXT="kann direkt weitergeleitete Invocation zeigen">
+<linktarget COLOR="#e9fea5" DESTINATION="ID_353022740" ENDARROW="Default" ENDINCLINATION="-90;-5;" ID="Arrow_ID_187000480" SOURCE="ID_1052614531" STARTARROW="None" STARTINCLINATION="51;7;"/>
+<icon BUILTIN="button_ok"/>
+</node>
 </node>
 </node>
 </node>