diff --git a/include/Monitoring/Monitoring.h b/include/Monitoring/Monitoring.h index d3c78274..9ff410b1 100644 --- a/include/Monitoring/Monitoring.h +++ b/include/Monitoring/Monitoring.h @@ -73,6 +73,10 @@ class Monitoring /// \param enabledMeasurements vector of monitor measurements, eg. PmMeasurement::Cpu void enableProcessMonitoring(const unsigned int interval = 5, std::vector enabledMeasurements = {PmMeasurement::Cpu, PmMeasurement::Mem, PmMeasurement::Smaps}); + /// Stops process monitoring and transmits the final measurement. Idempotent; + /// call explicitly where destructor timing is not guaranteed to be reached. + void finalizeProcessMonitoring(); + /// Flushes metric buffer (this can also happen when buffer is full) void flushBuffer(); diff --git a/include/Monitoring/ProcessMonitor.h b/include/Monitoring/ProcessMonitor.h index fbc291b2..762efa00 100644 --- a/include/Monitoring/ProcessMonitor.h +++ b/include/Monitoring/ProcessMonitor.h @@ -112,6 +112,9 @@ class ProcessMonitor /// Best-effort open of the retired-instructions counter (no-op off Linux) void openInstructionCounter(); + /// 'getrusage(RUSAGE_CHILDREN)' values from last execution + struct rusage mPreviousGetrUsageChildren; + ///each measurement will be saved to compute average/accumulation usage std::vector mVmSizeMeasurements; std::vector mVmRssMeasurements; @@ -128,7 +131,9 @@ class ProcessMonitor std::vector getSmaps(); /// Retrieves CPU usage (%) and number of context switches during the interval - std::vector getCpuAndContexts(); + /// \param force ignore the 1s minimum interval; for the final measurement, + /// where a skipped delta would be lost rather than deferred + std::vector getCpuAndContexts(bool force = false); std::vector makeLastMeasurementAndGetMetrics(); }; diff --git a/src/Monitoring.cxx b/src/Monitoring.cxx index 10414e81..27b7842f 100644 --- a/src/Monitoring.cxx +++ b/src/Monitoring.cxx @@ -130,13 +130,21 @@ void Monitoring::addBackend(std::unique_ptr 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(); } diff --git a/src/ProcessMonitor.cxx b/src/ProcessMonitor.cxx index 8f01ad60..72117f23 100644 --- a/src/ProcessMonitor.cxx +++ b/src/ProcessMonitor.cxx @@ -60,6 +60,7 @@ ProcessMonitor::ProcessMonitor() mPid = static_cast(::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 describe one monitoring period: monitoring that is 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,27 +175,41 @@ std::vector ProcessMonitor::getSmaps() return {{pssTotal, metricsNames[PSS]}, {cleanTotal, metricsNames[PRIVATE_CLEAN]}, {dirtyTotal, metricsNames[PRIVATE_DIRTY]}}; } -std::vector ProcessMonitor::getCpuAndContexts() +std::vector ProcessMonitor::getCpuAndContexts(bool force) { std::vector metrics; struct rusage currentUsage; + struct rusage currentUsageChildren; getrusage(RUSAGE_SELF, ¤tUsage); + // CPU of reaped children (e.g. an external event generator forked by o2-sim) + // is spent outside this process and is invisible to RUSAGE_SELF + getrusage(RUSAGE_CHILDREN, ¤tUsageChildren); auto timeNow = std::chrono::high_resolution_clock::now(); double timePassed = std::chrono::duration_cast(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); + auto micros = [](const timeval& t) { return t.tv_sec * 1000000.0 + t.tv_usec; }; + auto cpuDelta = [µs](const struct rusage& now, const struct rusage& before) { + return micros(now.ru_utime) - micros(before.ru_utime) + micros(now.ru_stime) - micros(before.ru_stime); + }; + uint64_t cpuUsedInMicroSeconds = cpuDelta(currentUsage, mPreviousGetrUsage) + + cpuDelta(currentUsageChildren, mPreviousGetrUsageChildren); double fractionCpuUsed = cpuUsedInMicroSeconds / timePassed; double cpuUsedPerctange = std::round(fractionCpuUsed * 100.0 * 100.0) / 100.0; - mCpuPerctange.push_back(cpuUsedPerctange); mCpuMicroSeconds.push_back(cpuUsedInMicroSeconds); - metrics.emplace_back(Metric{cpuUsedPerctange, metricsNames[CPU_USED_PERCENTAGE]}); + // A forced measurement may report CPU accumulated over the whole run but only + // made visible at once (children become visible on reap), for which an + // instantaneous rate is meaningless: report it as absolute time only. + if (!force) { + mCpuPerctange.push_back(cpuUsedPerctange); + metrics.emplace_back(Metric{cpuUsedPerctange, metricsNames[CPU_USED_PERCENTAGE]}); + } metrics.emplace_back(Metric{ static_cast(currentUsage.ru_nivcsw - mPreviousGetrUsage.ru_nivcsw), metricsNames[INVOLUNTARY_CONTEXT_SWITCHES]}); metrics.emplace_back(Metric{ @@ -212,6 +234,7 @@ std::vector ProcessMonitor::getCpuAndContexts() mTimeLastRun = timeNow; mPreviousGetrUsage = currentUsage; + mPreviousGetrUsageChildren = currentUsageChildren; return metrics; } @@ -262,14 +285,21 @@ std::vector ProcessMonitor::makeLastMeasurementAndGetMetrics() } #endif if (mEnabledMeasurements.at(static_cast(PmMeasurement::Cpu))) { - getCpuAndContexts(); + // forced: no later call will pick up a delta discarded here + auto lastCpuMetrics = getCpuAndContexts(true); + std::move(lastCpuMetrics.begin(), lastCpuMetrics.end(), std::back_inserter(metrics)); - auto avgCpuUsage = std::accumulate(mCpuPerctange.begin(), mCpuPerctange.end(), 0.0) / - mCpuPerctange.size(); uint64_t accumulationOfCpuTimeConsumption = std::accumulate(mCpuMicroSeconds.begin(), mCpuMicroSeconds.end(), 0UL); - metrics.emplace_back(avgCpuUsage, metricsNames[AVG_CPU_USED_PERCENTAGE]); + // Only forced measurements contribute no percentage, so a process that + // ends before the first periodic sample has none at all - report no + // average rather than a NaN one. + if (!mCpuPerctange.empty()) { + auto avgCpuUsage = std::accumulate(mCpuPerctange.begin(), mCpuPerctange.end(), 0.0) / + mCpuPerctange.size(); + metrics.emplace_back(avgCpuUsage, metricsNames[AVG_CPU_USED_PERCENTAGE]); + } metrics.emplace_back(accumulationOfCpuTimeConsumption, metricsNames[ACCUMULATED_CPU_TIME]); } return metrics;