fix(on-demand): show a named live mode; end a session that cannot resume

CHANGELOG.md

@@ -505,6 +505,26 @@ policies are unchanged.
   stored `ttl` was stretched the same way. A memory hit is now also checked against
   the record's own timestamp, and a stale one falls through to disk, which
   returns a newer write if there is one.
+- An on-demand request that names a `*_live` mode now shows that mode. On
+  ledpi, `{"plugin_id": "football-scoreboard", "mode": "ncaa_fb_live"}` with
+  15 college games on answered 200 and showed `nfl_recent`. The session's
+  mode list kept a live mode only when the plugin's `has_live_content()`
+  said so. That method answers the live-priority question, and the sports
+  plugins answer it for favourite teams only. A mode the request names
+  (not one resolved from a bare plugin id) now leads the session, with the
+  plugin's other modes after it. If it has nothing to draw, the session
+  moves on to the next of those modes, like any empty on-demand mode. The
+  name is saved with the session (`named_mode` in
+  `display_on_demand_config`), so a restart resumes on it.
+- A restart during an on-demand session whose plugin then fails to load no
+  longer leaves a session with no modes. On ledpi, `clock-simple` failed
+  config validation after a crash. The display logged `No valid display
+  modes found for on-demand plugin 'clock-simple' after restoration` and
+  kept reporting the session as active until its first pass ended it as
+  `idle`. The cached request stayed behind for the next restart. The session
+  now ends at startup with status `error` and error `restore-failed`, which
+  `/display/on-demand/status` reports, and the cached request is dropped. The
+  same applies when the plugin system itself fails to start.
 - The garbage-collection timer (`GcMonitor`, above) no longer prints
   `Exception ignored while calling GC callback ... 'NoneType' object has no
   attribute 'perf_counter'` when the display service or a test run exits.

docs/RUN_LOOP_REDESIGN.md

@@ -181,13 +181,14 @@ that the harness patches in today.
   - dynamic duration (cycle complete, plugin cap, global cap)
   - live priority taking over and handing back; live round-robin
   - on-demand start/stop/expiry; pinned on-demand; a session resumed after
-    a restart
+    a restart, and one that cannot resume (its plugin did not load); a
+    request naming a live mode the plugin's live check would drop
   - schedule off and dim, with an on-demand override during downtime
   - WiFi notice; sync follower
   - Vegas, with and without `live_in_ticker`
 - Each trace row is `[start, mode, duration, exit_reason, frames,
   force_clear]`. The exit reason is the event that decided what came next.
-- All 16 tests run in under a second. The goldens were generated from
+- All 18 tests run in under a second. The goldens were generated from
   main's `run()` before any code moved.
 - Vegas uses `FakeVegas`, which implements only the contract the controller
   depends on: `run_iteration()` returns True after its duration and False

src/display_controller.py

@@ -368,6 +368,10 @@ def _follower_gated_update():
         self.on_demand_last_error: Optional[str] = None
         self.on_demand_last_event: Optional[str] = None
         self.on_demand_schedule_override = False
+        # The mode the request named, when it named one (not a mode resolved
+        # from a bare plugin id). Shown even when the plugin's live checks
+        # would leave it out of the session (_on_demand_modes_for_plugin).
+        self._on_demand_named_mode: Optional[str] = None
         # Plugins that are disabled in config and loaded only because an
         # on-demand request named them. The main loop unloads each one once
         # on-demand has moved off it (_release_on_demand_plugins).
@@ -561,6 +565,17 @@ def load_single_plugin(plugin_id):
         except Exception:  # pylint: disable=broad-except
             logger.exception("Plugin system initialization failed")
             self.plugin_manager = None
+            # A restored session has no plugin to resume on. It may have been
+            # read already (on_demand_active) or not yet, if initialization
+            # failed before the restore ran; either way, end it visibly.
+            try:
+                cached_session = self.cache_manager.get('display_on_demand_config',
+                                                        max_age=3600)
+            except Exception:  # pylint: disable=broad-except
+                cached_session = None
+            if self.on_demand_active or cached_session:
+                self.cache_manager.clear_cache('display_on_demand_config')
+                self._set_on_demand_error('restore-failed')
             # Its state machine no longer describes what runs; let the last
             # snapshot go stale (readers then say unknown) rather than keep
             # refreshing it.
@@ -1665,6 +1680,7 @@ def _reset_on_demand_fields(self) -> None:
         self.on_demand_expires_at = None
         self.on_demand_pinned = False
         self.on_demand_schedule_override = False
+        self._on_demand_named_mode = None
         # While the session ran, _evaluate_schedule may have forced
         # is_display_active on over a scheduled-off answer. Drop the minute
         # gate so the next _check_schedule recomputes it; otherwise the panel
@@ -1831,6 +1847,7 @@ def _select_startup_plugins(self, discovered_plugins: List[str],
         self.on_demand_pinned = on_demand_config.get('pinned', False)
         self.on_demand_requested_at = on_demand_config.get('requested_at')
         self.on_demand_expires_at = on_demand_config.get('expires_at')
+        self._on_demand_named_mode = on_demand_config.get('named_mode')
         self.on_demand_status = 'active'
         self.on_demand_schedule_override = True
         logger.info("On-demand mode detected during initialization: resuming on plugin '%s'; "
@@ -2317,13 +2334,25 @@ def _resolve_mode_for_plugin(self, plugin_id: Optional[str], mode: Optional[str]
                 return modes[0]
         return plugin_id
 
-    def _on_demand_modes_for_plugin(self, plugin_id: str) -> List[str]:
+    def _on_demand_modes_for_plugin(self, plugin_id: str,
+                                    named_mode: Optional[str] = None) -> List[str]:
         """Every loaded display mode belonging to `plugin_id`, in rotation order.
 
         Live modes that actually have content lead, then the rest, then live
         modes with nothing to show -- so an on-demand request for a sports
         plugin opens on a game in progress rather than an empty live screen.
         Returns an empty list when the plugin has no loaded modes.
+
+        `named_mode` is a mode the request asked for by name. It is always
+        in the list, first when the checks below would have dropped it.
+        Those checks ask has_live_content(), which is the live-priority
+        question -- "should this plugin take the panel from the rotation?"
+        -- and the sports plugins answer it for favourite teams only. Asking
+        for ncaa_fb_live with fifteen games on and no favourite playing got
+        a 200 and nfl_recent on the panel. The plugin's display() is what
+        knows whether the mode has anything to draw; when it has not, the
+        session moves to the plugin's next mode like any empty on-demand
+        mode.
         """
         plugin_modes = self.plugin_display_modes.get(plugin_id, [])
         if not plugin_modes:
@@ -2364,6 +2393,15 @@ def _on_demand_modes_for_plugin(self, plugin_id: str) -> List[str]:
             # Only live modes available but no content - use them anyway
             ordered_modes = live_modes
 
+        if named_mode and named_mode in available_plugin_modes:
+            # The named mode leads whether or not the live check kept it: a
+            # second live mode with content is already in the list, but behind
+            # the first, so the session would rotate away before reaching it.
+            if named_mode not in ordered_modes:
+                logger.info("On-demand: showing %s as requested; plugin '%s' reports no "
+                            "live-priority content for it", named_mode, plugin_id)
+            ordered_modes = [named_mode] + [m for m in ordered_modes if m != named_mode]
+
         return ordered_modes
 
     def _apply_on_demand_pin(self, ordered_modes: List[str], resolved_mode: Optional[str],
@@ -2392,10 +2430,20 @@ def _populate_on_demand_modes_from_plugin(self) -> None:
 
         plugin_id = self.on_demand_plugin_id
 
-        ordered_modes = self._on_demand_modes_for_plugin(plugin_id)
+        ordered_modes = self._on_demand_modes_for_plugin(plugin_id, self._on_demand_named_mode)
         if not ordered_modes:
-            logger.warning("No valid display modes found for on-demand plugin '%s' after restoration", plugin_id)
-            self.on_demand_modes = []
+            # The plugin did not load this time (seen on a rig: its config
+            # failed validation after the crash that caused the restart), so
+            # there is nothing to resume. Leaving the session active with no
+            # modes published it as active for a plugin that was not running
+            # until the first pass ended it as an ordinary 'idle', and kept
+            # the cached request for the next restart to trip over. End it
+            # as a failure the status endpoint reports, and drop the cache.
+            logger.error("On-demand session for plugin '%s' cannot resume after the "
+                         "restart: the plugin has no loaded display modes (did it "
+                         "fail to load?); ending it", plugin_id)
+            self.cache_manager.clear_cache('display_on_demand_config')
+            self._set_on_demand_error('restore-failed')
             return
 
         # A restart must not silently un-pin: the pin is part of the request
@@ -2596,7 +2644,10 @@ def _activate_on_demand(self, request: Dict[str, Any]) -> None:
         if resolved_mode in self.available_modes:
             self.current_mode_index = self.available_modes.index(resolved_mode)
 
-        ordered_modes = self._on_demand_modes_for_plugin(resolved_plugin_id)
+        # Named: the request gave this mode itself, rather than a plugin id
+        # (or a mode the plugin doesn't have) that resolved to a default.
+        named_mode = resolved_mode if mode == resolved_mode else None
+        ordered_modes = self._on_demand_modes_for_plugin(resolved_plugin_id, named_mode)
         if not ordered_modes:
             logger.error("No valid display modes found for plugin '%s'", resolved_plugin_id)
             self._set_on_demand_error("no-modes")
@@ -2613,6 +2664,7 @@ def _activate_on_demand(self, request: Dict[str, Any]) -> None:
         self.on_demand_requested_at = now
         self.on_demand_expires_at = (now + duration) if duration else None
         self.on_demand_pinned = pinned
+        self._on_demand_named_mode = named_mode
         self.on_demand_status = 'active'
         self.on_demand_last_error = None
         self.on_demand_last_event = 'started'
@@ -2641,6 +2693,7 @@ def _activate_on_demand(self, request: Dict[str, Any]) -> None:
             'mode': resolved_mode,
             'duration': duration,
             'pinned': pinned,
+            'named_mode': named_mode,
             'requested_at': now,
             'expires_at': self.on_demand_expires_at
         }

test/_run_loop_harness.py

@@ -724,11 +724,14 @@ def post():
         self.clock.at(t, post)
 
     def restore_on_demand(self, plugin_id: str, mode: Optional[str] = None,
-                          duration: Optional[float] = None, pinned: bool = False):
+                          duration: Optional[float] = None, pinned: bool = False,
+                          named_mode: Optional[str] = None):
         """Start with an on-demand session resumed from the cache, as after
         a restart: the state _select_startup_plugins restores, then
-        _populate_on_demand_modes_from_plugin, as __init__ calls it."""
+        _populate_on_demand_modes_from_plugin, as __init__ calls it. A
+        session that cannot resume is logged as ``on-demand-error``."""
         dc = self.controller
+        dc._on_demand_named_mode = named_mode
         dc.on_demand_active = True
         dc.on_demand_plugin_id = plugin_id
         dc.on_demand_mode = mode
@@ -739,6 +742,8 @@ def restore_on_demand(self, plugin_id: str, mode: Optional[str] = None,
         dc.on_demand_status = 'active'
         dc.on_demand_schedule_override = True
         dc._populate_on_demand_modes_from_plugin()
+        if dc.on_demand_status == 'error':
+            self.log("on-demand-error", dc.on_demand_last_error)
 
     def wifi_message(self, t: float, message: str, duration: float = 5):
         def write():

test/fixtures/run_loop_golden/on_demand_named_live.json

@@ -0,0 +1,29 @@
+{
+  "screens": [
+    [0.0, "clock", 5.0, "on-demand-start", 6, false],
+    [5.0, "sports_live", 15.0, "duration", 15, true],
+    [20.0, "sports_recent", 15.0, "duration", 15, true],
+    [35.0, "sports_upcoming", 5.0, "on-demand-requested-stop", 6, true],
+    [40.0, "clock", 20.0, "duration", 20, true],
+    [60.0, "sports_live", 15.0, "display-false", 11, true],
+    [75.0, "sports_recent", 15.0, "duration", 15, true],
+    [90.0, "sports_upcoming", 10.0, "on-demand-start", 11, true],
+    [100.0, "sports_live", 0.0, "empty", 1, true],
+    [100.0, "sports_recent", 15.0, "duration", 15, true],
+    [115.0, "sports_upcoming", 15.0, "duration", 15, true],
+    [130.0, "sports_live", 0.0, "empty", 1, true],
+    [130.0, "sports_recent", 10.0, "on-demand-requested-stop", 11, true],
+    [140.0, "sports_upcoming", 15.0, "duration", 15, true],
+    [155.0, "clock", 5.0, "horizon", 5, true]
+  ],
+  "events": [
+    [5.0, "request", "start:n1"],
+    [5.0, "on-demand-start", "sports"],
+    [40.0, "request", "stop:n2"],
+    [40.0, "on-demand-requested-stop"],
+    [100.0, "request", "start:n3"],
+    [100.0, "on-demand-start", "sports"],
+    [140.0, "request", "stop:n4"],
+    [140.0, "on-demand-requested-stop"]
+  ]
+}

test/fixtures/run_loop_golden/on_demand_restore_failed.json

@@ -0,0 +1,10 @@
+{
+  "screens": [
+    [0.0, "clock", 20.0, "duration", 20, false],
+    [20.0, "weather", 20.0, "duration", 20, true],
+    [40.0, "clock", 20.0, "horizon", 20, true]
+  ],
+  "events": [
+    [0.0, "on-demand-error", "restore-failed"]
+  ]
+}