Skip to content

Commit 4f8de26

Browse files
committed
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. Related to https://its.cern.ch/jira/browse/O2-7096 Assisted by Claude Opus 5
1 parent f90781d commit 4f8de26

4 files changed

Lines changed: 44 additions & 8 deletions

File tree

include/Monitoring/Monitoring.h

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -73,6 +73,10 @@ class Monitoring
7373
/// \param enabledMeasurements vector of monitor measurements, eg. PmMeasurement::Cpu
7474
void enableProcessMonitoring(const unsigned int interval = 5, std::vector<PmMeasurement> enabledMeasurements = {PmMeasurement::Cpu, PmMeasurement::Mem, PmMeasurement::Smaps});
7575

76+
/// Stops process monitoring and transmits the final measurement. Idempotent;
77+
/// call explicitly where destructor timing is not guaranteed to be reached.
78+
void finalizeProcessMonitoring();
79+
7680
/// Flushes metric buffer (this can also happen when buffer is full)
7781
void flushBuffer();
7882

include/Monitoring/ProcessMonitor.h

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -102,6 +102,9 @@ class ProcessMonitor
102102
/// 'getrusage' values from last execution
103103
struct rusage mPreviousGetrUsage;
104104

105+
/// 'getrusage(RUSAGE_CHILDREN)' values from last execution
106+
struct rusage mPreviousGetrUsageChildren;
107+
105108
///each measurement will be saved to compute average/accumulation usage
106109
std::vector<double> mVmSizeMeasurements;
107110
std::vector<double> mVmRssMeasurements;
@@ -118,7 +121,9 @@ class ProcessMonitor
118121
std::vector<Metric> getSmaps();
119122

120123
/// Retrieves CPU usage (%) and number of context switches during the interval
121-
std::vector<Metric> getCpuAndContexts();
124+
/// \param force ignore the 1s minimum interval; for the final measurement,
125+
/// where a skipped delta would be lost rather than deferred
126+
std::vector<Metric> getCpuAndContexts(bool force = false);
122127

123128
std::vector<Metric> makeLastMeasurementAndGetMetrics();
124129
};

src/Monitoring.cxx

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -130,13 +130,21 @@ void Monitoring::addBackend(std::unique_ptr<Backend> backend)
130130
mBackends.push_back(std::move(backend));
131131
}
132132

133-
Monitoring::~Monitoring()
133+
void Monitoring::finalizeProcessMonitoring()
134134
{
135+
if (!mMonitorRunning) {
136+
return;
137+
}
135138
mMonitorRunning = false;
136139
if (mMonitorThread.joinable()) {
137140
mMonitorThread.join();
138141
transmit(mProcessMonitor->makeLastMeasurementAndGetMetrics());
139142
}
143+
}
144+
145+
Monitoring::~Monitoring()
146+
{
147+
finalizeProcessMonitoring();
140148
flushBuffer();
141149
}
142150

src/ProcessMonitor.cxx

Lines changed: 25 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -42,6 +42,7 @@ ProcessMonitor::ProcessMonitor()
4242
mPid = static_cast<unsigned int>(::getpid());
4343
mTimeLastRun = std::chrono::high_resolution_clock::now();
4444
getrusage(RUSAGE_SELF, &mPreviousGetrUsage);
45+
getrusage(RUSAGE_CHILDREN, &mPreviousGetrUsageChildren);
4546
#ifdef O2_MONITORING_OS_LINUX
4647
setTotalMemory();
4748
#endif
@@ -52,6 +53,7 @@ void ProcessMonitor::init()
5253
{
5354
mTimeLastRun = std::chrono::high_resolution_clock::now();
5455
getrusage(RUSAGE_SELF, &mPreviousGetrUsage);
56+
getrusage(RUSAGE_CHILDREN, &mPreviousGetrUsageChildren);
5557
}
5658

5759
void ProcessMonitor::enable(PmMeasurement measurement)
@@ -118,27 +120,41 @@ std::vector<Metric> ProcessMonitor::getSmaps()
118120
return {{pssTotal, metricsNames[PSS]}, {cleanTotal, metricsNames[PRIVATE_CLEAN]}, {dirtyTotal, metricsNames[PRIVATE_DIRTY]}};
119121
}
120122

121-
std::vector<Metric> ProcessMonitor::getCpuAndContexts()
123+
std::vector<Metric> ProcessMonitor::getCpuAndContexts(bool force)
122124
{
123125
std::vector<Metric> metrics;
124126
struct rusage currentUsage;
127+
struct rusage currentUsageChildren;
125128
getrusage(RUSAGE_SELF, &currentUsage);
129+
// CPU of reaped children (e.g. an external event generator forked by o2-sim)
130+
// is spent outside this process and is invisible to RUSAGE_SELF
131+
getrusage(RUSAGE_CHILDREN, &currentUsageChildren);
126132
auto timeNow = std::chrono::high_resolution_clock::now();
127133
double timePassed = std::chrono::duration_cast<std::chrono::microseconds>(timeNow - mTimeLastRun).count();
128-
if (timePassed < 950) {
134+
if (timePassed < 950 && !force) {
129135
MonLogger::Get(Severity::Warn) << "Do not invoke Process Monitor more frequent then every 1s" << MonLogger::End();
130136
metrics.emplace_back("processPerformance");
131137
return metrics;
132138
}
133139

134-
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);
140+
auto micros = [](const timeval& t) { return t.tv_sec * 1000000.0 + t.tv_usec; };
141+
auto cpuDelta = [&micros](const struct rusage& now, const struct rusage& before) {
142+
return micros(now.ru_utime) - micros(before.ru_utime) + micros(now.ru_stime) - micros(before.ru_stime);
143+
};
144+
uint64_t cpuUsedInMicroSeconds = cpuDelta(currentUsage, mPreviousGetrUsage) +
145+
cpuDelta(currentUsageChildren, mPreviousGetrUsageChildren);
135146
double fractionCpuUsed = cpuUsedInMicroSeconds / timePassed;
136147

137148
double cpuUsedPerctange = std::round(fractionCpuUsed * 100.0 * 100.0) / 100.0;
138-
mCpuPerctange.push_back(cpuUsedPerctange);
139149
mCpuMicroSeconds.push_back(cpuUsedInMicroSeconds);
140150

141-
metrics.emplace_back(Metric{cpuUsedPerctange, metricsNames[CPU_USED_PERCENTAGE]});
151+
// A forced measurement may report CPU accumulated over the whole run but only
152+
// made visible at once (children become visible on reap), for which an
153+
// instantaneous rate is meaningless: report it as absolute time only.
154+
if (!force) {
155+
mCpuPerctange.push_back(cpuUsedPerctange);
156+
metrics.emplace_back(Metric{cpuUsedPerctange, metricsNames[CPU_USED_PERCENTAGE]});
157+
}
142158
metrics.emplace_back(Metric{
143159
static_cast<uint64_t>(currentUsage.ru_nivcsw - mPreviousGetrUsage.ru_nivcsw), metricsNames[INVOLUNTARY_CONTEXT_SWITCHES]});
144160
metrics.emplace_back(Metric{
@@ -147,6 +163,7 @@ std::vector<Metric> ProcessMonitor::getCpuAndContexts()
147163

148164
mTimeLastRun = timeNow;
149165
mPreviousGetrUsage = currentUsage;
166+
mPreviousGetrUsageChildren = currentUsageChildren;
150167
return metrics;
151168
}
152169

@@ -197,7 +214,9 @@ std::vector<Metric> ProcessMonitor::makeLastMeasurementAndGetMetrics()
197214
}
198215
#endif
199216
if (mEnabledMeasurements.at(static_cast<short>(PmMeasurement::Cpu))) {
200-
getCpuAndContexts();
217+
// forced: no later call will pick up a delta discarded here
218+
auto lastCpuMetrics = getCpuAndContexts(true);
219+
std::move(lastCpuMetrics.begin(), lastCpuMetrics.end(), std::back_inserter(metrics));
201220

202221
auto avgCpuUsage = std::accumulate(mCpuPerctange.begin(), mCpuPerctange.end(), 0.0) /
203222
mCpuPerctange.size();

0 commit comments

Comments
 (0)