From d06bab01ac8294d7cd431b15a101db12cf79cee6 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 09:09:07 -0600 Subject: [PATCH 01/16] runtime_stats --- esphome/components/runtime_stats/__init__.py | 26 ++++ esphome/core/application.cpp | 4 + esphome/core/application.h | 13 ++ esphome/core/component.cpp | 3 + esphome/core/component.h | 1 + esphome/core/runtime_stats.cpp | 92 ++++++++++++++ esphome/core/runtime_stats.h | 121 +++++++++++++++++++ 7 files changed, 260 insertions(+) create mode 100644 esphome/components/runtime_stats/__init__.py create mode 100644 esphome/core/runtime_stats.cpp create mode 100644 esphome/core/runtime_stats.h diff --git a/esphome/components/runtime_stats/__init__.py b/esphome/components/runtime_stats/__init__.py new file mode 100644 index 0000000000..966503202a --- /dev/null +++ b/esphome/components/runtime_stats/__init__.py @@ -0,0 +1,26 @@ +""" +Runtime statistics component for ESPHome. +""" + +import esphome.codegen as cg +import esphome.config_validation as cv + +DEPENDENCIES = [] + +CONF_ENABLED = "enabled" +CONF_LOG_INTERVAL = "log_interval" + +CONFIG_SCHEMA = cv.Schema( + { + cv.Optional(CONF_ENABLED, default=True): cv.boolean, + cv.Optional( + CONF_LOG_INTERVAL, default=60000 + ): cv.positive_time_period_milliseconds, + } +) + + +async def to_code(config): + """Generate code for the runtime statistics component.""" + cg.add(cg.App.set_runtime_stats_enabled(config[CONF_ENABLED])) + cg.add(cg.App.set_runtime_stats_log_interval(config[CONF_LOG_INTERVAL])) diff --git a/esphome/core/application.cpp b/esphome/core/application.cpp index d6fab018cc..4dd892dd66 100644 --- a/esphome/core/application.cpp +++ b/esphome/core/application.cpp @@ -141,6 +141,10 @@ void Application::loop() { this->in_loop_ = false; this->app_state_ = new_app_state; + // Process any pending runtime stats printing after all components have run + // This ensures stats printing doesn't affect component timing measurements + runtime_stats.process_pending_stats(last_op_end_time); + // Use the last component's end time instead of calling millis() again auto elapsed = last_op_end_time - this->last_loop_; if (elapsed >= this->loop_interval_ || HighFrequencyLoopRequester::is_high_frequency()) { diff --git a/esphome/core/application.h b/esphome/core/application.h index f2b5cb5c89..ee3ddebf8d 100644 --- a/esphome/core/application.h +++ b/esphome/core/application.h @@ -9,6 +9,7 @@ #include "esphome/core/hal.h" #include "esphome/core/helpers.h" #include "esphome/core/preferences.h" +#include "esphome/core/runtime_stats.h" #include "esphome/core/scheduler.h" #ifdef USE_DEVICES @@ -348,6 +349,18 @@ class Application { uint32_t get_loop_interval() const { return static_cast(this->loop_interval_); } + /** Enable or disable runtime statistics collection. + * + * @param enable Whether to enable runtime statistics collection. + */ + void set_runtime_stats_enabled(bool enable) { runtime_stats.set_enabled(enable); } + + /** Set the interval at which runtime statistics are logged. + * + * @param interval The interval in milliseconds between logging of runtime statistics. + */ + void set_runtime_stats_log_interval(uint32_t interval) { runtime_stats.set_log_interval(interval); } + void schedule_dump_config() { this->dump_config_at_ = 0; } void feed_wdt(uint32_t time = 0); diff --git a/esphome/core/component.cpp b/esphome/core/component.cpp index 9d863e56cd..9ff85532bb 100644 --- a/esphome/core/component.cpp +++ b/esphome/core/component.cpp @@ -395,6 +395,9 @@ uint32_t WarnIfComponentBlockingGuard::finish() { uint32_t curr_time = millis(); uint32_t blocking_time = curr_time - this->started_; + + // Record component runtime stats + runtime_stats.record_component_time(this->component_, blocking_time, curr_time); bool should_warn; if (this->component_ != nullptr) { should_warn = this->component_->should_warn_of_blocking(blocking_time); diff --git a/esphome/core/component.h b/esphome/core/component.h index 3734473a02..8b51c14507 100644 --- a/esphome/core/component.h +++ b/esphome/core/component.h @@ -6,6 +6,7 @@ #include #include "esphome/core/optional.h" +#include "esphome/core/runtime_stats.h" namespace esphome { diff --git a/esphome/core/runtime_stats.cpp b/esphome/core/runtime_stats.cpp new file mode 100644 index 0000000000..da19349537 --- /dev/null +++ b/esphome/core/runtime_stats.cpp @@ -0,0 +1,92 @@ +#include "esphome/core/runtime_stats.h" +#include "esphome/core/component.h" +#include + +namespace esphome { + +RuntimeStatsCollector runtime_stats; + +void RuntimeStatsCollector::record_component_time(Component *component, uint32_t duration_ms, uint32_t current_time) { + if (!this->enabled_ || component == nullptr) + return; + + // Check if we have cached the name for this component + auto name_it = this->component_names_cache_.find(component); + if (name_it == this->component_names_cache_.end()) { + // First time seeing this component, cache its name + const char *source = component->get_component_source(); + this->component_names_cache_[component] = source; + this->component_stats_[source].record_time(duration_ms); + } else { + // Use cached name - no string operations, just map lookup + this->component_stats_[name_it->second].record_time(duration_ms); + } + + // If next_log_time_ is 0, initialize it + if (this->next_log_time_ == 0) { + this->next_log_time_ = current_time + this->log_interval_; + return; + } + + // Don't print stats here anymore - let process_pending_stats handle it +} + +void RuntimeStatsCollector::log_stats_() { + ESP_LOGI(RUNTIME_TAG, "Component Runtime Statistics"); + ESP_LOGI(RUNTIME_TAG, "Period stats (last %" PRIu32 "ms):", this->log_interval_); + + // First collect stats we want to display + std::vector stats_to_display; + + for (const auto &it : this->component_stats_) { + const ComponentRuntimeStats &stats = it.second; + if (stats.get_period_count() > 0) { + ComponentStatPair pair = {it.first, &stats}; + stats_to_display.push_back(pair); + } + } + + // Sort by period runtime (descending) + std::sort(stats_to_display.begin(), stats_to_display.end(), std::greater()); + + // Log top components by period runtime + for (const auto &it : stats_to_display) { + const std::string &source = it.name; + const ComponentRuntimeStats *stats = it.stats; + + ESP_LOGI(RUNTIME_TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms", source.c_str(), + stats->get_period_count(), stats->get_period_avg_time_ms(), stats->get_period_max_time_ms(), + stats->get_period_time_ms()); + } + + // Log total stats since boot + ESP_LOGI(RUNTIME_TAG, "Total stats (since boot):"); + + // Re-sort by total runtime for all-time stats + std::sort(stats_to_display.begin(), stats_to_display.end(), + [](const ComponentStatPair &a, const ComponentStatPair &b) { + return a.stats->get_total_time_ms() > b.stats->get_total_time_ms(); + }); + + for (const auto &it : stats_to_display) { + const std::string &source = it.name; + const ComponentRuntimeStats *stats = it.stats; + + ESP_LOGI(RUNTIME_TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms", source.c_str(), + stats->get_total_count(), stats->get_total_avg_time_ms(), stats->get_total_max_time_ms(), + stats->get_total_time_ms()); + } +} + +void RuntimeStatsCollector::process_pending_stats(uint32_t current_time) { + if (!this->enabled_ || this->next_log_time_ == 0) + return; + + if (current_time >= this->next_log_time_) { + this->log_stats_(); + this->reset_stats_(); + this->next_log_time_ = current_time + this->log_interval_; + } +} + +} // namespace esphome diff --git a/esphome/core/runtime_stats.h b/esphome/core/runtime_stats.h new file mode 100644 index 0000000000..6ae80750a6 --- /dev/null +++ b/esphome/core/runtime_stats.h @@ -0,0 +1,121 @@ +#pragma once + +#include +#include +#include +#include +#include +#include "esphome/core/helpers.h" +#include "esphome/core/log.h" + +namespace esphome { + +static const char *const RUNTIME_TAG = "runtime"; + +class Component; // Forward declaration + +class ComponentRuntimeStats { + public: + ComponentRuntimeStats() + : period_count_(0), + total_count_(0), + period_time_ms_(0), + total_time_ms_(0), + period_max_time_ms_(0), + total_max_time_ms_(0) {} + + void record_time(uint32_t duration_ms) { + // Update period counters + this->period_count_++; + this->period_time_ms_ += duration_ms; + if (duration_ms > this->period_max_time_ms_) + this->period_max_time_ms_ = duration_ms; + + // Update total counters + this->total_count_++; + this->total_time_ms_ += duration_ms; + if (duration_ms > this->total_max_time_ms_) + this->total_max_time_ms_ = duration_ms; + } + + void reset_period_stats() { + this->period_count_ = 0; + this->period_time_ms_ = 0; + this->period_max_time_ms_ = 0; + } + + // Period stats (reset each logging interval) + uint32_t get_period_count() const { return this->period_count_; } + uint32_t get_period_time_ms() const { return this->period_time_ms_; } + uint32_t get_period_max_time_ms() const { return this->period_max_time_ms_; } + float get_period_avg_time_ms() const { + return this->period_count_ > 0 ? this->period_time_ms_ / static_cast(this->period_count_) : 0.0f; + } + + // Total stats (persistent until reboot) + uint32_t get_total_count() const { return this->total_count_; } + uint32_t get_total_time_ms() const { return this->total_time_ms_; } + uint32_t get_total_max_time_ms() const { return this->total_max_time_ms_; } + float get_total_avg_time_ms() const { + return this->total_count_ > 0 ? this->total_time_ms_ / static_cast(this->total_count_) : 0.0f; + } + + protected: + // Period stats (reset each logging interval) + uint32_t period_count_; + uint32_t period_time_ms_; + uint32_t period_max_time_ms_; + + // Total stats (persistent until reboot) + uint32_t total_count_; + uint32_t total_time_ms_; + uint32_t total_max_time_ms_; +}; + +// For sorting components by run time +struct ComponentStatPair { + std::string name; + const ComponentRuntimeStats *stats; + + bool operator>(const ComponentStatPair &other) const { + // Sort by period time as that's what we're displaying in the logs + return stats->get_period_time_ms() > other.stats->get_period_time_ms(); + } +}; + +class RuntimeStatsCollector { + public: + RuntimeStatsCollector() : log_interval_(60000), next_log_time_(0), enabled_(true) {} + + void set_log_interval(uint32_t log_interval) { this->log_interval_ = log_interval; } + uint32_t get_log_interval() const { return this->log_interval_; } + + void set_enabled(bool enabled) { this->enabled_ = enabled; } + bool is_enabled() const { return this->enabled_; } + + void record_component_time(Component *component, uint32_t duration_ms, uint32_t current_time); + + // Process any pending stats printing (should be called after component loop) + void process_pending_stats(uint32_t current_time); + + protected: + void log_stats_(); + + void reset_stats_() { + for (auto &it : this->component_stats_) { + it.second.reset_period_stats(); + } + } + + // Back to string keys, but we'll cache the source name per component + std::map component_stats_; + std::map component_names_cache_; + uint32_t log_interval_; + uint32_t next_log_time_; + bool enabled_; +}; + +// Global instance for runtime stats collection +extern RuntimeStatsCollector runtime_stats; + +} // namespace esphome \ No newline at end of file From a3c8f667a709ebd268f302508bda77cf3bc1eb12 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 09:16:42 -0600 Subject: [PATCH 02/16] cleanup --- esphome/components/runtime_stats/__init__.py | 15 ++++++++++++--- .../runtime_stats}/runtime_stats.cpp | 11 ++++++++--- .../runtime_stats}/runtime_stats.h | 12 ++++++------ esphome/core/application.cpp | 2 ++ esphome/core/application.h | 12 +++++------- esphome/core/component.cpp | 2 ++ esphome/core/component.h | 4 +++- 7 files changed, 38 insertions(+), 20 deletions(-) rename esphome/{core => components/runtime_stats}/runtime_stats.cpp (95%) rename esphome/{core => components/runtime_stats}/runtime_stats.h (95%) diff --git a/esphome/components/runtime_stats/__init__.py b/esphome/components/runtime_stats/__init__.py index 966503202a..1843bdd94f 100644 --- a/esphome/components/runtime_stats/__init__.py +++ b/esphome/components/runtime_stats/__init__.py @@ -7,12 +7,10 @@ import esphome.config_validation as cv DEPENDENCIES = [] -CONF_ENABLED = "enabled" CONF_LOG_INTERVAL = "log_interval" CONFIG_SCHEMA = cv.Schema( { - cv.Optional(CONF_ENABLED, default=True): cv.boolean, cv.Optional( CONF_LOG_INTERVAL, default=60000 ): cv.positive_time_period_milliseconds, @@ -20,7 +18,18 @@ CONFIG_SCHEMA = cv.Schema( ) +def FILTER_SOURCE_FILES() -> list[str]: + """Filter out runtime_stats.cpp when not enabled.""" + # When runtime_stats component is not included in the configuration, + # we don't want to compile runtime_stats.cpp + # This function is called when the component IS included, so we return + # an empty list to include all source files + return [] + + async def to_code(config): """Generate code for the runtime statistics component.""" - cg.add(cg.App.set_runtime_stats_enabled(config[CONF_ENABLED])) + # Define USE_RUNTIME_STATS when this component is used + cg.add_define("USE_RUNTIME_STATS") + cg.add(cg.App.set_runtime_stats_log_interval(config[CONF_LOG_INTERVAL])) diff --git a/esphome/core/runtime_stats.cpp b/esphome/components/runtime_stats/runtime_stats.cpp similarity index 95% rename from esphome/core/runtime_stats.cpp rename to esphome/components/runtime_stats/runtime_stats.cpp index da19349537..c2b43ed4ce 100644 --- a/esphome/core/runtime_stats.cpp +++ b/esphome/components/runtime_stats/runtime_stats.cpp @@ -1,4 +1,7 @@ -#include "esphome/core/runtime_stats.h" +#include "runtime_stats.h" + +#ifdef USE_RUNTIME_STATS + #include "esphome/core/component.h" #include @@ -7,7 +10,7 @@ namespace esphome { RuntimeStatsCollector runtime_stats; void RuntimeStatsCollector::record_component_time(Component *component, uint32_t duration_ms, uint32_t current_time) { - if (!this->enabled_ || component == nullptr) + if (component == nullptr) return; // Check if we have cached the name for this component @@ -79,7 +82,7 @@ void RuntimeStatsCollector::log_stats_() { } void RuntimeStatsCollector::process_pending_stats(uint32_t current_time) { - if (!this->enabled_ || this->next_log_time_ == 0) + if (this->next_log_time_ == 0) return; if (current_time >= this->next_log_time_) { @@ -90,3 +93,5 @@ void RuntimeStatsCollector::process_pending_stats(uint32_t current_time) { } } // namespace esphome + +#endif // USE_RUNTIME_STATS diff --git a/esphome/core/runtime_stats.h b/esphome/components/runtime_stats/runtime_stats.h similarity index 95% rename from esphome/core/runtime_stats.h rename to esphome/components/runtime_stats/runtime_stats.h index 6ae80750a6..ba4f352568 100644 --- a/esphome/core/runtime_stats.h +++ b/esphome/components/runtime_stats/runtime_stats.h @@ -1,5 +1,7 @@ #pragma once +#ifdef USE_RUNTIME_STATS + #include #include #include @@ -85,14 +87,11 @@ struct ComponentStatPair { class RuntimeStatsCollector { public: - RuntimeStatsCollector() : log_interval_(60000), next_log_time_(0), enabled_(true) {} + RuntimeStatsCollector() : log_interval_(60000), next_log_time_(0) {} void set_log_interval(uint32_t log_interval) { this->log_interval_ = log_interval; } uint32_t get_log_interval() const { return this->log_interval_; } - void set_enabled(bool enabled) { this->enabled_ = enabled; } - bool is_enabled() const { return this->enabled_; } - void record_component_time(Component *component, uint32_t duration_ms, uint32_t current_time); // Process any pending stats printing (should be called after component loop) @@ -112,10 +111,11 @@ class RuntimeStatsCollector { std::map component_names_cache_; uint32_t log_interval_; uint32_t next_log_time_; - bool enabled_; }; // Global instance for runtime stats collection extern RuntimeStatsCollector runtime_stats; -} // namespace esphome \ No newline at end of file +} // namespace esphome + +#endif // USE_RUNTIME_STATS \ No newline at end of file diff --git a/esphome/core/application.cpp b/esphome/core/application.cpp index 4dd892dd66..224989c73c 100644 --- a/esphome/core/application.cpp +++ b/esphome/core/application.cpp @@ -141,9 +141,11 @@ void Application::loop() { this->in_loop_ = false; this->app_state_ = new_app_state; +#ifdef USE_RUNTIME_STATS // Process any pending runtime stats printing after all components have run // This ensures stats printing doesn't affect component timing measurements runtime_stats.process_pending_stats(last_op_end_time); +#endif // Use the last component's end time instead of calling millis() again auto elapsed = last_op_end_time - this->last_loop_; diff --git a/esphome/core/application.h b/esphome/core/application.h index ee3ddebf8d..588ab1a92a 100644 --- a/esphome/core/application.h +++ b/esphome/core/application.h @@ -9,7 +9,9 @@ #include "esphome/core/hal.h" #include "esphome/core/helpers.h" #include "esphome/core/preferences.h" -#include "esphome/core/runtime_stats.h" +#ifdef USE_RUNTIME_STATS +#include "esphome/components/runtime_stats/runtime_stats.h" +#endif #include "esphome/core/scheduler.h" #ifdef USE_DEVICES @@ -349,17 +351,13 @@ class Application { uint32_t get_loop_interval() const { return static_cast(this->loop_interval_); } - /** Enable or disable runtime statistics collection. - * - * @param enable Whether to enable runtime statistics collection. - */ - void set_runtime_stats_enabled(bool enable) { runtime_stats.set_enabled(enable); } - +#ifdef USE_RUNTIME_STATS /** Set the interval at which runtime statistics are logged. * * @param interval The interval in milliseconds between logging of runtime statistics. */ void set_runtime_stats_log_interval(uint32_t interval) { runtime_stats.set_log_interval(interval); } +#endif void schedule_dump_config() { this->dump_config_at_ = 0; } diff --git a/esphome/core/component.cpp b/esphome/core/component.cpp index 9ff85532bb..e446dd378e 100644 --- a/esphome/core/component.cpp +++ b/esphome/core/component.cpp @@ -396,8 +396,10 @@ uint32_t WarnIfComponentBlockingGuard::finish() { uint32_t blocking_time = curr_time - this->started_; +#ifdef USE_RUNTIME_STATS // Record component runtime stats runtime_stats.record_component_time(this->component_, blocking_time, curr_time); +#endif bool should_warn; if (this->component_ != nullptr) { should_warn = this->component_->should_warn_of_blocking(blocking_time); diff --git a/esphome/core/component.h b/esphome/core/component.h index 8b51c14507..c7342cd563 100644 --- a/esphome/core/component.h +++ b/esphome/core/component.h @@ -6,7 +6,9 @@ #include #include "esphome/core/optional.h" -#include "esphome/core/runtime_stats.h" +#ifdef USE_RUNTIME_STATS +#include "esphome/components/runtime_stats/runtime_stats.h" +#endif namespace esphome { From f2ac6b0af61714feb084e9353a07d63d9ea5c165 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 09:25:00 -0600 Subject: [PATCH 03/16] cleanup --- esphome/components/runtime_stats/__init__.py | 10 ++++++++- .../runtime_stats/runtime_stats.cpp | 21 +++++++++++++------ .../components/runtime_stats/runtime_stats.h | 14 ++++++++----- esphome/core/application.cpp | 4 +++- esphome/core/application.h | 8 ------- esphome/core/component.cpp | 4 +++- 6 files changed, 39 insertions(+), 22 deletions(-) diff --git a/esphome/components/runtime_stats/__init__.py b/esphome/components/runtime_stats/__init__.py index 1843bdd94f..64382194ec 100644 --- a/esphome/components/runtime_stats/__init__.py +++ b/esphome/components/runtime_stats/__init__.py @@ -4,13 +4,18 @@ Runtime statistics component for ESPHome. import esphome.codegen as cg import esphome.config_validation as cv +from esphome.const import CONF_ID DEPENDENCIES = [] CONF_LOG_INTERVAL = "log_interval" +runtime_stats_ns = cg.esphome_ns.namespace("runtime_stats") +RuntimeStatsCollector = runtime_stats_ns.class_("RuntimeStatsCollector") + CONFIG_SCHEMA = cv.Schema( { + cv.GenerateID(): cv.declare_id(RuntimeStatsCollector), cv.Optional( CONF_LOG_INTERVAL, default=60000 ): cv.positive_time_period_milliseconds, @@ -32,4 +37,7 @@ async def to_code(config): # Define USE_RUNTIME_STATS when this component is used cg.add_define("USE_RUNTIME_STATS") - cg.add(cg.App.set_runtime_stats_log_interval(config[CONF_LOG_INTERVAL])) + # Create the runtime stats instance (constructor sets global_runtime_stats) + var = cg.new_Pvariable(config[CONF_ID]) + + cg.add(var.set_log_interval(config[CONF_LOG_INTERVAL])) diff --git a/esphome/components/runtime_stats/runtime_stats.cpp b/esphome/components/runtime_stats/runtime_stats.cpp index c2b43ed4ce..72411ffd6f 100644 --- a/esphome/components/runtime_stats/runtime_stats.cpp +++ b/esphome/components/runtime_stats/runtime_stats.cpp @@ -7,7 +7,11 @@ namespace esphome { -RuntimeStatsCollector runtime_stats; +namespace runtime_stats { + +RuntimeStatsCollector::RuntimeStatsCollector() : log_interval_(60000), next_log_time_(0) { + global_runtime_stats = this; +} void RuntimeStatsCollector::record_component_time(Component *component, uint32_t duration_ms, uint32_t current_time) { if (component == nullptr) @@ -35,8 +39,8 @@ void RuntimeStatsCollector::record_component_time(Component *component, uint32_t } void RuntimeStatsCollector::log_stats_() { - ESP_LOGI(RUNTIME_TAG, "Component Runtime Statistics"); - ESP_LOGI(RUNTIME_TAG, "Period stats (last %" PRIu32 "ms):", this->log_interval_); + ESP_LOGI(TAG, "Component Runtime Statistics"); + ESP_LOGI(TAG, "Period stats (last %" PRIu32 "ms):", this->log_interval_); // First collect stats we want to display std::vector stats_to_display; @@ -57,13 +61,13 @@ void RuntimeStatsCollector::log_stats_() { const std::string &source = it.name; const ComponentRuntimeStats *stats = it.stats; - ESP_LOGI(RUNTIME_TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms", source.c_str(), + ESP_LOGI(TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms", source.c_str(), stats->get_period_count(), stats->get_period_avg_time_ms(), stats->get_period_max_time_ms(), stats->get_period_time_ms()); } // Log total stats since boot - ESP_LOGI(RUNTIME_TAG, "Total stats (since boot):"); + ESP_LOGI(TAG, "Total stats (since boot):"); // Re-sort by total runtime for all-time stats std::sort(stats_to_display.begin(), stats_to_display.end(), @@ -75,7 +79,7 @@ void RuntimeStatsCollector::log_stats_() { const std::string &source = it.name; const ComponentRuntimeStats *stats = it.stats; - ESP_LOGI(RUNTIME_TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms", source.c_str(), + ESP_LOGI(TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms", source.c_str(), stats->get_total_count(), stats->get_total_avg_time_ms(), stats->get_total_max_time_ms(), stats->get_total_time_ms()); } @@ -92,6 +96,11 @@ void RuntimeStatsCollector::process_pending_stats(uint32_t current_time) { } } +} // namespace runtime_stats + +runtime_stats::RuntimeStatsCollector *global_runtime_stats = + nullptr; // NOLINT(cppcoreguidelines-avoid-non-const-global-variables) + } // namespace esphome #endif // USE_RUNTIME_STATS diff --git a/esphome/components/runtime_stats/runtime_stats.h b/esphome/components/runtime_stats/runtime_stats.h index ba4f352568..24dae46b2e 100644 --- a/esphome/components/runtime_stats/runtime_stats.h +++ b/esphome/components/runtime_stats/runtime_stats.h @@ -12,10 +12,12 @@ namespace esphome { -static const char *const RUNTIME_TAG = "runtime"; - class Component; // Forward declaration +namespace runtime_stats { + +static const char *const TAG = "runtime_stats"; + class ComponentRuntimeStats { public: ComponentRuntimeStats() @@ -87,7 +89,7 @@ struct ComponentStatPair { class RuntimeStatsCollector { public: - RuntimeStatsCollector() : log_interval_(60000), next_log_time_(0) {} + RuntimeStatsCollector(); void set_log_interval(uint32_t log_interval) { this->log_interval_ = log_interval; } uint32_t get_log_interval() const { return this->log_interval_; } @@ -113,8 +115,10 @@ class RuntimeStatsCollector { uint32_t next_log_time_; }; -// Global instance for runtime stats collection -extern RuntimeStatsCollector runtime_stats; +} // namespace runtime_stats + +extern runtime_stats::RuntimeStatsCollector + *global_runtime_stats; // NOLINT(cppcoreguidelines-avoid-non-const-global-variables) } // namespace esphome diff --git a/esphome/core/application.cpp b/esphome/core/application.cpp index 224989c73c..6face23e3c 100644 --- a/esphome/core/application.cpp +++ b/esphome/core/application.cpp @@ -144,7 +144,9 @@ void Application::loop() { #ifdef USE_RUNTIME_STATS // Process any pending runtime stats printing after all components have run // This ensures stats printing doesn't affect component timing measurements - runtime_stats.process_pending_stats(last_op_end_time); + if (global_runtime_stats != nullptr) { + global_runtime_stats->process_pending_stats(last_op_end_time); + } #endif // Use the last component's end time instead of calling millis() again diff --git a/esphome/core/application.h b/esphome/core/application.h index 588ab1a92a..2cdcdf9e6a 100644 --- a/esphome/core/application.h +++ b/esphome/core/application.h @@ -351,14 +351,6 @@ class Application { uint32_t get_loop_interval() const { return static_cast(this->loop_interval_); } -#ifdef USE_RUNTIME_STATS - /** Set the interval at which runtime statistics are logged. - * - * @param interval The interval in milliseconds between logging of runtime statistics. - */ - void set_runtime_stats_log_interval(uint32_t interval) { runtime_stats.set_log_interval(interval); } -#endif - void schedule_dump_config() { this->dump_config_at_ = 0; } void feed_wdt(uint32_t time = 0); diff --git a/esphome/core/component.cpp b/esphome/core/component.cpp index e446dd378e..8dbd054602 100644 --- a/esphome/core/component.cpp +++ b/esphome/core/component.cpp @@ -398,7 +398,9 @@ uint32_t WarnIfComponentBlockingGuard::finish() { #ifdef USE_RUNTIME_STATS // Record component runtime stats - runtime_stats.record_component_time(this->component_, blocking_time, curr_time); + if (global_runtime_stats != nullptr) { + global_runtime_stats->record_component_time(this->component_, blocking_time, curr_time); + } #endif bool should_warn; if (this->component_ != nullptr) { From 02395c92a19ea5bd52cf7b396bc1af2f60ada83f Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 09:26:13 -0600 Subject: [PATCH 04/16] cleanup --- esphome/components/runtime_stats/__init__.py | 2 +- esphome/components/runtime_stats/runtime_stats.h | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/esphome/components/runtime_stats/__init__.py b/esphome/components/runtime_stats/__init__.py index 64382194ec..e70e010748 100644 --- a/esphome/components/runtime_stats/__init__.py +++ b/esphome/components/runtime_stats/__init__.py @@ -11,7 +11,7 @@ DEPENDENCIES = [] CONF_LOG_INTERVAL = "log_interval" runtime_stats_ns = cg.esphome_ns.namespace("runtime_stats") -RuntimeStatsCollector = runtime_stats_ns.class_("RuntimeStatsCollector") +RuntimeStatsCollector = runtime_stats_ns.class_("RuntimeStatsCollector", cg.Component) CONFIG_SCHEMA = cv.Schema( { diff --git a/esphome/components/runtime_stats/runtime_stats.h b/esphome/components/runtime_stats/runtime_stats.h index 24dae46b2e..9ec4ec49a9 100644 --- a/esphome/components/runtime_stats/runtime_stats.h +++ b/esphome/components/runtime_stats/runtime_stats.h @@ -87,7 +87,7 @@ struct ComponentStatPair { } }; -class RuntimeStatsCollector { +class RuntimeStatsCollector : public Component { public: RuntimeStatsCollector(); From d1609de25ab6b060c96a5593ceb7c8d5aa11fb97 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 09:28:09 -0600 Subject: [PATCH 05/16] cleanup --- esphome/components/runtime_stats/__init__.py | 2 +- esphome/components/runtime_stats/runtime_stats.cpp | 1 + esphome/components/runtime_stats/runtime_stats.h | 2 +- 3 files changed, 3 insertions(+), 2 deletions(-) diff --git a/esphome/components/runtime_stats/__init__.py b/esphome/components/runtime_stats/__init__.py index e70e010748..64382194ec 100644 --- a/esphome/components/runtime_stats/__init__.py +++ b/esphome/components/runtime_stats/__init__.py @@ -11,7 +11,7 @@ DEPENDENCIES = [] CONF_LOG_INTERVAL = "log_interval" runtime_stats_ns = cg.esphome_ns.namespace("runtime_stats") -RuntimeStatsCollector = runtime_stats_ns.class_("RuntimeStatsCollector", cg.Component) +RuntimeStatsCollector = runtime_stats_ns.class_("RuntimeStatsCollector") CONFIG_SCHEMA = cv.Schema( { diff --git a/esphome/components/runtime_stats/runtime_stats.cpp b/esphome/components/runtime_stats/runtime_stats.cpp index 72411ffd6f..75c59e77ba 100644 --- a/esphome/components/runtime_stats/runtime_stats.cpp +++ b/esphome/components/runtime_stats/runtime_stats.cpp @@ -1,4 +1,5 @@ #include "runtime_stats.h" +#include "esphome/core/defines.h" #ifdef USE_RUNTIME_STATS diff --git a/esphome/components/runtime_stats/runtime_stats.h b/esphome/components/runtime_stats/runtime_stats.h index 9ec4ec49a9..24dae46b2e 100644 --- a/esphome/components/runtime_stats/runtime_stats.h +++ b/esphome/components/runtime_stats/runtime_stats.h @@ -87,7 +87,7 @@ struct ComponentStatPair { } }; -class RuntimeStatsCollector : public Component { +class RuntimeStatsCollector { public: RuntimeStatsCollector(); From 0097a55eaae62e2cd60ba92b968c137f5abefd0d Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 09:34:16 -0600 Subject: [PATCH 06/16] fixes --- esphome/components/runtime_stats/runtime_stats.cpp | 4 +++- esphome/components/runtime_stats/runtime_stats.h | 4 +++- 2 files changed, 6 insertions(+), 2 deletions(-) diff --git a/esphome/components/runtime_stats/runtime_stats.cpp b/esphome/components/runtime_stats/runtime_stats.cpp index 75c59e77ba..96a222da84 100644 --- a/esphome/components/runtime_stats/runtime_stats.cpp +++ b/esphome/components/runtime_stats/runtime_stats.cpp @@ -1,5 +1,4 @@ #include "runtime_stats.h" -#include "esphome/core/defines.h" #ifdef USE_RUNTIME_STATS @@ -10,6 +9,9 @@ namespace esphome { namespace runtime_stats { +// Forward declaration to help compiler +class RuntimeStatsCollector; + RuntimeStatsCollector::RuntimeStatsCollector() : log_interval_(60000), next_log_time_(0) { global_runtime_stats = this; } diff --git a/esphome/components/runtime_stats/runtime_stats.h b/esphome/components/runtime_stats/runtime_stats.h index 24dae46b2e..de241e439c 100644 --- a/esphome/components/runtime_stats/runtime_stats.h +++ b/esphome/components/runtime_stats/runtime_stats.h @@ -1,5 +1,7 @@ #pragma once +#include "esphome/core/defines.h" + #ifdef USE_RUNTIME_STATS #include @@ -122,4 +124,4 @@ extern runtime_stats::RuntimeStatsCollector } // namespace esphome -#endif // USE_RUNTIME_STATS \ No newline at end of file +#endif // USE_RUNTIME_STATS From be84f12100ff29a32c306715e884792db6e0fe55 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 09:34:56 -0600 Subject: [PATCH 07/16] fixes --- esphome/components/runtime_stats/runtime_stats.cpp | 3 --- esphome/components/runtime_stats/runtime_stats.h | 3 +-- 2 files changed, 1 insertion(+), 5 deletions(-) diff --git a/esphome/components/runtime_stats/runtime_stats.cpp b/esphome/components/runtime_stats/runtime_stats.cpp index 96a222da84..72411ffd6f 100644 --- a/esphome/components/runtime_stats/runtime_stats.cpp +++ b/esphome/components/runtime_stats/runtime_stats.cpp @@ -9,9 +9,6 @@ namespace esphome { namespace runtime_stats { -// Forward declaration to help compiler -class RuntimeStatsCollector; - RuntimeStatsCollector::RuntimeStatsCollector() : log_interval_(60000), next_log_time_(0) { global_runtime_stats = this; } diff --git a/esphome/components/runtime_stats/runtime_stats.h b/esphome/components/runtime_stats/runtime_stats.h index de241e439c..7e763810eb 100644 --- a/esphome/components/runtime_stats/runtime_stats.h +++ b/esphome/components/runtime_stats/runtime_stats.h @@ -11,11 +11,10 @@ #include #include "esphome/core/helpers.h" #include "esphome/core/log.h" +#include "esphome/core/component.h" namespace esphome { -class Component; // Forward declaration - namespace runtime_stats { static const char *const TAG = "runtime_stats"; From 3862e3b4e73e8c254b18f363c31e8eb0b1e5c8fa Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 09:35:31 -0600 Subject: [PATCH 08/16] fixes --- esphome/components/runtime_stats/runtime_stats.h | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/esphome/components/runtime_stats/runtime_stats.h b/esphome/components/runtime_stats/runtime_stats.h index 7e763810eb..de241e439c 100644 --- a/esphome/components/runtime_stats/runtime_stats.h +++ b/esphome/components/runtime_stats/runtime_stats.h @@ -11,10 +11,11 @@ #include #include "esphome/core/helpers.h" #include "esphome/core/log.h" -#include "esphome/core/component.h" namespace esphome { +class Component; // Forward declaration + namespace runtime_stats { static const char *const TAG = "runtime_stats"; From 7d2726ab21d891e78f5da9c76c5e8ce73cd673cc Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 09:37:07 -0600 Subject: [PATCH 09/16] fixes --- esphome/components/runtime_stats/runtime_stats.h | 1 - 1 file changed, 1 deletion(-) diff --git a/esphome/components/runtime_stats/runtime_stats.h b/esphome/components/runtime_stats/runtime_stats.h index de241e439c..5f258469a1 100644 --- a/esphome/components/runtime_stats/runtime_stats.h +++ b/esphome/components/runtime_stats/runtime_stats.h @@ -8,7 +8,6 @@ #include #include #include -#include #include "esphome/core/helpers.h" #include "esphome/core/log.h" From 07a4f6f53c16971d6f2287d28d4caaa8768a4f07 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 09:40:12 -0600 Subject: [PATCH 10/16] fixes --- esphome/components/runtime_stats/runtime_stats.cpp | 8 ++++---- esphome/components/runtime_stats/runtime_stats.h | 14 +++++++++----- 2 files changed, 13 insertions(+), 9 deletions(-) diff --git a/esphome/components/runtime_stats/runtime_stats.cpp b/esphome/components/runtime_stats/runtime_stats.cpp index 72411ffd6f..9d87534fec 100644 --- a/esphome/components/runtime_stats/runtime_stats.cpp +++ b/esphome/components/runtime_stats/runtime_stats.cpp @@ -58,10 +58,10 @@ void RuntimeStatsCollector::log_stats_() { // Log top components by period runtime for (const auto &it : stats_to_display) { - const std::string &source = it.name; + const char *source = it.name; const ComponentRuntimeStats *stats = it.stats; - ESP_LOGI(TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms", source.c_str(), + ESP_LOGI(TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms", source, stats->get_period_count(), stats->get_period_avg_time_ms(), stats->get_period_max_time_ms(), stats->get_period_time_ms()); } @@ -76,10 +76,10 @@ void RuntimeStatsCollector::log_stats_() { }); for (const auto &it : stats_to_display) { - const std::string &source = it.name; + const char *source = it.name; const ComponentRuntimeStats *stats = it.stats; - ESP_LOGI(TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms", source.c_str(), + ESP_LOGI(TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms", source, stats->get_total_count(), stats->get_total_avg_time_ms(), stats->get_total_max_time_ms(), stats->get_total_time_ms()); } diff --git a/esphome/components/runtime_stats/runtime_stats.h b/esphome/components/runtime_stats/runtime_stats.h index 5f258469a1..36572e2094 100644 --- a/esphome/components/runtime_stats/runtime_stats.h +++ b/esphome/components/runtime_stats/runtime_stats.h @@ -5,9 +5,9 @@ #ifdef USE_RUNTIME_STATS #include -#include #include #include +#include #include "esphome/core/helpers.h" #include "esphome/core/log.h" @@ -79,7 +79,7 @@ class ComponentRuntimeStats { // For sorting components by run time struct ComponentStatPair { - std::string name; + const char *name; const ComponentRuntimeStats *stats; bool operator>(const ComponentStatPair &other) const { @@ -109,9 +109,13 @@ class RuntimeStatsCollector { } } - // Back to string keys, but we'll cache the source name per component - std::map component_stats_; - std::map component_names_cache_; + // Use const char* keys for efficiency + // Custom comparator for const char* keys in map + struct CStrCompare { + bool operator()(const char *a, const char *b) const { return std::strcmp(a, b) < 0; } + }; + std::map component_stats_; + std::map component_names_cache_; uint32_t log_interval_; uint32_t next_log_time_; }; From 97a476b4755636528abb5c60e812f6f20af493c3 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 09:52:44 -0600 Subject: [PATCH 11/16] stats --- tests/integration/fixtures/runtime_stats.yaml | 37 ++++++++ tests/integration/test_runtime_stats.py | 88 +++++++++++++++++++ 2 files changed, 125 insertions(+) create mode 100644 tests/integration/fixtures/runtime_stats.yaml create mode 100644 tests/integration/test_runtime_stats.py diff --git a/tests/integration/fixtures/runtime_stats.yaml b/tests/integration/fixtures/runtime_stats.yaml new file mode 100644 index 0000000000..47ad30d95c --- /dev/null +++ b/tests/integration/fixtures/runtime_stats.yaml @@ -0,0 +1,37 @@ +esphome: + name: runtime-stats-test + +host: + +api: + +logger: + level: INFO + +runtime_stats: + log_interval: 1s + +# Add some components that will execute periodically to generate stats +sensor: + - platform: template + name: "Test Sensor 1" + id: test_sensor_1 + lambda: return 42.0; + update_interval: 0.1s + + - platform: template + name: "Test Sensor 2" + id: test_sensor_2 + lambda: return 24.0; + update_interval: 0.2s + +switch: + - platform: template + name: "Test Switch" + id: test_switch + optimistic: true + +interval: + - interval: 0.5s + then: + - switch.toggle: test_switch diff --git a/tests/integration/test_runtime_stats.py b/tests/integration/test_runtime_stats.py new file mode 100644 index 0000000000..f0af04c2d8 --- /dev/null +++ b/tests/integration/test_runtime_stats.py @@ -0,0 +1,88 @@ +"""Test runtime statistics component.""" + +from __future__ import annotations + +import asyncio +import re + +import pytest + +from .types import APIClientConnectedFactory, RunCompiledFunction + + +@pytest.mark.asyncio +async def test_runtime_stats( + yaml_config: str, + run_compiled: RunCompiledFunction, + api_client_connected: APIClientConnectedFactory, +) -> None: + """Test runtime stats logs statistics at configured interval and tracks components.""" + loop = asyncio.get_running_loop() + + # Track how many times we see the total stats + stats_count = 0 + first_stats_future = loop.create_future() + second_stats_future = loop.create_future() + + # Track component stats + component_stats_found = set() + + # Patterns to match + total_stats_pattern = re.compile(r"Total stats \(since boot\):") + component_pattern = re.compile(r"^\s+(\w+):\s+count=(\d+),\s+avg=([\d.]+)ms") + + def check_output(line: str) -> None: + """Check log output for runtime stats messages.""" + nonlocal stats_count + + # Debug: print ALL lines to see what we're getting + if "[I]" in line or "[D]" in line or "[W]" in line or "[E]" in line: + print(f"LOG: {line}") + + # Check for total stats line + if total_stats_pattern.search(line): + stats_count += 1 + + if stats_count == 1 and not first_stats_future.done(): + first_stats_future.set_result(True) + elif stats_count == 2 and not second_stats_future.done(): + second_stats_future.set_result(True) + + # Check for component stats + match = component_pattern.match(line) + if match: + component_name = match.group(1) + component_stats_found.add(component_name) + + async with run_compiled(yaml_config, line_callback=check_output): + async with api_client_connected() as client: + # Verify device is connected + device_info = await client.device_info() + assert device_info is not None + + # Wait for first "Total stats" log (should happen at 1s) + try: + await asyncio.wait_for(first_stats_future, timeout=5.0) + except asyncio.TimeoutError: + pytest.fail("First 'Total stats' log not seen within 5 seconds") + + # Wait for second "Total stats" log (should happen at 2s) + try: + await asyncio.wait_for(second_stats_future, timeout=5.0) + except asyncio.TimeoutError: + pytest.fail( + f"Second 'Total stats' log not seen. Total seen: {stats_count}" + ) + + # Verify we got at least 2 stats logs + assert stats_count >= 2, ( + f"Expected at least 2 'Total stats' logs, got {stats_count}" + ) + + # Verify we found stats for our components + assert "sensor" in component_stats_found, ( + f"Expected sensor stats, found: {component_stats_found}" + ) + assert "switch" in component_stats_found, ( + f"Expected switch stats, found: {component_stats_found}" + ) From defa452aa19d48f38b0580527cdbd6ee46f8454a Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 09:58:02 -0600 Subject: [PATCH 12/16] preen --- tests/integration/fixtures/runtime_stats.yaml | 4 +++- tests/integration/test_runtime_stats.py | 20 +++++++++---------- 2 files changed, 13 insertions(+), 11 deletions(-) diff --git a/tests/integration/fixtures/runtime_stats.yaml b/tests/integration/fixtures/runtime_stats.yaml index 47ad30d95c..aad1c275fb 100644 --- a/tests/integration/fixtures/runtime_stats.yaml +++ b/tests/integration/fixtures/runtime_stats.yaml @@ -6,7 +6,9 @@ host: api: logger: - level: INFO + level: DEBUG + logs: + runtime_stats: INFO runtime_stats: log_interval: 1s diff --git a/tests/integration/test_runtime_stats.py b/tests/integration/test_runtime_stats.py index f0af04c2d8..e12c907f17 100644 --- a/tests/integration/test_runtime_stats.py +++ b/tests/integration/test_runtime_stats.py @@ -27,18 +27,18 @@ async def test_runtime_stats( # Track component stats component_stats_found = set() - # Patterns to match + # Patterns to match - need to handle ANSI color codes and timestamps + # The log format is: [HH:MM:SS][color codes][I][tag]: message total_stats_pattern = re.compile(r"Total stats \(since boot\):") - component_pattern = re.compile(r"^\s+(\w+):\s+count=(\d+),\s+avg=([\d.]+)ms") + # Match component names that may include dots (e.g., template.sensor) + component_pattern = re.compile( + r"^\[[^\]]+\].*?\s+([\w.]+):\s+count=(\d+),\s+avg=([\d.]+)ms" + ) def check_output(line: str) -> None: """Check log output for runtime stats messages.""" nonlocal stats_count - # Debug: print ALL lines to see what we're getting - if "[I]" in line or "[D]" in line or "[W]" in line or "[E]" in line: - print(f"LOG: {line}") - # Check for total stats line if total_stats_pattern.search(line): stats_count += 1 @@ -80,9 +80,9 @@ async def test_runtime_stats( ) # Verify we found stats for our components - assert "sensor" in component_stats_found, ( - f"Expected sensor stats, found: {component_stats_found}" + assert "template.sensor" in component_stats_found, ( + f"Expected template.sensor stats, found: {component_stats_found}" ) - assert "switch" in component_stats_found, ( - f"Expected switch stats, found: {component_stats_found}" + assert "template.switch" in component_stats_found, ( + f"Expected template.switch stats, found: {component_stats_found}" ) From cb670105747a9aee9b7f64b9c20816cca8f3b9bf Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 10:11:24 -0600 Subject: [PATCH 13/16] remove dead code --- CODEOWNERS | 1 + esphome/components/runtime_stats/__init__.py | 11 ----------- 2 files changed, 1 insertion(+), 11 deletions(-) diff --git a/CODEOWNERS b/CODEOWNERS index ca3849eb0d..fb3c049db3 100644 --- a/CODEOWNERS +++ b/CODEOWNERS @@ -376,6 +376,7 @@ esphome/components/rp2040_pwm/* @jesserockz esphome/components/rpi_dpi_rgb/* @clydebarrow esphome/components/rtl87xx/* @kuba2k2 esphome/components/rtttl/* @glmnet +esphome/components/runtime_stats/* @bdraco esphome/components/safe_mode/* @jsuanet @kbx81 @paulmonigatti esphome/components/scd4x/* @martgras @sjtrny esphome/components/script/* @esphome/core diff --git a/esphome/components/runtime_stats/__init__.py b/esphome/components/runtime_stats/__init__.py index 64382194ec..fcbf6cea08 100644 --- a/esphome/components/runtime_stats/__init__.py +++ b/esphome/components/runtime_stats/__init__.py @@ -6,8 +6,6 @@ import esphome.codegen as cg import esphome.config_validation as cv from esphome.const import CONF_ID -DEPENDENCIES = [] - CONF_LOG_INTERVAL = "log_interval" runtime_stats_ns = cg.esphome_ns.namespace("runtime_stats") @@ -23,15 +21,6 @@ CONFIG_SCHEMA = cv.Schema( ) -def FILTER_SOURCE_FILES() -> list[str]: - """Filter out runtime_stats.cpp when not enabled.""" - # When runtime_stats component is not included in the configuration, - # we don't want to compile runtime_stats.cpp - # This function is called when the component IS included, so we return - # an empty list to include all source files - return [] - - async def to_code(config): """Generate code for the runtime statistics component.""" # Define USE_RUNTIME_STATS when this component is used From ae346bb94e1aa06dae21b23cd87cee93ca54b35e Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 10:11:47 -0600 Subject: [PATCH 14/16] remove dead code --- esphome/components/runtime_stats/__init__.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/esphome/components/runtime_stats/__init__.py b/esphome/components/runtime_stats/__init__.py index fcbf6cea08..aff0bf086f 100644 --- a/esphome/components/runtime_stats/__init__.py +++ b/esphome/components/runtime_stats/__init__.py @@ -6,6 +6,8 @@ import esphome.codegen as cg import esphome.config_validation as cv from esphome.const import CONF_ID +CODEOWNERS = ["@bdraco"] + CONF_LOG_INTERVAL = "log_interval" runtime_stats_ns = cg.esphome_ns.namespace("runtime_stats") From d32db20aa085e573bc8c6e044a8e9b21fbef8b0b Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 11:10:32 -0600 Subject: [PATCH 15/16] preen --- esphome/components/runtime_stats/runtime_stats.cpp | 4 ---- esphome/components/runtime_stats/runtime_stats.h | 2 ++ 2 files changed, 2 insertions(+), 4 deletions(-) diff --git a/esphome/components/runtime_stats/runtime_stats.cpp b/esphome/components/runtime_stats/runtime_stats.cpp index 9d87534fec..8f5d5daf01 100644 --- a/esphome/components/runtime_stats/runtime_stats.cpp +++ b/esphome/components/runtime_stats/runtime_stats.cpp @@ -25,17 +25,13 @@ void RuntimeStatsCollector::record_component_time(Component *component, uint32_t this->component_names_cache_[component] = source; this->component_stats_[source].record_time(duration_ms); } else { - // Use cached name - no string operations, just map lookup this->component_stats_[name_it->second].record_time(duration_ms); } - // If next_log_time_ is 0, initialize it if (this->next_log_time_ == 0) { this->next_log_time_ = current_time + this->log_interval_; return; } - - // Don't print stats here anymore - let process_pending_stats handle it } void RuntimeStatsCollector::log_stats_() { diff --git a/esphome/components/runtime_stats/runtime_stats.h b/esphome/components/runtime_stats/runtime_stats.h index 36572e2094..20b0c08313 100644 --- a/esphome/components/runtime_stats/runtime_stats.h +++ b/esphome/components/runtime_stats/runtime_stats.h @@ -111,6 +111,8 @@ class RuntimeStatsCollector { // Use const char* keys for efficiency // Custom comparator for const char* keys in map + // Without this, std::map would compare pointer addresses instead of string contents, + // causing identical component names at different addresses to be treated as different keys struct CStrCompare { bool operator()(const char *a, const char *b) const { return std::strcmp(a, b) < 0; } }; From 748604d374357597b6b85c6c0c69b99fa92ad1fa Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 8 Jul 2025 11:12:46 -0600 Subject: [PATCH 16/16] preen --- tests/integration/test_runtime_stats.py | 56 ++++++++++++------------- 1 file changed, 28 insertions(+), 28 deletions(-) diff --git a/tests/integration/test_runtime_stats.py b/tests/integration/test_runtime_stats.py index e12c907f17..cd8546facc 100644 --- a/tests/integration/test_runtime_stats.py +++ b/tests/integration/test_runtime_stats.py @@ -54,35 +54,35 @@ async def test_runtime_stats( component_name = match.group(1) component_stats_found.add(component_name) - async with run_compiled(yaml_config, line_callback=check_output): - async with api_client_connected() as client: - # Verify device is connected - device_info = await client.device_info() - assert device_info is not None + async with ( + run_compiled(yaml_config, line_callback=check_output), + api_client_connected() as client, + ): + # Verify device is connected + device_info = await client.device_info() + assert device_info is not None - # Wait for first "Total stats" log (should happen at 1s) - try: - await asyncio.wait_for(first_stats_future, timeout=5.0) - except asyncio.TimeoutError: - pytest.fail("First 'Total stats' log not seen within 5 seconds") + # Wait for first "Total stats" log (should happen at 1s) + try: + await asyncio.wait_for(first_stats_future, timeout=5.0) + except asyncio.TimeoutError: + pytest.fail("First 'Total stats' log not seen within 5 seconds") - # Wait for second "Total stats" log (should happen at 2s) - try: - await asyncio.wait_for(second_stats_future, timeout=5.0) - except asyncio.TimeoutError: - pytest.fail( - f"Second 'Total stats' log not seen. Total seen: {stats_count}" - ) + # Wait for second "Total stats" log (should happen at 2s) + try: + await asyncio.wait_for(second_stats_future, timeout=5.0) + except asyncio.TimeoutError: + pytest.fail(f"Second 'Total stats' log not seen. Total seen: {stats_count}") - # Verify we got at least 2 stats logs - assert stats_count >= 2, ( - f"Expected at least 2 'Total stats' logs, got {stats_count}" - ) + # Verify we got at least 2 stats logs + assert stats_count >= 2, ( + f"Expected at least 2 'Total stats' logs, got {stats_count}" + ) - # Verify we found stats for our components - assert "template.sensor" in component_stats_found, ( - f"Expected template.sensor stats, found: {component_stats_found}" - ) - assert "template.switch" in component_stats_found, ( - f"Expected template.switch stats, found: {component_stats_found}" - ) + # Verify we found stats for our components + assert "template.sensor" in component_stats_found, ( + f"Expected template.sensor stats, found: {component_stats_found}" + ) + assert "template.switch" in component_stats_found, ( + f"Expected template.switch stats, found: {component_stats_found}" + )