From 8911d9d28f1adb2414f67a00c0035295e554f388 Mon Sep 17 00:00:00 2001 From: Kevin Ahrendt Date: Tue, 3 Mar 2026 19:42:36 -0600 Subject: [PATCH 1/3] [media_source] Clarify threading contract (#14433) --- esphome/components/media_source/media_source.h | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/esphome/components/media_source/media_source.h b/esphome/components/media_source/media_source.h index 688c27134f..f21ba486b8 100644 --- a/esphome/components/media_source/media_source.h +++ b/esphome/components/media_source/media_source.h @@ -67,11 +67,13 @@ class MediaSource { /// @brief Start playing the given URI /// Sources should validate the URI and state, returning false if the source is busy. /// The orchestrator is responsible for stopping active sources before starting a new one. + /// @note Must only be called from the main loop. /// @param uri URI to play; e.g., "http://stream_url" /// @return true if playback started successfully, false otherwise virtual bool play_uri(const std::string &uri) = 0; - /// @brief Handle playback commands (pause, stop, next, etc.) + /// @brief Handle playback commands; e.g., pause, stop, next, etc. + /// @note Must only be called from the main loop. /// @param command Command to execute virtual void handle_command(MediaSourceCommand command) = 0; @@ -81,7 +83,8 @@ class MediaSource { // === State Access === - /// @brief Get current playback state (must only be called from the main loop) + /// @brief Get current playback state + /// @note Must only be called from the main loop. /// @return Current state of this source MediaSourceState get_state() const { return this->state_; } @@ -136,9 +139,10 @@ class MediaSource { virtual void notify_audio_played(uint32_t frames, int64_t timestamp) {} protected: - /// @brief Update state and notify listener (must only be called from the main loop) + /// @brief Update state and notify listener /// This is the only way to change state_, ensuring listener notifications always fire. /// Sources running FreeRTOS tasks should signal via event groups and call this from loop(). + /// @note Must only be called from the main loop. /// @param state New state to set void set_state_(MediaSourceState state) { if (this->state_ != state) { From cba34e770e8077f95305bdbbf5352def17d58dcf Mon Sep 17 00:00:00 2001 From: Tilman Vogel Date: Wed, 4 Mar 2026 03:18:36 +0100 Subject: [PATCH 2/3] [core] improve help text for --device option, mention `OTA` (#14445) Co-authored-by: Jesse Hills <3060199+jesserockz@users.noreply.github.com> --- esphome/__main__.py | 7 ++++--- esphome/const.py | 3 +++ 2 files changed, 7 insertions(+), 3 deletions(-) diff --git a/esphome/__main__.py b/esphome/__main__.py index ffedb90bde..0164e2eeb3 100644 --- a/esphome/__main__.py +++ b/esphome/__main__.py @@ -23,6 +23,7 @@ import esphome.codegen as cg from esphome.config import iter_component_configs, read_config, strip_default_ids from esphome.const import ( ALLOWED_NAME_CHARS, + ARGUMENT_HELP_DEVICE, CONF_API, CONF_BAUD_RATE, CONF_BROKER, @@ -1367,7 +1368,7 @@ def parse_args(argv): parser_upload.add_argument( "--device", action="append", - help="Manually specify the serial port/address to use, for example /dev/ttyUSB0. Can be specified multiple times for fallback addresses.", + help=ARGUMENT_HELP_DEVICE, ) parser_upload.add_argument( "--upload_speed", @@ -1390,7 +1391,7 @@ def parse_args(argv): parser_logs.add_argument( "--device", action="append", - help="Manually specify the serial port/address to use, for example /dev/ttyUSB0. Can be specified multiple times for fallback addresses.", + help=ARGUMENT_HELP_DEVICE, ) parser_logs.add_argument( "--reset", @@ -1420,7 +1421,7 @@ def parse_args(argv): parser_run.add_argument( "--device", action="append", - help="Manually specify the serial port/address to use, for example /dev/ttyUSB0. Can be specified multiple times for fallback addresses.", + help=ARGUMENT_HELP_DEVICE, ) parser_run.add_argument( "--upload_speed", diff --git a/esphome/const.py b/esphome/const.py index d5625f6a54..060e962573 100644 --- a/esphome/const.py +++ b/esphome/const.py @@ -11,6 +11,9 @@ VALID_SUBSTITUTIONS_CHARACTERS = ( "abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789_" ) +# CLI Help Text Constants +ARGUMENT_HELP_DEVICE = "Manually specify the serial port/address to use, for example /dev/ttyUSB0. Can be specified multiple times for fallback addresses. Use 'OTA' for resolving from MQTT, DNS or mDNS and avoiding the interactive prompt." + class Platform(StrEnum): """Platform identifiers for ESPHome.""" From 87f37b7c380e40ff1c08e56a40548555b92bbc3c Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 3 Mar 2026 23:06:28 -1000 Subject: [PATCH 3/3] [runtime_stats] Use micros() for accurate per-component timing MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The previous millis()-based timing had insufficient resolution. Most components complete their loop() in microseconds, but millis() only has 1ms granularity. Components taking <1ms would show either 0ms or 1ms depending on whether a millisecond boundary happened to tick over during execution — essentially random noise rather than useful data. Switch to self-timed micros() per guard (only when USE_RUNTIME_STATS is compiled in — zero cost in production builds). Track internally in microseconds, display in milliseconds with fractional precision. Use uint64_t for total_time_us_ to avoid overflow (uint32_t would wrap after ~10 hours at typical loop rates). --- .../runtime_stats/runtime_stats.cpp | 22 ++++---- .../components/runtime_stats/runtime_stats.h | 56 +++++++++---------- esphome/core/component.cpp | 7 ++- esphome/core/component.h | 16 +++++- 4 files changed, 60 insertions(+), 41 deletions(-) diff --git a/esphome/components/runtime_stats/runtime_stats.cpp b/esphome/components/runtime_stats/runtime_stats.cpp index 410695da04..d9fa22d949 100644 --- a/esphome/components/runtime_stats/runtime_stats.cpp +++ b/esphome/components/runtime_stats/runtime_stats.cpp @@ -13,12 +13,12 @@ RuntimeStatsCollector::RuntimeStatsCollector() : log_interval_(60000), next_log_ global_runtime_stats = this; } -void RuntimeStatsCollector::record_component_time(Component *component, uint32_t duration_ms, uint32_t current_time) { +void RuntimeStatsCollector::record_component_time(Component *component, uint32_t duration_us, uint32_t current_time) { if (component == nullptr) return; // Record stats using component pointer as key - this->component_stats_[component].record_time(duration_ms); + this->component_stats_[component].record_time(duration_us); if (this->next_log_time_ == 0) { this->next_log_time_ = current_time + this->log_interval_; @@ -58,15 +58,16 @@ void RuntimeStatsCollector::log_stats_() { // Sort by period runtime (descending) std::sort(sorted, sorted + count, [this](Component *a, Component *b) { - return this->component_stats_[a].get_period_time_ms() > this->component_stats_[b].get_period_time_ms(); + return this->component_stats_[a].get_period_time_us() > this->component_stats_[b].get_period_time_us(); }); // Log top components by period runtime for (size_t i = 0; i < count; i++) { const auto &stats = this->component_stats_[sorted[i]]; - ESP_LOGI(TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms", - LOG_STR_ARG(sorted[i]->get_component_log_str()), stats.get_period_count(), stats.get_period_avg_time_ms(), - stats.get_period_max_time_ms(), stats.get_period_time_ms()); + 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 total stats since boot (only for active components - idle ones haven't changed) @@ -74,14 +75,15 @@ void RuntimeStatsCollector::log_stats_() { // 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_ms() > this->component_stats_[b].get_total_time_ms(); + return this->component_stats_[a].get_total_time_us() > this->component_stats_[b].get_total_time_us(); }); for (size_t i = 0; i < count; i++) { const auto &stats = this->component_stats_[sorted[i]]; - ESP_LOGI(TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms", - LOG_STR_ARG(sorted[i]->get_component_log_str()), stats.get_total_count(), stats.get_total_avg_time_ms(), - stats.get_total_max_time_ms(), stats.get_total_time_ms()); + 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); } } diff --git a/esphome/components/runtime_stats/runtime_stats.h b/esphome/components/runtime_stats/runtime_stats.h index c7fea7474b..0847529720 100644 --- a/esphome/components/runtime_stats/runtime_stats.h +++ b/esphome/components/runtime_stats/runtime_stats.h @@ -22,58 +22,58 @@ class ComponentRuntimeStats { public: ComponentRuntimeStats() : period_count_(0), - period_time_ms_(0), - period_max_time_ms_(0), + period_time_us_(0), + period_max_time_us_(0), total_count_(0), - total_time_ms_(0), - total_max_time_ms_(0) {} + total_time_us_(0), + total_max_time_us_(0) {} - void record_time(uint32_t duration_ms) { + void record_time(uint32_t duration_us) { // 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; + this->period_time_us_ += duration_us; + if (duration_us > this->period_max_time_us_) + this->period_max_time_us_ = duration_us; - // Update total counters + // Update total counters (uint64_t to avoid overflow — uint32_t would overflow after ~10 hours) this->total_count_++; - this->total_time_ms_ += duration_ms; - if (duration_ms > this->total_max_time_ms_) - this->total_max_time_ms_ = duration_ms; + 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_ms_ = 0; - this->period_max_time_ms_ = 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_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; + 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(this->period_count_) : 0.0f; } - // Total stats (persistent until reboot) + // Total stats (persistent until reboot, uint64_t to avoid overflow) 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; + 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(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_; + uint32_t period_time_us_; + uint32_t period_max_time_us_; // Total stats (persistent until reboot) uint32_t total_count_; - uint32_t total_time_ms_; - uint32_t total_max_time_ms_; + uint64_t total_time_us_; + uint32_t total_max_time_us_; }; class RuntimeStatsCollector { @@ -83,7 +83,7 @@ class RuntimeStatsCollector { void set_log_interval(uint32_t log_interval) { this->log_interval_ = log_interval; } uint32_t get_log_interval() const { return this->log_interval_; } - void record_component_time(Component *component, uint32_t duration_ms, uint32_t current_time); + void record_component_time(Component *component, uint32_t duration_us, uint32_t current_time); // Process any pending stats printing (should be called after component loop) void process_pending_stats(uint32_t current_time); diff --git a/esphome/core/component.cpp b/esphome/core/component.cpp index 4ccc747819..8c2c8d38e8 100644 --- a/esphome/core/component.cpp +++ b/esphome/core/component.cpp @@ -529,9 +529,12 @@ uint32_t WarnIfComponentBlockingGuard::finish() { uint32_t curr_time = millis(); uint32_t blocking_time = curr_time - this->started_; #ifdef USE_RUNTIME_STATS - // Record component 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) { - global_runtime_stats->record_component_time(this->component_, blocking_time, curr_time); + uint32_t duration_us = micros() - this->started_us_; + global_runtime_stats->record_component_time(this->component_, duration_us, curr_time); } #endif if (blocking_time > WARN_IF_BLOCKING_OVER_MS) { diff --git a/esphome/core/component.h b/esphome/core/component.h index e5127b0c9f..59222dc4f4 100644 --- a/esphome/core/component.h +++ b/esphome/core/component.h @@ -563,10 +563,21 @@ class PollingComponent : public Component { uint32_t update_interval_; }; +#ifdef USE_RUNTIME_STATS +uint32_t micros(); // Forward declare for inline constructor +#endif + class WarnIfComponentBlockingGuard { public: WarnIfComponentBlockingGuard(Component *component, uint32_t start_time) - : started_(start_time), component_(component) {} + : started_(start_time), + component_(component) +#ifdef USE_RUNTIME_STATS + , + started_us_(micros()) +#endif + { + } // Finish the timing operation and return the current time uint32_t finish(); @@ -576,6 +587,9 @@ class WarnIfComponentBlockingGuard { protected: uint32_t started_; Component *component_; +#ifdef USE_RUNTIME_STATS + uint32_t started_us_; +#endif }; // Function to clear setup priority overrides after all components are set up