Recent

Author Topic: The time in Sleep is wrong, + 1  (Read 1628 times)

rvk

  • Hero Member
  • *****
  • Posts: 3505
Re: The time in Sleep is wrong, + 1
« Reply #15 on: November 23, 2018, 10:25:42 am »
O, wow, there must be something really wrong with my system  :o

Code: [Select]
Between: 00:00:00.011
Duration: 00:00:10.659

Edit: This was with debugging information on but running without debugger. Compiling with debugging information off gave more normal results. Didn't know that compiling with just debugger information on gave such slowdown (even without running in gdb).
« Last Edit: November 23, 2018, 11:11:56 am by rvk »

zanden30@hetnet.nl

  • New member
  • *
  • Posts: 9
Re: The time in Sleep is wrong, + 1
« Reply #16 on: November 23, 2018, 12:02:51 pm »
@User137. That's exactly what I measure. 1 mS too much when I repeat measurements 1.000 times.

My SW is a Finite State Machine experiment. It does nothing but printing 7 independently running tasks that switch continuously, and it counts also the time. I have a .py procedure to generate a flexible FSM with unlimited number of tasks. See attachment.

Code: Pascal  [Select]
  1.  
  2.  
  3. Program FSMDemo7x10;
  4.  
  5. Uses Sysutils, keyboard, typinfo;
  6.  
  7. Type
  8.  
  9.         t_State = (Start_State, S1, S2, S3, S4, S5, S6, S7, S8, S9, Delay_State, Exit_State);
  10.         t_Task  = (T1, T2, T3, T4, T5, T6, T7);
  11.  
  12.  
  13. Var     //Required variables for the FSM and the Delay function
  14.         Task    : t_Task; // Represents the actual active FSM
  15.         State   : t_State; // Represents the actual state, most important variable of the FSM!!
  16.        
  17.         States                          : Array[T1 .. T7] of t_State; //Store of state
  18.        
  19.         Delay_Time              : Array[T1 .. T7] of longint; //Common Delay Time per FSM
  20.         Delay_States    : Array[T1 .. T7] of t_State; //Store of caller state is Delay is activated.
  21.  
  22.         Millis, n, Loop_Time : longint;  //Time in milli seconds
  23.        
  24. Const
  25.         Loop_Count = 1000;
  26.                
  27. //Application variables; can be removed
  28. Var
  29.         X : Array[T1 .. T7] of integer;
  30.         Ch: String;
  31.         Delay_mS : longint;  // app variable
  32.  
  33. (***************)
  34. Procedure Change_State(Target: t_State); Forward;
  35. Procedure Do_Delay_State; Forward;
  36. Procedure Delay(t: longint); Forward;
  37. (***************)
  38.  
  39. //All writeln / output and input statements are for demo only. Can be omitted.
  40. (***************)
  41. Procedure PL(s : string);
  42. (***************)
  43. var
  44.         i : integer;
  45.        
  46. Begin
  47.         for i := 0 to Ord(Task) - 1 do
  48.                 write('*************');
  49.         writeln(' T: ' + GetEnumName(TypeInfo(t_Task), integer(Task)) + ' ' + s)
  50. end;
  51.  
  52. (***************)
  53. Procedure Print_Error(s : string);
  54. (***************)
  55. Begin
  56.         writeln('**************');
  57.         writeln(s);
  58.         writeln('**************');
  59. end;
  60.  
  61. (***************)
  62. Procedure Do_S1;
  63. (***************)
  64. Begin
  65.         PL('Do_S1, # ' + IntToStr(X[Task]));
  66.         X[Task]:= X[Task] + 1;
  67.         if X[Task] >= Ord(High(t_Task)) + 5 - Ord(Task) then
  68.         begin
  69.                 Change_State(S2);
  70.                 PL('My Delay = ' + IntToStr(Delay_mS +  (1333 * Ord(Task))));
  71.         end
  72.         else
  73.         begin
  74.                 Delay(Delay_mS +  (1333 * Ord(Task)));
  75.         end;
  76. end;
  77.  
  78. (***************)
  79. Procedure Entry_S1;
  80. (***************)
  81. Begin
  82.         PL('Entry S1');
  83.         X[Task] := 0;
  84. end;
  85.  
  86. (***************)
  87. Procedure Exit_S1;
  88. (***************)
  89. Begin
  90.         PL('Exit S1');
  91. end;
  92.  
  93. (***************)
  94. Procedure Do_S2;
  95. (***************)
  96. Begin
  97.         PL('Do_S2, # ' + IntToStr(X[Task]));
  98.         X[Task]:= X[Task] + 1;
  99.         if X[Task] >= Ord(High(t_Task)) + 5 - Ord(Task) then
  100.         begin
  101.                 Change_State(S3);
  102.                 PL('My Delay = ' + IntToStr(Delay_mS +  (1333 * Ord(Task))));
  103.         end
  104.         else
  105.         begin
  106.                 Delay(Delay_mS +  (1333 * Ord(Task)));
  107.         end;
  108. end;
  109.  
  110. (***************)
  111. Procedure Entry_S2;
  112. (***************)
  113. Begin
  114.         PL('Entry S2');
  115.         X[Task] := 0;
  116. end;
  117.  
  118. (***************)
  119. Procedure Exit_S2;
  120. (***************)
  121. Begin
  122.         PL('Exit S2');
  123. end;
  124.  
  125. (***************)
  126. Procedure Do_S3;
  127. (***************)
  128. Begin
  129.         PL('Do_S3, # ' + IntToStr(X[Task]));
  130.         X[Task]:= X[Task] + 1;
  131.         if X[Task] >= Ord(High(t_Task)) + 5 - Ord(Task) then
  132.         begin
  133.                 Change_State(S4);
  134.                 PL('My Delay = ' + IntToStr(Delay_mS +  (1333 * Ord(Task))));
  135.         end
  136.         else
  137.         begin
  138.                 Delay(Delay_mS +  (1333 * Ord(Task)));
  139.         end;
  140. end;
  141.  
  142. (***************)
  143. Procedure Entry_S3;
  144. (***************)
  145. Begin
  146.         PL('Entry S3');
  147.         X[Task] := 0;
  148. end;
  149.  
  150. (***************)
  151. Procedure Exit_S3;
  152. (***************)
  153. Begin
  154.         PL('Exit S3');
  155. end;
  156.  
  157. (***************)
  158. Procedure Do_S4;
  159. (***************)
  160. Begin
  161.         PL('Do_S4, # ' + IntToStr(X[Task]));
  162.         X[Task]:= X[Task] + 1;
  163.         if X[Task] >= Ord(High(t_Task)) + 5 - Ord(Task) then
  164.         begin
  165.                 Change_State(S5);
  166.                 PL('My Delay = ' + IntToStr(Delay_mS +  (1333 * Ord(Task))));
  167.         end
  168.         else
  169.         begin
  170.                 Delay(Delay_mS +  (1333 * Ord(Task)));
  171.         end;
  172. end;
  173.  
  174. (***************)
  175. Procedure Entry_S4;
  176. (***************)
  177. Begin
  178.         PL('Entry S4');
  179.         X[Task] := 0;
  180. end;
  181.  
  182. (***************)
  183. Procedure Exit_S4;
  184. (***************)
  185. Begin
  186.         PL('Exit S4');
  187. end;
  188.  
  189. (***************)
  190. Procedure Do_S5;
  191. (***************)
  192. Begin
  193.         PL('Do_S5, # ' + IntToStr(X[Task]));
  194.         X[Task]:= X[Task] + 1;
  195.         if X[Task] >= Ord(High(t_Task)) + 5 - Ord(Task) then
  196.         begin
  197.                 Change_State(S6);
  198.                 PL('My Delay = ' + IntToStr(Delay_mS +  (1333 * Ord(Task))));
  199.         end
  200.         else
  201.         begin
  202.                 Delay(Delay_mS +  (1333 * Ord(Task)));
  203.         end;
  204. end;
  205.  
  206. (***************)
  207. Procedure Entry_S5;
  208. (***************)
  209. Begin
  210.         PL('Entry S5');
  211.         X[Task] := 0;
  212. end;
  213.  
  214. (***************)
  215. Procedure Exit_S5;
  216. (***************)
  217. Begin
  218.         PL('Exit S5');
  219. end;
  220.  
  221. (***************)
  222. Procedure Do_S6;
  223. (***************)
  224. Begin
  225.         PL('Do_S6, # ' + IntToStr(X[Task]));
  226.         X[Task]:= X[Task] + 1;
  227.         if X[Task] >= Ord(High(t_Task)) + 5 - Ord(Task) then
  228.         begin
  229.                 Change_State(S7);
  230.                 PL('My Delay = ' + IntToStr(Delay_mS +  (1333 * Ord(Task))));
  231.         end
  232.         else
  233.         begin
  234.                 Delay(Delay_mS +  (1333 * Ord(Task)));
  235.         end;
  236. end;
  237.  
  238. (***************)
  239. Procedure Entry_S6;
  240. (***************)
  241. Begin
  242.         PL('Entry S6');
  243.         X[Task] := 0;
  244. end;
  245.  
  246. (***************)
  247. Procedure Exit_S6;
  248. (***************)
  249. Begin
  250.         PL('Exit S6');
  251. end;
  252.  
  253. (***************)
  254. Procedure Do_S7;
  255. (***************)
  256. Begin
  257.         PL('Do_S7, # ' + IntToStr(X[Task]));
  258.         X[Task]:= X[Task] + 1;
  259.         if X[Task] >= Ord(High(t_Task)) + 5 - Ord(Task) then
  260.         begin
  261.                 Change_State(S8);
  262.                 PL('My Delay = ' + IntToStr(Delay_mS +  (1333 * Ord(Task))));
  263.         end
  264.         else
  265.         begin
  266.                 Delay(Delay_mS +  (1333 * Ord(Task)));
  267.         end;
  268. end;
  269.  
  270. (***************)
  271. Procedure Entry_S7;
  272. (***************)
  273. Begin
  274.         PL('Entry S7');
  275.         X[Task] := 0;
  276. end;
  277.  
  278. (***************)
  279. Procedure Exit_S7;
  280. (***************)
  281. Begin
  282.         PL('Exit S7');
  283. end;
  284.  
  285. (***************)
  286. Procedure Do_S8;
  287. (***************)
  288. Begin
  289.         PL('Do_S8, # ' + IntToStr(X[Task]));
  290.         X[Task]:= X[Task] + 1;
  291.         if X[Task] >= Ord(High(t_Task)) + 5 - Ord(Task) then
  292.         begin
  293.                 Change_State(S9);
  294.                 PL('My Delay = ' + IntToStr(Delay_mS +  (1333 * Ord(Task))));
  295.         end
  296.         else
  297.         begin
  298.                 Delay(Delay_mS +  (1333 * Ord(Task)));
  299.         end;
  300. end;
  301.  
  302. (***************)
  303. Procedure Entry_S8;
  304. (***************)
  305. Begin
  306.         PL('Entry S8');
  307.         X[Task] := 0;
  308. end;
  309.  
  310. (***************)
  311. Procedure Exit_S8;
  312. (***************)
  313. Begin
  314.         PL('Exit S8');
  315. end;
  316.  
  317. (***************)
  318. Procedure Do_S9;
  319. (***************)
  320. Begin
  321.         PL('Do_S9, # ' + IntToStr(X[Task]));
  322.         X[Task]:= X[Task] + 1;
  323.         if X[Task] >= Ord(High(t_Task)) + 5 - Ord(Task) then
  324.         begin
  325.                 Change_State(S1);
  326.                 PL('My Delay = ' + IntToStr(Delay_mS +  (1333 * Ord(Task))));
  327.         end
  328.         else
  329.         begin
  330.                 Delay(Delay_mS +  (1333 * Ord(Task)));
  331.         end;
  332. end;
  333.  
  334. (***************)
  335. Procedure Entry_S9;
  336. (***************)
  337. Begin
  338.         PL('Entry S9');
  339.         X[Task] := 0;
  340. end;
  341.  
  342. (***************)
  343. Procedure Exit_S9;
  344. (***************)
  345. Begin
  346.         PL('Exit S9');
  347. end;
  348.  
  349. (***************)
  350. Procedure Do_Delay_State__;
  351. (***************)
  352. Begin
  353.         PL('Do_Delay_State__, # ' + IntToStr(X[Task]));
  354.         X[Task]:= X[Task] + 1;
  355.         if X[Task] >= Ord(High(t_Task)) + 5 - Ord(Task) then
  356.         begin
  357.                 Change_State(S2);
  358.                 PL('My Delay = ' + IntToStr(Delay_mS +  (1333 * Ord(Task))));
  359.         end
  360.         else
  361.         begin
  362.                 Delay(Delay_mS +  (1333 * Ord(Task)));
  363.         end;
  364. end;
  365.  
  366. (***************)
  367. Procedure Entry_Delay_State;
  368. (***************)
  369. Begin
  370.         PL('Entry Delay_State');
  371.         X[Task] := 0;
  372. end;
  373.  
  374. (***************)
  375. Procedure Exit_Delay_State;
  376. (***************)
  377. Begin
  378.         PL('Exit Delay_State');
  379. end;
  380.  
  381. (***************)
  382. Procedure Entries;
  383. (***************)
  384. Begin
  385.         Case State of
  386.         S1 : Entry_S1;
  387.         S2 : Entry_S2;
  388.         S3 : Entry_S3;
  389.         S4 : Entry_S4;
  390.         S5 : Entry_S5;
  391.         S6 : Entry_S6;
  392.         S7 : Entry_S7;
  393.         S8 : Entry_S8;
  394.         S9 : Entry_S9;
  395.         Delay_State : Entry_Delay_State;
  396.  
  397.         Otherwise
  398.                 Write(State); PL(' = Illegal Entry state');
  399.         end;
  400. end;
  401.  
  402. (***************)
  403. Procedure Exits;
  404. (***************)
  405. Begin
  406.         Case State of
  407.         S1 : Exit_S1;
  408.         S2 : Exit_S2;
  409.         S3 : Exit_S3;
  410.         S4 : Exit_S4;
  411.         S5 : Exit_S5;
  412.         S6 : Exit_S6;
  413.         S7 : Exit_S7;
  414.         S8 : Exit_S8;
  415.         S9 : Exit_S9;
  416.         Delay_State : Exit_Delay_State;
  417.        
  418.         Otherwise
  419.                 Write(State); PL(' = Illegal Exit state');
  420.         end;
  421. end;
  422.  
  423. (***************)
  424. Procedure Dispatch;
  425. (***************)
  426. Begin
  427.         Case State of
  428.                 //Insert all possible states with Do-actions
  429.         S1 : Do_S1;
  430.         S2 : Do_S2;
  431.         S3 : Do_S3;
  432.         S4 : Do_S4;
  433.         S5 : Do_S5;
  434.         S6 : Do_S6;
  435.         S7 : Do_S7;
  436.         S8 : Do_S8;
  437.         S9 : Do_S9;
  438.         Delay_State : Do_Delay_State;
  439.  
  440.         Otherwise
  441.                 Print_Error('Illegal Dispatch state <' {+ Str(State)} + '>') ;
  442.         end;
  443. end;
  444.  
  445. (***************)
  446. Procedure Init_FSM_Vars;
  447. (***************)
  448. Begin
  449.         Delay_mS := 2000;
  450.         States[ T1 ] := S1;
  451.         State := S1;
  452.         Task  := T1;
  453.         Entries;
  454.  
  455.         States[ T2 ] := S2;
  456.         State := S2;
  457.         Task  := T2;
  458.         Entries;
  459.  
  460.         States[ T3 ] := S3;
  461.         State := S3;
  462.         Task  := T3;
  463.         Entries;
  464.  
  465.         States[ T4 ] := S4;
  466.         State := S4;
  467.         Task  := T4;
  468.         Entries;
  469.  
  470.         States[ T5 ] := S5;
  471.         State := S5;
  472.         Task  := T5;
  473.         Entries;
  474.  
  475.         States[ T6 ] := S6;
  476.         State := S6;
  477.         Task  := T6;
  478.         Entries;
  479.  
  480.         States[ T7 ] := S7;
  481.         State := S7;
  482.         Task  := T7;
  483.         Entries;
  484.  
  485.  
  486. End;
  487.  
  488. (***************)
  489. Procedure Do_Delay_State; //This procedure will be generated double
  490. (***************)
  491. Var
  492.   KeyEvent: TKeyEvent;
  493.  
  494. Begin
  495.         if millis >= Delay_Time[Task] then
  496.         begin
  497.                 State := Delay_States[Task]; //Return to caller state. No exits & entries !!
  498.         end
  499.         else
  500.         begin   //This part is application dependent; in this case p resp m in/decreases the delay
  501.                 if KeyPressed then
  502.                 begin
  503.                         ch := KeyEventToString(TranslateKeyEvent(getkeyevent));
  504.                         PL('Key Char = <'+ ch + '>');
  505.                 end
  506.                 else
  507.                   ch := '';
  508.                                 //write('<',ch,'>');
  509.                                 //readln;
  510.                 if (ch = 'p' ) then
  511.                 begin
  512.                   Delay_mS := Delay_mS + 100;
  513.                   Writeln('Delay_mS = ', Delay_mS);
  514.                 end
  515.                 else
  516.                 if (ch = 'm' ) then
  517.                 begin
  518.                   Delay_mS := Delay_mS - 100;
  519.                   if Delay_mS <= 0 then
  520.                         Delay_mS := 100;
  521.                   Writeln('Delay_mS = ', Delay_mS);
  522.                 end
  523.                 else
  524.         if ch = 'q' then
  525.                   Change_State(Exit_State)
  526.                 else
  527.         if ch = ' ' then
  528.         begin
  529.                   beep;
  530.                   writeln('More :  ');
  531.                   readln;
  532.                 end;
  533.                 ch := '';
  534.                 initkeyboard;
  535.         end;
  536. end;
  537.  
  538. (***************)
  539. Procedure Delay(t : longint);
  540. (***************)
  541. Begin
  542.         Delay_States[Task] := State; //save this state
  543.         Delay_Time  [Task] := millis + t;
  544.         State := Delay_State;                                   // change to Do_Delay State.
  545. end;
  546.  
  547. (***************)
  548. Procedure Change_State(Target: t_State);
  549. (***************)
  550. Begin
  551.                 //      writeln('Change ', State, ' ====> ', Target);
  552.  
  553.         Exits;
  554.         State := Target;                //Change the complete state
  555.         Entries;                                                //change to self-transition forces also an Exit & Entry
  556. end;
  557.  
  558. (***************)
  559. //Mainloop
  560. (***************)
  561. Begin
  562.         Init_FSM_vars;
  563.                
  564. //      Change_state(Start_State);      // Enter and Initiate starting state correctly
  565.         Writeln('Demo of a Finite State Machine with 7 tasks and 10 states, independently running');
  566.         Writeln('with different delay times and # of Do_actions per thread');
  567.         Writeln('Type m = accelerating; p = decelerating; q = exit; Space = Pause');
  568.         Writeln('Type Enter to start : ');
  569.         Readln;
  570.         n := Loop_Count + 1;
  571.         Loop_Time := 0;
  572.         Repeat
  573.                 millis := DateTimeToTimeStamp(Now).time;
  574.                 if n > Loop_Count then
  575.                 begin
  576.                         Writeln('====== Loop Time = ', (millis - Loop_Time),
  577.                                                         ' mS per ', Loop_Count, ' loops');
  578.                         Loop_Time := millis;
  579.                         n := 0;
  580.                 end
  581.                 else
  582.                 begin
  583.                         n := n + 1;
  584.                 end;
  585.  
  586.                 //Do here some input action, that the FSM can react on
  587.                 //Or let that action be done by interrupts of in other tasks in shared/static memory.
  588.  
  589.                 for Task := T1 to T7 do  //Start the FSM´s of this demo.
  590.                 begin
  591.                         State := States[Task]; //restore the State
  592.                                                                                                                                                 //Write('Task <', Task, '> ');
  593.                         Dispatch; //Start the FSM
  594.                         if State = Exit_State then Break;
  595.                         States[Task] := State; //save the (new) State.
  596.  
  597.                 end;
  598.                 sleep(9);
  599.  
  600.                                                 //              Writeln('After Dispatch : ' ); Readln(Ch);
  601.                                                 //Or do here some action (too)
  602.  
  603.         until State = Exit_State;
  604.  
  605.         Writeln('FSM Ready. Type Enter ');
  606.         Readln;
  607. end.
  608.  
  609.  
« Last Edit: November 23, 2018, 12:10:05 pm by zanden30@hetnet.nl »

440bx

  • Sr. Member
  • ****
  • Posts: 387
Re: The time in Sleep is wrong, + 1
« Reply #17 on: November 23, 2018, 01:35:32 pm »
It is simply incorrect to expect a thread/task to be given CPU cycles just because it got out of a sleep state.

The OS scheduler's priority is to keep the system as responsive to the user as possible.  The scheduler will prioritize a task based on what events need to be taken care of in order to keep the system running smoothly. 

A process which is running at normal priority and has no events to take care of (such as pending keys, I/Os, etc) will not be scheduled ahead of other tasks which have events to service just because it came out of a sleep state.

if someone wants to increase the likeliness of the scheduler giving some CPU time to their task(s), they should set the tasks priority to real time and, even that doesn't guarantee CPU time.  In addition to that, setting a process' priority to real time can easily have detrimental effects on the OS smooth operation.

The sleep function isn't meant to control how the O/S scheduler decides which thread gets CPU time next.  All it does is tell the scheduler that it doesn't need attention for x amount of time.  That's all it does. Nothing else.  Just because a task could use some CPU cycles, it doesn't mean it's going to get them.

HTH

BrunoK

  • Jr. Member
  • **
  • Posts: 81
  • Retired programmer
Re: The time in Sleep is wrong, + 1
« Reply #18 on: November 23, 2018, 02:49:18 pm »
Intel only and maybe windows 32 only, never tested my function GetCPUTicks in 64 bit.

Here after a little program that runs Sleep in a loop and pick Now / GetTickCount64 / RDTSC and displays the timings for each iteration.

Conclusion : except for Sleep(0) the OS (Windows) always Sleeps IN multiple of ~14 ms, which is, if I remember well, the minimum time slice allocated to each thread in normal priority.

There is nothing wrong  in Sleep(x) in FPC because FPC just calls the OS for this instruction. You'll have to use another strategy.
Code: Pascal  [Select]
  1. (* ======================================================================= *)
  2. (* prjTestSleep : This program catches timings of Sleep(x) instruction and *)
  3. (*                then prints them. Now()/GetTickCount64()/CPUTicks if     *)
  4. (*                available.                                               *)
  5. (* ======================================================================= *)
  6.  
  7. program prjTestSleep;
  8.  
  9. {$mode objfpc}{$H+}
  10.  
  11. uses {$IFDEF UNIX} {$IFDEF UseCThreads}
  12.   cthreads, {$ENDIF} {$ENDIF}
  13.   SysUtils;
  14.  
  15. // Utility function costs approx 26-28 Ticks
  16. {$IF DEFINED(CPUi386) or DEFINED(CPUX86_64)}
  17. {$ASMMODE Intel}
  18.   function GetCPUTicks: uint64; assembler; nostackframe;
  19.   asm
  20.     xor eax,eax
  21.     xor edx,edx
  22.     shl edx,1   // Make it a positive Int64
  23.     shr edx,1
  24.     rdtsc
  25.   {$IFDEF CPUX86_64} { NOT TESTED }
  26.     shl   rdx, 32
  27.     or    rax, rdx
  28.   {$ENDIF CPUX64}
  29.   end;
  30. {$ELSE}
  31.   function GetCPUTicks: uint64; inline;
  32.   begin
  33.     Result :=0;
  34.   end;
  35. {$ENDIF}
  36.  
  37. type
  38.   RTiming = record
  39.     Last: TDateTime;
  40.     CPUTicks : int64;
  41.     LastTick64: QWord;
  42.   end;
  43.  
  44. const
  45.   CMaxTestMs = 10000; // Limit for feed loop in ms
  46. var
  47.   lFirst: TDateTime;       // Now
  48.   lFirstCPUTick: int64;   // RDTSC
  49.   lFirstTick64: QWord;     // GetTickCount64
  50.   lTimeingAr: array [0..100] of RTiming;
  51.   lSleepStr: string;
  52.   lSleep: integer;
  53.   ix: integer;
  54.   lTopIx:integer;
  55.  
  56.   lCPUMsPerCPU : Double;
  57.   lCPUTicksPerMsStr : string;
  58.   lDeltaCPU : int64;
  59.   procedure SetupFirstFrom(var aRTiming : RTiming);
  60.   begin
  61.     with aRTiming do begin
  62.       lFirstCPUTick := CPUTicks;         // RDTSC
  63.       lFirstTick64 := LastTick64;        // GetTickCount64
  64.       lFirst:= Last;                     // Now
  65.     end;
  66.   end;
  67.  
  68. begin
  69.   // FormatSettings.ThousandSeparator:='''';
  70.   WriteLn('Maximum time allowed for FEED LOOP (ms)-> ',CMaxTestMs,' for ', High(lTimeingAr), ' items');
  71.   WriteLn('---------------------------------------');
  72.   WriteLn;
  73.   Write('Enter sleep delay ? ');
  74.   ReadLn(lSleepStr);
  75.   repeat
  76.     // Test / reenter
  77.     repeat
  78.       if TryStrToInt(lSleepStr, lSleep) then
  79.         break;
  80.       Write('Redo from start ? ');
  81.       ReadLn(lSleepStr);
  82.     until lSleepStr='';
  83.     if lSleepStr='' then
  84.       break;
  85.     // START ============ FEED DATA in Loop ============== START
  86.     lFirstTick64 := GetTickCount64; // Initialize for CMaxTestMs for loop
  87.     for ix := 0 to High(lTimeingAr) do begin
  88.       with lTimeingAr[ix] do begin
  89.         LastTick64 := GetTickCount64;
  90.         CPUTicks := GetCPUTicks;
  91.         Last := Now;
  92.         lTopIx:=ix; // To be strict on use of ix after loop
  93.         if LastTick64-lFirstTick64>CMaxTestMs then
  94.           Break;
  95. {SLEEP} Sleep(lSleep); {SLEEP}
  96.       end;
  97.     end;
  98.     // END ============== FEED DATA in Loop ================= END
  99.  
  100.     SetupFirstFrom(lTimeingAr[0]);
  101.     // Adjust lTimeingAr data to store as offsets relative to start of test
  102.     for ix := 1 to lTopIx do
  103.       with lTimeingAr[ix] do begin
  104.         CPUTicks:=CPUTicks-lFirstCPUTick;
  105.         Last:=Last-lFirst;
  106.         LastTick64:=LastTick64-lFirstTick64;
  107.     end;
  108.  
  109.     FillChar(lTimeingAr[0], SizeOf(RTiming), 0); // Zero base offset
  110.     SetupFirstFrom(lTimeingAr[0]);
  111.  
  112.     // Estimate ratio of elapsed CPUTicks to GetTickCount64 + Some offset.
  113.     // Loop so lCPUMsPerCPU is in narrow range
  114.     with lTimeingAr[lTopIx] do begin
  115.       if LastTick64 - lFirstTick64 = 0 then
  116.         lFirstTick64 := 0
  117.       else repeat
  118.         lCPUMsPerCPU := 1 / ((CPUTicks - lFirstCPUTick) / (LastTick64 - lFirstTick64));
  119.         lDeltaCPU := Trunc((lTimeingAr[1].CPUTicks - lFirstCPUTick) * lCPUMsPerCPU);
  120.         lDeltaCPU := Trunc((lTimeingAr[1].LastTick64 - lFirstTick64) - lDeltaCPU);
  121.         // Correct start CPUTick offset (signed integer)
  122.         lDeltaCPU := Trunc(lDeltaCPU / lCPUMsPerCPU);
  123.         if lDeltaCPU=0 then
  124.           break;
  125.         lFirstCPUTick := lFirstCPUTick - lDeltaCPU;
  126.         WriteLn('CPU tick offset -> ', lFirstCPUTick);
  127.       until False;
  128.     end;
  129.  
  130.     // Print results
  131.     WriteLn('Elapsed from start');
  132.     WriteLn('==================');
  133.     for ix := 1 to lTopIx do
  134.       with lTimeingAr[ix] do begin
  135.         lCPUTicksPerMsStr := FormatFloat(',.000',(CPUTicks - lFirstCPUTick)*lCPUMsPerCPU);
  136.         WriteLn(ix:4,' Now(s.)->', FormatDateTime('ss.zzz', last - lFirst): 7,
  137.                 '  Tick64 ms->',(LastTick64 - lFirstTick64): 8,
  138.                 '  From CPUTicks ms->',lCPUTicksPerMsStr:10);
  139.       end;
  140.     Write('Enter to exit or new sleep delay ? ');
  141.     ReadLn(lSleepStr);
  142.   until lSleepStr = '';
  143. end.
Lazarus trunk 2018.11.07 (+/- patches regarding enabled, TScrollBar). FPC 3.0.4 32 bits. (+heaptrc with leaked ClassName+Revisited TList) , Windows 10 Pro x64 (v. 1803)

BrunoK

  • Jr. Member
  • **
  • Posts: 81
  • Retired programmer
Re: The time in Sleep is wrong, + 1
« Reply #19 on: November 27, 2018, 11:01:30 am »
A slightly corrected version in attachment.
Lazarus trunk 2018.11.07 (+/- patches regarding enabled, TScrollBar). FPC 3.0.4 32 bits. (+heaptrc with leaked ClassName+Revisited TList) , Windows 10 Pro x64 (v. 1803)