Skip to content

Commit 72323b3

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 30281f8 commit 72323b3

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
@@ -112,6 +112,9 @@ class ProcessMonitor
112112
/// Best-effort open of the retired-instructions counter (no-op off Linux)
113113
void openInstructionCounter();
114114

115+
/// 'getrusage(RUSAGE_CHILDREN)' values from last execution
116+
struct rusage mPreviousGetrUsageChildren;
117+
115118
///each measurement will be saved to compute average/accumulation usage
116119
std::vector<double> mVmSizeMeasurements;
117120
std::vector<double> mVmRssMeasurements;
@@ -128,7 +131,9 @@ class ProcessMonitor
128131
std::vector<Metric> getSmaps();
129132

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

133138
std::vector<Metric> makeLastMeasurementAndGetMetrics();
134139
};

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
@@ -60,6 +60,7 @@ ProcessMonitor::ProcessMonitor()
6060
mPid = static_cast<unsigned int>(::getpid());
6161
mTimeLastRun = std::chrono::high_resolution_clock::now();
6262
getrusage(RUSAGE_SELF, &mPreviousGetrUsage);
63+
getrusage(RUSAGE_CHILDREN, &mPreviousGetrUsageChildren);
6364
#ifdef O2_MONITORING_OS_LINUX
6465
setTotalMemory();
6566
#endif
@@ -99,6 +100,7 @@ void ProcessMonitor::init()
99100
{
100101
mTimeLastRun = std::chrono::high_resolution_clock::now();
101102
getrusage(RUSAGE_SELF, &mPreviousGetrUsage);
103+
getrusage(RUSAGE_CHILDREN, &mPreviousGetrUsageChildren);
102104
}
103105

104106
void ProcessMonitor::enable(PmMeasurement measurement)
@@ -167,27 +169,41 @@ std::vector<Metric> ProcessMonitor::getSmaps()
167169
return {{pssTotal, metricsNames[PSS]}, {cleanTotal, metricsNames[PRIVATE_CLEAN]}, {dirtyTotal, metricsNames[PRIVATE_DIRTY]}};
168170
}
169171

170-
std::vector<Metric> ProcessMonitor::getCpuAndContexts()
172+
std::vector<Metric> ProcessMonitor::getCpuAndContexts(bool force)
171173
{
172174
std::vector<Metric> metrics;
173175
struct rusage currentUsage;
176+
struct rusage currentUsageChildren;
174177
getrusage(RUSAGE_SELF, &currentUsage);
178+
// CPU of reaped children (e.g. an external event generator forked by o2-sim)
179+
// is spent outside this process and is invisible to RUSAGE_SELF
180+
getrusage(RUSAGE_CHILDREN, &currentUsageChildren);
175181
auto timeNow = std::chrono::high_resolution_clock::now();
176182
double timePassed = std::chrono::duration_cast<std::chrono::microseconds>(timeNow - mTimeLastRun).count();
177-
if (timePassed < 950) {
183+
if (timePassed < 950 && !force) {
178184
MonLogger::Get(Severity::Warn) << "Do not invoke Process Monitor more frequent then every 1s" << MonLogger::End();
179185
metrics.emplace_back("processPerformance");
180186
return metrics;
181187
}
182188

183-
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);
189+
auto micros = [](const timeval& t) { return t.tv_sec * 1000000.0 + t.tv_usec; };
190+
auto cpuDelta = [&micros](const struct rusage& now, const struct rusage& before) {
191+
return micros(now.ru_utime) - micros(before.ru_utime) + micros(now.ru_stime) - micros(before.ru_stime);
192+
};
193+
uint64_t cpuUsedInMicroSeconds = cpuDelta(currentUsage, mPreviousGetrUsage) +
194+
cpuDelta(currentUsageChildren, mPreviousGetrUsageChildren);
184195
double fractionCpuUsed = cpuUsedInMicroSeconds / timePassed;
185196

186197
double cpuUsedPerctange = std::round(fractionCpuUsed * 100.0 * 100.0) / 100.0;
187-
mCpuPerctange.push_back(cpuUsedPerctange);
188198
mCpuMicroSeconds.push_back(cpuUsedInMicroSeconds);
189199

190-
metrics.emplace_back(Metric{cpuUsedPerctange, metricsNames[CPU_USED_PERCENTAGE]});
200+
// A forced measurement may report CPU accumulated over the whole run but only
201+
// made visible at once (children become visible on reap), for which an
202+
// instantaneous rate is meaningless: report it as absolute time only.
203+
if (!force) {
204+
mCpuPerctange.push_back(cpuUsedPerctange);
205+
metrics.emplace_back(Metric{cpuUsedPerctange, metricsNames[CPU_USED_PERCENTAGE]});
206+
}
191207
metrics.emplace_back(Metric{
192208
static_cast<uint64_t>(currentUsage.ru_nivcsw - mPreviousGetrUsage.ru_nivcsw), metricsNames[INVOLUNTARY_CONTEXT_SWITCHES]});
193209
metrics.emplace_back(Metric{
@@ -212,6 +228,7 @@ std::vector<Metric> ProcessMonitor::getCpuAndContexts()
212228

213229
mTimeLastRun = timeNow;
214230
mPreviousGetrUsage = currentUsage;
231+
mPreviousGetrUsageChildren = currentUsageChildren;
215232
return metrics;
216233
}
217234

@@ -262,7 +279,9 @@ std::vector<Metric> ProcessMonitor::makeLastMeasurementAndGetMetrics()
262279
}
263280
#endif
264281
if (mEnabledMeasurements.at(static_cast<short>(PmMeasurement::Cpu))) {
265-
getCpuAndContexts();
282+
// forced: no later call will pick up a delta discarded here
283+
auto lastCpuMetrics = getCpuAndContexts(true);
284+
std::move(lastCpuMetrics.begin(), lastCpuMetrics.end(), std::back_inserter(metrics));
266285

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

0 commit comments

Comments
 (0)