From 72838ed7ba1d10603f736136fc7894db2e90b1e5 Mon Sep 17 00:00:00 2001
From: "s.zharko@gsi.de" <s.zharko@gsi.de>
Date: Thu, 19 Oct 2023 10:13:10 +0200
Subject: [PATCH] CA: The CaTimer class is introduced

---
 algo/ca/core/CMakeLists.txt        |   2 +
 algo/ca/core/utils/CaMonitor.h     |  54 ++++++------
 algo/ca/core/utils/CaTimer.cxx     |  29 +++++++
 algo/ca/core/utils/CaTimer.h       | 129 +++++++++++++++++++++++++++++
 reco/L1/CbmL1.cxx                  |   5 +-
 reco/L1/CbmL1.h                    |   1 +
 reco/L1/L1Algo/L1Algo.cxx          |   3 +
 reco/L1/L1Algo/L1Algo.h            |  10 +--
 reco/L1/L1Algo/L1CaTrackFinder.cxx |   3 +
 9 files changed, 200 insertions(+), 36 deletions(-)
 create mode 100644 algo/ca/core/utils/CaTimer.cxx
 create mode 100644 algo/ca/core/utils/CaTimer.h

diff --git a/algo/ca/core/CMakeLists.txt b/algo/ca/core/CMakeLists.txt
index d527c55fcf..78756d5be1 100644
--- a/algo/ca/core/CMakeLists.txt
+++ b/algo/ca/core/CMakeLists.txt
@@ -26,6 +26,7 @@ set(SRCS
   ${CMAKE_CURRENT_SOURCE_DIR}/pars/CaSearchWindow.cxx
   ${CMAKE_CURRENT_SOURCE_DIR}/pars/CaStation.cxx
   ${CMAKE_CURRENT_SOURCE_DIR}/pars/CaStationInitializer.cxx
+  ${CMAKE_CURRENT_SOURCE_DIR}/utils/CaTimer.cxx
   ${CMAKE_CURRENT_SOURCE_DIR}/tracking/CaTrackFit.cxx
 )
 
@@ -87,6 +88,7 @@ install(
     utils/CaSimd.h
     utils/CaSimdVc.h
     utils/CaSimdPseudo.h
+    utils/CaTimer.h
     utils/CaVector.h
     utils/CaUtils.h
     utils/CaDefines.h
diff --git a/algo/ca/core/utils/CaMonitor.h b/algo/ca/core/utils/CaMonitor.h
index 5ba1711a40..749f11fc82 100644
--- a/algo/ca/core/utils/CaMonitor.h
+++ b/algo/ca/core/utils/CaMonitor.h
@@ -2,66 +2,66 @@
    SPDX-License-Identifier: GPL-3.0-only
    Authors: Sergei Zharko [committer] */
 
-/// @file   CaMonitor.h
-/// @brief  CA Tracking monitor class
-/// @since  25.08.2023
-/// @author S.Zharko <s.zharko@gsi.de>
+/// \file   CaMonitor.h
+/// \brief  CA Tracking monitor class
+/// \since  25.08.2023
+/// \author S.Zharko <s.zharko@gsi.de>
 
 #pragma once  // include this header only once per compilation unit
 
-
 #include <iomanip>
 #include <sstream>
 #include <string>
 
 #include "CaEnumArray.h"
+#include "CaTimer.h"
 
 namespace cbm::algo::ca
 {
-  /// @class  Monitor
-  /// @brief  Monitor class for CA tracking
-  /// @tparam EMonitorKey  A enum class, containing keys for monitorables
+  /// \class  Monitor
+  /// \brief  Monitor class for the CA tracking
+  /// \tparam EMonitorKey  A enum class, containing keys for monitorables
   ///
   template<class EMonitorKey>
   class Monitor {
   public:
-    /// @brief Alias to array, indexed by Monitorable enumeration
+    /// \brief Alias to array, indexed by Monitorable enumeration
     template<typename T>
     using MonitorableArr_t = EnumArray<EMonitorKey, T>;
 
-    /// @brief Constructor
-    /// @param name Name of monitor
+    /// \brief Constructor
+    /// \param name Name of monitor
     Monitor(const std::string& name) : fsName(name) {}
 
-    /// @brief Gets key name
-    /// @param key Monitorable key
+    /// \brief Gets key name
+    /// \param key Monitorable key
     const std::string& GetKeyName(EMonitorKey key) const { return faKeyNames[key]; }
 
-    /// @brief Gets counter value
-    /// @param key
+    /// \brief Gets counter value
+    /// \param key
     int GetValue(EMonitorKey key) const { return faKeyCounters[key]; }
 
-    /// @brief Increments key counter by 1
-    /// @param key Monitorable key
+    /// \brief Increments key counter by 1
+    /// \param key Monitorable key
     void Increment(EMonitorKey key) { ++faKeyCounters[key]; };
 
-    /// @brief Increments key counter by a number
-    /// @param key  Monitorable key
-    /// @param num  Number to add
+    /// \brief Increments key counter by a number
+    /// \param key  Monitorable key
+    /// \param num  Number to add
     void Increment(EMonitorKey key, int num) { faKeyCounters[key] += num; }
 
-    /// @brief Resets the counters
+    /// \brief Resets the counters
     void Reset() { faKeyCounters.fill(0); }
 
-    /// @brief Sets keys of monitorables, which are used as denominators for ratios
-    /// @param vKeys Vector of keys
+    /// \brief Sets keys of monitorables, which are used as denominators for ratios
+    /// \param vKeys Vector of keys
     void SetRatioKeys(const std::vector<EMonitorKey>& vKeys) { fvRatioKeys = vKeys; }
 
-    /// @brief Sets name of key
-    /// @param name  Name of monitoralble
+    /// \brief Sets name of key
+    /// \param name  Name of monitoralble
     void SetKeyName(EMonitorKey key, const char* name) { faKeyNames[key] = name; }
 
-    /// @brief Prints counters summary to string
+    /// \brief Prints counters summary to string
     std::string ToString() const;
 
   private:
@@ -71,11 +71,11 @@ namespace cbm::algo::ca
     MonitorableArr_t<int> faKeyCounters {};       ///< Counters of keys
   };
 
+
   // *****************************************
   // **  Template function implementations  **
   // *****************************************
 
-
   // ---------------------------------------------------------------------------------------------------------------------
   //
   template<class EMonitorKey>
diff --git a/algo/ca/core/utils/CaTimer.cxx b/algo/ca/core/utils/CaTimer.cxx
new file mode 100644
index 0000000000..84cc02a6e4
--- /dev/null
+++ b/algo/ca/core/utils/CaTimer.cxx
@@ -0,0 +1,29 @@
+/* Copyright (C) 2023 GSI Helmholtzzentrum fuer Schwerionenforschung, Darmstadt
+   SPDX-License-Identifier: GPL-3.0-only
+   Authors: Sergei Zharko [committer] */
+
+/// \file   CaTimer.h
+/// \brief  Timer class for CA tracking (implementation)
+/// \since  18.10.2023
+/// \author S.Zharko <s.zharko@gsi.de>
+
+#include "CaTimer.h"
+
+#include <iomanip>
+#include <sstream>
+
+using cbm::algo::ca::Timer;
+
+// ---------------------------------------------------------------------------------------------------------------------
+//
+std::string Timer::ToString() const
+{
+  using std::left;
+  using std::right;
+  using std::setw;
+
+  std::stringstream msg;
+  msg << left << setw(25) << fName << right << " min = " << setw(15) << fMin << " ns, max = " << setw(15) << fMax
+      << " ns, average = " << setw(15) << GetAverage() << " ns, total = " << fTotal << " ns, N calls = " << fNofCalls;
+  return msg.str();
+}
diff --git a/algo/ca/core/utils/CaTimer.h b/algo/ca/core/utils/CaTimer.h
new file mode 100644
index 0000000000..49f8be69e7
--- /dev/null
+++ b/algo/ca/core/utils/CaTimer.h
@@ -0,0 +1,129 @@
+/* Copyright (C) 2023 GSI Helmholtzzentrum fuer Schwerionenforschung, Darmstadt
+   SPDX-License-Identifier: GPL-3.0-only
+   Authors: Sergei Zharko [committer] */
+
+/// \file   CaTimer.h
+/// \brief  Timer class for CA tracking (header)
+/// \since  18.10.2023
+/// \author S.Zharko <s.zharko@gsi.de>
+
+#pragma once
+
+#include <chrono>
+#include <cstdint>
+#include <limits>
+#include <string>
+
+namespace cbm::algo::ca
+{
+  /// \class  Timer
+  /// \brief  A timer class for the monitor
+  ///
+  class Timer {
+  public:
+    using Clock         = std::chrono::high_resolution_clock;
+    using Duration      = std::chrono::nanoseconds;
+    using DurationCount = Duration::rep;
+    using TimePoint     = std::chrono::time_point<Clock, Duration>;
+
+    /// \brief Default constructor
+    Timer() = default;
+
+    /// \brief Destructor
+    ~Timer() = default;
+
+    /// \brief Copy constructor
+    Timer(const Timer&) = default;
+
+    /// \brief Move constructor
+    Timer(Timer&&) = default;
+
+    /// \brief Copy assignment operator
+    Timer& operator=(const Timer&) = default;
+
+    /// \brief Move assignment operator
+    Timer& operator=(Timer&&) = default;
+
+    /// \brief Gets average time [ns]
+    DurationCount GetAverage() const { return fTotal / fNofCalls; }
+
+    /// \brief Gets time of the longest call [ns]
+    DurationCount GetMax() const { return fMax; }
+
+    /// \brief Gets time of the shortest call [ns]
+    DurationCount GetMin() const { return fMin; }
+
+    /// \brief Gets index of the longest call
+    int GetMaxCallIndex() const { return fMaxCallIndex; }
+
+    /// \brief Gets index of the longest call
+    int GetMinCallIndex() const { return fMinCallIndex; }
+
+    /// \brief Gets name
+    const std::string& GetName() const { return fName; }
+
+    /// \brief Gets total time [ns]
+    DurationCount GetTotal() const;
+
+    /// \brief Resets the timer
+    void Reset();
+
+    /// \brief Sets name
+    void SetName(const std::string& name) { fName = name; }
+
+    /// \brief Starts the timer
+    void Start() { fStart = Clock::now(); }
+
+    /// \brief Stops the timer
+    void Stop();
+
+    /// \brief Prints statistics
+    std::string ToString() const;
+
+  private:
+    std::string fName    = "no name";  ///< Name of the timer
+    TimePoint fStart     = TimePoint();
+    DurationCount fMin   = std::numeric_limits<DurationCount>::max();  ///< Minimal time period
+    DurationCount fMax   = std::numeric_limits<DurationCount>::min();  ///< Maximal time period
+    DurationCount fTotal = DurationCount(0);                           ///< Total measured time period
+    int fNofCalls        = 0;                                          ///< Number of timer calls
+    int fMinCallIndex    = -1;                                         ///< Index of the shortest call
+    int fMaxCallIndex    = -1;                                         ///< Index of the longest call
+  };                                                                   // class Timer
+
+
+  // ************************************
+  // **   Inline function definition   **
+  // ************************************
+
+  // -------------------------------------------------------------------------------------------------------------------
+  //
+  inline void Timer::Reset()
+  {
+    fStart        = TimePoint();
+    fMin          = std::numeric_limits<DurationCount>::max();
+    fMax          = std::numeric_limits<DurationCount>::min();
+    fMinCallIndex = -1;
+    fMaxCallIndex = -1;
+    fTotal        = DurationCount(0);
+    fNofCalls     = 0;
+  }
+
+  // -------------------------------------------------------------------------------------------------------------------
+  //
+  inline void Timer::Stop()
+  {
+    auto stop = Clock::now();
+    auto time = std::chrono::duration_cast<Duration>(stop - fStart).count();
+    if (fMin > time) {
+      fMin          = time;
+      fMinCallIndex = fNofCalls;
+    }
+    else if (fMax < time) {
+      fMax          = time;
+      fMaxCallIndex = fNofCalls;
+    }
+    fTotal += time;
+    ++fNofCalls;
+  }
+}  // namespace cbm::algo::ca
\ No newline at end of file
diff --git a/reco/L1/CbmL1.cxx b/reco/L1/CbmL1.cxx
index f32cff1496..25a31f9f4c 100644
--- a/reco/L1/CbmL1.cxx
+++ b/reco/L1/CbmL1.cxx
@@ -796,7 +796,7 @@ void CbmL1::Reconstruct(CbmEvent* event)
   if (fVerbose > 1) { LOG(info) << "L1 Track finder..."; }
   fpAlgo->CaTrackFinder();
   //       IdealTrackFinder();
-  fTrackingTime = fpAlgo->fCaRecoTime;
+  fTrackingTime = fpAlgo->fCaRecoTime;  // TODO: remove (not used)
 
   if (fVerbose > 1) { LOG(info) << "L1 Track finder ok"; }
 
@@ -825,7 +825,8 @@ void CbmL1::Reconstruct(CbmEvent* event)
 
   fMonitor.Increment(EMonitorKey::kRecoTrack, fvRecoTracks.size());
 
-  LOG(debug) << "CA Track Finder: " << fpAlgo->fCaRecoTime << " s/sub-ts";
+  LOG(info) << "CA Track Finder: " << fpAlgo->fCaRecoTime << " s/sub-ts";
+  LOG(info) << GetName() << ": " << fpAlgo->fRecoTimer.ToString();
 
 
   // output performance
diff --git a/reco/L1/CbmL1.h b/reco/L1/CbmL1.h
index 239e692043..f430443a2a 100644
--- a/reco/L1/CbmL1.h
+++ b/reco/L1/CbmL1.h
@@ -539,6 +539,7 @@ private:
   Int_t fPerformance   = 0;   ///< performance mode: 0 - w\o perf. 1 - L1-Efficiency definition. 2 - QA-Eff.definition
   double fTrackingTime = 0.;  ///< time of track finding procedure
 
+
   /// Option to work with files for the standalone mode
   ///  - #0 standalone mode is not used
   ///  - #1 data for standalone mode is written to configuration file (currently does not work)
diff --git a/reco/L1/L1Algo/L1Algo.cxx b/reco/L1/L1Algo/L1Algo.cxx
index 82c52410de..910afa8a7d 100644
--- a/reco/L1/L1Algo/L1Algo.cxx
+++ b/reco/L1/L1Algo/L1Algo.cxx
@@ -53,6 +53,9 @@ void L1Algo::ReceiveParameters(Parameters&& parameters)
   fGhostSuppression = fParameters.GetGhostSuppression();
 
   ca::FieldRegion::ForceUseOfOriginalField(fParameters.DevIsUseOfOriginalField());
+
+  fRecoTimer.SetName("track finder + track fitter");
+  fRecoTimer.Reset();
 }
 
 int L1Algo::GetMcTrackIdForCaHit(int iHit) const
diff --git a/reco/L1/L1Algo/L1Algo.h b/reco/L1/L1Algo/L1Algo.h
index e625198f28..f33bae1a6c 100644
--- a/reco/L1/L1Algo/L1Algo.h
+++ b/reco/L1/L1Algo/L1Algo.h
@@ -35,6 +35,7 @@ class L1AlgoDraw;
 #include "CaMeasurementXy.h"
 #include "CaParameters.h"
 #include "CaStation.h"
+#include "CaTimer.h"
 #include "CaTrack.h"
 #include "CaTrackParam.h"
 #include "CaTriplet.h"
@@ -45,13 +46,6 @@ using namespace cbm::algo::ca;  //TODO: remove
 
 class CbmL1MCTrack;
 
-//namespace
-//{
-//  using cbm::algo::ca::Track;      // TMP
-//  using cbm::algo::ca::Vector;     // TMP
-//  using cbm::algo::ca::Iteration;  // TMP
-//}  // namespace
-
 // *******************************
 // ** Types definition (global) **
 // *******************************
@@ -304,6 +298,8 @@ public:
 
   double fCaRecoTime {0.};  // time of the track finder + fitter
 
+  ca::Timer fRecoTimer;  // TMP
+
   Vector<Track> fRecoTracks {"L1Algo::fRecoTracks"};       ///< reconstructed tracks
   Vector<ca::HitIndex_t> fRecoHits {"L1Algo::fRecoHits"};  ///< packed hits of reconstructed tracks
 
diff --git a/reco/L1/L1Algo/L1CaTrackFinder.cxx b/reco/L1/L1Algo/L1CaTrackFinder.cxx
index ab026223b1..081b193c94 100644
--- a/reco/L1/L1Algo/L1CaTrackFinder.cxx
+++ b/reco/L1/L1Algo/L1CaTrackFinder.cxx
@@ -33,7 +33,9 @@ void L1Algo::CaTrackFinder()
   // and runs the track finder over the sub-slices
   //
 
+  fRecoTimer.Reset();
   auto timerStart = std::chrono::high_resolution_clock::now();
+  fRecoTimer.Start();
 
   // ----- Reset data arrays -------------------------------------------------------------------------------------------
   fvHitKeyFlags.reset(fInputData.GetNhitKeys(), 0);
@@ -227,6 +229,7 @@ void L1Algo::CaTrackFinder()
   }
 
   auto timerEnd = std::chrono::high_resolution_clock::now();
+  fRecoTimer.Stop();
   fCaRecoTime   = (double) (std::chrono::duration<double>(timerEnd - timerStart).count());
   LOG(debug) << "CaTracker: nSubSlices processed = " << nSubSlices;
 }
-- 
GitLab