Add Stopwatch.Reporter utility and refactor Rate_Group to use it

src/components/rate_group/component-rate_group-implementation.adb

@@ -4,8 +4,6 @@
 
 with Sys_Time.Arithmetic;
 with Delta_Time.Arithmetic;
-with Stopwatch;
-with Task_Timing_Report;
 
 package body Component.Rate_Group.Implementation is
 
@@ -35,16 +33,15 @@ package body Component.Rate_Group.Implementation is
       use Delta_Time.Arithmetic;
 
       -- Local vars:
-      Cycle_Time : Time_Span;
-      Execution_Time : Time_Span;
       Stop_Wall_Time : Sys_Time.T;
       Event_Time : Delta_Time.T;
       Ignore : Sys_Time_Status;
-      Sw : Stopwatch.Wall_Timer_Instance;
-      Sw_Cpu : Stopwatch.Cpu_Timer_Instance;
    begin
-      -- Start execution timer:
-      Sw_Cpu.Start;
+      -- Start the timers. The wall clock timer measures the time starting at
+      -- the time stamp of the incoming Tick.T, ending at the end of the
+      -- execution of this rate group. The execution timer only measures the
+      -- time this task was actually executing on the CPU during this cycle.
+      Self.Timer.Start (Wall_Start_Time => To_Time (Arg.Time));
 
       -- Invoke all members of this rate group:
       for Index in Self.Connector_Tick_T_Send'Range loop
@@ -58,48 +55,29 @@ package body Component.Rate_Group.Implementation is
       -- Pet the watchdog to indicate this subprogram is executing.
       Self.Pet_T_Send_If_Connected ((Count => Arg.Count));
 
-      -- Stop execution timer:
-      Sw_Cpu.Stop;
+      -- Stop the timers. The CPU timer is stopped first so that fetching the
+      -- wall clock stop time from the time source is not included in the CPU
+      -- measurement:
+      Self.Timer.Stop_Cpu_Timer;
       Stop_Wall_Time := Self.Sys_Time_T_Get;
+      Self.Timer.Stop_Wall_Timer (Wall_Stop_Time => To_Time (Stop_Wall_Time));
 
       if Self.Ticks_Since_Startup >= Self.Timing_Report_Delay_Ticks then
-         -- Compute time differences for execution timer
-         -- and wall clock timer.
-         --
-         -- The wall clock timer measures
-         -- the time starting at the time stamp of the incoming
-         -- Tick.T, ending at the end of the execution of this
-         -- rate group.
-         --
-         -- The execution timer only measures the time this task
-         -- was actually executing on the CPU during this cycle.
-         --
-         Sw.Start_Time := To_Time (Arg.Time);
-         Sw.Stop_Time := To_Time (Stop_Wall_Time);
-         Cycle_Time := Sw.Result;
-         Execution_Time := Sw_Cpu.Result;
-
          -- Store max times and report any update:
-         if Cycle_Time > Self.Recent_Max_Cycle_Time then
-            Self.Recent_Max_Cycle_Time := Cycle_Time;
-         end if;
-         if Execution_Time > Self.Recent_Max_Execution_Time then
-            Self.Recent_Max_Execution_Time := Execution_Time;
-         end if;
-         if Cycle_Time > Self.Max_Cycle_Time then
-            Self.Max_Cycle_Time := Cycle_Time;
-            if Self.Issue_Time_Exceeded_Events then
-               Ignore := To_Delta_Time (Self.Max_Cycle_Time, Event_Time);
+         declare
+            Max_Cycle_Time_Updated : Boolean;
+            Max_Execution_Time_Updated : Boolean;
+         begin
+            Self.Timer.Accumulate (Max_Wall_Time_Updated => Max_Cycle_Time_Updated, Max_Execution_Time_Updated => Max_Execution_Time_Updated);
+            if Max_Cycle_Time_Updated and then Self.Issue_Time_Exceeded_Events then
+               Ignore := To_Delta_Time (Self.Timer.Max_Wall_Time, Event_Time);
                Self.Event_T_Send_If_Connected (Self.Events.Max_Cycle_Time_Exceeded (Stop_Wall_Time, (Time_Delta => Event_Time, Count => Arg.Count)));
             end if;
-         end if;
-         if Execution_Time > Self.Max_Execution_Time then
-            Self.Max_Execution_Time := Execution_Time;
-            if Self.Issue_Time_Exceeded_Events then
-               Ignore := To_Delta_Time (Self.Max_Execution_Time, Event_Time);
+            if Max_Execution_Time_Updated and then Self.Issue_Time_Exceeded_Events then
+               Ignore := To_Delta_Time (Self.Timer.Max_Execution_Time, Event_Time);
                Self.Event_T_Send_If_Connected (Self.Events.Max_Execution_Time_Exceeded (Stop_Wall_Time, (Time_Delta => Event_Time, Count => Arg.Count)));
             end if;
-         end if;
+         end;
 
          -- If the Ticks_Per_Timing_Report is greater than zero, then we need to send out a
          -- data product periodically.
@@ -109,25 +87,14 @@ package body Component.Rate_Group.Implementation is
 
             -- If we are at the period then send out the data product:
             if Self.Num_Ticks >= Self.Ticks_Per_Timing_Report then
-               declare
-                  Timing_Report : Task_Timing_Report.T;
-               begin
-                  -- Convert Time_Spans to the Delta_Time.T's stored in the data product type:
-                  Ignore := To_Delta_Time (Self.Max_Cycle_Time, Timing_Report.Max.Wall_Time);
-                  Ignore := To_Delta_Time (Self.Max_Execution_Time, Timing_Report.Max.Execution_Time);
-                  Ignore := To_Delta_Time (Self.Recent_Max_Cycle_Time, Timing_Report.Recent_Max.Wall_Time);
-                  Ignore := To_Delta_Time (Self.Recent_Max_Execution_Time, Timing_Report.Recent_Max.Execution_Time);
-
-                  -- Send the data product:
-                  Self.Data_Product_T_Send_If_Connected (Self.Data_Products.Timing_Report (Stop_Wall_Time, Timing_Report));
-
-                  -- Reset the recent cycle and execution times:
-                  Self.Recent_Max_Cycle_Time := Microseconds (0);
-                  Self.Recent_Max_Execution_Time := Microseconds (0);
-
-                  -- Reset the number of ticks:
-                  Self.Num_Ticks := 0;
-               end;
+               -- Send the data product:
+               Self.Data_Product_T_Send_If_Connected (Self.Data_Products.Timing_Report (Stop_Wall_Time, Self.Timer.Report));
+
+               -- Reset the recent cycle and execution times:
+               Self.Timer.Reset_Recent_Max;
+
+               -- Reset the number of ticks:
+               Self.Num_Ticks := 0;
             end if;
          end if;
       else

src/components/rate_group/component-rate_group-implementation.ads

@@ -3,7 +3,7 @@
 --------------------------------------------------------------------------------
 
 -- Standard Includes:
-with Ada.Real_Time; use Ada.Real_Time;
+with Stopwatch.Reporter;
 
 -- The Rate Group component is a queued component which invokes Tick connectors attached to it whenever it receives a Tick in. The tick in is intended to be periodic, allowing the component to control the execution of other components at a periodic rate. All components attached to the invoker connector of this component are said to be in a rate group, since they all execute at the same rate. Components are executed in the order they are attached to the components invoker connector. The execution of all attached connectors is expected to complete before another incoming Tick is put on the Rate Group component's queue. If the execution runs long, a cycle slip event is reported.
 --
@@ -29,13 +29,11 @@ private
 
    -- The component class instance record:
    type Instance is new Rate_Group.Base_Instance with record
-      -- Time spans for keeping track of maximum
-      -- execution data:
+      -- Timer for keeping track of maximum execution data. The wall timer
+      -- measures the cycle time, starting at the time stamp of the incoming
+      -- tick:
+      Timer : Stopwatch.Reporter.Instance;
       Issue_Time_Exceeded_Events : Boolean := False;
-      Max_Cycle_Time : Time_Span := Microseconds (0);
-      Max_Execution_Time : Time_Span := Microseconds (0);
-      Recent_Max_Cycle_Time : Time_Span := Microseconds (0);
-      Recent_Max_Execution_Time : Time_Span := Microseconds (0);
       -- Timing report data:
       Ticks_Per_Timing_Report : Unsigned_16 := 1;
       Timing_Report_Delay_Ticks : Unsigned_16 := 1;

src/components/rate_group/test/tests-implementation.adb

@@ -5,7 +5,7 @@
 with Connector_Types;
 with Basic_Assertions; use Basic_Assertions;
 with Tick.Assertion; use Tick.Assertion;
---with Time_Exceeded.Assertion; use Time_Exceeded.Assertion;
+with Time_Exceeded.Assertion; use Time_Exceeded.Assertion;
 with Cycle_Slip_Param.Assertion; use Cycle_Slip_Param.Assertion;
 with Full_Queue_Param.Assertion; use Full_Queue_Param.Assertion;
 
@@ -143,9 +143,13 @@ package body Tests.Implementation is
       -- Check events:
       Natural_Assert.Eq (T.Cycle_Slip_History.Get_Count, 0);
       Natural_Assert.Eq (T.Max_Cycle_Time_Exceeded_History.Get_Count, 1);
-      --Time_Exceeded_Assert.eq(t.Max_Cycle_Time_Exceeded_History.get(1), (Time_Delta => (2, 0), Count => 1));
+      -- The wall (cycle) time measurement is deterministic in test: it spans
+      -- the tick's timestamp to the tester-provided system time, which the
+      -- tester increments by Seconds_Delta on each invoked connector. The
+      -- execution time measurement uses the real CPU clock and can only be
+      -- checked by count.
+      Time_Exceeded_Assert.Eq (T.Max_Cycle_Time_Exceeded_History.Get (1), (Time_Delta => (2, 0), Count => 1));
       Natural_Assert.Eq (T.Max_Execution_Time_Exceeded_History.Get_Count, 1);
-      --Time_Exceeded_Assert.eq(t.Max_Execution_Time_Exceeded_History.get(1), (Time_Delta => (2, 0), Count => 1));
 
       -- Check data products:
       Natural_Assert.Eq (T.Timing_Report_History.Get_Count, 1);
@@ -154,8 +158,11 @@ package body Tests.Implementation is
       Natural_Assert.Eq (T.Pet_T_Recv_Sync_History.Get_Count, 1);
 
       --
-      -- We can no longer test the following since we are using Ada.Real_Time and Ada.Execution_Time
-      -- instead of Sys_Time arithmetic in the component.
+      -- The following cases are not run because they assert on execution
+      -- time values, which come from the real CPU clock
+      -- (Ada.Execution_Time) and are not deterministic in a unit test. The
+      -- wall (cycle) time is deterministic (see above) and is asserted by
+      -- value where possible.
       --
       --   --------------------------------------------------
       --   -- Send another of the same tick, we expect

src/util/stopwatch/stopwatch-reporter.adb

@@ -0,0 +1,102 @@
+with Delta_Time.Arithmetic;
+with Sys_Time.Arithmetic;
+
+package body Stopwatch.Reporter is
+
+   procedure Start (Self : in out Instance) is
+   begin
+      Self.Start (Wall_Start_Time => Ada.Real_Time.Clock);
+   end Start;
+
+   procedure Start (Self : in out Instance; Wall_Start_Time : in Ada.Real_Time.Time) is
+   begin
+      Self.Wall_Timer.Start_Time := Wall_Start_Time;
+      Self.Cpu_Timer.Start;
+   end Start;
+
+   procedure Stop (Self : in out Instance) is
+   begin
+      -- Stop the CPU timer first so the wall clock read below is excluded
+      -- from the CPU measurement:
+      Self.Stop_Cpu_Timer;
+      Self.Stop_Wall_Timer (Wall_Stop_Time => Ada.Real_Time.Clock);
+   end Stop;
+
+   procedure Stop (Self : in out Instance; Wall_Stop_Time : in Ada.Real_Time.Time) is
+   begin
+      Self.Stop_Cpu_Timer;
+      Self.Stop_Wall_Timer (Wall_Stop_Time => Wall_Stop_Time);
+   end Stop;
+
+   procedure Stop_Cpu_Timer (Self : in out Instance) is
+   begin
+      Self.Cpu_Timer.Stop;
+      Self.Last_Execution_Time := Self.Cpu_Timer.Result;
+   end Stop_Cpu_Timer;
+
+   procedure Stop_Wall_Timer (Self : in out Instance; Wall_Stop_Time : in Ada.Real_Time.Time) is
+   begin
+      Self.Wall_Timer.Stop_Time := Wall_Stop_Time;
+      Self.Last_Wall_Time := Self.Wall_Timer.Result;
+   end Stop_Wall_Timer;
+
+   procedure Accumulate (Self : in out Instance) is
+      Ignore_Max_Wall, Ignore_Max_Execution : Boolean;
+   begin
+      Self.Accumulate (Max_Wall_Time_Updated => Ignore_Max_Wall, Max_Execution_Time_Updated => Ignore_Max_Execution);
+   end Accumulate;
+
+   procedure Accumulate (Self : in out Instance; Max_Wall_Time_Updated : out Boolean; Max_Execution_Time_Updated : out Boolean) is
+      use Ada.Real_Time;
+
+      -- Fold a measured value into a recent-maximum and maximum pair,
+      -- reporting whether the maximum was updated:
+      procedure Update_Maximums (Value : in Time_Span; Recent_Max : in out Time_Span; Max : in out Time_Span; Updated : out Boolean) is
+      begin
+         Updated := False;
+         if Value > Recent_Max then
+            Recent_Max := Value;
+         end if;
+         if Value > Max then
+            Max := Value;
+            Updated := True;
+         end if;
+      end Update_Maximums;
+   begin
+      Update_Maximums (Self.Last_Wall_Time, Self.Recent_Max_Wall_Time, Self.Max_Wall_Time, Max_Wall_Time_Updated);
+      Update_Maximums (Self.Last_Execution_Time, Self.Recent_Max_Execution_Time, Self.Max_Execution_Time, Max_Execution_Time_Updated);
+   end Accumulate;
+
+   -- Convert a set of wall and execution time measurements into a
+   -- Task_Timing_Report.T:
+   function To_Report (Max_Wall_Time : in Ada.Real_Time.Time_Span; Max_Execution_Time : in Ada.Real_Time.Time_Span; Recent_Wall_Time : in Ada.Real_Time.Time_Span; Recent_Execution_Time : in Ada.Real_Time.Time_Span) return Task_Timing_Report.T is
+      use Delta_Time.Arithmetic;
+      To_Return : Task_Timing_Report.T;
+      Ignore : Sys_Time.Arithmetic.Sys_Time_Status;
+   begin
+      Ignore := To_Delta_Time (Max_Wall_Time, To_Return.Max.Wall_Time);
+      Ignore := To_Delta_Time (Max_Execution_Time, To_Return.Max.Execution_Time);
+      Ignore := To_Delta_Time (Recent_Wall_Time, To_Return.Recent_Max.Wall_Time);
+      Ignore := To_Delta_Time (Recent_Execution_Time, To_Return.Recent_Max.Execution_Time);
+      return To_Return;
+   end To_Report;
+
+   function Report (Self : in Instance) return Task_Timing_Report.T is
+      (To_Report (Max_Wall_Time => Self.Max_Wall_Time, Max_Execution_Time => Self.Max_Execution_Time, Recent_Wall_Time => Self.Recent_Max_Wall_Time, Recent_Execution_Time => Self.Recent_Max_Execution_Time));
+
+   function Report_Last (Self : in Instance) return Task_Timing_Report.T is
+      (To_Report (Max_Wall_Time => Self.Max_Wall_Time, Max_Execution_Time => Self.Max_Execution_Time, Recent_Wall_Time => Self.Last_Wall_Time, Recent_Execution_Time => Self.Last_Execution_Time));
+
+   procedure Reset_Recent_Max (Self : in out Instance) is
+      use Ada.Real_Time;
+   begin
+      Self.Recent_Max_Wall_Time := Time_Span_Zero;
+      Self.Recent_Max_Execution_Time := Time_Span_Zero;
+   end Reset_Recent_Max;
+
+   procedure Reset (Self : in out Instance) is
+   begin
+      Self := (others => <>);
+   end Reset;
+
+end Stopwatch.Reporter;

src/util/stopwatch/stopwatch-reporter.ads

@@ -0,0 +1,73 @@
+with Task_Timing_Report;
+
+-- A paired wall-clock and CPU-execution stopwatch for timing a section of
+-- code. The reporter accumulates recent-maximum and all-time-maximum (high
+-- water mark) values for both timers, and produces reports of the
+-- accumulated values as a Task_Timing_Report.T, suitable for publishing as
+-- a data product.
+package Stopwatch.Reporter is
+
+   type Instance is tagged record
+      -- The underlying stopwatch pair. These are exposed so that users may
+      -- manipulate the start and stop times directly for cases the Start and
+      -- Stop subprograms below do not cover.
+      Wall_Timer : Wall_Timer_Instance;
+      Cpu_Timer : Cpu_Timer_Instance;
+      -- The results of the most recent Stop:
+      Last_Wall_Time : Ada.Real_Time.Time_Span := Ada.Real_Time.Time_Span_Zero;
+      Last_Execution_Time : Ada.Real_Time.Time_Span := Ada.Real_Time.Time_Span_Zero;
+      -- The accumulated maximum values:
+      Recent_Max_Wall_Time : Ada.Real_Time.Time_Span := Ada.Real_Time.Time_Span_Zero;
+      Max_Wall_Time : Ada.Real_Time.Time_Span := Ada.Real_Time.Time_Span_Zero;
+      Recent_Max_Execution_Time : Ada.Real_Time.Time_Span := Ada.Real_Time.Time_Span_Zero;
+      Max_Execution_Time : Ada.Real_Time.Time_Span := Ada.Real_Time.Time_Span_Zero;
+   end record;
+
+   -- Start both the wall and CPU timers now. The wall timer is started
+   -- first, so that the timing bookkeeping itself is excluded from the CPU
+   -- measurement:
+   procedure Start (Self : in out Instance);
+   -- Start both timers, with the wall timer's start time supplied by the
+   -- caller instead of read from the clock. This is useful to backdate the
+   -- wall measurement, for example to the timestamp of an incoming tick so
+   -- that queue latency is included in the measurement:
+   procedure Start (Self : in out Instance; Wall_Start_Time : in Ada.Real_Time.Time);
+   -- Stop both timers now and store the measurement results. The CPU timer
+   -- is stopped first, so that the timing bookkeeping itself is excluded
+   -- from the CPU measurement:
+   procedure Stop (Self : in out Instance);
+   -- Stop both timers, with the wall timer's stop time supplied by the
+   -- caller instead of read from the clock. Note that the provided wall stop
+   -- time is necessarily acquired before the CPU timer stops; if that
+   -- acquisition is expensive, use the split subprograms below instead:
+   procedure Stop (Self : in out Instance; Wall_Stop_Time : in Ada.Real_Time.Time);
+   -- The two halves of Stop, exposed so that the CPU timer can be stopped
+   -- before the wall clock stop time is acquired, when that acquisition is
+   -- itself expensive (e.g. a system time fetched through a connector). Call
+   -- Stop_Cpu_Timer first, acquire the wall stop time, and then call
+   -- Stop_Wall_Timer. Each stops its timer and stores that timer's
+   -- measurement result:
+   procedure Stop_Cpu_Timer (Self : in out Instance);
+   procedure Stop_Wall_Timer (Self : in out Instance; Wall_Stop_Time : in Ada.Real_Time.Time);
+   -- Fold the results of the most recent Stop into the recent-maximum and
+   -- maximum accumulators:
+   procedure Accumulate (Self : in out Instance);
+   -- Same as above, but additionally reports whether either all-time maximum
+   -- value was updated, which is useful for issuing time-exceeded events:
+   procedure Accumulate (Self : in out Instance; Max_Wall_Time_Updated : out Boolean; Max_Execution_Time_Updated : out Boolean);
+   -- Produce a report of the currently accumulated values:
+   function Report (Self : in Instance) return Task_Timing_Report.T;
+   -- Produce a report with the Recent_Max fields holding the results of the
+   -- most recent Stop instead of the recent maximums. This is useful for
+   -- per-operation reporting, where each report carries the timing of the
+   -- operation just performed alongside the all-time maximums:
+   function Report_Last (Self : in Instance) return Task_Timing_Report.T;
+   -- Reset only the recent-maximum values. This is intended to be called
+   -- after each report is published so that the recent maximums cover a
+   -- single reporting period:
+   procedure Reset_Recent_Max (Self : in out Instance);
+   -- Reset all stored values, including the all-time maximums. Any
+   -- in-progress measurement (a Start without a Stop) is also discarded:
+   procedure Reset (Self : in out Instance);
+
+end Stopwatch.Reporter;

src/util/stopwatch/test/env.py

@@ -0,0 +1 @@
+from environments import test  # noqa: F401

src/util/stopwatch/test/stopwatch_reporter.tests.yaml

@@ -0,0 +1,11 @@
+---
+description: This is a unit test suite for the Stopwatch.Reporter utility
+tests:
+  - name: Test_Start_Stop
+    description: This unit test tests starting and stopping the timer pair, including supplying the wall clock start and stop times externally.
+  - name: Test_Accumulation
+    description: This unit test tests accumulating measurements into the recent-maximum and maximum values, including the maximum-updated indications.
+  - name: Test_Reports
+    description: This unit test tests the contents of the accumulated report and the last-measurement report.
+  - name: Test_Reset
+    description: This unit test tests resetting the recent-maximum values and resetting all values.