Scheduler: can demonstrate basic behaviour

- invoked right away
- pre-sleep to tend next
- post-sleep if next activity follows at a distance
This commit is contained in:
Fischlurch 2023-10-26 01:55:26 +02:00
parent a71bcaae43
commit a90a5d9636
4 changed files with 218 additions and 25 deletions

View file

@ -202,10 +202,11 @@ namespace gear {
Capacity
markOutgoingCapacity (Time head, Time now)
{
if (head == Time::NEVER) return IDLEWAIT; // empty queue
auto horizon = classifyTimeHorizon (Offset{head - now});
return horizon > SPINTIME
and not tendedNext(head)? TENDNEXT
: horizon==IDLEWAIT ? WORKTIME
: horizon==IDLEWAIT ? WORKTIME // re-randomise sleeper cycles
: horizon;
}

View file

@ -194,7 +194,7 @@ namespace gear {
Time
headTime() const
{
return priority_.empty()? Time::ANYTIME
return priority_.empty()? Time::NEVER
: Time{TimeValue{priority_.top().waterlevel}};
} //Note: 64-bit waterLevel corresponds to µ-Ticks

View file

@ -35,6 +35,7 @@
//#include "lib/util.hpp"
//#include <utility>
#include <thread>
using test::Test;
//using std::move;
@ -48,7 +49,14 @@ namespace test {
// using lib::time::FrameRate;
// using lib::time::Offset;
using lib::time::Time;
using std::this_thread::sleep_for;
namespace { ////////////////////////////////////////////////////////////////////TICKET #1055 want to construct lumiera Time from std::chrono literals
Time t100us = Time{FSecs{1, 10'000}};
Time t200us = t100us + t100us;
Time t500us = t200us + t200us + t100us;
Time t1ms = Time{1,0};
}
@ -85,7 +93,13 @@ namespace test {
/** @test TODO verify visible behaviour of the work-pulling function
/** @test verify visible behaviour of the [work-pulling function](\ref Scheduler::getWork)
* - use a rigged Activity probe to capture the schedule time on invocation
* - additionally perform a timing measurement for invoking the work-function
* - empty invocations cost ~5µs (-O3) rsp. ~25µs (debug)
* - this implies we can show timing-delay effects in the millisecond range
* - demonstrated behaviour
* + an Activity already due will be dispatched immediately by post()
* @todo WIP 10/23 🔁 define implement
*/
void
@ -98,9 +112,24 @@ namespace test {
ActivityDetector detector;
Activity& probe = detector.buildActivationProbe ("testProbe");
// this test class is declared friend to get a backdoor to Scheduler internals...
auto& schedCtx = Scheduler::ExecutionCtx::from(scheduler);
TimeVar start;
int64_t delay_us;
int64_t slip_us;
activity::Proc res;
auto post = [&](Time start)
{ // this test class is declared friend to get a backdoor to Scheduler internals...
auto& schedCtx = Scheduler::ExecutionCtx::from(scheduler);
schedCtx.post (start, &probe, schedCtx);
};
auto pullWork = [&] {
uint REPETITIONS = 1;
delay_us = lib::test::benchmarkTime([&]{ res = scheduler.getWork(); }, REPETITIONS);
slip_us = _raw(detector.invokeTime(probe)) - _raw(start);
cout << "res:"<<res<<" delay="<<delay_us<<"µs slip="<<slip_us<<"µs"<<endl;
};
auto wasClose = [](TimeValue a, TimeValue b)
@ -114,25 +143,17 @@ namespace test {
and wasClose (invoked, start);
};
TimeVar start = RealClock::now();
schedCtx.post (start, &probe, schedCtx);
cout << "Scheduled right away..."<<endl;
start = RealClock::now();
post(start);
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);
};
cout << "pullWork() on empty queue..."<<endl;
// start = RealClock::now();
pullWork();
@ -143,6 +164,104 @@ SHOW_EXPR(delay_us)
SHOW_EXPR(slip_us)
SHOW_EXPR(wasInvoked(start))
CHECK (activity::WAIT == res);
CHECK (slip_us < 100);
cout << "Due at pullWork()..."<<endl;
TimeVar now = RealClock::now();
start = now + t100us;
post (start);
CHECK (not scheduler.empty());
TimeVar cow = RealClock::now();
sleep_for (100us);
TimeVar wow = RealClock::now();
pullWork();
SHOW_EXPR(_raw(now))
SHOW_EXPR(_raw(cow))
SHOW_EXPR(_raw(wow))
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);
CHECK (wasInvoked(start));
CHECK (scheduler.empty());
CHECK (delay_us < 500);
CHECK (slip_us < 500);
cout << "next some time ahead => up-front delay"<<endl;
now = RealClock::now();
start = now + t500us;
post (start);
CHECK (not scheduler.empty());
pullWork();
SHOW_EXPR(_raw(now))
SHOW_EXPR(_raw(cow))
SHOW_EXPR(_raw(wow))
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::PASS == res);
CHECK (not wasInvoked(start));
CHECK (delay_us > 500);
CHECK (delay_us < 1000);
pullWork();
SHOW_EXPR(_raw(now))
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 (wasInvoked(start));
CHECK (delay_us < 200);
CHECK (slip_us < 500);
CHECK (activity::WAIT == res);
CHECK (scheduler.empty());
cout << "follow-up with some distance => follow-up delay"<<endl;
now = RealClock::now();
start = now + t100us;
post (start);
post (start+t1ms);
sleep_for (100us);
pullWork();
SHOW_EXPR(_raw(now))
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))
SHOW_EXPR(scheduler.empty())
CHECK (wasInvoked(start));
CHECK (delay_us > 900);
CHECK (slip_us < 100);
CHECK (activity::PASS == res);
CHECK (not scheduler.empty());
start += t1ms;
pullWork();
SHOW_EXPR(_raw(now))
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))
SHOW_EXPR(scheduler.empty())
CHECK (wasInvoked(start));
CHECK (delay_us < 500);
CHECK (slip_us < 500);
CHECK (activity::WAIT == res);
CHECK (scheduler.empty());
cout << detector.showLog()<<endl; // HINT: use this for investigation...
}

View file

@ -88162,14 +88162,14 @@ Date:&#160;&#160;&#160;Thu Apr 20 18:53:17 2023 +0200<br/>
</node>
<node BACKGROUND_COLOR="#f0d5c5" COLOR="#990033" CREATED="1698243664309" ID="ID_654541946" MODIFIED="1698243687277" TEXT="was kann man sinnvollerweise pr&#xfc;fen?">
<icon BUILTIN="help"/>
<node CREATED="1698243697817" ID="ID_83311166" MODIFIED="1698243708627" TEXT="eine eingespiele Activity wird aufgerufen"/>
<node CREATED="1698243756225" ID="ID_489965107" MODIFIED="1698268874810" TEXT="was f&#xe4;llig ist, wird direkt vom post() aufgerufen"/>
<node CREATED="1698243756225" ID="ID_831882516" MODIFIED="1698268923359" TEXT="was f&#xe4;llig wurde, wird unverz&#xf6;gert aufgerufen"/>
<node COLOR="#435e98" CREATED="1698243697817" ID="ID_83311166" MODIFIED="1698282740280" TEXT="eine eingespiele Activity wird aufgerufen"/>
<node COLOR="#435e98" CREATED="1698243756225" ID="ID_489965107" MODIFIED="1698282742903" TEXT="was f&#xe4;llig ist, wird direkt vom post() aufgerufen"/>
<node COLOR="#435e98" CREATED="1698243756225" ID="ID_831882516" MODIFIED="1698282748223" TEXT="was f&#xe4;llig wurde, wird unverz&#xf6;gert aufgerufen"/>
<node CREATED="1698243881573" ID="ID_1520192624" MODIFIED="1698243892539" TEXT="es wird genau eine scheduled Activity aufgerufen"/>
<node CREATED="1698243927930" ID="ID_1326757783" MODIFIED="1698243935709" TEXT="die Zeit wird in etwa eingehalten"/>
<node CREATED="1698243794737" ID="ID_1290805695" MODIFIED="1698243800463" TEXT="das Delay-Regime">
<node CREATED="1698243828655" ID="ID_763249245" MODIFIED="1698243855201" TEXT="Abstand davor &#x27f6; delay"/>
<node CREATED="1698243897342" ID="ID_1722957398" MODIFIED="1698243904507" TEXT="Abstand danch &#x27f6; delay"/>
<node COLOR="#435e98" CREATED="1698243828655" ID="ID_763249245" MODIFIED="1698283821102" TEXT="Abstand davor &#x27f6; delay"/>
<node COLOR="#435e98" CREATED="1698243897342" ID="ID_1722957398" MODIFIED="1698284587766" TEXT="Abstand danch &#x27f6; delay"/>
<node CREATED="1698243973380" ID="ID_664100190" MODIFIED="1698244000012" TEXT="tendedNext &#x27f6; re-Fokussiert"/>
<node CREATED="1698245002134" ID="ID_1016395299" MODIFIED="1698245069840" TEXT="nichts danach &#x27f6; re-Distribution">
<linktarget COLOR="#758fa6" DESTINATION="ID_1016395299" ENDARROW="Default" ENDINCLINATION="302;-22;" ID="Arrow_ID_1135387860" SOURCE="ID_28419292" STARTARROW="None" STARTINCLINATION="246;369;"/>
@ -88196,11 +88196,72 @@ 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 COLOR="#338800" CREATED="1698273941216" ID="ID_206667469" MODIFIED="1698284642804" TEXT="Kurznotation entwickeln zum Formulieren der Testf&#xe4;lle">
<icon BUILTIN="button_ok"/>
<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 COLOR="#338800" CREATED="1698284627849" ID="ID_67028891" MODIFIED="1698284640378" TEXT="Kurzzusammenfassung auf COUT">
<icon BUILTIN="button_ok"/>
</node>
</node>
</node>
<node CREATED="1698284661806" ID="ID_1944621845" MODIFIED="1698284671052" TEXT="Beobachtungen">
<icon BUILTIN="forward"/>
<node CREATED="1698284676624" ID="ID_298507876" MODIFIED="1698284714617" TEXT="sleep_for() schl&#xe4;ft meist mindestens 100&#xb5;s l&#xe4;nger"/>
<node CREATED="1698284725963" ID="ID_1453000254" MODIFIED="1698284777544" TEXT="das h&#xe4;ngt &#xfc;berhaupt nicht mit den Laufzeiten zusammen">
<richcontent TYPE="NOTE"><html>
<head>
</head>
<body>
<p>
also optimized vs. Debug-Build; ja man sieht diesen Unterschied im &quot;slip&quot;, weil einfach die Verarbeitung l&#228;nger dauert
</p>
</body>
</html>
</richcontent>
</node>
<node BACKGROUND_COLOR="#fafe99" COLOR="#fa002a" CREATED="1698285072189" ID="ID_1552477309" MODIFIED="1698285083854" TEXT="Logik-Fehler mit tendNext">
<icon BUILTIN="broken-line"/>
<node CREATED="1698285085530" ID="ID_991445216" MODIFIED="1698285104841">
<richcontent TYPE="NODE"><html>
<head>
</head>
<body>
<p>
habe generell hier den Fall der <i>leeren Queue </i>nicht bedacht
</p>
</body>
</html>
</richcontent>
</node>
<node BACKGROUND_COLOR="#e0ceaa" COLOR="#690f14" CREATED="1698285116679" ID="ID_496699258" MODIFIED="1698285143092" TEXT="Logik versucht auf Time::NEVER zu warten">
<icon BUILTIN="ksmiletris"/>
</node>
<node BACKGROUND_COLOR="#fdfdcf" COLOR="#ff0000" CREATED="1698285158209" ID="ID_506319711" MODIFIED="1698285203986" TEXT="korrekt w&#xe4;re: per Nach-Verz&#xf6;gerung die Schl&#xe4;fer umverteilen">
<icon BUILTIN="forward"/>
</node>
</node>
<node BACKGROUND_COLOR="#f0d5c5" COLOR="#990033" CREATED="1698284783980" ID="ID_40062147" MODIFIED="1698284826263" TEXT="warum sehe ich auch in den &#xbb;leer&#xab;-F&#xe4;llen einen delay ~ 100&#xb5;s ?">
<font NAME="SansSerif" SIZE="12"/>
<icon BUILTIN="help"/>
<node CREATED="1698284852474" ID="ID_1979114462" MODIFIED="1698284871452" TEXT="Beispiel: der Fall &#xbb;Abstand danach&#xab;"/>
<node CREATED="1698284873176" ID="ID_408802871" MODIFIED="1698284905711" TEXT="in diesen F&#xe4;llen erwarte ich keinerlei sleep-Aufruf">
<node CREATED="1698284916562" ID="ID_78118685" MODIFIED="1698284962495" TEXT="der n&#xe4;chste ist schon f&#xe4;llig &#x27fc; DISPATCH"/>
<node CREATED="1698284926059" ID="ID_1262945790" MODIFIED="1698284978965" TEXT="Dispatch &#x27fc; sollte nur ca. 25&#xb5;s kosten"/>
<node CREATED="1698284937287" ID="ID_1614190627" MODIFIED="1698284953462" TEXT="danach nix &#x27fc; WAIT"/>
</node>
<node CREATED="1698284989240" ID="ID_787590297" MODIFIED="1698285028273" TEXT="Theorien">
<icon BUILTIN="idea"/>
<node CREATED="1698284992319" ID="ID_837253629" MODIFIED="1698285031113" TEXT="die Logik stimmt nicht und es wird doch geschlafen">
<icon BUILTIN="full-1"/>
</node>
<node CREATED="1698285004782" ID="ID_667307245" MODIFIED="1698285033374" TEXT="die Implementierung der Kette hat ein Performance-Problem">
<icon BUILTIN="full-2"/>
</node>
</node>
</node>
</node>
</node>
@ -88243,6 +88304,18 @@ Date:&#160;&#160;&#160;Thu Apr 20 18:53:17 2023 +0200<br/>
<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 COLOR="#338800" CREATED="1698282705004" ID="ID_414397611" MODIFIED="1698282730689" TEXT="kann pullWork()-Delay und schedule-Verz&#xf6;gerung (slip) messen">
<icon BUILTIN="button_ok"/>
</node>
<node COLOR="#338800" CREATED="1698282777051" ID="ID_1817040421" MODIFIED="1698282807346" TEXT="direkt f&#xe4;llige Aufrufe passieren mit &lt;100&#xb5;s slip">
<icon BUILTIN="button_ok"/>
</node>
<node COLOR="#338800" CREATED="1698284606988" ID="ID_936409120" MODIFIED="1698284613772" TEXT="delay davor">
<icon BUILTIN="button_ok"/>
</node>
<node COLOR="#338800" CREATED="1698284614614" ID="ID_98846661" MODIFIED="1698284618170" TEXT="delay danach">
<icon BUILTIN="button_ok"/>
</node>
</node>
</node>
</node>