fix(status): runtime status agrees with the heartbeat; current-status republishes on wake

CHANGELOG.md

@@ -223,6 +223,22 @@ policies are unchanged.
   being stopped, blanks the panel within about a second. It used to stay on
   until the next minute, because the once-a-minute schedule check had
   already run that minute and the session had overridden its answer.
+- `/api/v3/plugins/installed` no longer reports the display's plugins as
+  `live` while `/api/v3/health` says `display_loop: stalled`. The runtime
+  snapshot is written from its own thread, which kept going while the render
+  loop was hung. The web interface now also reads the render loop's
+  heartbeat: a fresh snapshot whose process's heartbeat is 60 s or older is
+  `data.runtime.status: "stalled"`, with the per-plugin fields null, and
+  `data.runtime` gains `heartbeat_age_seconds`. A snapshot from a process
+  that no longer exists, as after a watchdog kill (systemd removes the
+  heartbeat when the service stops), is `stale` at once instead of `live`
+  for up to 180 s. No new files or writes: both checks are on the reading
+  side.
+- `/api/v3/display/current-status` reflects a wake from scheduled-off, a
+  schedule-off blank, or an on-demand session starting or ending at once,
+  even when the mode name stays the same. The display republished its
+  current state only on a mode change or every 30 s, so `is_display_active`
+  and `on_demand_active` could be up to 30 s out of date.
 
 ### Scrolling
 

docs/REST_API_REFERENCE.md

@@ -551,7 +551,8 @@ List all installed plugins with their status and metadata.
       "status": "live",
       "published_at": 1790000030.0,
       "age_seconds": 12.4,
-      "stale_after": 180.0
+      "stale_after": 180.0,
+      "heartbeat_age_seconds": 2.1
     }
   }
 }
@@ -572,10 +573,15 @@ until the display restarts. A plugin a live snapshot does not list is
 `loaded: false`, `state: "unloaded"`.
 
 `runtime.status` says whether to believe them: `live` (fresh snapshot from
-a running display), `stale` (not refreshed within `stale_after` seconds: the
-display is hung or died), `stopped` (the display shut down) or `unknown`
+a running display), `stalled` (fresh snapshot, but the same process's
+render-loop heartbeat is 60 s or older -- the render loop is hung, as
+[`/health`](#health-check)'s `display_loop: stalled` says), `stale` (not refreshed
+within `stale_after` seconds, or the process that wrote it no longer exists:
+the display is hung or died), `stopped` (the display shut down) or `unknown`
 (nothing published yet). Unless it is `live`, every one of those fields is
-`null`. Health and metrics are at [`/plugins/health`](#get-plugin-health)
+`null`. `heartbeat_age_seconds` is the heartbeat's age when it was taken into
+account, `null` otherwise (no heartbeat, as on the dev server, or one from
+another process). Health and metrics are at [`/plugins/health`](#get-plugin-health)
 and `/plugins/metrics`.
 
 `vegas_participation` is what Vegas mode does with the plugin: `"scroll"`,
@@ -1138,7 +1144,7 @@ it is neither installed nor configured).
       "last_updated": "2025-01-15T10:30:00"
     }
   },
-  "runtime": {"status": "live", "published_at": 1790000030.0, "age_seconds": 12.4, "stale_after": 180.0}
+  "runtime": {"status": "live", "published_at": 1790000030.0, "age_seconds": 12.4, "stale_after": 180.0, "heartbeat_age_seconds": 2.1}
 }
 ```
 

src/display_controller.py

@@ -552,6 +552,9 @@ def load_single_plugin(plugin_id):
         # Last mode written to the display_current_state cache key, and when.
         self._last_published_mode: Optional[str] = None
         self._last_published_at = 0.0
+        # (is_display_active, on_demand_active) as last published: a change
+        # to either is republished at once, like a mode change.
+        self._last_published_flags: Optional[Tuple[bool, bool]] = None
         self.global_dynamic_config = (
             self.config.get("display", {}).get("dynamic_duration", {}) or {}
         )
@@ -1438,21 +1441,32 @@ def _publish_current_mode_state(self) -> None:
             }
             self.cache_manager.set('display_current_state', state)
             self._last_published_mode = self.current_display_mode
+            self._last_published_flags = self._current_state_flags()
             self._last_published_at = time.monotonic()
         except (OSError, RuntimeError, ValueError, TypeError) as err:
             logger.error("Failed to publish current display state: %s", err, exc_info=True)
 
+    def _current_state_flags(self) -> Tuple[bool, bool]:
+        """The published flags besides the mode that a reader acts on."""
+        return (bool(self.is_display_active), bool(self.on_demand_active))
+
     def _publish_current_mode_state_if_changed(self) -> None:
         """Publish the current mode state when it changed, or when the last
         publish is older than CURRENT_STATE_REFRESH_SECONDS.
 
+        A change is the mode, or ``is_display_active`` / ``on_demand_active``:
+        waking from scheduled-off, or an on-demand session starting or ending,
+        often leaves the mode name as it was, and the web UI would otherwise
+        show the old flag until the next refresh.
+
         The web UI reads this key with a max_age (api_v3/display.py), so a mode
         that stays on screen longer than that -- a live game under live
         priority, a single enabled plugin -- has to be republished or the UI
         reports it as unknown. Otherwise this writes only on a change, not on
         every render tick.
         """
         if (self.current_display_mode != self._last_published_mode
+                or self._current_state_flags() != getattr(self, '_last_published_flags', None)
                 or time.monotonic() - self._last_published_at >= CURRENT_STATE_REFRESH_SECONDS):
             self._publish_current_mode_state()
 

src/plugin_system/plugin_runtime.py

@@ -25,6 +25,23 @@
 on the way out, so readers see "stopped" at once rather than after the
 stale window. Nothing on the reading side reports a runtime fact from a
 snapshot that is not live.
+
+Render-loop liveness. The snapshot is written from its own thread, which
+keeps going when the render loop hangs inside a plugin. So the reader also
+checks the render loop's heartbeat (``src/display_watchdog.py``, the file
+``/api/v3/health`` reports as ``checks.display_loop``): a live snapshot from
+the process whose heartbeat has gone stale is ``stalled``, as the health
+check says, not ``live``. No extra writes: the heartbeat already exists, on
+tmpfs. A missing heartbeat (dev server, emulator, Windows, a display still
+starting up) or one from another process (a display restarted after a
+watchdog kill) says nothing, and the snapshot is judged on its own.
+
+A dead publisher. systemd removes the heartbeat's directory when the
+service stops, so after a watchdog kill there is no heartbeat to go stale.
+The reader then asks whether the snapshot's ``pid`` still exists (POSIX
+``kill(pid, 0)``, which sends nothing): a running snapshot from a process
+that is gone is ``stale`` at once rather than ``live`` for the rest of its
+``stale_after`` window.
 """
 
 import math
@@ -34,6 +51,7 @@
 from dataclasses import dataclass, field
 from typing import Any, Callable, Dict, Optional
 
+from src import display_watchdog
 from src.logging_config import get_logger
 from src.redaction import redact_credentials
 
@@ -70,6 +88,9 @@
 #: Reader statuses. Only LIVE carries runtime facts.
 LIVE = "live"
 STALE = "stale"
+#: The snapshot is fresh but the render loop's heartbeat is not: the display
+#: is hung (or was just killed by the watchdog), as /api/v3/health reports.
+STALLED = "stalled"
 STOPPED = "stopped"
 UNKNOWN = "unknown"
 
@@ -281,7 +302,9 @@ class PluginRuntimeView:
 
     ``status``: ``live`` (a fresh snapshot from a running display),
     ``stale`` (the last snapshot is older than its ``stale_after``: the
-    display is hung or died without cleaning up), ``stopped`` (the display
+    display is hung or died without cleaning up), ``stalled`` (the snapshot
+    is fresh but the same process's render-loop heartbeat is stale: the
+    render loop is hung), ``stopped`` (the display
     said so on its way out) or ``unknown`` (no readable snapshot). Only a
     live view reports per-plugin facts; every other status answers None for
     them, so a caller cannot pass stale truth on by accident.
@@ -292,6 +315,8 @@ class PluginRuntimeView:
     age_seconds: Optional[float] = None
     stale_after: float = STALE_AFTER
     plugins: Dict[str, Dict[str, Any]] = field(default_factory=dict)
+    #: Age of the render loop's heartbeat, when it was taken into account.
+    heartbeat_age_seconds: Optional[float] = None
 
     @property
     def live(self) -> bool:
@@ -321,6 +346,8 @@ def describe(self) -> Dict[str, Any]:
             "published_at": self.published_at,
             "age_seconds": None if self.age_seconds is None else round(self.age_seconds, 1),
             "stale_after": self.stale_after,
+            "heartbeat_age_seconds": (None if self.heartbeat_age_seconds is None
+                                      else round(self.heartbeat_age_seconds, 1)),
         }
 
 
@@ -334,8 +361,56 @@ def _stale_after_of(snapshot: Dict[str, Any]) -> float:
     return min(max(number, _STALE_AFTER_MIN), _STALE_AFTER_MAX)
 
 
-def view_from_snapshot(snapshot: Any, now: Optional[float] = None) -> PluginRuntimeView:
-    """Judge a snapshot read from the cache; never raises."""
+def _heartbeat_age_for(snapshot: Dict[str, Any], heartbeat: Any,
+                       now_mono: Optional[float]) -> Optional[float]:
+    """Age of ``heartbeat`` if it comes from the process that published
+    ``snapshot``; None when there is none, it has no time, or it belongs to
+    another process (a restarted display, or a heartbeat left by a killed one)."""
+    if not isinstance(heartbeat, dict):
+        return None
+    beat_pid = heartbeat.get("pid")
+    snap_pid = snapshot.get("pid")
+    if (isinstance(beat_pid, bool) or not isinstance(beat_pid, int)
+            or isinstance(snap_pid, bool) or not isinstance(snap_pid, int)
+            or beat_pid != snap_pid):
+        return None
+    return display_watchdog.heartbeat_age(heartbeat, now_mono=now_mono)
+
+
+def process_exists(pid: int) -> Optional[bool]:
+    """Whether process ``pid`` exists: True, False, or None when this
+    platform cannot tell. POSIX only -- on Windows ``os.kill`` terminates.
+    Signal 0 sends nothing; EPERM (the display runs as root, the web
+    interface does not) still means the process is there."""
+    if os.name != "posix" or pid <= 0:
+        return None
+    try:
+        os.kill(pid, 0)
+    except ProcessLookupError:
+        return False
+    except PermissionError:
+        return True
+    except OSError:
+        return None
+    return True
+
+
+def view_from_snapshot(snapshot: Any, now: Optional[float] = None,
+                       heartbeat: Any = None,
+                       now_mono: Optional[float] = None,
+                       process_alive: Optional[Callable[[int], Optional[bool]]] = None,
+                       ) -> PluginRuntimeView:
+    """Judge a snapshot read from the cache; never raises.
+
+    ``heartbeat`` is the render loop's heartbeat
+    (``display_watchdog.read_heartbeat()``), or None when there is none. A
+    live snapshot whose process's heartbeat is at least
+    ``display_watchdog.HEARTBEAT_STALE_SECONDS`` old is ``stalled``: the
+    threshold /api/v3/health uses for ``checks.display_loop``.
+    ``process_alive`` (``process_exists`` when reading the real cache) says
+    whether the snapshot's publisher still exists; a running snapshot from
+    one that is gone is ``stale``.
+    """
     if not isinstance(snapshot, dict) or snapshot.get("schema") != SNAPSHOT_SCHEMA:
         return PluginRuntimeView(status=UNKNOWN)
     published_at = _epoch(snapshot.get("published_at"))
@@ -351,21 +426,34 @@ def view_from_snapshot(snapshot: Any, now: Optional[float] = None) -> PluginRunt
     if age > stale_after or age < -stale_after:
         return PluginRuntimeView(status=STALE, published_at=published_at,
                                  age_seconds=age, stale_after=stale_after)
+    pid = snapshot.get("pid")
+    if (process_alive is not None and isinstance(pid, int) and not isinstance(pid, bool)
+            and process_alive(pid) is False):
+        return PluginRuntimeView(status=STALE, published_at=published_at,
+                                 age_seconds=max(age, 0.0), stale_after=stale_after)
+    beat_age = _heartbeat_age_for(snapshot, heartbeat, now_mono)
+    if beat_age is not None and beat_age >= display_watchdog.HEARTBEAT_STALE_SECONDS:
+        return PluginRuntimeView(status=STALLED, published_at=published_at,
+                                 age_seconds=max(age, 0.0), stale_after=stale_after,
+                                 heartbeat_age_seconds=beat_age)
     plugins = snapshot.get("plugins")
     return PluginRuntimeView(
         status=LIVE, published_at=published_at, age_seconds=max(age, 0.0),
-        stale_after=stale_after,
+        stale_after=stale_after, heartbeat_age_seconds=beat_age,
         plugins={k: v for k, v in plugins.items() if isinstance(v, dict)}
         if isinstance(plugins, dict) else {},
     )
 
 
-def read_plugin_runtime(cache_manager: Any, now: Optional[float] = None) -> PluginRuntimeView:
-    """The display's latest snapshot, judged for staleness. Never raises; a
-    missing cache manager or an unreadable snapshot is ``unknown``.
+def read_plugin_runtime(cache_manager: Any, now: Optional[float] = None,
+                        heartbeat_path: Optional[str] = None) -> PluginRuntimeView:
+    """The display's latest snapshot, judged for staleness and against the
+    render loop's heartbeat. Never raises; a missing cache manager or an
+    unreadable snapshot is ``unknown``.
 
     memory_ttl=0: the key is written by the other process, so only the file
-    is current.
+    is current. ``heartbeat_path`` defaults to
+    ``display_watchdog.HEARTBEAT_PATH``.
     """
     if cache_manager is None:
         return PluginRuntimeView(status=UNKNOWN)
@@ -374,4 +462,11 @@ def read_plugin_runtime(cache_manager: Any, now: Optional[float] = None) -> Plug
     except Exception as err:
         logger.debug("Could not read the plugin runtime snapshot: %s", err, exc_info=True)
         return PluginRuntimeView(status=UNKNOWN)
-    return view_from_snapshot(snapshot, now=now)
+    try:
+        heartbeat = display_watchdog.read_heartbeat(
+            heartbeat_path or display_watchdog.HEARTBEAT_PATH)
+    except Exception as err:  # read_heartbeat does not raise; belt and braces
+        logger.debug("Could not read the display heartbeat: %s", err, exc_info=True)
+        heartbeat = None
+    return view_from_snapshot(snapshot, now=now, heartbeat=heartbeat,
+                              process_alive=process_exists)

test/test_display_controller_shutdown_and_state.py

@@ -3,6 +3,8 @@
 - systemd stops the service with SIGTERM; it must run the same cleanup as Ctrl-C.
 - The current mode is republished while it stays on screen, so the web UI's
   "Now showing" does not turn into "unknown" after its 120 s max_age.
+- Waking from scheduled-off, blanking, or on-demand starting or ending with
+  the mode name unchanged is republished at once, not up to 30 s later.
 - Switching Vegas on in the web UI works when Vegas was off at startup.
 """
 
@@ -78,6 +80,67 @@ def test_unchanged_mode_is_republished_after_the_refresh_interval():
     assert dc.cache_manager.set.call_count == 2
 
 
+def _published(dc):
+    return dc.cache_manager.set.call_args[0][1]
+
+
+@pytest.mark.parametrize("attr,before,after", [
+    ("is_display_active", False, True),    # woke from scheduled-off
+    ("is_display_active", True, False),    # blanked for scheduled-off
+    ("on_demand_active", False, True),     # on-demand started on this mode
+    ("on_demand_active", True, False),     # ...and ended on it
+])
+def test_a_flag_change_with_the_same_mode_is_republished_at_once(attr, before, after):
+    """ledpi: current-status showed is_display_active stale for up to 30 s
+    after a wake from scheduled-off, because the mode name had not changed."""
+    dc = _publisher()
+    setattr(dc, attr, before)
+    now = [1000.0]
+    with patch.object(dc_module.time, "monotonic", lambda: now[0]):
+        dc._publish_current_mode_state()            # e.g. the blank's publish
+        assert _published(dc)[attr] is before
+        now[0] += 1                                 # well inside the refresh
+        setattr(dc, attr, after)
+        dc._publish_current_mode_state_if_changed()  # the next publish point
+    assert dc.cache_manager.set.call_count == 2
+    assert _published(dc)[attr] is after
+    assert _published(dc)["mode"] == "mlb_live"
+
+
+def test_wake_inside_the_blank_sleep_is_published_by_the_service_helper():
+    """The blank sleeps through _service_pending_changes; the schedule turning
+    the display back on there reaches the web UI on that same call."""
+    dc = _publisher()
+    dc.is_display_active = False
+    dc._last_pending_service = None
+    dc.PENDING_CHANGES_INTERVAL = 0.25
+    for name in ("_poll_on_demand_requests", "_check_on_demand_expiration",
+                 "_apply_brightness_target"):
+        setattr(dc, name, MagicMock())
+
+    def wake():
+        dc.is_display_active = True
+    dc._evaluate_schedule = MagicMock(side_effect=wake)
+    now = [5000.0]
+    with patch.object(dc_module.time, "monotonic", lambda: now[0]):
+        dc._publish_current_mode_state()            # published while blank
+        now[0] += 2
+        dc._service_pending_changes()
+    assert dc.cache_manager.set.call_count == 2
+    assert _published(dc)["is_display_active"] is True
+
+
+def test_unchanged_flags_do_not_add_writes():
+    dc = _publisher()
+    now = [1000.0]
+    with patch.object(dc_module.time, "monotonic", lambda: now[0]):
+        dc._publish_current_mode_state_if_changed()
+        for _ in range(5):
+            now[0] += 1
+            dc._publish_current_mode_state_if_changed()
+    assert dc.cache_manager.set.call_count == 1
+
+
 def test_refresh_interval_is_well_inside_the_web_max_age():
     # api_v3/display.py reads display_current_state with max_age=120.
     assert dc_module.CURRENT_STATE_REFRESH_SECONDS < 120 / 2