(WIP) instrumentation for investigation of sleep-behaviour

src/vault/gear/scheduler.hpp

@@ -108,6 +108,7 @@
 //#include "lib/symbol.hpp"
 #include  "lib/nocopy.hpp"
 //#include "lib/util.hpp"
+#include "lib/format-cout.hpp"/////////////////TODO
 
 //#include <string>
 #include <utility>
@@ -263,7 +264,7 @@ namespace gear {
       
       
       /** send this thread into a targeted short-time wait. */
-      activity::Proc scatteredDelay (Time now, LoadController::Capacity);
+      activity::Proc scatteredDelay (Time now, LoadController::Capacity,bool in);////////////TODO
       
       
       /**
@@ -410,7 +411,7 @@ namespace gear {
                                         Time now = ctx.getSchedTime();
                                         Time head = layer1_.headTime();
                                         return scatteredDelay(now,
-                                                  loadControl_.markIncomingCapacity (head,now));
+                                                  loadControl_.markIncomingCapacity (head,now),true);
                                       })
                       .performStep([&]{
                                         Time now = ctx.getSchedTime();
@@ -421,7 +422,7 @@ namespace gear {
                                         Time now = ctx.getSchedTime();
                                         Time head = layer1_.headTime();
                                         return scatteredDelay(now,
-                                                  loadControl_.markOutgoingCapacity (head,now));
+                                                  loadControl_.markOutgoingCapacity (head,now),false);
                                       });
         
         // ensure lock clean-up
@@ -453,7 +454,7 @@ namespace gear {
    *       place the current thread into a short-term targeted sleep.
    */
   inline activity::Proc
-  Scheduler::scatteredDelay (Time now, LoadController::Capacity capacity)
+  Scheduler::scatteredDelay (Time now, LoadController::Capacity capacity, bool in)
   {
     auto doTargetedSleep = [&]
           { // ensure not to block the Scheduler after management work
@@ -462,7 +463,11 @@ namespace gear {
               layer2_.dropGroomingToken();
              // relocate this thread(capacity) to a time where its more useful
             Offset targetedDelay = loadControl_.scatteredDelayTime (now, capacity);
+TimeVar head = layer1_.headTime()-now;
+cout <<"\n|oo|"<<(in?"^":"v")<<" Sleep-->"<<_raw(targetedDelay)<<"  <head:"<<_raw(head);
             std::this_thread::sleep_for (std::chrono::microseconds (_raw(targetedDelay)));
+head = layer1_.headTime()-now;
+cout <<"\n|••|"<<(in?"^":"v")<<"   eep<--"<<_raw(targetedDelay)<<"  <head:"<<_raw(head);
           };
     auto doTendNextHead = [&]
           {
@@ -481,6 +486,10 @@ namespace gear {
         std::this_thread::yield();
         return activity::SKIP;     //  prompts to abort chain but call again immediately
       case LoadController::IDLEWAIT:
+{        
+Time head = layer1_.headTime()-now;
+cout <<"\n|**|"<<(in?"^":"v")<<" --------------------------------------------Deep-Sleep-->  <head:"<<_raw(head);
+}
         return activity::WAIT;     //  prompts to switch this thread into sleep mode
       case LoadController::TENDNEXT:
         doTendNextHead();

tests/vault/gear/scheduler-service-test.cpp

@@ -57,6 +57,8 @@ namespace test {
     Time t200us = t100us + t100us;
     Time t500us = t200us + t200us + t100us;
     Time t1ms   = Time{1,0};
+    
+    const uint TYPICAL_TIME_FOR_ONE_SCHEDULE_us = 20;
   }
   
   
@@ -144,29 +146,33 @@ namespace test {
           CHECK (isnil (scheduler));
           
           Activity dummy{Activity::FEED};
+          
+          auto anchor = RealClock::now();
+auto wuff = [&](Time when =RealClock::now()){ return _raw(when) - _raw(anchor); };
           auto createLoad = [&](Offset start, uint cnt) 
                             { // use internal API (this test is declared as friend)  
                               auto& schedCtx = Scheduler::ExecutionCtx::from(scheduler);
                               for (uint i=0; i<cnt; ++i)           // flood the queue
-                                schedCtx.post (RealClock::now() + start + TimeValue{i}, &dummy, schedCtx);
+                                schedCtx.post (anchor + start + TimeValue{i}, &dummy, schedCtx);
                             };
           
           
-          auto fatPackage = work::Config::COMPUTATION_CAPACITY * 1000/20; 
+          auto LOAD_PEAK_DURATION_us = 2000;
+          auto fatPackage = work::Config::COMPUTATION_CAPACITY * LOAD_PEAK_DURATION_us/TYPICAL_TIME_FOR_ONE_SCHEDULE_us; 
+SHOW_EXPR(wuff())
+SHOW_EXPR(wuff(scheduler.layer1_.headTime()))
           createLoad (Offset{Time{5,0}}, fatPackage);
+          createLoad (Offset{Time{15,0}}, fatPackage);
           
+SHOW_EXPR(wuff())
           scheduler.ignite();
-          auto wau = RealClock::now();
-          auto wuff = [&]{ return _raw(RealClock::now()) - _raw(wau); };
-SHOW_EXPR(wuff())
-//          CHECK (isnil (scheduler));
-//          CHECK (not isnil (scheduler));
 SHOW_EXPR(wuff())
+SHOW_EXPR(wuff(scheduler.layer1_.headTime()))
           while (not isnil (scheduler))
             {
               sleep_for(50us);
               cout << wuff() << " +++ Load: "<<scheduler.getLoadIndicator()
-                             <<" --- HT= "<<_raw(scheduler.layer1_.headTime())-_raw(wau)
+                             <<" --- HT= "<<wuff(scheduler.layer1_.headTime())
                              <<" -+- Lag "<< scheduler.loadControl_.averageLag()
                              <<endl;
             }