Scheduler-test: implement accounting for concurrency for instrumentation

...since we've established already an integration over the event timeline,
it is just one simple further step to determine the concurrency level
on each individual segment of the timeline. Based on this attribution

- the averaged concurrenty within the observation range can be computed as weighted mean
- moreover we can account for the precise cumulated time spent at each concurrency level
This commit is contained in:
Fischlurch 2024-02-14 04:18:43 +01:00
parent a1abed68f4
commit 9f0878f885
3 changed files with 135 additions and 49 deletions

View file

@ -175,11 +175,13 @@ namespace lib {
size_t activationCnt{0};
double cumulatedTime{0};
double coveredTime{0};
double avgConcurrency{0};
vector<size_t> caseCntr{};
vector<size_t> thrdCntr{};
vector<double> caseTime{};
vector<double> thrdTime{};
vector<double> concTime{};
template<typename VAL>
static VAL
@ -192,6 +194,7 @@ namespace lib {
size_t cntThread(size_t id) { return access (thrdCntr, id); }
double timeCase (size_t id) { return access (caseTime, id); }
double timeThread(size_t id) { return access (thrdTime, id); }
double timeAtConc(size_t id) { return access (concTime, id); }
};
Statistic evaluate();
@ -237,6 +240,7 @@ namespace lib {
vector<int> active_thrd(numThreads);
stat.thrdCntr.resize (numThreads);
stat.thrdTime.resize (numThreads);
stat.concTime.resize (numThreads);
// Integrate over the timeline...
// - book the preceding interval length into each affected partial sum
@ -255,6 +259,10 @@ namespace lib {
stat.caseTime[i] += active_case[i] * timeSlice.count();
for (uint i=0; i < numThreads; ++i)
stat.thrdTime[i] += active_thrd[i] * timeSlice.count();
size_t concurr = explore(active_thrd).filter([](int a){ return 0 < a; }).count();
ENSURE (concurr <= numThreads);
stat.avgConcurrency += concurr * timeSlice.count(); // contribution for weighted average
stat.concTime[concurr] += timeSlice.count();
if (event.isLeave)
{
ASSERT (0 < active);
@ -278,6 +286,9 @@ namespace lib {
Dur covered = timeline.back().when - timeline.front().when;
stat.coveredTime = covered.count();
stat.eventCnt = timeline.size();
ENSURE (0 < stat.activationCnt);
ENSURE (stat.eventCnt % 2 == 0);
stat.avgConcurrency /= stat.coveredTime; // time used as weight sum
return stat;
}

View file

@ -27,7 +27,9 @@
#include "lib/test/run.hpp"
#include "lib/test/diagnostic-output.hpp"//////////////TODO RLY?
#include "lib/test/microbenchmark.hpp"
#include "lib/incidence-count.hpp"
#include "lib/thread.hpp"
#include "lib/util.hpp"
//#include <string>
@ -38,6 +40,7 @@
using util::isLimited;
using std::this_thread::sleep_for;
using std::chrono_literals::operator ""ms;
using std::chrono::microseconds;
namespace lib {
@ -58,7 +61,8 @@ namespace test{
{
demonstrate_usage();
verify_incidentCount();
verify_multithreadCount();
verify_concurrencyStatistic();
perform_multithreadStressTest();
}
@ -86,8 +90,8 @@ namespace test{
}
/** @test TODO verify proper counting of possibly overlapping incidences
* @todo WIP 2/24 define 🔁 implement
/** @test verify proper counting of possibly overlapping incidences
* @todo WIP 2/24 define implement
*/
void
verify_incidentCount()
@ -154,11 +158,100 @@ SHOW_EXPR(stat.timeThread(1));
}
/** @test TODO verify observation of concurrency degree
* @todo WIP 2/24 define implement
*/
void
verify_concurrencyStatistic()
{
MARK_TEST_FUN
const size_t CONCURR = std::thread::hardware_concurrency();
IncidenceCount watch;
watch.expectThreads(CONCURR)
.expectIncidents(5000);
auto act = [&]{ // two nested activities with random delay
uint delay = 100 + rand() % 800;
watch.markEnter();
sleep_for (microseconds(delay));
watch.markEnter(2);
sleep_for (microseconds(delay));
watch.markLeave(2);
watch.markLeave();
};
auto run_parallel = [&]
{
ThreadJoinable t1("test-1", act);
ThreadJoinable t2("test-2", act);
t1.join();
t2.join();
};
double runTime = test::benchmarkTime (run_parallel);
// join ensures visibility of all data changes from within threads,
// which is a prerequisite for performing the data evaluation safely.
auto stat = watch.evaluate();
SHOW_EXPR(runTime)
SHOW_EXPR(stat.cumulatedTime);
SHOW_EXPR(stat.coveredTime);
SHOW_EXPR(stat.eventCnt);
SHOW_EXPR(stat.activationCnt);
SHOW_EXPR(stat.cntCase(0));
SHOW_EXPR(stat.cntCase(1));
SHOW_EXPR(stat.cntCase(2));
SHOW_EXPR(stat.cntCase(3));
SHOW_EXPR(stat.timeCase(0));
SHOW_EXPR(stat.timeCase(1));
SHOW_EXPR(stat.timeCase(2));
SHOW_EXPR(stat.timeCase(3));
SHOW_EXPR(stat.cntThread(0));
SHOW_EXPR(stat.cntThread(1));
SHOW_EXPR(stat.cntThread(2));
SHOW_EXPR(stat.timeThread(0));
SHOW_EXPR(stat.timeThread(1));
SHOW_EXPR(stat.timeThread(2));
SHOW_EXPR(stat.avgConcurrency);
SHOW_EXPR(stat.timeAtConc(0));
SHOW_EXPR(stat.timeAtConc(1));
SHOW_EXPR(stat.timeAtConc(2));
CHECK (runTime > stat.coveredTime);
CHECK (stat.coveredTime < stat.cumulatedTime);
CHECK (8 == stat.eventCnt);
CHECK (4 == stat.activationCnt);
CHECK (2 == stat.cntCase(0));
CHECK (0 == stat.cntCase(1));
CHECK (2 == stat.cntCase(2));
CHECK (0 == stat.cntCase(3));
CHECK (2 == stat.cntThread(0));
CHECK (2 == stat.cntThread(1));
CHECK (0 == stat.cntThread(3));
CHECK (isLimited(0, stat.avgConcurrency, 2));
CHECK (stat.timeAtConc(0) == 0.0);
CHECK (stat.timeAtConc(1) < stat.coveredTime);
CHECK (stat.timeAtConc(2) < stat.coveredTime);
auto isNumEq = [](double d1, double d2){ return 0,001 > abs(d1-d2); };
CHECK (isNumEq (stat.avgConcurrency, (1*stat.timeAtConc(1) + 2*stat.timeAtConc(2)) // average concurrency is a weighted mean
/ stat.coveredTime)); // of the times spent at each concurrency level
CHECK (isNumEq (stat.cumulatedTime , stat.timeThread(0) + stat.timeThread(1))); // cumulated time is spent in both threads
CHECK (isNumEq (stat.cumulatedTime , stat.timeCase(0) + stat.timeCase(2))); // and likewise in all cases together
CHECK (isNumEq (stat.coveredTime , stat.timeAtConc(1) + stat.timeAtConc(2))); // the covered time happens at any non-zero concurrency level
CHECK (stat.timeCase(2) < stat.timeCase(0)); // Note: case-2 is nested into case-0
CHECK (isNumEq (stat.coveredTime , stat.timeCase(0) - stat.timeAtConc(2))); // Thus, case-0 brackets all time, minus the overlapping segment
}
/** @test TODO verify thread-safe operation under pressure
* @todo WIP 2/24 🔁 define implement
*/
void
verify_multithreadCount()
perform_multithreadStressTest()
{
UNIMPLEMENTED("verify thread-safe operation under pressure");
}

View file

@ -110889,9 +110889,7 @@ Date:&#160;&#160;&#160;Thu Apr 20 18:53:17 2023 +0200<br/>
<icon BUILTIN="forward"/>
<node BACKGROUND_COLOR="#ccb59b" COLOR="#6e2a38" CREATED="1707665182324" ID="ID_38878183" MODIFIED="1707665243637">
<richcontent TYPE="NODE"><html>
<head>
</head>
<head/>
<body>
<p>
Fokus &#10233; Ziel &#10233; es geht um <b>Halten</b>&#160;&#10231; <b>Brechen</b>
@ -110904,9 +110902,7 @@ Date:&#160;&#160;&#160;Thu Apr 20 18:53:17 2023 +0200<br/>
<node CREATED="1707665340816" ID="ID_1649163016" MODIFIED="1707665348132" TEXT="Konsequenzen">
<node CREATED="1707665349725" ID="ID_1672692374" MODIFIED="1707665380600">
<richcontent TYPE="NODE"><html>
<head>
</head>
<head/>
<body>
<p>
es geht <b>nicht</b>&#160;um die Ermittlung einer empirischen &#187;Performance&#171;
@ -110917,9 +110913,7 @@ Date:&#160;&#160;&#160;Thu Apr 20 18:53:17 2023 +0200<br/>
<node CREATED="1707665489034" ID="ID_238132768" MODIFIED="1707665508227" TEXT="es geht um Vertrauen in die geschaffene Basis">
<node CREATED="1707665558521" ID="ID_863513545" MODIFIED="1707665588174">
<richcontent TYPE="NODE"><html>
<head>
</head>
<head/>
<body>
<p>
sie mu&#223; <i>gut genug </i>im Sinn von <i>tauglich </i>sein
@ -110937,42 +110931,33 @@ Date:&#160;&#160;&#160;Thu Apr 20 18:53:17 2023 +0200<br/>
<icon BUILTIN="button_cancel"/>
<node CREATED="1707695763705" ID="ID_173852025" MODIFIED="1707754003327" TEXT="Zweck: &#x2205; Abweichung unter Real-Bedingungen">
<richcontent TYPE="NOTE"><html>
<head>
</head>
<head/>
<body>
<p>
Zwar ist die ComputationalLoad auf die jeweilige Hardware dynamisch geeicht, aber in den Einzelbeobachtungen habe ich immer ganz erhebliche Abweichungen f&#252;r Node-Aufrufe mit Load gesehen. Daher ist die Frage, wie verh&#228;lt sich die insgesamt (kumuliert, d.h. integriert) verbrachte Zeit zu der nominell geeichten Zeit? Daraus erg&#228;be sich ein Korrektur-Faktor, den man aus dem StressFac herausrechnen k&#246;nnte
</p>
</body>
</html>
</richcontent>
</html></richcontent>
</node>
<node CREATED="1707696028662" ID="ID_318007219" MODIFIED="1707696045583" TEXT="Bestehende Aufruf-Struktur ist komplex">
<node CREATED="1707696078703" ID="ID_740891424" MODIFIED="1707696109200" TEXT="es l&#xe4;uft stets eine Zeitmessung mit &#x2014; auch wenn der R&#xfc;ckgabewert weggeworfen wird"/>
<node CREATED="1707696046458" ID="ID_1059195796" MODIFIED="1707696231139">
<richcontent TYPE="NODE"><html>
<head>
</head>
<head/>
<body>
<p>
Untersuchung per Godbolt.org : SystemClock-Aufrufe werden <b>nicht</b>&#160;wegoptimiert
</p>
</body>
</html>
</richcontent>
</html></richcontent>
<richcontent TYPE="NOTE"><html>
<head>
</head>
<head/>
<body>
<p>
...das ist &#252;berraschend, denn sonst wird wirklich alles wie erwartet eingedampft und es bleibt nur die eigentliche Nutzfunktion &#252;brig; der Grund ist aber leicht einzusehen: es handelt sich um einen externen Call, der Seiteneffekte haben k&#246;nnte.
</p>
</body>
</html>
</richcontent>
</html></richcontent>
</node>
</node>
<node CREATED="1707753820611" ID="ID_1314209321" MODIFIED="1707753843774" TEXT="puh... das wird eine mehrstufige Entscheidungssequenz...">
@ -110992,16 +110977,13 @@ Date:&#160;&#160;&#160;Thu Apr 20 18:53:17 2023 +0200<br/>
<node CREATED="1707753922654" ID="ID_141944428" MODIFIED="1707753933624" TEXT="direkte Me&#xdf;-Aufrufen eingehend/ausgehend"/>
<node CREATED="1707753934275" ID="ID_174167267" MODIFIED="1707754562093" TEXT="Multi-Thread-f&#xe4;hig ohne Overhead im Me&#xdf;modus">
<richcontent TYPE="NOTE"><html>
<head>
</head>
<head/>
<body>
<p>
das bedeutet: jeder Thread hat seinen eigenen &#187;Slot&#171;, den er ohne jedwede Synchronisation zugreifen kann
</p>
</body>
</html>
</richcontent>
</html></richcontent>
</node>
<node CREATED="1707754287446" ID="ID_1946786749" MODIFIED="1707764788791" TEXT="Einmal / Wegwerf-Objekt &#x2014; kein Reset m&#xf6;glich">
<icon BUILTIN="messagebox_warning"/>
@ -111010,16 +110992,13 @@ Date:&#160;&#160;&#160;Thu Apr 20 18:53:17 2023 +0200<br/>
</node>
<node CREATED="1707764811980" ID="ID_237325015" MODIFIED="1707765252943" TEXT="aber das geht nicht &#x2014; thread_local ist implizit statisch (oder global)">
<richcontent TYPE="NOTE"><html>
<head>
</head>
<head/>
<body>
<p>
Aus Performance-Gr&#252;nden m&#246;chte ich f&#252;r jeden separaten Thread eine initial belegte slotID haben, so da&#223; der Thread direkt ohne weiteres Locking mit seinen separaten Daten arbeiten kann. Daf&#252;r mu&#223; ich f&#252;r neu auftauchende Threads immer die n&#228;chste ID vergeben, brauche also einen atomaren counter. Da aber jeder Thread dann seine ID kennen mu&#223;, brauche ich zudem eine thread_local-Variable, in der er sich seinen Slot merken kann. Und damit tut sich ein Dilemma auf: ein &#252;bergreifendes Management von Instanzen wird richtig komplex, besonders dann, wenn es auch noch performant sein soll. Daher der KISS-Beschlu&#223; &#10233; das gesamte Thema wird auf den User abgew&#228;ltzt
</p>
</body>
</html>
</richcontent>
</html></richcontent>
</node>
<node BACKGROUND_COLOR="#ccb59b" COLOR="#6e2a38" CREATED="1707764840510" ID="ID_302736823" MODIFIED="1707764853515" TEXT="also dann ... KISS">
<font ITALIC="true" NAME="SansSerif" SIZE="14"/>
@ -111062,8 +111041,8 @@ Date:&#160;&#160;&#160;Thu Apr 20 18:53:17 2023 +0200<br/>
<icon BUILTIN="button_ok"/>
</node>
</node>
<node BACKGROUND_COLOR="#eef0c5" COLOR="#990000" CREATED="1707754873263" ID="ID_961298794" MODIFIED="1707768327245" TEXT="Statistik-Auswertung">
<icon BUILTIN="pencil"/>
<node COLOR="#338800" CREATED="1707754873263" ID="ID_961298794" MODIFIED="1707880373240" TEXT="Statistik-Auswertung">
<icon BUILTIN="button_ok"/>
<node COLOR="#338800" CREATED="1707754895979" ID="ID_1713684347" MODIFIED="1707787270143" TEXT="Statistik-Record">
<icon BUILTIN="button_ok"/>
</node>
@ -111097,26 +111076,29 @@ Date:&#160;&#160;&#160;Thu Apr 20 18:53:17 2023 +0200<br/>
<icon BUILTIN="idea"/>
</node>
</node>
<node BACKGROUND_COLOR="#eee5c3" COLOR="#990000" CREATED="1707787292247" ID="ID_1168581526" MODIFIED="1707787298581" TEXT="Concurrency buchen">
<icon BUILTIN="flag-yellow"/>
<node BACKGROUND_COLOR="#eee5c3" COLOR="#990000" CREATED="1707787306154" ID="ID_545614192" MODIFIED="1707787347330" TEXT="globales gewichtetes Mittel &#xfc;ber alle Segmente">
<icon BUILTIN="flag-yellow"/>
<node COLOR="#338800" CREATED="1707787292247" ID="ID_1168581526" MODIFIED="1707880372381" TEXT="Concurrency buchen">
<icon BUILTIN="button_ok"/>
<node COLOR="#338800" CREATED="1707787306154" ID="ID_545614192" MODIFIED="1707880370562" TEXT="globales gewichtetes Mittel &#xfc;ber alle Segmente">
<icon BUILTIN="button_ok"/>
</node>
<node BACKGROUND_COLOR="#eee5c3" COLOR="#990000" CREATED="1707787318991" ID="ID_1203625704" MODIFIED="1707787347331" TEXT="Zeiten auf bestimmtem Concurrency-Niveau separat z&#xe4;hlen">
<icon BUILTIN="flag-yellow"/>
<node COLOR="#338800" CREATED="1707787318991" ID="ID_1203625704" MODIFIED="1707880371599" TEXT="Zeiten auf bestimmtem Concurrency-Niveau separat z&#xe4;hlen">
<icon BUILTIN="button_ok"/>
</node>
</node>
</node>
</node>
<node BACKGROUND_COLOR="#eee5c3" COLOR="#990000" CREATED="1707754958979" ID="ID_284055307" MODIFIED="1707754989232" TEXT="IncidenceCount_test">
<icon BUILTIN="flag-yellow"/>
<node BACKGROUND_COLOR="#eef0c5" COLOR="#990000" CREATED="1707754958979" ID="ID_284055307" MODIFIED="1707880406370" TEXT="IncidenceCount_test">
<icon BUILTIN="pencil"/>
<node COLOR="#338800" CREATED="1707754993819" ID="ID_1476552932" MODIFIED="1707770394988" TEXT="demonstrate_simpleUsage">
<icon BUILTIN="button_ok"/>
</node>
<node COLOR="#338800" CREATED="1707755010724" ID="ID_6728381" MODIFIED="1707787282628" TEXT="verify_incidentCount">
<icon BUILTIN="button_ok"/>
</node>
<node BACKGROUND_COLOR="#eee5c3" COLOR="#990000" CREATED="1707755017591" ID="ID_464212476" MODIFIED="1707755044792" TEXT="verify_multithreadCount">
<node COLOR="#338800" CREATED="1707880388944" ID="ID_1618021077" MODIFIED="1707880390672" TEXT="verify_concurrencyStatistic">
<icon BUILTIN="button_ok"/>
</node>
<node BACKGROUND_COLOR="#eee5c3" COLOR="#990000" CREATED="1707755017591" ID="ID_464212476" MODIFIED="1707880399746" TEXT="perform_multithreadStressTest">
<icon BUILTIN="flag-yellow"/>
</node>
</node>