From a0ac226e6c0d6888998cbda2b857c72169e042fe Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Thu, 16 Apr 2026 14:27:39 -1000 Subject: [PATCH 1/4] [core] decouple main loop cadence from scheduler wake timing MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Restructures Application::loop() into two independent phases to stop the scheduler from silently pulling the component loop cadence forward. Before: Application::loop() bounded its sleep by min(loop_interval_ - elapsed, next_schedule_in()) with a delay_time/2 floor. Any scheduler item due sooner than loop_interval_/2 dragged the whole component phase with it. On a typical ESP32 config with default loop_interval_=16ms, combined scheduler activity from api / esp32_ble / esp32_ble_tracker / debug was keeping every component's loop() running at ~128 Hz instead of the documented ~62 Hz. This has become more visible recently as more components convert to PollingComponent (which uses set_interval internally) and more in-tree code uses set_interval / set_timeout directly. Adding or removing any scheduled item silently changed every other component's loop cadence. App.set_loop_interval() for power savings was also silently defeated. After: - Phase A (every tick): drain wake notifications, run scheduler.call(), feed WDT - Phase B (gated by loop_interval_ or HighFrequencyLoopRequester): iterate registered components and update last_loop_ Sleep = min(time-until-next-component-phase, next_schedule_in()). When a scheduler event wakes us early, Phase A services it and the component phase stays gated independently. loop_interval_ is now a true minimum interval between component phases. The delay_time/2 floor is removed. Any legitimate need to wake faster than loop_interval_ has proper mechanisms: - HighFrequencyLoopRequester for sustained fast-loop needs - Application::wake_loop_threadsafe() from any context (new in 2026.4.0) for one-shot wake-on-event Also guards against set_interval(0) misuse — it asks the main loop to spin forever, which was never the intended API. Warns at creation time pointing authors at HighFrequencyLoopRequester. set_timeout(0)/defer() is unaffected; zero-delay one-shots remain legitimate. Runtime stats: process_pending_stats is now called on every tick (not just when the component phase runs) so log_interval_ isn't quantized to the component-phase cadence. Added an inline fast-path gate in runtime_stats.h that early-outs unless now >= next_log_time_, keeping Application::loop() slim; the log_stats_ work stays out-of-line. Ordering constraints preserved: - defer() callbacks still FIFO before components same-tick (Phase A runs before Phase B) - Scheduled items still execute before components when both due - Scheduled callbacks still run on main thread only - loop_component_start_time_ is still set fresh at each component's loop - WDT is still fed at least once per tick --- .../runtime_stats/runtime_stats.cpp | 11 +- .../components/runtime_stats/runtime_stats.h | 18 ++- esphome/core/application.cpp | 7 +- esphome/core/application.h | 117 +++++++++++------- esphome/core/scheduler.cpp | 9 ++ .../fixtures/loop_interval_decoupling.yaml | 60 +++++++++ .../test_loop_interval_decoupling.py | 73 +++++++++++ 7 files changed, 242 insertions(+), 53 deletions(-) create mode 100644 tests/integration/fixtures/loop_interval_decoupling.yaml create mode 100644 tests/integration/test_loop_interval_decoupling.py diff --git a/esphome/components/runtime_stats/runtime_stats.cpp b/esphome/components/runtime_stats/runtime_stats.cpp index 9ed141155a..d733394b78 100644 --- a/esphome/components/runtime_stats/runtime_stats.cpp +++ b/esphome/components/runtime_stats/runtime_stats.cpp @@ -137,11 +137,12 @@ 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->next_log_time_ = current_time + this->log_interval_; - } +// Slow path for process_pending_stats — gate already checked by the inline +// wrapper in runtime_stats.h. Out-of-line keeps the log_stats_ machinery out +// of Application::loop(). +void RuntimeStatsCollector::process_pending_stats_slow_(uint32_t current_time) { + this->log_stats_(); + this->next_log_time_ = current_time + this->log_interval_; } } // namespace runtime_stats diff --git a/esphome/components/runtime_stats/runtime_stats.h b/esphome/components/runtime_stats/runtime_stats.h index 82e0fb7c61..58abfa8da1 100644 --- a/esphome/components/runtime_stats/runtime_stats.h +++ b/esphome/components/runtime_stats/runtime_stats.h @@ -6,6 +6,7 @@ #include #include "esphome/core/hal.h" +#include "esphome/core/helpers.h" #include "esphome/core/log.h" namespace esphome { @@ -26,14 +27,22 @@ class RuntimeStatsCollector { } uint32_t get_log_interval() const { return this->log_interval_; } - // Process any pending stats printing (should be called after component loop) - void process_pending_stats(uint32_t current_time); + // Process any pending stats printing. Called on every Application::loop() + // tick, so the common "not yet time to log" path must be cheap — inline + // the gate check and keep the actual logging work out-of-line. + void ESPHOME_ALWAYS_INLINE process_pending_stats(uint32_t current_time) { + if ((int32_t) (current_time - this->next_log_time_) >= 0) [[unlikely]] { + this->process_pending_stats_slow_(current_time); + } + } // Record the wall time of one main loop iteration excluding the yield/sleep. // Called once per loop from Application::loop(). // active_us = total time between loop start and just before yield. - // before_us = time spent in before_loop_tasks_ (scheduler + ISR enable_loop). - // tail_us = time spent in after_loop_tasks_ + the trailing record/stats prefix. + // before_us = time spent in Phase A (scheduler tick) excluding time + // already attributed to per-component stats. + // tail_us = time spent in after_loop_tasks_ + the trailing record/stats + // prefix. Zero on Phase A-only ticks (component phase gated). // 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, @@ -55,6 +64,7 @@ class RuntimeStatsCollector { } protected: + void process_pending_stats_slow_(uint32_t current_time); void log_stats_(); // Static comparators — member functions have friend access, lambdas do not static bool compare_period_time(Component *a, Component *b); diff --git a/esphome/core/application.cpp b/esphome/core/application.cpp index 866edebbf6..4fc28e092e 100644 --- a/esphome/core/application.cpp +++ b/esphome/core/application.cpp @@ -93,8 +93,11 @@ void Application::setup() { do { uint32_t now = millis(); - // Process pending loop enables to handle GPIO interrupts during setup - this->before_loop_tasks_(now); + // Service scheduler and process pending loop enables to handle GPIO + // interrupts during setup. During setup we always run the component + // phase (no loop_interval_ gate), so call both helpers unconditionally. + this->scheduler_tick_(now); + this->before_component_phase_(); for (uint32_t j = 0; j <= i; j++) { // Update loop_component_start_time_ right before calling each component diff --git a/esphome/core/application.h b/esphome/core/application.h index bc40fe0c7e..c5b6a87817 100644 --- a/esphome/core/application.h +++ b/esphome/core/application.h @@ -399,7 +399,8 @@ class Application { void enable_component_loop_(Component *component); void enable_pending_loops_(); void activate_looping_component_(uint16_t index); - inline void ESPHOME_ALWAYS_INLINE before_loop_tasks_(uint32_t loop_start_time); + inline void ESPHOME_ALWAYS_INLINE scheduler_tick_(uint32_t now); + inline void ESPHOME_ALWAYS_INLINE before_component_phase_(); inline void ESPHOME_ALWAYS_INLINE after_loop_tasks_() { this->in_loop_ = false; } /// Process dump_config output one component per loop iteration. @@ -543,19 +544,22 @@ inline void Application::drain_wake_notifications_() { } #endif // USE_HOST -inline void ESPHOME_ALWAYS_INLINE Application::before_loop_tasks_(uint32_t loop_start_time) { +// Phase A: drain wake notifications and run the scheduler. Invoked on every +// Application::loop() tick regardless of whether a component phase runs, so +// scheduler items fire at their requested cadence even when the caller has +// raised loop_interval_ for power savings (see Application::loop()). +inline void ESPHOME_ALWAYS_INLINE Application::scheduler_tick_(uint32_t now) { #ifdef USE_HOST // Drain wake notifications first to clear socket for next wake this->drain_wake_notifications_(); #endif + this->scheduler.call(now); +} - // Process scheduled tasks. Scheduler::call now feeds the watchdog itself - // after each scheduled item that actually runs, so we no longer need an - // unconditional feed here — when Scheduler::call has no work to do, the - // only elapsed time is a sleep wake + a few instructions, and when it does - // have work, it fed the wdt as it went. - this->scheduler.call(loop_start_time); - +// Phase B entry: only invoked when a component loop phase is about to run. +// Processes pending enable_loop requests from ISRs and marks in_loop_ so +// reentrant modifications during component.loop() are safe. +inline void ESPHOME_ALWAYS_INLINE Application::before_component_phase_() { // Process any pending enable_loop requests from ISRs // This must be done before marking in_loop_ = true to avoid race conditions if (this->has_pending_enable_loop_requests_) { @@ -586,40 +590,70 @@ inline void ESPHOME_ALWAYS_INLINE Application::loop() { // so charging it again to "before" would double-count. uint64_t loop_recorded_snap = ComponentRuntimeStats::global_recorded_us; #endif - // Get the initial loop time at the start - uint32_t last_op_end_time = millis(); + uint32_t now = millis(); + + // Phase A: always service the scheduler. Decouples scheduler cadence from + // loop_interval_ so raised intervals (for power savings) don't drag scheduled + // items forward. A tick that only runs the scheduler is cheap. + this->scheduler_tick_(now); + // Guarantee one WDT feed per tick even when the scheduler had nothing to + // dispatch and the component phase is gated out (setup() has its own + // per-component feed_wdt calls, so only do this here, not in scheduler_tick_). + this->feed_wdt_with_time(now); - this->before_loop_tasks_(last_op_end_time); #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 == 0 on Phase A-only ticks. + uint32_t loop_tail_start_us = loop_before_end_us; #endif - for (this->current_loop_index_ = 0; this->current_loop_index_ < this->looping_components_active_end_; - this->current_loop_index_++) { - Component *component = this->looping_components_[this->current_loop_index_]; + // Gate the component phase on loop_interval_ or an active high-frequency + // request. When a scheduler wake preempts sleep early, this gate keeps the + // component phase from running more often than loop_interval_. + // We deliberately reuse the pre-scheduler `now` rather than refreshing it + // via another millis() call: empty scheduler.call() is sub-microsecond, and + // any scheduled item that takes long enough to matter is a blocking + // violation that will self-correct on the next tick anyway. The one saved + // millis() call per tick is worth that acceptable one-tick drift. + const bool high_frequency = HighFrequencyLoopRequester::is_high_frequency(); + const uint32_t elapsed = now - this->last_loop_; + const bool do_component_phase = high_frequency || (elapsed >= this->loop_interval_); - // Update the cached time before each component runs - this->loop_component_start_time_ = last_op_end_time; + if (do_component_phase) { + this->before_component_phase_(); - { - this->set_current_component(component); - WarnIfComponentBlockingGuard guard{component, last_op_end_time}; - component->loop(); - // Use the finish method to get the current time as the end time - last_op_end_time = guard.finish(); + uint32_t last_op_end_time = now; + for (this->current_loop_index_ = 0; this->current_loop_index_ < this->looping_components_active_end_; + this->current_loop_index_++) { + Component *component = this->looping_components_[this->current_loop_index_]; + + // Update the cached time before each component runs + this->loop_component_start_time_ = last_op_end_time; + + { + this->set_current_component(component); + WarnIfComponentBlockingGuard guard{component, last_op_end_time}; + component->loop(); + // Use the finish method to get the current time as the end time + last_op_end_time = guard.finish(); + } + this->feed_wdt_with_time(last_op_end_time); } - this->feed_wdt_with_time(last_op_end_time); + +#ifdef USE_RUNTIME_STATS + loop_tail_start_us = micros(); +#endif + this->after_loop_tasks_(); + + this->last_loop_ = last_op_end_time; + now = last_op_end_time; } #ifdef USE_RUNTIME_STATS - uint32_t loop_tail_start_us = micros(); -#endif - this->after_loop_tasks_(); - -#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 + // Record per-tick timing on every loop, not just component-phase ticks. + // record_loop_active is a small accumulator; process_pending_stats is an + // inline gate check that early-outs unless now >= next_log_time_. if (global_runtime_stats != nullptr) { uint32_t loop_now_us = micros(); // Subtract scheduled-component time from the "before" bucket so it is @@ -630,23 +664,22 @@ inline void ESPHOME_ALWAYS_INLINE Application::loop() { : 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); - global_runtime_stats->process_pending_stats(last_op_end_time); + global_runtime_stats->process_pending_stats(now); } #endif - // Use the last component's end time instead of calling millis() again + // Compute sleep: bounded by time-until-next-component-phase and the + // scheduler's next deadline. When a scheduler event wakes us early we + // re-enter loop(), Phase A services it, and the component phase stays gated. uint32_t delay_time = 0; - auto elapsed = last_op_end_time - this->last_loop_; - if (elapsed < this->loop_interval_ && !HighFrequencyLoopRequester::is_high_frequency()) { - delay_time = this->loop_interval_ - elapsed; - uint32_t next_schedule = this->scheduler.next_schedule_in(last_op_end_time).value_or(delay_time); - // next_schedule is max 0.5*delay_time - // otherwise interval=0 schedules result in constant looping with almost no sleep - next_schedule = std::max(next_schedule, delay_time / 2); - delay_time = std::min(next_schedule, delay_time); + if (!high_frequency) { + const uint32_t elapsed_since_phase = now - this->last_loop_; + const uint32_t until_phase = + (elapsed_since_phase >= this->loop_interval_) ? 0 : (this->loop_interval_ - elapsed_since_phase); + const uint32_t until_sched = this->scheduler.next_schedule_in(now).value_or(until_phase); + delay_time = std::min(until_phase, until_sched); } this->yield_with_select_(delay_time); - this->last_loop_ = last_op_end_time; if (this->dump_config_at_ < this->components_.size()) { this->process_dump_config_(); diff --git a/esphome/core/scheduler.cpp b/esphome/core/scheduler.cpp index 3e75a68064..fdb96c7343 100644 --- a/esphome/core/scheduler.cpp +++ b/esphome/core/scheduler.cpp @@ -144,6 +144,15 @@ void HOT Scheduler::set_timer_common_(Component *component, SchedulerItem::Type return; } + // An interval of 0 means "fire every tick forever," which is misuse: it + // asks the main loop to spin unbounded. The correct mechanism for running + // fast in the main loop is HighFrequencyLoopRequester, not a zero-delay + // interval. Zero-delay timeouts (defer) remain legitimate one-shots. + if (type == SchedulerItem::INTERVAL && delay == 0) [[unlikely]] { + ESP_LOGW(TAG, "[%s] set_interval(0) is misuse — use HighFrequencyLoopRequester", + component ? LOG_STR_ARG(component->get_component_log_str()) : LOG_STR_LITERAL("?")); + } + // Take lock early to protect scheduler_item_pool_ access and retry-cancelled check LockGuard guard{this->lock_}; diff --git a/tests/integration/fixtures/loop_interval_decoupling.yaml b/tests/integration/fixtures/loop_interval_decoupling.yaml new file mode 100644 index 0000000000..5aedd9aba5 --- /dev/null +++ b/tests/integration/fixtures/loop_interval_decoupling.yaml @@ -0,0 +1,60 @@ +esphome: + name: loop-interval-decouple + on_boot: + priority: -100 + then: + - lambda: |- + // Raise loop_interval_ to 500ms. With the decoupling fix the + // component phase should run ~twice per second while the 50ms + // scheduler interval below still fires at its requested cadence. + App.set_loop_interval(500); + # Start measurement after 1s so boot transients settle. + - delay: 1000ms + - lambda: |- + id(loop_at_start) = id(loop_counter)->get_loop_count(); + id(sched_at_start) = id(sched_count); + ESP_LOGI("test", "MEASUREMENT_STARTED loop=%d sched=%d", + id(loop_at_start), id(sched_at_start)); + # Observe for 2s. + - delay: 2000ms + - lambda: |- + int loop_delta = id(loop_counter)->get_loop_count() - id(loop_at_start); + int sched_delta = id(sched_count) - id(sched_at_start); + ESP_LOGI("test", "MEASUREMENT_DONE loop_delta=%d sched_delta=%d", + loop_delta, sched_delta); + +host: +api: +logger: + level: INFO + logs: + loop_test_component: WARN # Silence per-loop log spam + +external_components: + - source: + type: local + path: EXTERNAL_COMPONENT_PATH + +globals: + - id: sched_count + type: int + initial_value: "0" + - id: loop_at_start + type: int + initial_value: "0" + - id: sched_at_start + type: int + initial_value: "0" + +loop_test_component: + components: + - id: loop_counter + name: loop_counter + +interval: + # Fast scheduler interval — with the decoupling fix this should fire at + # its requested 50ms cadence regardless of loop_interval_. + - interval: 50ms + then: + - lambda: |- + id(sched_count) += 1; diff --git a/tests/integration/test_loop_interval_decoupling.py b/tests/integration/test_loop_interval_decoupling.py new file mode 100644 index 0000000000..1cf8bf477d --- /dev/null +++ b/tests/integration/test_loop_interval_decoupling.py @@ -0,0 +1,73 @@ +"""Test that loop_interval_ no longer clamps scheduler cadence. + +Regression test for the decoupling of Application::loop() component-phase +cadence from scheduler wake timing. + +Setup: +- App.set_loop_interval(500) — raised for power-savings style cadence +- Scheduler interval at 50ms — should fire at 50ms regardless of loop_interval_ +- Component loop (LoopTestComponent) — should run at 500ms cadence + +Before the decoupling fix the old `std::max(next_schedule, delay_time / 2)` +floor clamped the sleep to ~250ms, so the 50ms scheduler only fired ~8 times +per 2s (vs the ~40 expected). After the fix the scheduler fires close to its +requested cadence while the component phase stays gated at loop_interval_. +""" + +from __future__ import annotations + +import asyncio +import re + +import pytest + +from .types import APIClientConnectedFactory, RunCompiledFunction + + +@pytest.mark.asyncio +async def test_loop_interval_decoupling( + yaml_config: str, + run_compiled: RunCompiledFunction, + api_client_connected: APIClientConnectedFactory, +) -> None: + """Raised loop_interval_ must not clamp scheduler item cadence.""" + loop = asyncio.get_running_loop() + measurement_done: asyncio.Future[tuple[int, int]] = loop.create_future() + + def on_log_line(line: str) -> None: + match = re.search(r"MEASUREMENT_DONE loop_delta=(\d+) sched_delta=(\d+)", line) + if match and not measurement_done.done(): + measurement_done.set_result((int(match.group(1)), int(match.group(2)))) + + async with ( + run_compiled(yaml_config, line_callback=on_log_line), + api_client_connected() as client, + ): + device_info = await client.device_info() + assert device_info is not None + assert device_info.name == "loop-interval-decouple" + + try: + loop_delta, sched_delta = await asyncio.wait_for( + measurement_done, timeout=10.0 + ) + except TimeoutError: + pytest.fail("MEASUREMENT_DONE marker never appeared") + + # Observation window = 2s, loop_interval_ = 500ms. + # Component phase should fire ~4 times in 2s. The upper bound must be + # less than 8: the pre-decoupling behavior clamped to ~250ms cadence + # giving ~8 loops/2s, so allowing 8 would let the old behavior pass. + assert 2 <= loop_delta <= 6, ( + f"Component loop should fire ~4 times in 2s at loop_interval=500ms, " + f"got {loop_delta}" + ) + + # Scheduler interval = 50ms → ~40 fires in 2s. Before the decoupling + # fix this clamped to ~8 fires. Assert >= 20 to catch the old clamped + # behavior with comfortable jitter headroom for slow CI hosts. + assert sched_delta >= 20, ( + f"50ms scheduler interval should fire ~40 times in 2s but only " + f"fired {sched_delta}. This indicates loop_interval_ is still " + f"clamping scheduler cadence." + ) From 71636ba8a1ddde159d8610ea746dc742d0fca2af Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Thu, 16 Apr 2026 17:34:05 -1000 Subject: [PATCH 2/4] [core] coerce set_interval(0) to 1ms to prevent scheduler spin MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Users (notably PollingComponents with update_interval: 0ms) have historically relied on set_interval(0) as a pseudo-loop() mechanism. A literal interval=0 causes Scheduler::call() to spin — the item is always 'due now' after re-scheduling, so the scheduler loop never returns, starves the main loop, and triggers a WDT reset in the field. Coerce interval=0 to 1ms at creation so existing code keeps working at ~1kHz instead of spinning, while still emitting the warning pointing authors at HighFrequencyLoopRequester (the intended mechanism for running fast in the main loop). Zero-delay timeouts (defer/set_timeout) remain legitimate one-shots and are unaffected — defer is a one-shot, not a spin risk. --- esphome/core/scheduler.cpp | 14 +++++++++----- 1 file changed, 9 insertions(+), 5 deletions(-) diff --git a/esphome/core/scheduler.cpp b/esphome/core/scheduler.cpp index fdb96c7343..168230c274 100644 --- a/esphome/core/scheduler.cpp +++ b/esphome/core/scheduler.cpp @@ -144,13 +144,17 @@ void HOT Scheduler::set_timer_common_(Component *component, SchedulerItem::Type return; } - // An interval of 0 means "fire every tick forever," which is misuse: it - // asks the main loop to spin unbounded. The correct mechanism for running - // fast in the main loop is HighFrequencyLoopRequester, not a zero-delay - // interval. Zero-delay timeouts (defer) remain legitimate one-shots. + // An interval of 0 means "fire every tick forever," which is misuse: the + // item would always be due, causing Scheduler::call() to spin and starve + // the main loop (WDT reset in the field). Coerce to 1ms so existing code + // using update_interval=0ms as a pseudo-loop() continues to work at ~1kHz, + // and warn so authors can migrate to HighFrequencyLoopRequester which is + // the intended mechanism for running fast in the main loop. Zero-delay + // timeouts (defer) remain legitimate one-shots and are not affected. if (type == SchedulerItem::INTERVAL && delay == 0) [[unlikely]] { - ESP_LOGW(TAG, "[%s] set_interval(0) is misuse — use HighFrequencyLoopRequester", + ESP_LOGW(TAG, "[%s] set_interval(0) is misuse — coercing to 1ms. Use HighFrequencyLoopRequester instead.", component ? LOG_STR_ARG(component->get_component_log_str()) : LOG_STR_LITERAL("?")); + delay = 1; } // Take lock early to protect scheduler_item_pool_ access and retry-cancelled check From df72aa26c0a11a00b581ef65f5c528c840a20f70 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Sat, 18 Apr 2026 06:58:54 -0500 Subject: [PATCH 3/4] [core] Feed WDT unconditionally in main loop to fix empty-config panic (#15830) --- esphome/core/application.h | 22 +++++++++++++--------- esphome/core/scheduler.cpp | 5 ++++- esphome/core/scheduler.h | 3 ++- 3 files changed, 19 insertions(+), 11 deletions(-) diff --git a/esphome/core/application.h b/esphome/core/application.h index 82f399b2d6..9252a47446 100644 --- a/esphome/core/application.h +++ b/esphome/core/application.h @@ -402,7 +402,7 @@ class Application { void enable_component_loop_(Component *component); void enable_pending_loops_(); void activate_looping_component_(uint16_t index); - inline void ESPHOME_ALWAYS_INLINE before_loop_tasks_(uint32_t loop_start_time); + inline uint32_t ESPHOME_ALWAYS_INLINE before_loop_tasks_(uint32_t loop_start_time); inline void ESPHOME_ALWAYS_INLINE after_loop_tasks_() { this->in_loop_ = false; } /// Process dump_config output one component per loop iteration. @@ -546,18 +546,15 @@ inline void Application::drain_wake_notifications_() { } #endif // USE_HOST -inline void ESPHOME_ALWAYS_INLINE Application::before_loop_tasks_(uint32_t loop_start_time) { +inline uint32_t ESPHOME_ALWAYS_INLINE Application::before_loop_tasks_(uint32_t loop_start_time) { #ifdef USE_HOST // Drain wake notifications first to clear socket for next wake this->drain_wake_notifications_(); #endif - // Process scheduled tasks. Scheduler::call now feeds the watchdog itself - // after each scheduled item that actually runs, so we no longer need an - // unconditional feed here — when Scheduler::call has no work to do, the - // only elapsed time is a sleep wake + a few instructions, and when it does - // have work, it fed the wdt as it went. - this->scheduler.call(loop_start_time); + // Scheduler::call feeds the WDT per item and returns the timestamp of the + // last fired item, or the input unchanged when nothing ran. + uint32_t last_op_end_time = this->scheduler.call(loop_start_time); // Process any pending enable_loop requests from ISRs // This must be done before marking in_loop_ = true to avoid race conditions @@ -575,6 +572,7 @@ inline void ESPHOME_ALWAYS_INLINE Application::before_loop_tasks_(uint32_t loop_ // Mark that we're in the loop for safe reentrant modifications this->in_loop_ = true; + return last_op_end_time; } inline void ESPHOME_ALWAYS_INLINE Application::loop() { @@ -592,7 +590,13 @@ inline void ESPHOME_ALWAYS_INLINE Application::loop() { // Get the initial loop time at the start uint32_t last_op_end_time = millis(); - this->before_loop_tasks_(last_op_end_time); + // Returned timestamp keeps us monotonic with last_wdt_feed_ (advanced by + // the scheduler's per-item feeds) without an extra millis() call. + last_op_end_time = this->before_loop_tasks_(last_op_end_time); + // Guarantee a WDT touch every tick — covers configs with no looping + // components and no scheduler work, where the per-item / per-component + // feeds never fire. Rate-limited inline fast path, ~free when unneeded. + this->feed_wdt_with_time(last_op_end_time); #ifdef USE_RUNTIME_STATS uint32_t loop_before_end_us = micros(); uint64_t loop_before_scheduled_us = ComponentRuntimeStats::global_recorded_us - loop_recorded_snap; diff --git a/esphome/core/scheduler.cpp b/esphome/core/scheduler.cpp index 7e6ad19ac7..b0eaa670ac 100644 --- a/esphome/core/scheduler.cpp +++ b/esphome/core/scheduler.cpp @@ -533,7 +533,7 @@ void HOT Scheduler::process_defer_queue_slow_path_(uint32_t &now) { } #endif /* not ESPHOME_THREAD_SINGLE */ -void HOT Scheduler::call(uint32_t now) { +uint32_t HOT Scheduler::call(uint32_t now) { #ifndef ESPHOME_THREAD_SINGLE this->process_defer_queue_(now); #endif /* not ESPHOME_THREAD_SINGLE */ @@ -703,6 +703,9 @@ void HOT Scheduler::call(uint32_t now) { this->debug_verify_no_leak_(); } #endif + // execute_item_() advances `now` as items fire; return it so the caller + // stays monotonic with last_wdt_feed_. + return now; } void HOT Scheduler::process_to_add_slow_path_() { LockGuard guard{this->lock_}; diff --git a/esphome/core/scheduler.h b/esphome/core/scheduler.h index 7634b3bd08..b0ce365a6f 100644 --- a/esphome/core/scheduler.h +++ b/esphome/core/scheduler.h @@ -129,7 +129,8 @@ class Scheduler { // Execute all scheduled items that are ready // @param now Fresh timestamp from millis() - must not be stale/cached - void call(uint32_t now); + // @return Timestamp of the last item that ran, or `now` unchanged if none ran. + uint32_t call(uint32_t now); // Move items from to_add_ into the main heap. // IMPORTANT: This method should only be called from the main thread (loop task). From 4e05d39f4b9c26621b56270e35a3749ad0d906f3 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Sat, 18 Apr 2026 07:09:52 -0500 Subject: [PATCH 4/4] [core] use post-scheduler timestamp for gate check MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit scheduler_tick_ now returns the scheduler's advanced timestamp (free via PR #15830's Scheduler::call return). Previously we still used the pre-scheduler millis() for `elapsed = now - last_loop_`, which underestimated elapsed time by whatever the scheduler dispatch took. Adopt the returned value as `now` so the gate check, WDT feed, runtime stats, and sleep computation all see consistent post-scheduler time. Drops the obsolete "we deliberately reuse pre-scheduler now" comment — that rationale was predicated on saving a millis() call, which no longer applies. --- esphome/core/application.h | 17 ++++++----------- 1 file changed, 6 insertions(+), 11 deletions(-) diff --git a/esphome/core/application.h b/esphome/core/application.h index f480c15ab6..037789ae8b 100644 --- a/esphome/core/application.h +++ b/esphome/core/application.h @@ -596,19 +596,19 @@ inline void ESPHOME_ALWAYS_INLINE Application::loop() { // so charging it again to "before" would double-count. uint64_t loop_recorded_snap = ComponentRuntimeStats::global_recorded_us; #endif - uint32_t now = millis(); - // Phase A: always service the scheduler. Decouples scheduler cadence from // loop_interval_ so raised intervals (for power savings) don't drag scheduled // items forward. A tick that only runs the scheduler is cheap. - // Returned timestamp keeps us monotonic with last_wdt_feed_ (advanced by the - // scheduler's per-item feeds) without an extra millis() call. - const uint32_t scheduler_end = this->scheduler_tick_(now); + // scheduler_tick_ returns the timestamp of the last scheduler item that ran + // (advanced by its per-item feeds) or `now` unchanged. We adopt it as `now` + // so the gate check and WDT feed both reflect actual elapsed time after + // scheduler dispatch, without an extra millis() call. + uint32_t now = this->scheduler_tick_(millis()); // Guarantee one WDT feed per tick even when the scheduler had nothing to // dispatch and the component phase is gated out — covers configs with no // looping components and no scheduler work (setup() has its own // per-component feed_wdt calls, so only do this here, not in scheduler_tick_). - this->feed_wdt_with_time(scheduler_end); + this->feed_wdt_with_time(now); #ifdef USE_RUNTIME_STATS uint32_t loop_before_end_us = micros(); @@ -620,11 +620,6 @@ inline void ESPHOME_ALWAYS_INLINE Application::loop() { // Gate the component phase on loop_interval_ or an active high-frequency // request. When a scheduler wake preempts sleep early, this gate keeps the // component phase from running more often than loop_interval_. - // We deliberately reuse the pre-scheduler `now` rather than refreshing it - // via another millis() call: empty scheduler.call() is sub-microsecond, and - // any scheduled item that takes long enough to matter is a blocking - // violation that will self-correct on the next tick anyway. The one saved - // millis() call per tick is worth that acceptable one-tick drift. const bool high_frequency = HighFrequencyLoopRequester::is_high_frequency(); const uint32_t elapsed = now - this->last_loop_; const bool do_component_phase = high_frequency || (elapsed >= this->loop_interval_);