[runtime_stats] Store stats inline on Component to eliminate std::map lookup (#15345)

This commit is contained in:
J. Nick Koston
2026-04-01 07:09:04 -10:00
committed by GitHub
parent f33fd047ee
commit ea609d3552
6 changed files with 92 additions and 123 deletions
@@ -2,6 +2,7 @@
#ifdef USE_RUNTIME_STATS
#include "esphome/core/application.h"
#include "esphome/core/component.h"
#include <algorithm>
@@ -13,20 +14,16 @@ RuntimeStatsCollector::RuntimeStatsCollector() : log_interval_(60000), next_log_
global_runtime_stats = this;
}
void RuntimeStatsCollector::record_component_time(Component *component, uint32_t duration_us) {
if (component == nullptr)
return;
// Record stats using component pointer as key
this->component_stats_[component].record_time(duration_us);
}
void RuntimeStatsCollector::log_stats_() {
// First pass: count active components
auto &components = App.components_;
// Single pass: collect active components into stack buffer
SmallBufferWithHeapFallback<256, Component *> buffer(components.size());
Component **sorted = buffer.get();
size_t count = 0;
for (const auto &it : this->component_stats_) {
if (it.second.get_period_count() > 0) {
count++;
for (auto *component : components) {
if (component->runtime_stats_.period_count > 0) {
sorted[count++] = component;
}
}
@@ -39,61 +36,58 @@ void RuntimeStatsCollector::log_stats_() {
return;
}
// Stack buffer sized to actual active count (up to 256 components), heap fallback for larger
SmallBufferWithHeapFallback<256, Component *> buffer(count);
Component **sorted = buffer.get();
// Second pass: fill buffer with active components
size_t idx = 0;
for (const auto &it : this->component_stats_) {
if (it.second.get_period_count() > 0) {
sorted[idx++] = it.first;
}
}
// Sort by period runtime (descending)
std::sort(sorted, sorted + count, [this](Component *a, Component *b) {
return this->component_stats_[a].get_period_time_us() > this->component_stats_[b].get_period_time_us();
});
std::sort(sorted, sorted + count, compare_period_time);
// Log top components by period runtime
for (size_t i = 0; i < count; i++) {
const auto &stats = this->component_stats_[sorted[i]];
const auto &stats = sorted[i]->runtime_stats_;
ESP_LOGI(TAG, " %s: count=%" PRIu32 ", avg=%.3fms, max=%.2fms, total=%.1fms",
LOG_STR_ARG(sorted[i]->get_component_log_str()), stats.get_period_count(),
stats.get_period_avg_time_us() / 1000.0f, stats.get_period_max_time_us() / 1000.0f,
stats.get_period_time_us() / 1000.0f);
LOG_STR_ARG(sorted[i]->get_component_log_str()), stats.period_count,
stats.period_count > 0 ? stats.period_time_us / (float) stats.period_count / 1000.0f : 0.0f,
stats.period_max_time_us / 1000.0f, stats.period_time_us / 1000.0f);
}
// Log total stats since boot (only for active components - idle ones haven't changed)
ESP_LOGI(TAG, " Total stats (since boot): %zu active components", count);
// Re-sort by total runtime for all-time stats
std::sort(sorted, sorted + count, [this](Component *a, Component *b) {
return this->component_stats_[a].get_total_time_us() > this->component_stats_[b].get_total_time_us();
});
std::sort(sorted, sorted + count, compare_total_time);
for (size_t i = 0; i < count; i++) {
const auto &stats = this->component_stats_[sorted[i]];
const auto &stats = sorted[i]->runtime_stats_;
ESP_LOGI(TAG, " %s: count=%" PRIu32 ", avg=%.3fms, max=%.2fms, total=%.1fms",
LOG_STR_ARG(sorted[i]->get_component_log_str()), stats.get_total_count(),
stats.get_total_avg_time_us() / 1000.0f, stats.get_total_max_time_us() / 1000.0f,
stats.get_total_time_us() / 1000.0);
LOG_STR_ARG(sorted[i]->get_component_log_str()), stats.total_count,
stats.total_count > 0 ? stats.total_time_us / (float) stats.total_count / 1000.0f : 0.0f,
stats.total_max_time_us / 1000.0f, stats.total_time_us / 1000.0);
}
// Reset period stats
for (auto *component : components) {
component->runtime_stats_.reset_period();
}
}
bool RuntimeStatsCollector::compare_period_time(Component *a, Component *b) {
return a->runtime_stats_.period_time_us > b->runtime_stats_.period_time_us;
}
bool RuntimeStatsCollector::compare_total_time(Component *a, Component *b) {
return a->runtime_stats_.total_time_us > b->runtime_stats_.total_time_us;
}
void RuntimeStatsCollector::process_pending_stats(uint32_t current_time) {
if ((int32_t) (current_time - this->next_log_time_) >= 0) {
this->log_stats_();
this->reset_stats_();
this->next_log_time_ = current_time + this->log_interval_;
}
}
} // namespace runtime_stats
runtime_stats::RuntimeStatsCollector *global_runtime_stats =
nullptr; // NOLINT(cppcoreguidelines-avoid-non-const-global-variables)
runtime_stats::RuntimeStatsCollector
*global_runtime_stats = // NOLINT(cppcoreguidelines-avoid-non-const-global-variables)
nullptr;
} // namespace esphome
@@ -4,11 +4,8 @@
#ifdef USE_RUNTIME_STATS
#include <map>
#include <cstdint>
#include <cstring>
#include "esphome/core/hal.h"
#include "esphome/core/helpers.h"
#include "esphome/core/log.h"
namespace esphome {
@@ -19,64 +16,6 @@ namespace runtime_stats {
static const char *const TAG = "runtime_stats";
class ComponentRuntimeStats {
public:
ComponentRuntimeStats()
: period_count_(0),
period_time_us_(0),
period_max_time_us_(0),
total_count_(0),
total_time_us_(0),
total_max_time_us_(0) {}
void record_time(uint32_t duration_us) {
// Update period counters
this->period_count_++;
this->period_time_us_ += duration_us;
if (duration_us > this->period_max_time_us_)
this->period_max_time_us_ = duration_us;
// Update total counters (uint64_t to avoid overflow — uint32_t would overflow after ~10 hours)
this->total_count_++;
this->total_time_us_ += duration_us;
if (duration_us > this->total_max_time_us_)
this->total_max_time_us_ = duration_us;
}
void reset_period_stats() {
this->period_count_ = 0;
this->period_time_us_ = 0;
this->period_max_time_us_ = 0;
}
// Period stats (reset each logging interval)
uint32_t get_period_count() const { return this->period_count_; }
uint32_t get_period_time_us() const { return this->period_time_us_; }
uint32_t get_period_max_time_us() const { return this->period_max_time_us_; }
float get_period_avg_time_us() const {
return this->period_count_ > 0 ? this->period_time_us_ / static_cast<float>(this->period_count_) : 0.0f;
}
// Total stats (persistent until reboot, uint64_t to avoid overflow)
uint32_t get_total_count() const { return this->total_count_; }
uint64_t get_total_time_us() const { return this->total_time_us_; }
uint32_t get_total_max_time_us() const { return this->total_max_time_us_; }
float get_total_avg_time_us() const {
return this->total_count_ > 0 ? this->total_time_us_ / static_cast<float>(this->total_count_) : 0.0f;
}
protected:
// Period stats (reset each logging interval)
uint32_t period_count_;
uint32_t period_time_us_;
uint32_t period_max_time_us_;
// Total stats (persistent until reboot)
uint32_t total_count_;
uint64_t total_time_us_;
uint32_t total_max_time_us_;
};
class RuntimeStatsCollector {
public:
RuntimeStatsCollector();
@@ -87,23 +26,15 @@ class RuntimeStatsCollector {
}
uint32_t get_log_interval() const { return this->log_interval_; }
void record_component_time(Component *component, uint32_t duration_us);
// Process any pending stats printing (should be called after component loop)
void process_pending_stats(uint32_t current_time);
protected:
void log_stats_();
// Static comparators — member functions have friend access, lambdas do not
static bool compare_period_time(Component *a, Component *b);
static bool compare_total_time(Component *a, Component *b);
void reset_stats_() {
for (auto &it : this->component_stats_) {
it.second.reset_period_stats();
}
}
// Map from component to its stats
// We use Component* as the key since each component is unique
std::map<Component *, ComponentRuntimeStats> component_stats_;
uint32_t log_interval_;
uint32_t next_log_time_{0};
};
+9
View File
@@ -130,6 +130,12 @@ bool socket_ready_fd(int fd, bool loop_monitored); // NOLINT(readability-redund
#endif
} // namespace esphome::socket
#ifdef USE_RUNTIME_STATS
namespace esphome::runtime_stats {
class RuntimeStatsCollector;
} // namespace esphome::runtime_stats
#endif
// Forward declarations for friend access from codegen-generated setup()
void setup(); // NOLINT(readability-redundant-declaration) - may be declared in Arduino.h
void original_setup(); // NOLINT(readability-redundant-declaration) - used by cpp unit tests
@@ -590,6 +596,9 @@ class Application {
friend Component;
#if defined(USE_SOCKET_SELECT_SUPPORT) && !defined(USE_LWIP_FAST_SELECT)
friend bool socket::socket_ready_fd(int fd, bool loop_monitored);
#endif
#ifdef USE_RUNTIME_STATS
friend class runtime_stats::RuntimeStatsCollector;
#endif
friend void ::setup();
friend void ::original_setup();
+2 -10
View File
@@ -9,9 +9,6 @@
#include "esphome/core/hal.h"
#include "esphome/core/helpers.h"
#include "esphome/core/log.h"
#ifdef USE_RUNTIME_STATS
#include "esphome/components/runtime_stats/runtime_stats.h"
#endif
namespace esphome {
@@ -524,13 +521,8 @@ WarnIfComponentBlockingGuard::warn_blocking(Component *component, uint32_t block
#ifdef USE_RUNTIME_STATS
void WarnIfComponentBlockingGuard::record_runtime_stats_() {
// Use micros() for accurate sub-millisecond timing. millis() has insufficient
// resolution — most components complete in microseconds but millis() only has
// 1ms granularity, so results were essentially random noise.
if (global_runtime_stats != nullptr) {
uint32_t duration_us = micros() - this->started_us_;
global_runtime_stats->record_component_time(this->component_, duration_us);
}
uint32_t duration_us = micros() - this->started_us_;
this->component_->runtime_stats_.record_time(duration_us);
}
#endif
+42
View File
@@ -20,6 +20,12 @@ namespace esphome {
// Forward declaration for LogString
struct LogString;
#ifdef USE_RUNTIME_STATS
namespace runtime_stats {
class RuntimeStatsCollector;
} // namespace runtime_stats
#endif
/** Default setup priorities for components of different types.
*
* Components should return one of these setup priorities in get_setup_priority.
@@ -92,6 +98,37 @@ inline constexpr uint8_t WARN_IF_BLOCKING_OVER_CS = 5U; // 50ms in centiseconds
/// Weak default returns "<unknown>" so builds without codegen still link.
const LogString *component_source_lookup(uint8_t index);
#ifdef USE_RUNTIME_STATS
/// Inline runtime statistics — eliminates std::map lookup on every loop iteration.
/// Only present when USE_RUNTIME_STATS is defined (profiling builds).
struct ComponentRuntimeStats {
// Period stats (reset each logging interval)
uint32_t period_count{0};
uint32_t period_time_us{0};
uint32_t period_max_time_us{0};
// Total stats (persistent until reboot, uint64_t to avoid overflow)
uint32_t total_count{0};
uint64_t total_time_us{0};
uint32_t total_max_time_us{0};
void record_time(uint32_t duration_us) {
this->period_count++;
this->period_time_us += duration_us;
if (duration_us > this->period_max_time_us)
this->period_max_time_us = duration_us;
this->total_count++;
this->total_time_us += duration_us;
if (duration_us > this->total_max_time_us)
this->total_max_time_us = duration_us;
}
void reset_period() {
this->period_count = 0;
this->period_time_us = 0;
this->period_max_time_us = 0;
}
};
#endif
class Component {
public:
/** Where the component's initialization should happen.
@@ -529,6 +566,11 @@ class Component {
/// Bits 6-7: Unused - reserved for future expansion
uint8_t component_state_{0x00};
volatile bool pending_enable_loop_{false}; ///< ISR-safe flag for enable_loop_soon_any_context
#ifdef USE_RUNTIME_STATS
friend class runtime_stats::RuntimeStatsCollector;
friend class WarnIfComponentBlockingGuard;
ComponentRuntimeStats runtime_stats_;
#endif
};
/** This class simplifies creating components that periodically check a state.
+1
View File
@@ -180,6 +180,7 @@
#define USE_RUNTIME_IMAGE_BMP
#define USE_RUNTIME_IMAGE_PNG
#define USE_RUNTIME_IMAGE_JPEG
#define USE_RUNTIME_STATS
#define USE_OTA
#define USE_OTA_PASSWORD
#define USE_OTA_STATE_LISTENER