Re: how to analyze clock drift

[Dennis Lee Bieber <wlfraed@ix.netcom.com>]

On Sun, 23 Nov 2014 21:15:05 +0100, Emanuel Berg <embe8573@student.uu.se>
declaimed the following:

>I can explain that, and then add like, "If you were to
>employ this system in a critical setting, it would be
>necessary to have a much more reliable clock to
>trigger the interrupts. Although you can have widely
>diverging results due to many factors, to illustrate
>the lack of periodicity, and to some degree how that
>behaves and fluctuates [I'm referring to the stats
>here], run the program with `-l' and study the
>outputs..." (I'm not going to put it exactly like that,
>but you get the idea.) Is that better?

	Well -- but you haven't /tested/ the reliability of the clock itself;
only of the latency in responding to it...

	And just to put this back into an Ada context, I did spend some time
hacking (and I confess to the folks for just how badly hacked this is...
I've not used the packages before, and taking stuff from one package
internal form to something I can manipulate for stats took some klutzing
around) my attempt at collecting some data.

-=-=-=-=-=-
-- Simple experiment of Timer/Clock operation

with Text_IO; use Text_IO;
with Ada.Real_Time;
with Ada.Numerics.Generic_Elementary_Functions;

procedure Timer is

   package Rt renames Ada.Real_Time;

   type Statistic is digits 15;
   package M is new Ada.Numerics.Generic_Elementary_Functions (Statistic);


   procedure Runner (Ivl : Rt.Time_Span) is
      Num_Samples : constant Integer := 500;

      Samples     : array (1 .. Num_Samples) of Statistic;

      -- statistics stuff
      Sum         : Statistic := 0.0;
      Sum_Var     : Statistic := 0.0;
      Mean        : Statistic;
      Min         : Statistic;
      Max         : Statistic;
      Variance    : Statistic;

      Start       : Rt.Time;
      Stop        : Rt.Time;

      Log_File : File_Type;

      use type Rt.Time_Span;

   begin
      Put_Line ("Generating data for Time span: "
		& Duration'Image (Rt.To_Duration (Ivl)));

      Create (File => Log_File,
	      Mode => Out_File,
	      Name => "T"
	      & Duration'Image (Rt.To_Duration (Ivl))
	      & ".log");

      New_Line (Log_File);
      Put_Line (Log_File, "Data for Rt.Time span: "
		& Duration'Image (Rt.To_Duration (Ivl)));
      New_Line (Log_File);

      -- Just a bit of Rt.Time waster before starting actual loop
      -- probably not needed as I'm capturing the Rt.Clock before
      -- and after the delay statement
      delay until Rt.Clock + Ivl + Ivl;

      for I in 1 .. Num_Samples loop

	 -- capture the Rt.Clock at the start of the Rt.Time delay
	 Start := Rt.Clock;

	 -- delay until the captured Rt.Clock plus one Rt.Time-span interval
	 delay until Start + Ivl;

	 -- capture the Rt.Clock after the delay expired
	 Stop := Rt.Clock;

	 -- record the difference between stop and start Rt.Clock values
	 -- less the expected interval;
	 Put_Line (Log_File, Duration'Image (
	    Rt.To_Duration (Stop - Start - Ivl)));
	 Samples (I) := Statistic (Rt.To_Duration (Stop - Start - Ivl));

      end loop;

      -- compute statistics
      Min := Samples (1);
      Max := Samples (1);

      for I in 1 .. Num_Samples loop
	 Sum := Sum + Samples (I);
	 if Samples (I) > Max then
	    Max := Samples (I);
	 end if;
	 if Samples (I) < Min then
	    Min := Samples (I);
	 end if;
      end loop;

      Mean := Sum / Statistic (Num_Samples);

      for I in 1 .. Num_Samples loop
	 Sum_Var := Sum_Var + (Samples (I) - Mean) * (Samples (I) - Mean);
      end loop;
      Variance := Sum_Var / Statistic (Num_Samples - 1);


      Put_Line ("Statistics");
      New_Line;

      Put_Line ("Max:       " & Statistic'Image (Max));
      Put_Line ("Min:       " & Statistic'Image (Min));
      Put_Line ("Mean:      " & Statistic'Image (Mean));
--        Put_Line ("Variance:  " & Statistic'Image (Variance));
      Put_Line ("Std. Dev.: " & Statistic'Image (M.Sqrt (Variance)));

      New_Line(5);

   end Runner;

begin

   Put_Line ("Time Span Unit is " &
	       Duration'Image (Rt.To_Duration (Rt.Time_Span_Unit)));
   New_Line;

   Runner (Rt.Nanoseconds (1));
   Runner (Rt.Nanoseconds (10));
   Runner (Rt.Nanoseconds (100));
   Runner (Rt.Microseconds (1));
   Runner (Rt.Microseconds (10));
   Runner (Rt.Microseconds (100));
   Runner (Rt.Milliseconds (1));
   Runner (Rt.Milliseconds (10));
   Runner (Rt.Milliseconds (100));

end Timer;
-=-=-=-=-
Time Span Unit is  0.000000001

Generating data for Time span:  0.000000001
Statistics

Max:        8.45100000000000E-06
Min:        3.00000000000000E-07
Mean:       8.97321999999994E-07
Std. Dev.:  4.72299434498552E-07





Generating data for Time span:  0.000000010
Statistics

Max:        1.80100000000000E-06
Min:        2.91000000000000E-07
Mean:       8.82286000000004E-07
Std. Dev.:  1.24592289815071E-07





Generating data for Time span:  0.000000100
Statistics

Max:        1.40900000000000E-06
Min:        2.01000000000000E-07
Mean:       7.67528000000000E-07
Std. Dev.:  1.59364913224758E-07





Generating data for Time span:  0.000001000
Statistics

Max:        8.12000000000000E-07
Min:        5.09000000000000E-07
Mean:       7.43505999999995E-07
Std. Dev.:  1.25971025885818E-07





Generating data for Time span:  0.000010000
Statistics

Max:        9.31900000000000E-06
Min:        2.63000000000000E-07
Mean:       6.92286000000001E-07
Std. Dev.:  9.61985163666378E-07





Generating data for Time span:  0.000100000
Statistics

Max:        1.59120000000000E-05
Min:        2.15000000000000E-07
Mean:       7.22622000000002E-07
Std. Dev.:  1.10564358388459E-06





Generating data for Time span:  0.001000000
Statistics

Max:        5.10477000000000E-04
Min:        3.43000000000000E-07
Mean:       2.97962600000000E-06
Std. Dev.:  3.19996443996105E-05





Generating data for Time span:  0.010000000
Statistics

Max:        5.31683000000000E-04
Min:        4.19000000000000E-07
Mean:       5.65434000000001E-06
Std. Dev.:  4.44572946856412E-05





Generating data for Time span:  0.100000000
Statistics

Max:        5.01349000000000E-04
Min:        5.74000000000000E-07
Mean:       3.99113399999998E-06
Std. Dev.:  3.06653091148658E-05

-=-=-=-=-

	One thing not seen in the above, is that under Windows, there are
uncontrollable events that will throw a data point out to the extreme...
Look at the millisecond data (0.001). The max latency was 5.1E-4, while the
mean was 2.9E-6. In a run of 500 samples, only 2 or 3 data points jumped to
that high value. That's a sign of the OS doing some house-keeping and
blocking the program from responding. But to see it requires plotting the
data -- once seen, one can attempt to explain that data point. Excluding
those data points will bring the mean down a small amount, but will reduce
the standard deviation significantly.

	Also note that for intervals less than 1microsecond, the latency swamps
the delay. Even for 1microsecond, the latency is 0.7microseconds (the
numbers shown above are AFTER the expected delay value has been subtracted
from the stop-start clock times, leaving only the latency from delay
expiration to the read).

	
-- 
	Wulfraed                 Dennis Lee Bieber         AF6VN
    wlfraed@ix.netcom.com    HTTP://wlfraed.home.netcom.com/