diff --git a/include/Monitoring/Monitoring.h b/include/Monitoring/Monitoring.h index d3c78274..9b0d3352 100644 --- a/include/Monitoring/Monitoring.h +++ b/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 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(); diff --git a/include/Monitoring/ProcessMonitor.h b/include/Monitoring/ProcessMonitor.h index fbc291b2..6955b564 100644 --- a/include/Monitoring/ProcessMonitor.h +++ b/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 getSmaps(); /// Retrieves CPU usage (%) and number of context switches during the interval - std::vector 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 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..9de2f0b5 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 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 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; + // 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, ¤tUsage); + 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); - 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(currentUsage.ru_nivcsw - mPreviousGetrUsage.ru_nivcsw), metricsNames[INVOLUNTARY_CONTEXT_SWITCHES]}); - metrics.emplace_back(Metric{ - static_cast(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 ProcessMonitor::getCpuAndContexts() mTimeLastRun = timeNow; mPreviousGetrUsage = currentUsage; + mPreviousGetrUsageChildren = currentUsageChildren; return metrics; } @@ -262,14 +285,20 @@ std::vector ProcessMonitor::makeLastMeasurementAndGetMetrics() } #endif if (mEnabledMeasurements.at(static_cast(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;