mirror of
https://github.com/ChuckBuilds/LEDMatrix.git
synced 2026-10-04 06:15:09 +00:00
fix(display): a raising display() counts as a circuit-breaker failure (#707)
The first-frame dispatch (_dispatch_first_frame) now asks PluginExecutor.execute_display() to re-raise (raise_errors=True) and records a raise inside the executor as a breaker failure, with the original exception as last_error, instead of a success. The screen is still an empty pass and rotation is unchanged; a hung display() is still recorded once, as a hang. The run-loop golden trace plugin_error.json is regenerated (crashy now records health failures and is skipped by the breaker), and behaviour 7 is dropped from docs/RUN_LOOP_REDESIGN.md. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
@@ -36,6 +36,18 @@ accepts both, but the store flags the old spelling as deprecated
|
||||
`_needs_high_fps`, `_advance_after_screen` and others), and the traces are
|
||||
identical before and after the move.
|
||||
|
||||
### Fixes
|
||||
|
||||
- A plugin whose `display()` raises now opens its circuit breaker. The first
|
||||
frame of each screen goes through the plugin executor, which caught the
|
||||
exception and returned False. The display read that as "no content" and
|
||||
recorded a success, which reset the plugin's failure streak, so the breaker
|
||||
never tripped. The plugin stayed in rotation and logged a traceback on
|
||||
every screen. The raise now counts as a failure, so after three in a row
|
||||
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.
|
||||
|
||||
## 3.8.0
|
||||
|
||||
Live Vegas elements: plugin content that keeps changing while it scrolls
|
||||
|
||||
@@ -271,7 +271,3 @@ changed by the restructure.
|
||||
6. **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.
|
||||
7. **A plugin whose `display()` raises inside the executor counts as "no
|
||||
content"**, and the circuit breaker records it as a success, so it never
|
||||
trips (`plugin_error`, `crashy`). Only an exception raised outside the
|
||||
executor counts as a failure.
|
||||
|
||||
@@ -41,6 +41,7 @@ from src.config_service import ConfigService
|
||||
from src.cache_manager import CacheManager
|
||||
from src.font_manager import FontManager
|
||||
from src.logging_config import get_logger
|
||||
from src.exceptions import PluginError
|
||||
from src.common.sync_manager import DisplaySyncManager, SyncRole
|
||||
from src.ipc.server import ControlServer, start_control_server
|
||||
from src.vegas_mode.render_pipeline import SYNC_SEND_INTERVAL
|
||||
@@ -2499,6 +2500,8 @@ class DisplayController:
|
||||
display_lock = pm.get_plugin_lock(plugin_id) if pm else None
|
||||
can_display = display_lock is None or display_lock.acquire(blocking=False)
|
||||
display_hung = False
|
||||
# Set when display() raised inside the executor.
|
||||
display_error: Optional[Exception] = None
|
||||
|
||||
if display_lock is None:
|
||||
# Only when plugin loading failed part-way.
|
||||
@@ -2556,8 +2559,23 @@ class DisplayController:
|
||||
# the SimpleNamespace built above -- a
|
||||
# fresh callable every call, so nothing
|
||||
# there can ever cache.
|
||||
accepts_display_mode=_accepts_display_mode
|
||||
accepts_display_mode=_accepts_display_mode,
|
||||
# A raise must reach the breaker as a
|
||||
# failure. As a bare False it read as
|
||||
# "no content" and was recorded as a
|
||||
# success, so the breaker never tripped
|
||||
# on a plugin that raises every time.
|
||||
raise_errors=True
|
||||
)
|
||||
except PluginError as exc:
|
||||
# display() raised. The executor has logged
|
||||
# and recorded it, and _display_target's
|
||||
# finally released the lock. The screen is
|
||||
# an empty pass, as before; only the health
|
||||
# record changes. Keep what display() raised
|
||||
# as last_error, not the executor's wrapper.
|
||||
display_error = exc.__cause__ or exc
|
||||
result = False
|
||||
except Exception: # pragma: no cover - defensive;
|
||||
# execute_display catches everything
|
||||
# internally, but guarantee the lock is
|
||||
@@ -2589,9 +2607,14 @@ class DisplayController:
|
||||
# frame, not a real success, and must not clear
|
||||
# force_change or the pending mode-switch clear will
|
||||
# be lost when display() finally does run.
|
||||
# A hang was already recorded as a failure by
|
||||
# record_display_hang, so it records nothing here.
|
||||
if can_display:
|
||||
health_tracker = self._health_tracker()
|
||||
if health_tracker is not None and not display_hung:
|
||||
if display_error is not None:
|
||||
health_tracker.record_failure(plugin_id, display_error)
|
||||
else:
|
||||
health_tracker.record_success(plugin_id)
|
||||
self.force_change = False
|
||||
except Exception as exc: # pylint: disable=broad-except
|
||||
|
||||
@@ -173,7 +173,8 @@ class PluginExecutor:
|
||||
force_clear: bool = False,
|
||||
display_mode: Optional[str] = None,
|
||||
timeout: Optional[float] = None,
|
||||
accepts_display_mode: Optional[bool] = None
|
||||
accepts_display_mode: Optional[bool] = None,
|
||||
raise_errors: bool = False
|
||||
) -> bool:
|
||||
"""
|
||||
Execute plugin display() method with error handling.
|
||||
@@ -187,9 +188,18 @@ class PluginExecutor:
|
||||
accepts_display_mode: Whether plugin.display() takes a
|
||||
display_mode keyword. Pass it when the caller already knows;
|
||||
None falls back to inspecting the callable.
|
||||
raise_errors: Re-raise the PluginError wrapping an exception
|
||||
display() raised, instead of returning False. False alone
|
||||
cannot tell "no content" from "raised", and a caller that
|
||||
feeds the circuit breaker needs that difference. The error
|
||||
is still logged and recorded first. A timeout still returns
|
||||
False either way.
|
||||
|
||||
Returns:
|
||||
True if display succeeded, False otherwise
|
||||
|
||||
Raises:
|
||||
PluginError: Only with ``raise_errors``, when display() raised.
|
||||
"""
|
||||
try:
|
||||
start_time = time.monotonic()
|
||||
@@ -245,6 +255,8 @@ class PluginExecutor:
|
||||
return False
|
||||
except PluginError:
|
||||
# Already logged and recorded in execute_with_timeout
|
||||
if raise_errors:
|
||||
raise
|
||||
return False
|
||||
except Exception as e:
|
||||
self.logger.error(
|
||||
|
||||
+5
-3
@@ -12,16 +12,18 @@
|
||||
[50.0, "broken_a", 0.0, "breaker", 0, null],
|
||||
[50.0, "broken_b", 0.0, "breaker", 0, null],
|
||||
[50.0, "weather", 10.0, "duration", 10, true],
|
||||
[60.0, "crashy", 0.0, "raised", 1, true],
|
||||
[60.0, "crashy", 0.0, "breaker", 0, null],
|
||||
[60.0, "clock", 10.0, "duration", 10, true],
|
||||
[70.0, "broken_a", 0.0, "breaker", 0, null],
|
||||
[70.0, "broken_b", 0.0, "breaker", 0, null],
|
||||
[70.0, "weather", 10.0, "duration", 10, true],
|
||||
[80.0, "crashy", 0.0, "raised", 1, true],
|
||||
[80.0, "crashy", 0.0, "breaker", 0, null],
|
||||
[80.0, "clock", 10.0, "horizon", 10, true]
|
||||
],
|
||||
"events": [
|
||||
[10.0, "health-failure", "broken"],
|
||||
[30.0, "health-failure", "broken"]
|
||||
[20.0, "health-failure", "crashy"],
|
||||
[30.0, "health-failure", "broken"],
|
||||
[40.0, "health-failure", "crashy"]
|
||||
]
|
||||
}
|
||||
|
||||
@@ -0,0 +1,303 @@
|
||||
"""A plugin whose display() raises must count as a circuit-breaker failure.
|
||||
|
||||
The first frame of every screen goes through PluginExecutor.execute_display,
|
||||
which catches whatever display() raises and reports False. run() read that
|
||||
False as "no content" and called record_success() on it, so a plugin that
|
||||
raised on every screen reset its own failure streak each time and the breaker
|
||||
never opened. It stayed in rotation, logging a traceback per screen, forever.
|
||||
|
||||
These tests drive the real run() on a fake clock with the real executor and
|
||||
the real health tracker.
|
||||
"""
|
||||
|
||||
import copy
|
||||
import threading
|
||||
import types
|
||||
from unittest.mock import MagicMock
|
||||
|
||||
import pytest
|
||||
|
||||
from src.exceptions import PluginError
|
||||
from src.plugin_system.plugin_executor import PluginExecutor
|
||||
from src.plugin_system.plugin_health import CircuitState, PluginHealthTracker
|
||||
|
||||
THRESHOLD = 3
|
||||
COOLDOWN = 300.0
|
||||
SCREEN_SECONDS = 10
|
||||
|
||||
|
||||
class FakeClock:
|
||||
"""Moves only when the code under test sleeps; runs events as it passes them."""
|
||||
|
||||
def __init__(self, start=10_000.0):
|
||||
self.t = start
|
||||
self._events = []
|
||||
|
||||
def now(self):
|
||||
return self.t
|
||||
|
||||
def sleep(self, seconds):
|
||||
self.t += max(seconds, 0.0005)
|
||||
while self._events and self._events[0][0] <= self.t:
|
||||
_, fn = self._events.pop(0)
|
||||
fn()
|
||||
|
||||
def after(self, seconds, fn):
|
||||
self._events.append((self.t + seconds, fn))
|
||||
self._events.sort(key=lambda e: e[0])
|
||||
|
||||
def module(self):
|
||||
return types.SimpleNamespace(time=self.now, monotonic=self.now,
|
||||
perf_counter=self.now, sleep=self.sleep)
|
||||
|
||||
|
||||
class _Stop(KeyboardInterrupt):
|
||||
"""Ends run(): it catches KeyboardInterrupt and cleans up."""
|
||||
|
||||
|
||||
class _Cache:
|
||||
def __init__(self):
|
||||
self.store = {}
|
||||
|
||||
def set(self, key, data, ttl=None, **kwargs):
|
||||
self.store[key] = copy.deepcopy(data)
|
||||
|
||||
def get(self, key, max_age=None, memory_ttl=None, **kwargs):
|
||||
return copy.deepcopy(self.store.get(key))
|
||||
|
||||
|
||||
class _Plugin:
|
||||
"""A static plugin. ``outcomes`` scripts each screen's first frame in
|
||||
turn: True/False is returned, an exception instance is raised; once the
|
||||
script runs out it returns True. Later frames of a screen return True.
|
||||
|
||||
A screen's first frame is the one PluginExecutor dispatches, on its own
|
||||
thread; the render loop's later frames run on the calling thread.
|
||||
"""
|
||||
|
||||
needs_high_fps = False
|
||||
|
||||
def __init__(self, plugin_id, clock, outcomes=()):
|
||||
self.plugin_id = plugin_id
|
||||
self._clock = clock
|
||||
self._outcomes = list(outcomes)
|
||||
self._caller = threading.current_thread()
|
||||
self.first_frames = [] # (time, outcome) of each executor dispatch
|
||||
self.calls = 0
|
||||
|
||||
def display(self, force_clear=False):
|
||||
if threading.current_thread() is self._caller:
|
||||
return True # a later frame of a screen that started fine
|
||||
self.calls += 1
|
||||
outcome = self._outcomes.pop(0) if self._outcomes else True
|
||||
self.first_frames.append((self._clock.t, outcome))
|
||||
if isinstance(outcome, BaseException):
|
||||
raise outcome
|
||||
return outcome
|
||||
|
||||
|
||||
@pytest.fixture
|
||||
def clock(monkeypatch):
|
||||
c = FakeClock()
|
||||
fake_time = c.module()
|
||||
monkeypatch.setattr('src.display_controller.time', fake_time)
|
||||
# The breaker's cooldown is wall-clock; put it on the same clock.
|
||||
monkeypatch.setattr('src.plugin_system.plugin_health.time', fake_time)
|
||||
return c
|
||||
|
||||
|
||||
@pytest.fixture
|
||||
def tracker():
|
||||
return PluginHealthTracker(_Cache(), failure_threshold=THRESHOLD,
|
||||
cooldown_period=COOLDOWN)
|
||||
|
||||
|
||||
@pytest.fixture
|
||||
def controller(test_display_controller, clock, tracker):
|
||||
c = test_display_controller
|
||||
c._refresh_config_cache({'display': {'hardware': {'brightness': 90}}})
|
||||
c.current_brightness = 90
|
||||
c.is_display_active = True
|
||||
c._check_wifi_status_message = MagicMock(return_value=None)
|
||||
c._cleanup_expired_wifi_status = MagicMock()
|
||||
c.cache_manager.get = MagicMock(return_value=None)
|
||||
c.cache_manager.set = MagicMock()
|
||||
c.cache_manager.delete = MagicMock()
|
||||
c.display_manager.set_brightness = MagicMock(return_value=True)
|
||||
c.display_manager.update_display = MagicMock()
|
||||
|
||||
pm = c.plugin_manager
|
||||
# The real executor: its exception handling is what is under test.
|
||||
pm.plugin_executor = PluginExecutor(default_timeout=5.0)
|
||||
pm.health_tracker = tracker
|
||||
locks = {}
|
||||
pm.get_plugin_lock = lambda pid: locks.setdefault(pid, threading.Lock())
|
||||
pm.record_display_hang = MagicMock()
|
||||
pm.note_display_duration = MagicMock()
|
||||
return c
|
||||
|
||||
|
||||
def _install(c, *plugins):
|
||||
c.plugin_modes.clear()
|
||||
c.mode_to_plugin_id.clear()
|
||||
c.plugin_display_modes.clear()
|
||||
for plugin in plugins:
|
||||
c.plugin_modes[plugin.plugin_id] = plugin
|
||||
c.mode_to_plugin_id[plugin.plugin_id] = plugin.plugin_id
|
||||
c.plugin_display_modes[plugin.plugin_id] = [plugin.plugin_id]
|
||||
c.available_modes = [p.plugin_id for p in plugins]
|
||||
c.current_mode_index = 0
|
||||
c.current_display_mode = c.available_modes[0]
|
||||
c.config.setdefault('display', {})['display_durations'] = {
|
||||
p.plugin_id: SCREEN_SECONDS for p in plugins}
|
||||
|
||||
|
||||
def _run_for(c, clock, seconds):
|
||||
def stop():
|
||||
raise _Stop()
|
||||
clock.after(seconds, stop)
|
||||
c.run()
|
||||
|
||||
|
||||
def _boom():
|
||||
return RuntimeError("display() failed")
|
||||
|
||||
|
||||
class TestRaisingDisplayOpensTheBreaker:
|
||||
def test_opens_at_the_threshold_and_leaves_rotation(self, controller, clock, tracker):
|
||||
c = controller
|
||||
crashy = _Plugin('crashy', clock, [_boom() for _ in range(100)])
|
||||
good = _Plugin('good', clock)
|
||||
_install(c, good, crashy)
|
||||
|
||||
_run_for(c, clock, 200)
|
||||
|
||||
state = tracker.get_health_state('crashy')
|
||||
assert state['circuit_state'] == CircuitState.OPEN.value
|
||||
assert state['consecutive_failures'] == THRESHOLD
|
||||
assert state['last_error'].endswith("display() failed")
|
||||
# Exactly THRESHOLD raises reached display(); the open breaker kept
|
||||
# it out of every later pass, well inside the cooldown.
|
||||
assert crashy.calls == THRESHOLD
|
||||
# The display kept moving: the healthy plugin went on being shown.
|
||||
assert len(good.first_frames) > THRESHOLD + 2
|
||||
assert tracker.get_health_state('good')['consecutive_failures'] == 0
|
||||
|
||||
def test_back_in_rotation_after_the_cooldown(self, controller, clock, tracker):
|
||||
c = controller
|
||||
crashy = _Plugin('crashy', clock, [_boom() for _ in range(THRESHOLD)])
|
||||
good = _Plugin('good', clock)
|
||||
_install(c, good, crashy)
|
||||
|
||||
_run_for(c, clock, COOLDOWN + 100)
|
||||
|
||||
# Half-open after the cooldown, one attempt succeeded, circuit closed.
|
||||
assert crashy.calls > THRESHOLD
|
||||
state = tracker.get_health_state('crashy')
|
||||
assert state['circuit_state'] == CircuitState.CLOSED.value
|
||||
assert state['consecutive_failures'] == 0
|
||||
opened_at = crashy.first_frames[THRESHOLD - 1][0]
|
||||
retried_at = crashy.first_frames[THRESHOLD][0]
|
||||
assert retried_at - opened_at >= COOLDOWN
|
||||
|
||||
def test_one_success_resets_the_streak(self, controller, clock, tracker):
|
||||
c = controller
|
||||
script = [_boom(), _boom(), True, _boom(), _boom(), True]
|
||||
flaky = _Plugin('flaky', clock, script)
|
||||
good = _Plugin('good', clock)
|
||||
_install(c, good, flaky)
|
||||
|
||||
_run_for(c, clock, 6 * 2 * SCREEN_SECONDS + 5)
|
||||
|
||||
assert flaky.calls >= len(script)
|
||||
assert [o if o is True else 'raised' for _, o in flaky.first_frames[:6]] == [
|
||||
'raised', 'raised', True, 'raised', 'raised', True]
|
||||
state = tracker.get_health_state('flaky')
|
||||
assert state['circuit_state'] == CircuitState.CLOSED.value
|
||||
assert state['consecutive_failures'] == 0
|
||||
assert state['total_failures'] == 4
|
||||
|
||||
def test_no_content_is_still_not_a_failure(self, controller, clock, tracker):
|
||||
c = controller
|
||||
empty = _Plugin('empty', clock, [False] * 100)
|
||||
good = _Plugin('good', clock)
|
||||
_install(c, good, empty)
|
||||
|
||||
_run_for(c, clock, 200)
|
||||
|
||||
state = tracker.get_health_state('empty')
|
||||
assert state['circuit_state'] == CircuitState.CLOSED.value
|
||||
assert state.get('total_failures', 0) == 0
|
||||
assert empty.calls > THRESHOLD
|
||||
|
||||
|
||||
class TestHangIsNotCountedTwice:
|
||||
def test_a_timed_out_display_records_only_the_hang(self, controller, clock, tracker):
|
||||
c = controller
|
||||
c.plugin_manager.plugin_executor = PluginExecutor(default_timeout=0.05)
|
||||
release = threading.Event()
|
||||
|
||||
class _Hung(_Plugin):
|
||||
def display(self, force_clear=False):
|
||||
self.calls += 1
|
||||
release.wait(2.0) # real time: outlives the executor's timeout
|
||||
return True
|
||||
|
||||
hung = _Hung('hung', clock)
|
||||
good = _Plugin('good', clock)
|
||||
_install(c, hung, good)
|
||||
failures = []
|
||||
real_record_failure = tracker.record_failure
|
||||
tracker.record_failure = lambda pid, err=None: (
|
||||
failures.append(pid), real_record_failure(pid, err))
|
||||
try:
|
||||
_run_for(c, clock, SCREEN_SECONDS - 1)
|
||||
finally:
|
||||
release.set()
|
||||
|
||||
c.plugin_manager.record_display_hang.assert_called_once()
|
||||
assert c.plugin_manager.record_display_hang.call_args.args[0] == 'hung'
|
||||
# The hang path records the failure (PluginManager._record_hang); the
|
||||
# dispatch adds neither a failure nor a success on top.
|
||||
assert failures == []
|
||||
assert tracker.get_health_state('hung').get('total_successes', 0) == 0
|
||||
|
||||
|
||||
class TestExecutorRaiseErrors:
|
||||
def _plugin(self, display):
|
||||
return types.SimpleNamespace(display=display)
|
||||
|
||||
def test_default_still_returns_false(self):
|
||||
def display(force_clear=False):
|
||||
raise ValueError("bad")
|
||||
assert PluginExecutor().execute_display(
|
||||
self._plugin(display), 'p', accepts_display_mode=False) is False
|
||||
|
||||
def test_raise_errors_surfaces_the_plugin_error(self):
|
||||
def display(force_clear=False):
|
||||
raise ValueError("bad")
|
||||
with pytest.raises(PluginError) as info:
|
||||
PluginExecutor().execute_display(
|
||||
self._plugin(display), 'p', accepts_display_mode=False,
|
||||
raise_errors=True)
|
||||
assert isinstance(info.value.__cause__, ValueError)
|
||||
|
||||
def test_raise_errors_leaves_a_timeout_as_false(self):
|
||||
done = threading.Event()
|
||||
|
||||
def display(force_clear=False):
|
||||
done.wait(1.0)
|
||||
return True
|
||||
try:
|
||||
assert PluginExecutor(default_timeout=0.05).execute_display(
|
||||
self._plugin(display), 'p', accepts_display_mode=False,
|
||||
raise_errors=True) is False
|
||||
finally:
|
||||
done.set()
|
||||
|
||||
def test_raise_errors_passes_results_through(self):
|
||||
executor = PluginExecutor()
|
||||
for value, expected in ((True, True), (False, False), (None, True)):
|
||||
assert executor.execute_display(
|
||||
self._plugin(lambda force_clear=False, v=value: v), 'p',
|
||||
accepts_display_mode=False, raise_errors=True) is expected
|
||||
@@ -61,8 +61,9 @@ def scenario_all_empty(h: RunLoopHarness):
|
||||
def scenario_plugin_error(h: RunLoopHarness):
|
||||
# broken's dispatch raises (no display lock: loading failed part-way),
|
||||
# so all its modes are skipped together; two failures open the breaker.
|
||||
# crashy's display() raises inside the executor, which reports False:
|
||||
# an empty pass ("raised"), not a failure, so its modes are not skipped.
|
||||
# crashy's display() raises inside the executor: an empty pass
|
||||
# ("raised") that also counts as a breaker failure, so after two raises
|
||||
# it is skipped by the breaker. Its modes are not skipped together.
|
||||
h.add_plugin(FakePlugin("clock", ["clock"], duration=10))
|
||||
h.add_plugin(FakePlugin("broken", ["broken_a", "broken_b"], duration=10), lock=False)
|
||||
h.add_plugin(FakePlugin("weather", ["weather"], duration=10))
|
||||
|
||||
Reference in New Issue
Block a user