From 0aca40cf3ac14b6af125ffe2f8adaeb3c114a6c9 Mon Sep 17 00:00:00 2001 From: Chuck <33324927+ChuckBuilds@users.noreply.github.com> Date: Tue, 14 Jul 2026 08:08:51 -0400 Subject: [PATCH] perf(plugins): run scheduled updates off the render thread (#407) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * perf(plugins): run scheduled updates off the render thread plugin update() executed inline in the render loop — execute_update's internal thread.join(timeout=30) blocked it, so one slow plugin HTTP fetch froze scrolling for the whole fetch (up to 30s; DNS-retry storms made this a regular occurrence on flaky networks). Scheduling stays on the render thread and keeps every existing gate (enabled, circuit breaker, can_execute, interval); due updates are now enqueued to a single background worker (serialized — same one-at-a-time execution as before, no thundering herd). RUNNING is set at enqueue so can_execute blocks re-entry alongside the pending-set dedup. Per-plugin locks make the old implicit update/display no-overlap guarantee explicit: the worker holds the plugin's lock through its update; the display side try-locks and, when the plugin is mid-update, holds the last frame for that iteration — reported as success so a mid-update skip never advances the rotation. Unlike before, the guarantee now also holds across the post-timeout window (previously the lingering update thread overlapped display()). Deadlock-free by construction: the worker takes one lock; display never blocks. Timeout semantics unchanged (lingering daemon thread documented). Kill switch: plugin_system.synchronous_updates: true restores the inline path. 8 new concurrency tests (non-blocking scheduler, overlap assertion under a hammering display loop, lock release on failure/timeout paths, dedup, kill switch); 4-min devpi soak clean (updates completing, rotation advancing, no stuck RUNNING states). Co-Authored-By: Claude Fable 5 Claude-Session: https://claude.ai/code/session_01FqzC1nzTWL4kaqgMaQZFam * fix(plugins): fix skipped-frame health/force_change tracking, config validation, and lock-lifetime gaps in async updates Addresses PR #407 review findings: - display_controller: only clear force_change / record health success when display() actually ran this frame, not when the frame was skipped because the plugin's lock was busy (a skip must preserve a pending mode-switch force_clear). - plugin_manager: replace bool() coercion of synchronous_updates with explicit isinstance validation of plugin_system/synchronous_updates, failing safe to synchronous mode (with a logged reason) on malformed config instead of silently defaulting to async. - plugin_manager: _update_worker_loop now acquires the plugin lock before looking up its instance and re-checks under the lock, so an unloaded plugin's lifecycle state is never resurrected to ENABLED. - plugin_manager + display_controller: move lock ownership (and, for updates, RUNNING/pending lifecycle bookkeeping) into the actual update()/ display() call itself rather than the timeout-wrapped caller, so the lock stays held for the real operation's duration even after PluginExecutor's own join(timeout) elapses and a lingering daemon thread keeps running in the background. - DisplayController.cleanup() now stops the update worker before tearing down display/cache resources; stop_update_worker() logs when the join times out instead of failing silently. - test_async_plugin_updates: rewrite test_unloaded_while_queued_is_harmless to exercise the public unload_plugin() lifecycle (via a deterministic blocker) instead of deleting pm.plugins directly, and add a regression test proving the plugin lock stays held through PluginExecutor's own timeout while the real update() call is still running. Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01KEZK1P1Q1fu5pcuVrkrCFZ --------- Co-authored-by: Chuck Co-authored-by: Claude Fable 5 --- src/display_controller.py | 158 +++++++++++++--- src/plugin_system/plugin_manager.py | 269 ++++++++++++++++++++++----- test/test_async_plugin_updates.py | 270 ++++++++++++++++++++++++++++ test/test_plugin_system.py | 8 + 4 files changed, 637 insertions(+), 68 deletions(-) create mode 100644 test/test_async_plugin_updates.py diff --git a/src/display_controller.py b/src/display_controller.py index 3ba59262..ace55b58 100644 --- a/src/display_controller.py +++ b/src/display_controller.py @@ -23,6 +23,9 @@ Entry point: :func:`main` — instantiates :class:`DisplayController` and calls import time import os import json +import threading +import types +from contextlib import contextmanager from pathlib import Path from typing import Dict, Any, List, Optional, Callable from datetime import datetime @@ -892,6 +895,30 @@ class DisplayController: except Exception: # pylint: disable=broad-except logger.exception("Error running scheduled plugin updates") + @contextmanager + def _display_lock_or_skip(self, plugin_id): + """Try-lock guard keeping a plugin's display() off its in-flight update(). + + Yields True when display may run (lock held, released on exit) or + when no lock support exists (older plugin manager). Yields False when + the plugin's update() is currently executing on the background + worker — the caller should treat the frame as displayed (the panel + holds the last pushed frame) rather than as a plugin failure, so a + mid-update skip never advances the rotation. + """ + pm = self.plugin_manager + if not pm or not hasattr(pm, 'get_plugin_lock') or not plugin_id: + yield True + return + lock = pm.get_plugin_lock(plugin_id) + if not lock.acquire(blocking=False): + yield False + return + try: + yield True + finally: + lock.release() + _FOLLOWER_SEND_INTERVAL = 1.0 / 90 # raw bytes are cheap; 90fps > follower render rate def _follower_rebuild_scroll_image(self) -> None: @@ -1879,6 +1906,7 @@ class DisplayController: plugin_id = getattr(manager_to_display, 'plugin_id', active_mode) try: logger.debug(f"Calling display() for {active_mode} with force_clear={self.force_change}") + can_display = False if hasattr(manager_to_display, 'display'): # Opt #1: look up (or compute once) whether display() accepts display_mode _cache_key = plugin_id @@ -1889,14 +1917,64 @@ class DisplayController: ) _accepts_display_mode = self._plugin_accepts_display_mode[_cache_key] - # Use PluginExecutor for safe execution with timeout - if self.plugin_manager and hasattr(self.plugin_manager, 'plugin_executor'): - result = self.plugin_manager.plugin_executor.execute_display( - manager_to_display, - plugin_id, - force_clear=self.force_change, - display_mode=active_mode if _accepts_display_mode else None - ) + pm = self.plugin_manager + display_lock = None + can_display = True + if pm and hasattr(pm, 'get_plugin_lock'): + display_lock = pm.get_plugin_lock(plugin_id) + can_display = display_lock.acquire(blocking=False) + + if not can_display: + # update() in flight on the worker — hold + # the last frame; not a plugin failure + result = True + elif pm and hasattr(pm, 'plugin_executor'): + # PluginExecutor's own thread.join(timeout) can + # return before the real display() call + # finishes (a lingering daemon thread keeps + # running it) -- so the lock is released from + # inside the wrapped call itself, whichever + # thread actually finishes it, rather than + # here when this dispatch merely returns. + release_guard = threading.Lock() + released = {'done': False} + + def _release_display_lock(): + with release_guard: + if released['done']: + return + released['done'] = True + if display_lock is not None: + display_lock.release() + + if _accepts_display_mode: + def _display_target(display_mode=None, force_clear=False): + try: + return manager_to_display.display( + display_mode=display_mode, force_clear=force_clear) + finally: + _release_display_lock() + else: + def _display_target(force_clear=False): + try: + return manager_to_display.display(force_clear=force_clear) + finally: + _release_display_lock() + + try: + result = self.plugin_manager.plugin_executor.execute_display( + types.SimpleNamespace(display=_display_target), + plugin_id, + force_clear=self.force_change, + display_mode=active_mode if _accepts_display_mode else None + ) + except Exception: # pragma: no cover - defensive; + # execute_display catches everything + # internally, but guarantee the lock is + # never leaked if something unexpected + # slips through. + _release_display_lock() + raise # execute_display returns bool, convert to expected format if result: result = True # Success @@ -1904,10 +1982,14 @@ class DisplayController: result = False # Failed else: # Fallback to direct call if executor not available - if _accepts_display_mode: - result = manager_to_display.display(display_mode=active_mode, force_clear=self.force_change) - else: - result = manager_to_display.display(force_clear=self.force_change) + try: + if _accepts_display_mode: + result = manager_to_display.display(display_mode=active_mode, force_clear=self.force_change) + else: + result = manager_to_display.display(force_clear=self.force_change) + finally: + if display_lock is not None: + display_lock.release() logger.debug(f"display() returned: {result} (type: {type(result)})") # Check if display() returned a boolean (new behavior) @@ -1916,11 +1998,15 @@ class DisplayController: if not display_result: logger.info("Plugin %s display() returned False for mode %s", plugin_id, active_mode) - # Record success if display completed without exception - if self.plugin_manager and hasattr(self.plugin_manager, 'health_tracker') and self.plugin_manager.health_tracker: - self.plugin_manager.health_tracker.record_success(plugin_id) - - self.force_change = False + # Record success only when display() actually ran this + # frame -- a skipped frame (lock busy) held the last + # 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. + if can_display: + if self.plugin_manager and hasattr(self.plugin_manager, 'health_tracker') and self.plugin_manager.health_tracker: + self.plugin_manager.health_tracker.record_success(plugin_id) + self.force_change = False except Exception as exc: # pylint: disable=broad-except logger.exception("Error displaying %s", self.current_display_mode) # Record failure @@ -2205,11 +2291,16 @@ class DisplayController: while True: try: - # Pass display_mode to maintain sticky manager state - if _accepts_display_mode: - result = manager_to_display.display(display_mode=active_mode, force_clear=False) - else: - result = manager_to_display.display(force_clear=False) + with self._display_lock_or_skip(plugin_id) as can_display: + if can_display: + # Pass display_mode to maintain sticky manager state + if _accepts_display_mode: + result = manager_to_display.display(display_mode=active_mode, force_clear=False) + else: + result = manager_to_display.display(force_clear=False) + else: + # update() in flight — hold the last frame + result = True if isinstance(result, bool) and not result: logger.debug("Display returned False, breaking early") break @@ -2269,11 +2360,16 @@ class DisplayController: break try: - # Pass display_mode to maintain sticky manager state - if _accepts_display_mode: - result = manager_to_display.display(display_mode=active_mode, force_clear=False) - else: - result = manager_to_display.display(force_clear=False) + with self._display_lock_or_skip(plugin_id) as can_display: + if can_display: + # Pass display_mode to maintain sticky manager state + if _accepts_display_mode: + result = manager_to_display.display(display_mode=active_mode, force_clear=False) + else: + result = manager_to_display.display(force_clear=False) + else: + # update() in flight — hold the last frame + result = True if isinstance(result, bool) and not result: # For dynamic duration plugins, don't exit on False - keep looping # until cycle is complete or max duration is reached @@ -2791,6 +2887,14 @@ class DisplayController: def cleanup(self): """Clean up resources.""" + # Stop the async update worker first so no in-flight update() call + # is still touching display/cache-backed resources while they're + # torn down below. + if self.plugin_manager and hasattr(self.plugin_manager, 'stop_update_worker'): + try: + self.plugin_manager.stop_update_worker() + except Exception as e: + logger.warning("Error stopping plugin update worker: %s", e) # Shutdown config service if it exists if hasattr(self, 'config_service'): try: diff --git a/src/plugin_system/plugin_manager.py b/src/plugin_system/plugin_manager.py index aec53cca..4a571658 100644 --- a/src/plugin_system/plugin_manager.py +++ b/src/plugin_system/plugin_manager.py @@ -8,12 +8,13 @@ API Version: 1.0.0 """ import json +import queue import sys import time import threading import types from pathlib import Path -from typing import Dict, List, Optional, Any +from typing import Dict, List, Optional, Any, Tuple import logging from src.exceptions import PluginError, ConfigError from src.logging_config import get_logger @@ -97,6 +98,50 @@ class PluginManager: # Health tracking (optional, set by display_controller if available) self.health_tracker = None self.resource_monitor = None + + # --- Asynchronous plugin updates ------------------------------- + # update() used to run inline in the render loop (execute_update's + # internal thread.join(timeout=30) blocked it), so one slow plugin + # HTTP fetch froze scrolling for the whole fetch. Scheduling still + # happens on the render thread (run_scheduled_updates), but + # execution moves to this single background worker. Per-plugin + # locks keep a plugin's update() and display() mutually exclusive — + # today's implicit guarantee, now explicit (and, unlike today, + # also held across the post-timeout window). + # Kill switch: plugin_system.synchronous_updates: true restores the + # inline path. + self._update_queue: "queue.Queue[Optional[Tuple[str, float]]]" = queue.Queue() + self._pending_updates: set = set() + self._pending_lock = threading.Lock() + self._plugin_locks: Dict[str, threading.Lock] = {} + self._plugin_locks_guard = threading.Lock() + self._update_worker: Optional[threading.Thread] = None + self._synchronous_updates = False + if self.config_manager is not None: + try: + cfg = self.config_manager.get_config() or {} + except (OSError, ValueError) as exc: + self.logger.warning( + "Could not load config to check plugin_system.synchronous_updates " + "(%s: %s); defaulting to synchronous updates", type(exc).__name__, exc) + self._synchronous_updates = True + else: + plugin_system_cfg = cfg.get('plugin_system', {}) + if not isinstance(plugin_system_cfg, dict): + self.logger.warning( + "config plugin_system must be a mapping, got %s; " + "defaulting to synchronous updates", + type(plugin_system_cfg).__name__) + self._synchronous_updates = True + else: + sync_value = plugin_system_cfg.get('synchronous_updates', False) + if not isinstance(sync_value, bool): + self.logger.warning( + "config plugin_system.synchronous_updates must be a boolean, " + "got %r; defaulting to synchronous updates", sync_value) + self._synchronous_updates = True + else: + self._synchronous_updates = sync_value # Ensure plugins directory exists with proper permissions try: @@ -744,47 +789,189 @@ class PluginManager: last_update = self.plugin_last_update.get(plugin_id, 0.0) if last_update == 0.0 or (current_time - last_update) >= interval: - # Update state to RUNNING - self.state_manager.set_state(plugin_id, PluginState.RUNNING) - - try: - # Use PluginExecutor for safe execution - success = False - if self.resource_monitor: - # If resource monitor exists, wrap the call - def monitored_update(): - self.resource_monitor.monitor_call(plugin_id, plugin_instance.update) - # SimpleNamespace stores `update` as an *instance* - # attribute, so attribute lookup returns the plain - # function object as-is. A dynamically-built class - # (`type(..., {'update': monitored_update})`) instead - # stores it as a *class* attribute, which the - # descriptor protocol turns into a bound method on - # access -- silently prepending the instance as an - # implicit first argument to a function that takes - # none, raising "monitored_update() takes 0 - # positional arguments but 1 was given" on every call. - success = self.plugin_executor.execute_update( - types.SimpleNamespace(update=monitored_update), - plugin_id - ) - else: - success = self.plugin_executor.execute_update(plugin_instance, plugin_id) - - if success: - with self._plugin_last_update_lock: - self.plugin_last_update[plugin_id] = current_time - self.state_manager.record_update(plugin_id) - # Update state back to ENABLED - self.state_manager.set_state(plugin_id, PluginState.ENABLED) - # Record success - if self.health_tracker: - self.health_tracker.record_success(plugin_id) - else: - self._record_update_failure(plugin_id) - except Exception as exc: # pylint: disable=broad-except - self.logger.exception("Error updating plugin %s: %s", plugin_id, exc) + if self._synchronous_updates: + # Kill-switch path: the original inline execution + # (blocks the caller until update() completes/times out) + self.state_manager.set_state(plugin_id, PluginState.RUNNING) + self._execute_update_now(plugin_id, plugin_instance, current_time) + else: + self._enqueue_update(plugin_id, current_time) + + def get_plugin_lock(self, plugin_id: str) -> threading.Lock: + """Per-plugin lock keeping update() and display() mutually exclusive. + + The update worker holds it for the duration of a plugin's update(); + the display side acquires it non-blocking and skips that frame's + display() call when the plugin is mid-update. + """ + with self._plugin_locks_guard: + lock = self._plugin_locks.get(plugin_id) + if lock is None: + lock = threading.Lock() + self._plugin_locks[plugin_id] = lock + return lock + + def _enqueue_update(self, plugin_id: str, scheduled_time: float) -> None: + """Queue a due update for the background worker (dedup while pending).""" + with self._pending_lock: + if plugin_id in self._pending_updates: + return + self._pending_updates.add(plugin_id) + # RUNNING is set at enqueue time so can_execute() blocks re-entry and + # the web UI shows the truthful state while the item waits its turn. + self.state_manager.set_state(plugin_id, PluginState.RUNNING) + self._ensure_update_worker() + self._update_queue.put((plugin_id, scheduled_time)) + + def _ensure_update_worker(self) -> None: + if self._update_worker is not None and self._update_worker.is_alive(): + return + self._update_worker = threading.Thread( + target=self._update_worker_loop, name='plugin-update-worker', + daemon=True) + self._update_worker.start() + + def _update_worker_loop(self) -> None: + """Single worker: dispatches queued updates off the render thread + (matching the old inline behavior — no thundering herd of + concurrent fetches). + + The plugin's lock is acquired here, before its instance is looked + up, and the instance is re-fetched under the lock — a concurrent + unload_plugin() can't leave this loop about to run update() on an + instance that's already been torn down. The lock — and RUNNING/ + pending lifecycle state — is released by the update itself once the + real update() call genuinely finishes (see _execute_update_now), + which can be after this dispatch returns if PluginExecutor's own + timeout elapses first. + """ + while True: + item = self._update_queue.get() + if item is None: # shutdown sentinel + return + plugin_id, scheduled_time = item + lock = self.get_plugin_lock(plugin_id) + lock.acquire() + plugin_instance = self.plugins.get(plugin_id) + if plugin_instance is None: # unloaded while queued; its + # lifecycle state was already cleared by unload_plugin — + # leave it alone rather than resurrecting it to ENABLED + lock.release() + with self._pending_lock: + self._pending_updates.discard(plugin_id) + continue + try: + self._execute_update_now(plugin_id, plugin_instance, + scheduled_time, lock=lock) + except Exception: # pylint: disable=broad-except + # _execute_update_now guarantees the lock/pending bookkeeping + # is released via its own _finish() before returning or + # raising; this is a last-resort log only. + self.logger.exception("update worker: unexpected error for %s", + plugin_id) + + def stop_update_worker(self, timeout: float = 5.0) -> None: + """Signal the worker to exit (used by cleanup; thread is a daemon).""" + if self._update_worker is not None and self._update_worker.is_alive(): + self._update_queue.put(None) + self._update_worker.join(timeout=timeout) + if self._update_worker.is_alive(): + self.logger.warning( + "Update worker did not stop within %.1fs; it is a daemon " + "thread and will be abandoned on shutdown", timeout) + + def _execute_update_now(self, plugin_id: str, plugin_instance: Any, + scheduled_time: float, + lock: Optional[threading.Lock] = None) -> None: + """Execute a plugin's update() via PluginExecutor, then bookkeep. + + Caller is responsible for having set RUNNING state. + + On the synchronous path (``lock=None``) this is the original, + unchanged inline behavior. On the async worker path, PluginExecutor's + internal thread.join(timeout) blocks only the calling thread -- on + timeout the lingering daemon update-thread keeps running the real + plugin.update() call unkillable in the background. So that the + plugin's lock (and its RUNNING/pending lifecycle state) stays held + for that real duration rather than just this bounded wait, ownership + of both is carried by the wrapped update callable itself, released + from whichever thread actually finishes it -- see _finish() below. + """ + finish_guard = threading.Lock() + finished = {'done': False} + + def _finish(success: bool, exc: Optional[Exception] = None) -> None: + with finish_guard: + if finished['done']: + return + finished['done'] = True + try: + if success: + with self._plugin_last_update_lock: + self.plugin_last_update[plugin_id] = scheduled_time + self.state_manager.record_update(plugin_id) + self.state_manager.set_state(plugin_id, PluginState.ENABLED) + if self.health_tracker: + self.health_tracker.record_success(plugin_id) + else: self._record_update_failure(plugin_id, exc=exc) + finally: + if lock is not None: + lock.release() + with self._pending_lock: + self._pending_updates.discard(plugin_id) + + if lock is None: + # Synchronous / no-lock path: unchanged behavior. + try: + if self.resource_monitor: + def monitored_update(): + self.resource_monitor.monitor_call(plugin_id, plugin_instance.update) + # SimpleNamespace stores `update` as an *instance* + # attribute, so attribute lookup returns the plain + # function object as-is. A dynamically-built class + # (`type(..., {'update': monitored_update})`) instead + # stores it as a *class* attribute, which the + # descriptor protocol turns into a bound method on + # access -- silently prepending the instance as an + # implicit first argument to a function that takes + # none, raising "monitored_update() takes 0 + # positional arguments but 1 was given" on every call. + success = self.plugin_executor.execute_update( + types.SimpleNamespace(update=monitored_update), + plugin_id + ) + else: + success = self.plugin_executor.execute_update(plugin_instance, plugin_id) + _finish(success) + except Exception as exc: # pylint: disable=broad-except + self.logger.exception("Error updating plugin %s: %s", plugin_id, exc) + _finish(False, exc=exc) + return + + # Async worker path: the real update() call -- through the resource + # monitor, if configured -- owns finishing the lock/lifecycle + # bookkeeping, from whichever thread actually runs it to completion. + def _target_update() -> None: + try: + if self.resource_monitor: + self.resource_monitor.monitor_call(plugin_id, plugin_instance.update) + else: + plugin_instance.update() + except Exception as exc: + _finish(False, exc=exc) + raise + else: + _finish(True) + + try: + self.plugin_executor.execute_update( + types.SimpleNamespace(update=_target_update), plugin_id) + except Exception as exc: # pragma: no cover - defensive; execute_update + # catches everything internally, but guarantee _finish still + # runs (releasing the lock) if something unexpected slips through. + self.logger.exception("Unexpected error dispatching update for %s: %s", plugin_id, exc) + _finish(False, exc=exc) def run_scheduled_updates_with_changes(self, current_time: Optional[float] = None) -> List[str]: """ diff --git a/test/test_async_plugin_updates.py b/test/test_async_plugin_updates.py new file mode 100644 index 00000000..a27fea11 --- /dev/null +++ b/test/test_async_plugin_updates.py @@ -0,0 +1,270 @@ +"""Tests for asynchronous plugin updates (plugin_manager background worker). + +The invariants that keep this change safe: +1. run_scheduled_updates returns immediately — a slow update() can never + again freeze the render loop (the original defect: 30s scroll freezes). +2. A plugin's update() and display() are NEVER concurrent — the per-plugin + lock makes the old implicit no-overlap guarantee explicit, and it stays + held through PluginExecutor's own timeout: a lingering, still-running + update() keeps the lock even after PluginExecutor gives up waiting on it. +3. Failure/timeout bookkeeping is unchanged (same executor, same + _record_update_failure path, same last-update stamping). +4. The kill switch (plugin_system.synchronous_updates) restores the + inline path exactly. +""" + +import os +import sys +import threading +import time + +import pytest + +sys.path.insert(0, os.path.join(os.path.dirname(__file__), "..")) + +from src.plugin_system.plugin_manager import PluginManager # noqa: E402 +from src.plugin_system.plugin_state import PluginState # noqa: E402 + + +class SlowPlugin: + """Fake plugin whose update() sleeps and records overlap violations.""" + + def __init__(self, update_seconds=0.5): + self.enabled = True + self.update_seconds = update_seconds + self.update_calls = 0 + self.display_calls = 0 + self.in_update = False + self.overlap_detected = False + + def update(self): + self.in_update = True + self.update_calls += 1 + time.sleep(self.update_seconds) + self.in_update = False + return True + + def display(self, force_clear=False): + if self.in_update: + self.overlap_detected = True + self.display_calls += 1 + return True + + +@pytest.fixture +def pm(tmp_path): + manager = PluginManager(plugins_dir=str(tmp_path), config_manager=None, + display_manager=None, cache_manager=None) + yield manager + manager.stop_update_worker() + + +def _install(pm, plugin, plugin_id="slow-plugin"): + pm.plugins[plugin_id] = plugin + pm._update_interval_cache[plugin_id] = 0.01 # always due + # load_plugin normally registers state; can_execute() gates on it + pm.state_manager.set_state(plugin_id, PluginState.ENABLED) + return plugin_id + + +class TestSchedulerNonBlocking: + def test_run_scheduled_updates_returns_immediately(self, pm): + plugin_id = _install(pm, SlowPlugin(update_seconds=2.0)) + start = time.monotonic() + pm.run_scheduled_updates() + elapsed = time.monotonic() - start + assert elapsed < 0.1, f"scheduler blocked for {elapsed:.2f}s" + # the update actually runs in the background + deadline = time.monotonic() + 5 + while pm.plugins[plugin_id].update_calls == 0 and time.monotonic() < deadline: + time.sleep(0.05) + assert pm.plugins[plugin_id].update_calls == 1 + + def test_no_double_enqueue_while_pending(self, pm): + plugin_id = _install(pm, SlowPlugin(update_seconds=0.8)) + for _ in range(20): + pm.run_scheduled_updates() + time.sleep(0.01) + time.sleep(1.5) # let the single queued update finish + assert pm.plugins[plugin_id].update_calls == 1 + + +class TestUpdateDisplayExclusion: + def test_display_lock_held_during_update(self, pm): + plugin_id = _install(pm, SlowPlugin(update_seconds=0.6)) + pm.run_scheduled_updates() + # give the worker a moment to take the lock and enter update() + deadline = time.monotonic() + 2 + while not pm.plugins[plugin_id].in_update and time.monotonic() < deadline: + time.sleep(0.01) + lock = pm.get_plugin_lock(plugin_id) + assert lock.acquire(blocking=False) is False, \ + "lock must be held while update() runs" + # and released afterwards + deadline = time.monotonic() + 3 + while pm.plugins[plugin_id].in_update and time.monotonic() < deadline: + time.sleep(0.05) + time.sleep(0.1) + assert lock.acquire(blocking=False) is True + lock.release() + + def test_no_overlap_under_hammering_display_loop(self, pm): + """Simulate the render loop's try-lock display pattern at high rate + while updates fire — the plugin itself asserts no overlap.""" + plugin = SlowPlugin(update_seconds=0.15) + plugin_id = _install(pm, plugin) + stop = threading.Event() + + def render_loop(): + while not stop.is_set(): + lock = pm.get_plugin_lock(plugin_id) + if lock.acquire(blocking=False): + try: + plugin.display() + finally: + lock.release() + time.sleep(0.002) + + renderer = threading.Thread(target=render_loop, daemon=True) + renderer.start() + try: + for _ in range(6): + pm.plugin_last_update.pop(plugin_id, None) # force due + pm.run_scheduled_updates() + time.sleep(0.3) + finally: + stop.set() + renderer.join(timeout=2) + assert plugin.update_calls >= 3 + assert plugin.display_calls > 10 + assert plugin.overlap_detected is False + + def test_lock_held_through_timeout_until_real_update_finishes(self, pm): + """PluginExecutor's join(timeout) can return before the real + update() call does -- the lingering daemon thread keeps running it. + The plugin's lock must stay held for that whole real duration, not + just PluginExecutor's bounded wait, or display() could run + concurrently with a still-executing update().""" + plugin = SlowPlugin(update_seconds=0.3) + plugin_id = _install(pm, plugin) + pm.plugin_executor.default_timeout = 0.05 # times out well before + # update_seconds elapses + + pm.run_scheduled_updates() + + deadline = time.monotonic() + 2 + while not plugin.in_update and time.monotonic() < deadline: + time.sleep(0.01) + assert plugin.in_update is True + + # PluginExecutor's own timeout has now elapsed, but the real + # update() (0.3s) is still running in its lingering daemon thread. + time.sleep(0.15) + assert plugin.in_update is True, "test setup: update should still be running" + lock = pm.get_plugin_lock(plugin_id) + assert lock.acquire(blocking=False) is False, \ + "lock must stay held through PluginExecutor's timeout while the real update() runs" + + # Once the real update() genuinely finishes, the lock is released. + deadline = time.monotonic() + 2 + while plugin.in_update and time.monotonic() < deadline: + time.sleep(0.02) + time.sleep(0.1) + assert lock.acquire(blocking=False) is True + lock.release() + + def test_state_returns_to_enabled_after_update(self, pm): + """RUNNING is set at enqueue (blocks re-entry via can_execute) and + must return to an executable state once the update finishes.""" + plugin_id = _install(pm, SlowPlugin(update_seconds=0.1)) + pm.run_scheduled_updates() + # while queued/running, re-entry is blocked + assert pm.state_manager.can_execute(plugin_id) is False + deadline = time.monotonic() + 3 + while time.monotonic() < deadline: + if (pm.plugins[plugin_id].update_calls + and pm.state_manager.can_execute(plugin_id)): + break + time.sleep(0.05) + assert pm.plugins[plugin_id].update_calls == 1 + assert pm.state_manager.can_execute(plugin_id) is True + + +class TestFailurePaths: + def test_update_failure_routes_through_failure_bookkeeping(self, pm): + class FailingPlugin(SlowPlugin): + def update(self): + self.update_calls += 1 + raise RuntimeError("boom") + + plugin_id = _install(pm, FailingPlugin()) + pm.run_scheduled_updates() + deadline = time.monotonic() + 3 + while pm.plugins[plugin_id].update_calls == 0 and time.monotonic() < deadline: + time.sleep(0.05) + time.sleep(0.2) + # failure stamped so the interval gate holds (no hot retry loop) + assert pm.plugin_last_update.get(plugin_id, 0) > 0 + # lock released after failure + assert pm.get_plugin_lock(plugin_id).acquire(blocking=False) is True + pm.get_plugin_lock(plugin_id).release() + + def test_unloaded_while_queued_is_harmless(self, pm): + """Exercise the public unload_plugin() lifecycle rather than + deleting pm.plugins directly: queue the target's update behind a + deterministic blocker (occupying the single worker), unload the + target while its item still sits queued, then release the blocker + and confirm the target's update never ran and its state stayed + unloaded rather than being resurrected to ENABLED.""" + blocker_event = threading.Event() + + class BlockerPlugin(SlowPlugin): + def update(self): + self.update_calls += 1 + blocker_event.wait(timeout=5) + return True + + blocker_id = _install(pm, BlockerPlugin(), plugin_id="blocker-plugin") + target = SlowPlugin(update_seconds=0.05) + target_id = _install(pm, target, plugin_id="slow-plugin") + + # Dispatch the blocker first so it occupies the single worker + # thread, then enqueue the target behind it -- deterministically + # queued, not yet started. + pm._enqueue_update(blocker_id, time.time()) + deadline = time.monotonic() + 2 + while pm.plugins[blocker_id].update_calls == 0 and time.monotonic() < deadline: + time.sleep(0.01) + assert pm.plugins[blocker_id].update_calls == 1 + + pm._enqueue_update(target_id, time.time()) + assert target_id in pm._pending_updates + + assert pm.unload_plugin(target_id) is True + assert target_id not in pm.plugins + + blocker_event.set() # let the blocker finish; worker moves on to + # the target's queued item + + deadline = time.monotonic() + 3 + while target_id in pm._pending_updates and time.monotonic() < deadline: + time.sleep(0.02) + + assert target.update_calls == 0, "update() must not run for an unloaded plugin" + assert target_id not in pm._pending_updates + assert pm.state_manager.get_state(target_id) == PluginState.UNLOADED + + +class TestKillSwitch: + def test_synchronous_mode_blocks_like_before(self, pm): + pm._synchronous_updates = True + plugin_id = _install(pm, SlowPlugin(update_seconds=0.4)) + start = time.monotonic() + pm.run_scheduled_updates() + elapsed = time.monotonic() - start + assert elapsed >= 0.4, "synchronous mode must run inline" + assert pm.plugins[plugin_id].update_calls == 1 + + +if __name__ == "__main__": + sys.exit(pytest.main([__file__, "-v"])) diff --git a/test/test_plugin_system.py b/test/test_plugin_system.py index cfc3f95d..fce98c0f 100644 --- a/test/test_plugin_system.py +++ b/test/test_plugin_system.py @@ -123,6 +123,14 @@ class TestPluginManager: pm.run_scheduled_updates(current_time=time.time()) + # Updates now execute on the background worker (the scheduler + # returns immediately) — wait for completion before asserting. + deadline = time.time() + 5 + while (plugin_instance.update.call_count == 0 + and time.time() < deadline): + time.sleep(0.02) + pm.stop_update_worker() + plugin_instance.update.assert_called_once() assert "test_plugin" in pm.plugin_last_update assert pm.state_manager.get_state("test_plugin") == PluginState.ENABLED