diff --git a/CHANGELOG.md b/CHANGELOG.md index 1e00516b..3c8e4ff3 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -93,6 +93,14 @@ policies are unchanged. the plugin leaves rotation until the cooldown ends, the same as a raising `update()`. The display still moves straight on to the next mode. A hung `display()` is still recorded once, as a hang. +- A WiFi notice (such as "Connected to HomeNet" or "AP mode on") now shows + within about a second of being posted. It was only checked between + screens, so a 5 s notice posted during a 20 s screen expired before that + screen ended and never appeared. The screen it interrupts comes back in + full once the notice ends. When Vegas stops scrolling for a notice, the + notice is what shows next, and Vegas resumes after it; before, a rotation + screen showed instead and the notice expired behind it. An active + on-demand session still holds the panel until it ends. ## 3.8.0 diff --git a/docs/RUN_LOOP_REDESIGN.md b/docs/RUN_LOOP_REDESIGN.md index 0b8ee2c4..dafe3f19 100644 --- a/docs/RUN_LOOP_REDESIGN.md +++ b/docs/RUN_LOOP_REDESIGN.md @@ -41,12 +41,16 @@ Each pass, in order: brightness target. 4. **Scheduled off:** blank, dwell up to 60 s. `_blank_while_scheduled_off` 5. **Follower:** render one frame from the leader. `_run_follower_frame` -6. **WiFi notice** (unless on-demand): draw it, dwell 0.5 s. `_show_wifi_notice` +6. **WiFi notice** (unless on-demand): draw it, dwell 0.5 s. `_show_wifi_notice`. + It is also polled mid-screen (`_wifi_notice_pending`): the frame loops, + the dwell sleep and an interrupted Vegas iteration end within about a + second when one arrives, and a screen cut short resumes after it. 7. **Live priority** (unless on-demand, or Vegas keeps live content in the ticker): switch to the next live mode, or resume the rotation. 8. **Vegas** (unless on-demand, or live content preempts it): run one iteration of up to `max_cycle_duration`. A completed iteration ends the - pass. An interrupted one falls through to step 9 in the same pass. + pass, and so does one that yielded for a WiFi notice or the schedule. + Any other interrupted one falls through to step 9 in the same pass. 9. **One screen:** pick the mode (`_resolve_active_mode`), the plugin (`_plugin_for_mode`), draw the first frame through the executor (`_dispatch_first_frame`). On no content, rotate at once @@ -192,8 +196,8 @@ that the harness patches in today. WiFi message, schedule state) are collected first, so `decide()` stays pure. 3. Unit-test `decide()` with tables. The golden traces must not change. - This includes the missed WiFi notice described below: fixing it is a - separate PR. + The Wifi Source must keep the mid-screen preemption described in step 6 + of "What `run()` does today". Follower and Wifi go first because each is one self-contained branch that ends the pass. They prove the plumbing without touching the frame loops. @@ -254,20 +258,14 @@ These are recorded as they are today. Each one should be fixed in its own PR, which updates the affected trace and explains why. None of them is changed by the restructure. -1. **A WiFi notice is only checked between screens.** A 5 s notice posted - during a 20 s screen expires before the screen ends and is never shown - (`wifi_notice`, t=25). -2. **Vegas yields to a WiFi notice, then shows a rotation screen instead of - the notice.** An interrupted iteration falls through to step 9 in the - same pass, and the notice has expired by the next pass (`vegas`, t=200). -3. **Vegas yields to live content, then shows a rotation screen first.** +1. **Vegas yields to live content, then shows a rotation screen first.** The live game appears one screen later (`vegas`, t=70-90). -4. **Live priority only takes over between screens.** A game that goes +2. **Live priority only takes over between screens.** A game that goes live mid-screen waits for that screen to end (`live_priority`: live at t=50, shown at t=60). -5. **An on-demand session that expires during scheduled-off keeps the panel +3. **An on-demand session that expires during scheduled-off keeps the panel on** until the next minute boundary, because the schedule check runs at most once a minute (`schedule`, t=190-210). -6. **A schedule window's end minute is inclusive**, and whether the panel +4. **A schedule window's end minute is inclusive**, and whether the panel turns off at the start of that minute or the end depends on when in the minute the first check runs. diff --git a/src/display_controller.py b/src/display_controller.py index 490aed4c..3ebb108c 100644 --- a/src/display_controller.py +++ b/src/display_controller.py @@ -1144,9 +1144,10 @@ class DisplayController: Also services pending changes (see _service_pending_changes), and returns early when one of them changes what the panel should show -- - an on-demand start or stop, or the display schedule turning the panel - on or off -- so the caller can act on it instead of finishing a dwell - that could be a minute long (sixty seconds while scheduled off). + an on-demand start or stop, the display schedule turning the panel + on or off, or a WiFi notice arriving -- so the caller can act on it + instead of finishing a dwell that could be a minute long (sixty + seconds while scheduled off). """ if duration <= 0: return @@ -1156,6 +1157,9 @@ class DisplayController: mode = self.current_display_mode display_active = self.is_display_active on_demand = self.on_demand_active + # Edge-triggered: the notice's own dwell starts with it pending and + # must not cut itself short; any other dwell ends when one arrives. + wifi_pending = self._wifi_notice_pending() while True: remaining = end_time - time.time() @@ -1171,7 +1175,9 @@ class DisplayController: self._service_pending_changes() if (self.current_display_mode != mode or self.is_display_active != display_active - or self.on_demand_active != on_demand): + or self.on_demand_active != on_demand + or (not wifi_pending and self.is_display_active + and self._wifi_notice_pending())): break def _note_empty_pass(self) -> None: @@ -2427,6 +2433,22 @@ class DisplayController: self._sleep_with_plugin_updates(0.5) return True + def _wifi_notice_pending(self) -> bool: + """True when a WiFi notice is waiting that _show_wifi_notice would draw. + + Polled from the frame loops, the dwell sleep and after a Vegas + iteration yields, so a notice preempts whatever is on the panel + within about a second instead of waiting for the screen to end -- + by which time a short notice has usually expired unseen. Cheap at + frame rate: _check_wifi_status_message stats the file at most once + a second. On-demand outranks the notice, as in _show_wifi_notice. + """ + if self.on_demand_active: + return False + status = self._check_wifi_status_message() + # The 1 s throttle can hand back a result that has expired since. + return bool(status) and time.time() < status['expires_at'] + def _resolve_active_mode(self): """The mode this pass shows: the on-demand session's current mode while one is active, else the rotation's. @@ -2990,6 +3012,11 @@ class DisplayController: # Scheduled off mid-iteration: blank the # panel now rather than render a screen. continue + if self._wifi_notice_pending(): + # It yielded for a WiFi notice: the next + # pass shows it, not a rotation screen + # that would outlast a short notice. + continue except Exception: logger.exception("Vegas mode error") # Fall through to normal rotation on error @@ -3160,7 +3187,8 @@ class DisplayController: time.sleep(_remaining if _remaining > 0 else 0.001) if (self.current_display_mode != active_mode - or not self.is_display_active): + or not self.is_display_active + or self._wifi_notice_pending()): logger.debug("Mode changed during high-FPS loop, breaking early") break @@ -3223,7 +3251,8 @@ class DisplayController: self._service_pending_changes() if (self.current_display_mode != active_mode - or not self.is_display_active): + or not self.is_display_active + or self._wifi_notice_pending()): logger.info("Mode changed during display loop from %s to %s, breaking early", active_mode, self.current_display_mode) break @@ -3246,9 +3275,12 @@ class DisplayController: # _activate_on_demand already sets force_change=True and clears the # display, so the next loop iteration renders the new mode immediately. # Likewise if the schedule turned the display off - # mid-screen: the next iteration blanks it. + # mid-screen (the next iteration blanks it), or a WiFi + # notice arrived (the next iteration shows it, then this + # mode resumes rather than rotating past it). if (self.current_display_mode != active_mode - or not self.is_display_active): + or not self.is_display_active + or (not loop_completed and self._wifi_notice_pending())): continue # Ensure we honour minimum duration when not dynamic and loop ended early @@ -3261,6 +3293,11 @@ class DisplayController: remaining_sleep = max(0.0, max_duration - elapsed) if remaining_sleep > 0: self._sleep_with_plugin_updates(remaining_sleep) + # Cut short by a WiFi notice: show it, then + # resume this mode rather than rotating past it. + if (self._wifi_notice_pending() + and time.time() - start_time < max_duration): + continue if dynamic_enabled: elapsed_total = time.time() - start_time diff --git a/test/_run_loop_harness.py b/test/_run_loop_harness.py index c2684885..79f89eef 100644 --- a/test/_run_loop_harness.py +++ b/test/_run_loop_harness.py @@ -766,7 +766,14 @@ def reduce_trace(events, horizon: float) -> Dict[str, Any]: rows = [] for i, screen in enumerate(screens): end = screens[i + 1]["t"] if i + 1 < len(screens) else horizon - exit_reason = screen["exit"] or ("horizon" if i + 1 == len(screens) else "duration") + nxt = screens[i + 1] if i + 1 < len(screens) else None + # A WiFi notice logs no event at the moment it takes the panel (the + # file is written earlier), so a screen followed by one is labelled + # "wifi". Its duration column shows whether it was cut short. + exit_reason = screen["exit"] or ( + "horizon" if nxt is None + else "wifi" if nxt["mode"] == "" and screen["mode"] != "" + else "duration") rows.append([screen["t"], screen["mode"], round(end - screen["t"], 3), exit_reason, screen["frames"], screen["clear"]]) return {"screens": rows, "events": notable} diff --git a/test/fixtures/run_loop_golden/vegas.json b/test/fixtures/run_loop_golden/vegas.json index 468c89f6..4508a713 100644 --- a/test/fixtures/run_loop_golden/vegas.json +++ b/test/fixtures/run_loop_golden/vegas.json @@ -10,9 +10,9 @@ [150.263, "clock", 20.0, "duration", 20, true], [170.263, "clock", 5.0, "on-demand-expired", 5, true], [175.263, "", 24.959, "vegas-interrupt", 3120, null], - [200.222, "clock", 20.0, "duration", 20, true], - [220.222, "", 30.008, "duration", 3751, null], - [250.23, "", 9.77, "horizon", 1222, null] + [200.222, "", 3.0, "duration", 6, null], + [203.222, "", 30.008, "duration", 3751, null], + [233.23, "", 26.77, "horizon", 3347, null] ], "events": [ [70.255, "vegas-live"], diff --git a/test/fixtures/run_loop_golden/wifi_notice.json b/test/fixtures/run_loop_golden/wifi_notice.json index 7349b9f7..e2e7184a 100644 --- a/test/fixtures/run_loop_golden/wifi_notice.json +++ b/test/fixtures/run_loop_golden/wifi_notice.json @@ -1,13 +1,15 @@ { "screens": [ [0.0, "clock", 20.0, "duration", 20, false], - [20.0, "weather", 20.0, "duration", 20, true], - [40.0, "clock", 20.0, "on-demand-start", 20, true], - [60.0, "clock", 20.0, "on-demand-expired", 20, true], + [20.0, "weather", 5.0, "wifi", 6, true], + [25.0, "", 5.0, "duration", 10, null], + [30.0, "weather", 20.0, "duration", 20, true], + [50.0, "clock", 20.0, "on-demand-start", 20, true], + [70.0, "clock", 10.0, "on-demand-expired", 10, true], [80.0, "", 15.0, "duration", 30, null], - [95.0, "weather", 20.0, "duration", 20, true], - [115.0, "clock", 20.0, "duration", 20, true], - [135.0, "weather", 15.0, "horizon", 15, true] + [95.0, "clock", 20.0, "duration", 20, true], + [115.0, "weather", 20.0, "duration", 20, true], + [135.0, "clock", 15.0, "horizon", 15, true] ], "events": [ [25.0, "wifi-file", "Connected to HomeNet"], diff --git a/test/test_run_loop_golden.py b/test/test_run_loop_golden.py index d0b06c22..db3a34eb 100644 --- a/test/test_run_loop_golden.py +++ b/test/test_run_loop_golden.py @@ -148,8 +148,8 @@ def scenario_schedule(h: RunLoopHarness): def scenario_wifi_notice(h: RunLoopHarness): h.add_plugin(FakePlugin("clock", ["clock"], duration=20)) h.add_plugin(FakePlugin("weather", ["weather"], duration=20)) - # Posted mid-screen and expired before the screen ends: never shown, - # because the notice is only checked between screens. + # Posted mid-screen: it preempts the screen at its next frame, stays up + # until it expires, and the interrupted mode then comes back in full. h.wifi_message(25, "Connected to HomeNet", duration=5) # While on-demand is active the notice waits. h.on_demand_request(60, "w1", plugin_id="clock", duration=20) diff --git a/test/test_wifi_notice_preemption.py b/test/test_wifi_notice_preemption.py new file mode 100644 index 00000000..f854a35a --- /dev/null +++ b/test/test_wifi_notice_preemption.py @@ -0,0 +1,130 @@ +"""A WiFi notice preempts the current screen promptly and stays up. + +It used to be checked only between screens, so a notice shorter than the +screen it was posted during expired unseen, and Vegas yielding for one went +on to a rotation screen instead of the notice. Runs the real run() loop on +the fake clock of test/_run_loop_harness.py. +""" + +import os + +os.environ.setdefault("EMULATOR", "true") + +from test._run_loop_harness import FakePlugin, RunLoopHarness # noqa: E402 + + +def _rows(trace): + return [tuple(row[:4]) for row in trace["screens"]] + + +def _wifi_rows(trace): + return [row for row in trace["screens"] if row[1] == ""] + + +def test_notice_preempts_a_static_screen_and_the_mode_resumes(tmp_path): + h = RunLoopHarness(tmp_path, horizon=70) + h.add_plugin(FakePlugin("clock", ["clock"], duration=20)) + h.add_plugin(FakePlugin("weather", ["weather"], duration=20)) + h.wifi_message(25.3, "Connected to HomeNet", duration=5) + trace = h.run() + + (wifi,) = _wifi_rows(trace) + # Within about a second of being posted (the 1 Hz loop's next frame), + # and up until it expires at 30.3. + assert 25.3 <= wifi[0] <= 26.3 + assert wifi[0] + wifi[2] >= 30.3 + rows = _rows(trace) + i = rows.index(tuple(wifi[:4])) + assert rows[i - 1][1] == "weather" and rows[i - 1][3] == "wifi" + # The interrupted screen comes back in full; the rotation is not skipped. + assert rows[i + 1][1:3] == ("weather", 20.0) + assert rows[i + 2][1] == "clock" + + +def test_notice_preempts_a_high_fps_screen(tmp_path): + h = RunLoopHarness(tmp_path, horizon=60) + h.add_plugin(FakePlugin("ticker", ["ticker"], duration=30, enable_scrolling=True)) + h.add_plugin(FakePlugin("clock", ["clock"], duration=20)) + h.wifi_message(10.0, "AP mode on", duration=4) + trace = h.run() + + (wifi,) = _wifi_rows(trace) + assert 10.0 <= wifi[0] <= 11.0 + assert wifi[0] + wifi[2] >= 14.0 + assert trace["screens"][0][1:4] == ["ticker", wifi[0], "wifi"] + + +def test_notice_cuts_the_make_up_dwell_short(tmp_path): + # flaky returns False after its first frame, so the rest of its screen + # is a make-up dwell rather than a frame loop. + h = RunLoopHarness(tmp_path, horizon=40) + h.add_plugin(FakePlugin("flaky", ["flaky"], duration=20, first_frame_only=True)) + h.add_plugin(FakePlugin("clock", ["clock"], duration=20)) + h.wifi_message(8.0, "Connected to HomeNet", duration=5) + trace = h.run() + + (wifi,) = _wifi_rows(trace) + assert 8.0 <= wifi[0] <= 9.0 + assert wifi[0] + wifi[2] >= 13.0 + rows = _rows(trace) + i = rows.index(tuple(wifi[:4])) + # flaky was cut short, so it comes back rather than being rotated past. + assert rows[i + 1][1] == "flaky" + + +def test_a_screen_that_ran_its_full_time_is_not_repeated(tmp_path): + # Posted just before clock's 20 s are up: clock ends on time, the notice + # shows, and the rotation moves on to weather rather than clock again. + h = RunLoopHarness(tmp_path, horizon=50) + h.add_plugin(FakePlugin("clock", ["clock"], duration=20)) + h.add_plugin(FakePlugin("weather", ["weather"], duration=20)) + h.wifi_message(19.5, "Connected to HomeNet", duration=5) + trace = h.run() + + rows = _rows(trace) + assert rows[0] == (0.0, "clock", 20.0, "wifi") + assert rows[1][1] == "" + assert rows[2][1] == "weather" + + +def test_on_demand_still_outranks_the_notice(tmp_path): + h = RunLoopHarness(tmp_path, horizon=80) + h.add_plugin(FakePlugin("clock", ["clock"], duration=20)) + h.add_plugin(FakePlugin("weather", ["weather"], duration=20)) + h.on_demand_request(5, "o1", plugin_id="weather", duration=30) + h.wifi_message(15, "AP mode on", duration=30) + trace = h.run() + + (wifi,) = _wifi_rows(trace) + # Held back until the on-demand session expires at about t=35. + assert wifi[0] >= 35.0 + on_demand = [r for r in trace["screens"] if r[1] == "weather" and r[0] < 35] + assert on_demand and all(r[3] != "wifi" for r in on_demand[:-1]) + + +def test_vegas_yields_to_the_notice_then_resumes(tmp_path): + h = RunLoopHarness(tmp_path, horizon=80) + h.add_plugin(FakePlugin("clock", ["clock"], duration=20)) + h.enable_vegas(cycle=30) + h.wifi_message(40, "Connected to HomeNet", duration=3) + trace = h.run() + + rows = _rows(trace) + i = next(n for n, row in enumerate(rows) if row[3] == "vegas-interrupt") + assert rows[i][1] == "" and 40.0 <= rows[i][0] + rows[i][2] <= 41.0 + # The notice is what shows next, for its whole 3 s, and Vegas follows. + assert rows[i + 1][1] == "" + assert rows[i + 1][0] + rows[i + 1][2] >= 43.0 + assert rows[i + 2][1] == "" + assert "clock" not in [row[1] for row in rows[i:]] + + +def test_pending_check_ignores_a_cached_notice_that_has_expired(tmp_path): + h = RunLoopHarness(tmp_path, horizon=10) + dc = h.controller + dc._check_wifi_status_message = lambda: {"message": "x", "expires_at": 0.0} + assert not dc._wifi_notice_pending() + dc._check_wifi_status_message = lambda: {"message": "x", "expires_at": float("inf")} + assert dc._wifi_notice_pending() + dc.on_demand_active = True + assert not dc._wifi_notice_pending()