Account for CPU used by child processes (#378)

* Account for CPU used by child processes

getCpuAndContexts() only sampled RUSAGE_SELF, so CPU burned by forked
children was never reported. Sample RUSAGE_CHILDREN as well.

The final measurement is reachable via finalizeProcessMonitoring()
instead of only ~Monitoring(), and bypasses the 1s rate guard, which
would otherwise discard a delta that no later call can pick up.

Details:

* RUSAGE_CHILDREN only becomes non-zero once a child has been reaped, so
  this is one half of the fix: the caller has to reap the child, and has
  to do so without killing an intermediate shell first. See the
  companion change in AliceO2Group/AliceO2#15636.

* Forced (final) measurements are deliberately excluded from the
  percentage series. A reaped child's CPU becomes visible as one lump,
  and lump / (time since the last sample) is a meaningless rate - 14315%
  was observed before this exclusion. Only the absolute and accumulated
  fields carry meaning for such a sample, so consumers that care about
  external subprocesses (Hyperloop accounting) should read
  cpuTimeConsumedByProcess, not the percentage series.

* Consequently a process that ends before the first periodic sample has
  no percentage at all - pushLoop() sleeps 100ms before sampling - and
  averaging over the empty series produced a NaN averageCpuUsedPercentage.
  Verified with a Monitoring instance destroyed after 10ms: 'nan' before,
  '0.14' on the unpatched library. Such a measurement now reports no
  average instead of a NaN one.

* init() clears the aggregates, so monitoring that is stopped and started
  again reports the new period rather than blending it with the previous
  one. DPL devices go RUNNING -> READY -> RUNNING across runs and re-arm
  process monitoring on start.

Related to https://its.cern.ch/jira/browse/O2-7096

Assisted by Claude Opus 5

* Account for children in the context switches too

The previous commit made the CPU numbers the sum over this process and its
reaped children, but left the two context-switch counts on RUSAGE_SELF alone,
so a single measurement mixed a process-tree quantity with a parent-only one.
Both counts now sum the same pair of snapshots. Raised in review.

The surrounding measurement code is tidied while we are here: the CPU delta is
expressed in the same shape as the context-switch deltas, and the percentage is
computed only on the path that actually reports one.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

Author: sawenzel

include/Monitoring/Monitoring.h

@@ -73,6 +73,11 @@ class Monitoring
   /// \param enabledMeasurements vector of monitor measurements, eg. PmMeasurement::Cpu
   void enableProcessMonitoring(const unsigned int interval = 5, std::vector<PmMeasurement> enabledMeasurements = {PmMeasurement::Cpu, PmMeasurement::Mem, PmMeasurement::Smaps});
 
+  /// Stops process monitoring and transmits the final measurement. Idempotent;
+  /// call it explicitly where destructor timing is not guaranteed, e.g. on a
+  /// DPL device's RUNNING->READY transition.
+  void finalizeProcessMonitoring();
+
   /// Flushes metric buffer (this can also happen when buffer is full)
   void flushBuffer();
 

include/Monitoring/ProcessMonitor.h

@@ -104,6 +104,9 @@ class ProcessMonitor
   /// 'getrusage' values from last execution
   struct rusage mPreviousGetrUsage;
 
+  /// 'getrusage(RUSAGE_CHILDREN)' values from last execution
+  struct rusage mPreviousGetrUsageChildren;
+
   /// Retired-instructions hardware counter (perf_event_open, Linux only);
   /// -1 when unavailable (high perf_event_paranoid, container seccomp, or no PMU).
   int mInstructionsFd = -1;
@@ -128,7 +131,9 @@ class ProcessMonitor
   std::vector<Metric> getSmaps();
 
   /// Retrieves CPU usage (%) and number of context switches during the interval
-  std::vector<Metric> getCpuAndContexts();
+  /// \param force  ignore the 1s minimum interval and report no percentage;
+  ///               for the final measurement, whose delta no later call would pick up
+  std::vector<Metric> getCpuAndContexts(bool force = false);
 
   std::vector<Metric> makeLastMeasurementAndGetMetrics();
 };

src/Monitoring.cxx

@@ -130,13 +130,21 @@ void Monitoring::addBackend(std::unique_ptr<Backend> backend)
   mBackends.push_back(std::move(backend));
 }
 
-Monitoring::~Monitoring()
+void Monitoring::finalizeProcessMonitoring()
 {
+  if (!mMonitorRunning) {
+    return;
+  }
   mMonitorRunning = false;
   if (mMonitorThread.joinable()) {
     mMonitorThread.join();
     transmit(mProcessMonitor->makeLastMeasurementAndGetMetrics());
   }
+}
+
+Monitoring::~Monitoring()
+{
+  finalizeProcessMonitoring();
   flushBuffer();
 }
 

src/ProcessMonitor.cxx

@@ -60,6 +60,7 @@ ProcessMonitor::ProcessMonitor()
   mPid = static_cast<unsigned int>(::getpid());
   mTimeLastRun = std::chrono::high_resolution_clock::now();
   getrusage(RUSAGE_SELF, &mPreviousGetrUsage);
+  getrusage(RUSAGE_CHILDREN, &mPreviousGetrUsageChildren);
 #ifdef O2_MONITORING_OS_LINUX
   setTotalMemory();
 #endif
@@ -99,6 +100,13 @@ void ProcessMonitor::init()
 {
   mTimeLastRun = std::chrono::high_resolution_clock::now();
   getrusage(RUSAGE_SELF, &mPreviousGetrUsage);
+  getrusage(RUSAGE_CHILDREN, &mPreviousGetrUsageChildren);
+  // The aggregates cover one monitoring period: monitoring stopped and started
+  // again reports the new period, not both blended together.
+  mCpuPerctange.clear();
+  mCpuMicroSeconds.clear();
+  mVmSizeMeasurements.clear();
+  mVmRssMeasurements.clear();
 }
 
 void ProcessMonitor::enable(PmMeasurement measurement)
@@ -167,31 +175,45 @@ std::vector<Metric> ProcessMonitor::getSmaps()
   return {{pssTotal, metricsNames[PSS]}, {cleanTotal, metricsNames[PRIVATE_CLEAN]}, {dirtyTotal, metricsNames[PRIVATE_DIRTY]}};
 }
 
-std::vector<Metric> ProcessMonitor::getCpuAndContexts()
+std::vector<Metric> ProcessMonitor::getCpuAndContexts(bool force)
 {
   std::vector<Metric> metrics;
+  // RUSAGE_SELF does not see work done by reaped children (e.g. an external
+  // event generator forked by o2-sim), so every counter below sums the two.
   struct rusage currentUsage;
+  struct rusage currentUsageChildren;
   getrusage(RUSAGE_SELF, &currentUsage);
+  getrusage(RUSAGE_CHILDREN, &currentUsageChildren);
   auto timeNow = std::chrono::high_resolution_clock::now();
   double timePassed = std::chrono::duration_cast<std::chrono::microseconds>(timeNow - mTimeLastRun).count();
-  if (timePassed < 950) {
+  if (timePassed < 950 && !force) {
     MonLogger::Get(Severity::Warn) << "Do not invoke Process Monitor more frequent then every 1s" << MonLogger::End();
     metrics.emplace_back("processPerformance");
     return metrics;
   }
 
-  uint64_t cpuUsedInMicroSeconds = currentUsage.ru_utime.tv_sec * 1000000.0 + currentUsage.ru_utime.tv_usec - (mPreviousGetrUsage.ru_utime.tv_sec * 1000000.0 + mPreviousGetrUsage.ru_utime.tv_usec) + currentUsage.ru_stime.tv_sec * 1000000.0 + currentUsage.ru_stime.tv_usec - (mPreviousGetrUsage.ru_stime.tv_sec * 1000000.0 + mPreviousGetrUsage.ru_stime.tv_usec);
-  double fractionCpuUsed = cpuUsedInMicroSeconds / timePassed;
-
-  double cpuUsedPerctange = std::round(fractionCpuUsed * 100.0 * 100.0) / 100.0;
-  mCpuPerctange.push_back(cpuUsedPerctange);
+  // CPU time (user + system) of one snapshot, in microseconds
+  auto cpuMicros = [](const struct rusage& usage) {
+    return (usage.ru_utime.tv_sec + usage.ru_stime.tv_sec) * 1000000.0 + usage.ru_utime.tv_usec + usage.ru_stime.tv_usec;
+  };
+  uint64_t cpuUsedInMicroSeconds = (cpuMicros(currentUsage) - cpuMicros(mPreviousGetrUsage)) +
+                                   (cpuMicros(currentUsageChildren) - cpuMicros(mPreviousGetrUsageChildren));
   mCpuMicroSeconds.push_back(cpuUsedInMicroSeconds);
 
-  metrics.emplace_back(Metric{cpuUsedPerctange, metricsNames[CPU_USED_PERCENTAGE]});
-  metrics.emplace_back(Metric{
-    static_cast<uint64_t>(currentUsage.ru_nivcsw - mPreviousGetrUsage.ru_nivcsw), metricsNames[INVOLUNTARY_CONTEXT_SWITCHES]});
-  metrics.emplace_back(Metric{
-    static_cast<uint64_t>(currentUsage.ru_nvcsw - mPreviousGetrUsage.ru_nvcsw), metricsNames[VOLUNTARY_CONTEXT_SWITCHES]});
+  // A child's CPU time appears all at once when it is reaped, so the delta of a
+  // forced (final) measurement is not a rate over the interval: absolute time only.
+  if (!force) {
+    double fractionCpuUsed = cpuUsedInMicroSeconds / timePassed;
+    double cpuUsedPerctange = std::round(fractionCpuUsed * 100.0 * 100.0) / 100.0;
+    mCpuPerctange.push_back(cpuUsedPerctange);
+    metrics.emplace_back(Metric{cpuUsedPerctange, metricsNames[CPU_USED_PERCENTAGE]});
+  }
+  uint64_t involuntaryContextSwitches = (currentUsage.ru_nivcsw - mPreviousGetrUsage.ru_nivcsw) +
+                                        (currentUsageChildren.ru_nivcsw - mPreviousGetrUsageChildren.ru_nivcsw);
+  uint64_t voluntaryContextSwitches = (currentUsage.ru_nvcsw - mPreviousGetrUsage.ru_nvcsw) +
+                                      (currentUsageChildren.ru_nvcsw - mPreviousGetrUsageChildren.ru_nvcsw);
+  metrics.emplace_back(Metric{involuntaryContextSwitches, metricsNames[INVOLUNTARY_CONTEXT_SWITCHES]});
+  metrics.emplace_back(Metric{voluntaryContextSwitches, metricsNames[VOLUNTARY_CONTEXT_SWITCHES]});
   metrics.emplace_back(cpuUsedInMicroSeconds, metricsNames[CPU_USED_ABSOLUTE]);
 
 #ifdef O2_MONITORING_OS_LINUX
@@ -212,6 +234,7 @@ std::vector<Metric> ProcessMonitor::getCpuAndContexts()
 
   mTimeLastRun = timeNow;
   mPreviousGetrUsage = currentUsage;
+  mPreviousGetrUsageChildren = currentUsageChildren;
   return metrics;
 }
 
@@ -262,14 +285,20 @@ std::vector<Metric> ProcessMonitor::makeLastMeasurementAndGetMetrics()
   }
 #endif
   if (mEnabledMeasurements.at(static_cast<short>(PmMeasurement::Cpu))) {
-    getCpuAndContexts();
-
-    auto avgCpuUsage = std::accumulate(mCpuPerctange.begin(), mCpuPerctange.end(), 0.0) /
-                       mCpuPerctange.size();
+    // forced: no later call would pick up a delta the rate guard discards here
+    auto lastCpuMetrics = getCpuAndContexts(true);
+    std::move(lastCpuMetrics.begin(), lastCpuMetrics.end(), std::back_inserter(metrics));
+
+    // A process that ends before the first periodic measurement has no
+    // percentages at all (the forced one contributes none), and averaging an
+    // empty vector would give NaN.
+    if (!mCpuPerctange.empty()) {
+      auto avgCpuUsage = std::accumulate(mCpuPerctange.begin(), mCpuPerctange.end(), 0.0) /
+                         mCpuPerctange.size();
+      metrics.emplace_back(avgCpuUsage, metricsNames[AVG_CPU_USED_PERCENTAGE]);
+    }
     uint64_t accumulationOfCpuTimeConsumption = std::accumulate(mCpuMicroSeconds.begin(),
                                                                 mCpuMicroSeconds.end(), 0UL);
-
-    metrics.emplace_back(avgCpuUsage, metricsNames[AVG_CPU_USED_PERCENTAGE]);
     metrics.emplace_back(accumulationOfCpuTimeConsumption, metricsNames[ACCUMULATED_CPU_TIME]);
   }
   return metrics;