Merge branch 'decouple_scheduler_loop_cadence' into integration

esphome/components/runtime_stats/runtime_stats.h

@@ -42,7 +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_loop_tasks_ + the trailing record/stats
-  //               prefix. Zero on Phase A-only ticks (component phase gated).
+  //               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.
   // 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,

esphome/core/application.cpp

@@ -219,6 +219,11 @@ void Application::feed_wdt() {
   if (now - this->last_wdt_feed_ > WDT_FEED_INTERVAL_MS) {
     this->feed_wdt_slow_(now);
   }
+#ifdef USE_STATUS_LED
+  if (now - this->last_status_led_service_ > STATUS_LED_DISPATCH_INTERVAL_MS) {
+    this->service_status_led_slow_(now);
+  }
+#endif
 }
 
 void HOT Application::feed_wdt_slow_(uint32_t time) {
@@ -226,27 +231,36 @@ void HOT Application::feed_wdt_slow_(uint32_t time) {
   // confirmed the WDT_FEED_INTERVAL_MS rate limit was exceeded.
   arch_feed_wdt();
   this->last_wdt_feed_ = time;
-#ifdef USE_STATUS_LED
-  if (status_led::global_status_led != nullptr) {
-    auto *sl = status_led::global_status_led;
-    uint8_t sl_state = sl->get_component_state() & COMPONENT_STATE_MASK;
-    if (sl_state == COMPONENT_STATE_LOOP_DONE) {
-      // status_led only transitions to LOOP_DONE from inside its own loop() (after the
-      // first idle-path dispatch), so its pin is already initialized by pre_setup() and
-      // its setup() has already run. Re-dispatch only if an error or warning bit has been
-      // set since; otherwise skip entirely.
-      if ((this->app_state_ & STATUS_LED_MASK) == 0)
-        return;
-      sl->enable_loop();
-    } else if (sl_state != COMPONENT_STATE_LOOP) {
-      // CONSTRUCTION/SETUP/FAILED: not our job — App::setup() drives the lifecycle.
-      return;
-    }
-    sl->loop();
-  }
-#endif
 }
 
+#ifdef USE_STATUS_LED
+void HOT Application::service_status_led_slow_(uint32_t time) {
+  // Callers (feed_wdt(), feed_wdt_with_time()) have already confirmed the
+  // STATUS_LED_DISPATCH_INTERVAL_MS rate limit was exceeded. Rate-limited
+  // separately from arch_feed_wdt() so the LED blink pattern stays readable
+  // (status_led error blink period is 250 ms) while HAL watchdog pokes can
+  // still run at the much coarser WDT_FEED_INTERVAL_MS cadence.
+  this->last_status_led_service_ = time;
+  if (status_led::global_status_led == nullptr)
+    return;
+  auto *sl = status_led::global_status_led;
+  uint8_t sl_state = sl->get_component_state() & COMPONENT_STATE_MASK;
+  if (sl_state == COMPONENT_STATE_LOOP_DONE) {
+    // status_led only transitions to LOOP_DONE from inside its own loop() (after the
+    // first idle-path dispatch), so its pin is already initialized by pre_setup() and
+    // its setup() has already run. Re-dispatch only if an error or warning bit has been
+    // set since; otherwise skip entirely.
+    if ((this->app_state_ & STATUS_LED_MASK) == 0)
+      return;
+    sl->enable_loop();
+  } else if (sl_state != COMPONENT_STATE_LOOP) {
+    // CONSTRUCTION/SETUP/FAILED: not our job — App::setup() drives the lifecycle.
+    return;
+  }
+  sl->loop();
+}
+#endif
+
 bool Application::any_component_has_status_flag_(uint8_t flag) const {
   // Walk all components (not just looping ones) so non-looping components'
   // status bits are respected. Only called from the slow-path clear helpers

esphome/core/application.h

@@ -237,7 +237,8 @@ class Application {
   /// this threshold triggers a real feed naturally.
   /// Safety margins vs. platform watchdog timeouts:
   ///   - ESP32 task WDT default (5 s): ~16x
-  ///   - ESP8266 soft WDT (~1.6 s):    ~5x
+  ///   - ESP8266 soft WDT (~1.6 s):    ~5x  <-- floor case; any future change
+  ///                                             must keep comfortable margin here
   ///   - ESP8266 HW WDT (~6 s):        ~20x
   static constexpr uint32_t WDT_FEED_INTERVAL_MS = 300;
 
@@ -245,14 +246,33 @@ class Application {
   /// timestamp in hand. Out of line to keep call sites tiny.
   void feed_wdt();
 
+#ifdef USE_STATUS_LED
+  /// Dispatch interval for the status LED update. Deliberately shorter than
+  /// WDT_FEED_INTERVAL_MS because the status LED error blink has a 250 ms
+  /// period (status_led.cpp:ERROR_PERIOD_MS) and a 150 ms on-window; the
+  /// dispatch cadence must be short enough to render that blink without
+  /// aliasing. Sampling every 100 ms yields an on/off observation inside
+  /// every error period with headroom for the 250 ms warning on-window.
+  static constexpr uint32_t STATUS_LED_DISPATCH_INTERVAL_MS = 100;
+#endif
+
   /// Feed the task watchdog, hot entry. Callers that already have a
   /// millis() timestamp pay only a load + sub + branch on the common
-  /// (no-op) path. The actual arch feed + status LED update live in
-  /// feed_wdt_slow_.
+  /// (no-op) path. The actual arch feed lives in feed_wdt_slow_.
+  /// When USE_STATUS_LED is compiled in, also gates a separate (shorter)
+  /// interval for dispatching status_led so the LED blink pattern stays
+  /// readable even though arch_feed_wdt pokes are now rate-limited at
+  /// 300 ms. The two rate limits are independent so raising
+  /// WDT_FEED_INTERVAL_MS does not distort the LED cadence.
   void ESPHOME_ALWAYS_INLINE feed_wdt_with_time(uint32_t time) {
     if (static_cast<uint32_t>(time - this->last_wdt_feed_) > WDT_FEED_INTERVAL_MS) [[unlikely]] {
       this->feed_wdt_slow_(time);
     }
+#ifdef USE_STATUS_LED
+    if (static_cast<uint32_t>(time - this->last_status_led_service_) > STATUS_LED_DISPATCH_INTERVAL_MS) [[unlikely]] {
+      this->service_status_led_slow_(time);
+    }
+#endif
   }
 
   void reboot();
@@ -415,11 +435,21 @@ class Application {
   /// Caller must ensure dump_config_at_ < components_.size().
   void __attribute__((noinline)) process_dump_config_();
 
-  /// Slow path for feed_wdt(): actually calls arch_feed_wdt(), updates
-  /// last_wdt_feed_, and re-dispatches the status LED. Out of line so the
-  /// inline wrapper stays tiny.
+  /// Slow path for feed_wdt(): actually calls arch_feed_wdt() and updates
+  /// last_wdt_feed_. Out of line so the inline wrapper stays tiny. Does NOT
+  /// touch status_led — that's gated separately via service_status_led_slow_
+  /// because the two rate limits have very different safe ranges (~ seconds
+  /// for WDT, < 250 ms for LED blink rendering).
   void feed_wdt_slow_(uint32_t time);
 
+#ifdef USE_STATUS_LED
+  /// Slow path for the status_led dispatch rate limit. Runs the status_led
+  /// component's loop() based on its state (LOOP / LOOP_DONE with status
+  /// bits set), and updates last_status_led_service_. Out of line to keep
+  /// the feed_wdt_with_time hot path a couple of load+branch sequences.
+  void service_status_led_slow_(uint32_t time);
+#endif
+
   /// Perform a delay while also monitoring socket file descriptors for readiness
 #ifdef USE_HOST
   // select() fallback path is too complex to inline (host platform)
@@ -471,6 +501,10 @@ class Application {
   uint32_t last_loop_{0};
   uint32_t loop_component_start_time_{0};
   uint32_t last_wdt_feed_{0};  // millis() of most recent arch_feed_wdt(); rate-limits feed_wdt() hot path
+#ifdef USE_STATUS_LED
+  // millis() of most recent status_led dispatch; rate-limits independently of last_wdt_feed_
+  uint32_t last_status_led_service_{0};
+#endif
 
 #ifdef USE_HOST
   int max_fd_{-1};  // Highest file descriptor number for select()
@@ -616,7 +650,9 @@ inline void ESPHOME_ALWAYS_INLINE __attribute__((optimize("O2"))) Application::l
 #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.
+  // 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;
 #endif
 

tests/integration/fixtures/loop_interval_default_not_pulled_forward.yaml

@@ -0,0 +1,51 @@
+esphome:
+  name: loop-default-not-pulled
+  on_boot:
+    priority: -100
+    then:
+      # Leave loop_interval_ at its default (16 ms → ~62 Hz). Do NOT call
+      # set_loop_interval here. The fast scheduler interval below used to
+      # pull the component phase forward to ~128 Hz via the old
+      # std::max(next_schedule, delay_time / 2) floor.
+      # Start measurement after 1s so boot transients settle.
+      - delay: 1000ms
+      - lambda: |-
+          id(loop_at_start) = id(loop_counter)->get_loop_count();
+          ESP_LOGI("test", "MEASUREMENT_STARTED loop=%d", id(loop_at_start));
+      # Observe for 2s.
+      - delay: 2000ms
+      - lambda: |-
+          int loop_delta = id(loop_counter)->get_loop_count() - id(loop_at_start);
+          ESP_LOGI("test", "MEASUREMENT_DONE loop_delta=%d", loop_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: loop_at_start
+    type: int
+    initial_value: "0"
+
+loop_test_component:
+  components:
+    - id: loop_counter
+      name: loop_counter
+
+interval:
+  # Fast scheduler interval (well under loop_interval_/2 = 8ms). In the
+  # pre-decoupling code this would have pulled the component phase forward
+  # to ~128 Hz. After the decoupling fix the component phase stays at
+  # ~62 Hz regardless.
+  - interval: 5ms
+    then:
+      - lambda: |-
+          // No-op; the presence of a due scheduler item is what matters.

tests/integration/test_loop_interval_decoupling.py

@@ -58,7 +58,9 @@ async def test_loop_interval_decoupling(
         # 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, (
+        # Lower bound 3 (not 2) keeps the test honest: a >30% slowdown from
+        # the ~4 nominal is not normal CI jitter and should fail.
+        assert 3 <= loop_delta <= 6, (
             f"Component loop should fire ~4 times in 2s at loop_interval=500ms, "
             f"got {loop_delta}"
         )

tests/integration/test_loop_interval_default_not_pulled_forward.py

@@ -0,0 +1,67 @@
+"""Test that a fast scheduler item does not pull the component phase forward.
+
+Regression test for the original ~128 Hz → ~62 Hz bug fixed by decoupling
+Application::loop() component-phase cadence from scheduler wake timing.
+
+Setup:
+- loop_interval_ left at its default (16 ms → ~62 Hz component phase).
+- Scheduler interval at 5 ms (well under the old loop_interval_/2 = 8 ms floor).
+
+Before the decoupling fix the ``std::max(next_schedule, delay_time / 2)`` floor
+clamped the sleep to ~8 ms whenever any scheduler item was due sooner than
+loop_interval_/2. That pulled the component phase forward to ~128 Hz — twice
+what the documented ~62 Hz default promised. After the fix the component
+phase stays at ~62 Hz regardless of scheduler activity.
+"""
+
+from __future__ import annotations
+
+import asyncio
+import re
+
+import pytest
+
+from .types import APIClientConnectedFactory, RunCompiledFunction
+
+
+@pytest.mark.asyncio
+async def test_loop_interval_default_not_pulled_forward(
+    yaml_config: str,
+    run_compiled: RunCompiledFunction,
+    api_client_connected: APIClientConnectedFactory,
+) -> None:
+    """Fast scheduler item must not pull component phase past default ~62 Hz."""
+    loop = asyncio.get_running_loop()
+    measurement_done: asyncio.Future[int] = loop.create_future()
+
+    def on_log_line(line: str) -> None:
+        match = re.search(r"MEASUREMENT_DONE loop_delta=(\d+)", line)
+        if match and not measurement_done.done():
+            measurement_done.set_result(int(match.group(1)))
+
+    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-default-not-pulled"
+
+        try:
+            loop_delta = await asyncio.wait_for(measurement_done, timeout=10.0)
+        except TimeoutError:
+            pytest.fail("MEASUREMENT_DONE marker never appeared")
+
+        # Observation window = 2s, loop_interval_ default = 16ms → ~62 Hz →
+        # ~125 component-phase iterations expected.
+        # Pre-fix behavior: the 5 ms scheduler interval tripped the old
+        # delay_time/2 = 8 ms floor, pulling the phase to ~128 Hz → ~256.
+        # Upper bound 180 is comfortably below the ~256 pre-fix rate but
+        # above the ~125 nominal with CI jitter.
+        # Lower bound 80 covers very slow CI hosts without permitting a
+        # complete regression.
+        assert 80 <= loop_delta <= 180, (
+            f"Component loop at default loop_interval_ should fire ~125 times "
+            f"in 2s (≈62 Hz × 2s); got {loop_delta}. Values >200 indicate the "
+            f"scheduler is again pulling the component phase forward."
+        )