From ecdbe0f9bb29f01a47fb922731663b8171b3bc15 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Tue, 21 Apr 2026 06:22:55 +0200 Subject: [PATCH] [runtime_stats] report tail_us=0 on Phase A-only ticks MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Previously loop_tail_start_us defaulted to loop_before_end_us, so on ticks where Phase B was gated out (loop_interval_ not yet elapsed, no wake, no high-frequency request) tail_us measured "time from end of Phase A to stats recording" — i.e. gate-check + stats-prefix overhead — and was accumulated into the per-tick "tail" bucket even though no component tail had actually run. That mis-attributed gate-check + stats-prefix overhead to the tail metric, which is supposed to represent trailing overhead of the component phase specifically (after_component_phase_ + the little bit before record_loop_active). On a device whose loop_interval_ is raised for power savings, Phase A-only ticks dominate and the mis-attributed tail would skew the stats report. Fix: gate the tail_us computation on do_component_phase. Initialize loop_tail_start_us to 0 (unused on Phase A-only ticks) and only subtract from loop_now_us when Phase B ran. The overhead that used to land in "tail" now falls into "residual" (active − before − components − tail), which is the correct bucket for per-iteration bookkeeping that is not phase-specific. --- esphome/components/runtime_stats/runtime_stats.h | 6 +++--- esphome/core/application.h | 14 ++++++++------ 2 files changed, 11 insertions(+), 9 deletions(-) diff --git a/esphome/components/runtime_stats/runtime_stats.h b/esphome/components/runtime_stats/runtime_stats.h index 7299fd7315..888d48e672 100644 --- a/esphome/components/runtime_stats/runtime_stats.h +++ b/esphome/components/runtime_stats/runtime_stats.h @@ -42,9 +42,9 @@ class RuntimeStatsCollector { // before_us = time spent in Phase A (scheduler tick) excluding time // already attributed to per-component stats. // tail_us = time spent in after_component_phase_ + the trailing record/stats - // prefix. On Phase A-only ticks (component phase gated) this - // is just the small trailing prefix between loop_before_end_us - // and loop_now_us — non-zero but typically a few µs. + // prefix. Only meaningful on component-phase ticks; reported + // as 0 on Phase A-only ticks (no component phase ran, so any + // overhead between Phase A and stats belongs to "residual"). // Residual overhead at log time = active − Σ(component) − before − tail, // which captures per-iteration inter-component bookkeeping (set_current_component, // WarnIfComponentBlockingGuard construction/destruction, feed_wdt_with_time calls, diff --git a/esphome/core/application.h b/esphome/core/application.h index e1a6109f3e..d3851a32da 100644 --- a/esphome/core/application.h +++ b/esphome/core/application.h @@ -649,10 +649,10 @@ inline void ESPHOME_ALWAYS_INLINE Application::loop() { #ifdef USE_RUNTIME_STATS uint32_t loop_before_end_us = micros(); uint64_t loop_before_scheduled_us = ComponentRuntimeStats::global_recorded_us - loop_recorded_snap; - // Default tail_start to end-of-before so tail_us on Phase A-only ticks - // captures only the small gate-check + record_loop_active prefix between - // here and the loop_now_us sample below (not strictly zero, but tiny). - uint32_t loop_tail_start_us = loop_before_end_us; + // Only meaningful when do_component_phase is true; initialized to 0 so the + // tail bucket receives 0 on Phase A-only ticks (no component tail happened, + // the gate-check / stats-prefix overhead belongs to "residual", not "tail"). + uint32_t loop_tail_start_us = 0; #endif // Gate the component phase on loop_interval_, an active high-frequency @@ -711,8 +711,10 @@ inline void ESPHOME_ALWAYS_INLINE Application::loop() { uint32_t loop_before_overhead_us = loop_before_wall_us > loop_before_scheduled_us ? loop_before_wall_us - static_cast(loop_before_scheduled_us) : 0; - global_runtime_stats->record_loop_active(loop_now_us - loop_active_start_us, loop_before_overhead_us, - loop_now_us - loop_tail_start_us); + // tail_us is only defined when Phase B ran; 0 on Phase A-only ticks so the + // stats bucket keeps its "component-phase trailing overhead" meaning. + uint32_t loop_tail_us = do_component_phase ? (loop_now_us - loop_tail_start_us) : 0; + global_runtime_stats->record_loop_active(loop_now_us - loop_active_start_us, loop_before_overhead_us, loop_tail_us); global_runtime_stats->process_pending_stats(now); } #endif