mirror of
https://github.com/ChuckBuilds/LEDMatrix.git
synced 2026-10-04 06:15:09 +00:00
fix(ipc): a plugin reload no longer freezes the panel during Vegas (#723)
A plugin.reload no longer freezes the panel during Vegas: the old instance is torn down and the new one loaded off the render thread (frame gap 3017 ms -> 9 ms in the ledpi reproduction). A failed or timed-out teardown stops the reload with a restart hint instead of loading over stale modules or tearing down an instance still in use. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
@@ -161,6 +161,22 @@ policies are unchanged.
|
||||
|
||||
### Fixes
|
||||
|
||||
- A plugin reload after a store update (`plugin.reload`, #720) no longer
|
||||
freezes the panel during Vegas. On ledpi a football reload froze it for
|
||||
3.0 s (`Render stall over: no frame for 3043ms`). The reload ran on the
|
||||
render thread, and its unload waited for the plugin's lock. The strip's
|
||||
prefetch thread held that lock while it rebuilt the old instance's Vegas
|
||||
content. The render thread now only takes the plugin out of the rotation
|
||||
and out of the plugin manager (`PluginManager.detach_plugin`). A
|
||||
`plugin-reload-<id>` thread waits for the lock, tears the old instance
|
||||
down and loads the new one, and the new instance joins the rotation
|
||||
between two frames. In a test with a 3.0 s render holding the lock, the
|
||||
longest gap between frames went from 3017 ms to 9 ms. The reply still
|
||||
reports the real outcome, the modes keep their places in the rotation,
|
||||
and Vegas fetches the plugin again. While it reloads, an on-demand request
|
||||
for the plugin is refused (`plugin-reloading`), and a config reconcile
|
||||
neither loads it twice nor unloads it mid-load. A Vegas fetch that waited
|
||||
out a reload for the lock skips the old instance.
|
||||
- The schedule-off blank and the WiFi notice no longer start with a
|
||||
scroller's leftovers. Both are drawn by the display controller rather than
|
||||
dispatched to a plugin, so #716's handover never reached them: drawn while
|
||||
|
||||
@@ -96,7 +96,8 @@ with its modes kept in their place in the rotation. Only a running plugin
|
||||
can be reloaded (`not_loaded` otherwise), so the id never makes the display
|
||||
import anything new. A plugin loaded only for an on-demand session gets
|
||||
`busy`. A new version that fails to load gets `failed` and stays out of the
|
||||
rotation, as it would after a restart.
|
||||
rotation, as it would after a restart. The load runs off the render thread,
|
||||
so the panel keeps scrolling while it happens (see below).
|
||||
|
||||
**Acknowledgements.** A queued on-demand command is *accepted*, not *done*.
|
||||
`{"accepted": true, "request_id": …}` means the command is waiting in the
|
||||
@@ -167,13 +168,33 @@ place it reads the mailbox:
|
||||
afterwards.
|
||||
- `brightness.set` is applied there and then (`_apply_control_brightness`),
|
||||
and the current frame is pushed again so the panel shows it.
|
||||
- `plugin.reload` waits for the top of the next loop pass, the place where
|
||||
- `plugin.reload` starts at the top of the next loop pass, the place where
|
||||
plugins are enabled and disabled live, because there no `display()` and no
|
||||
Vegas iteration is on the stack (`_apply_pending_plugin_reloads`). Until
|
||||
then the current screen ends early, as it does for a WiFi notice: the
|
||||
frame loops, the dwell and Vegas's interrupt check all treat a pending
|
||||
reload as a reason to stop (`_screen_preempted`). The rotation then
|
||||
advances, and the next pass reloads before it draws.
|
||||
reload as a reason to stop (`_screen_preempted`).
|
||||
- Only the quick half of the reload runs on the render thread
|
||||
(`_start_plugin_reload`): the plugin's modes leave the rotation, its
|
||||
config subscription is dropped, and `PluginManager.detach_plugin` takes
|
||||
the instance out of `plugins`. After that nothing new calls the old
|
||||
instance: no `update()`, and no Vegas fetch. The rotation then advances
|
||||
(Vegas resumes its strip), and frames keep coming.
|
||||
- The slow half runs on a `plugin-reload-<id>` thread (`_PluginReloadJob`).
|
||||
It waits for the plugin's lock, then tears the old instance down
|
||||
(`unload_detached_plugin`) and loads the new one (`reload_plugin`). The
|
||||
lock can be held for seconds by a Vegas render of the old instance. On
|
||||
ledpi the render thread used to wait for it here, and a football reload
|
||||
froze the panel for 3.0 s.
|
||||
- The new instance joins the rotation between two frames
|
||||
(`_finish_plugin_reloads`, from `_service_pending_changes` or the top of
|
||||
the loop). Its modes go back to their old places, Vegas is told to fetch
|
||||
it again, and the command is answered.
|
||||
- While the plugin reloads, it is out of the rotation. Vegas scrolls what
|
||||
its strip already holds of it. An on-demand request for it gets
|
||||
`plugin-reloading`. A config reconcile neither loads it a second time nor
|
||||
unloads it mid-load; a disable saved meanwhile is applied once the
|
||||
reload is done. A second reload of the same plugin runs after the first.
|
||||
|
||||
The 0.25 s floor on the mailbox read does not apply to the queue, because
|
||||
draining it costs no disk read. A queued command also lets
|
||||
@@ -204,7 +225,10 @@ Now the queue wakes the render thread:
|
||||
So a command lands within a millisecond or so on a static screen and in a
|
||||
dwell, and within one frame in Vegas and on a scrolling screen. The mailbox
|
||||
keeps its old delays. Commands still run only on the render thread: the
|
||||
connection threads only queue them and set the event.
|
||||
connection threads only queue them and set the event. The one exception is
|
||||
the slow half of `plugin.reload` (tearing down and loading the plugin),
|
||||
which runs on its own thread. Every change to the display's state still
|
||||
happens on the render thread.
|
||||
|
||||
The waits are timed `Event.wait()` calls: no polling, and no more wake-ups
|
||||
than the sleeps they replace when nothing arrives. Measured under WSL
|
||||
|
||||
+203
-30
@@ -78,6 +78,57 @@ _MIN_INITIAL_UPDATE_TIMEOUT_SECONDS = 2.0
|
||||
|
||||
DEFAULT_DYNAMIC_DURATION_CAP = 180.0
|
||||
|
||||
|
||||
class _PluginReloadJob:
|
||||
"""A ``plugin.reload`` whose slow half runs off the render thread.
|
||||
|
||||
The render thread takes the plugin out of the rotation and out of the
|
||||
plugin manager (DisplayController._start_plugin_reload); then this job,
|
||||
on its own thread, tears the old instance down and loads the new one
|
||||
(run()). Tearing down waits for the plugin's lock, which a Vegas content
|
||||
render of the old instance can hold for seconds. Done on the render
|
||||
thread, that wait froze the panel (3.0 s on ledpi). The render thread
|
||||
puts the new instance in the rotation once ``done`` is set
|
||||
(DisplayController._finish_plugin_reloads).
|
||||
"""
|
||||
|
||||
def __init__(self, command: QueuedCommand, plugin_id: str,
|
||||
previous_order: Dict[str, int], old_instance: Any) -> None:
|
||||
self.command = command
|
||||
self.plugin_id = plugin_id
|
||||
#: Each mode's place in available_modes before the reload.
|
||||
self.previous_order = previous_order
|
||||
self.old_instance = old_instance
|
||||
self.done = threading.Event()
|
||||
self.loaded = False
|
||||
#: The old instance's teardown failed, so its modules may still be in
|
||||
#: sys.modules and a load now could quietly reuse the old code.
|
||||
self.unload_failed = False
|
||||
self.error: Optional[Exception] = None
|
||||
#: Reloads of the same plugin asked for while this one ran. They
|
||||
#: start once it is done, so they load the files as they are then.
|
||||
self.followers: List[QueuedCommand] = []
|
||||
|
||||
def run(self, plugin_manager: Any) -> None:
|
||||
"""Tear down the old instance, then load the plugin again. Never raises."""
|
||||
try:
|
||||
if self.old_instance is not None:
|
||||
if not plugin_manager.unload_detached_plugin(self.plugin_id, self.old_instance):
|
||||
# Loading now could reuse the old plugin_<id> module and
|
||||
# report a reload that never happened (the synchronous
|
||||
# path refused this too: reload_plugin stops when
|
||||
# unload_plugin fails).
|
||||
self.old_instance = None
|
||||
self.unload_failed = True
|
||||
return
|
||||
self.old_instance = None
|
||||
self.loaded = bool(plugin_manager.reload_plugin(self.plugin_id))
|
||||
except Exception as exc: # pylint: disable=broad-except
|
||||
self.error = exc
|
||||
finally:
|
||||
self.done.set()
|
||||
|
||||
|
||||
# Follower dead reckoning (the follower branch of DisplayController.run()).
|
||||
# A leader position further off than this fraction of the strip is a cycle
|
||||
# reset, and is snapped to rather than corrected toward.
|
||||
@@ -726,7 +777,8 @@ class DisplayController:
|
||||
if self._check_wifi_status_message():
|
||||
return True
|
||||
|
||||
# A plugin reload waits for the top of the loop, outside the iteration.
|
||||
# A plugin reload starts at the top of the loop, outside the
|
||||
# iteration; the iteration then resumes while it loads.
|
||||
if self._plugin_reload_pending:
|
||||
return True
|
||||
|
||||
@@ -1520,6 +1572,10 @@ class DisplayController:
|
||||
self._last_pending_service = now
|
||||
|
||||
try:
|
||||
# A reloaded plugin rejoins the rotation as soon as it has
|
||||
# loaded, between two frames of the screen or Vegas strip that
|
||||
# carried on while it loaded.
|
||||
self._finish_plugin_reloads()
|
||||
self._poll_on_demand_requests()
|
||||
self._check_on_demand_expiration()
|
||||
self._evaluate_schedule()
|
||||
@@ -1790,35 +1846,71 @@ class DisplayController:
|
||||
#: Plugin reloads from the control socket, waiting for the top of the
|
||||
#: next loop pass. A tuple, replaced rather than mutated.
|
||||
_pending_plugin_reloads: Tuple[QueuedCommand, ...] = ()
|
||||
#: Reloads started and not finished yet. Their plugin is out of the
|
||||
#: rotation while a plugin-reload thread loads it again. A tuple,
|
||||
#: replaced rather than mutated, so the config watcher can read it.
|
||||
_plugin_reload_jobs: Tuple[_PluginReloadJob, ...] = ()
|
||||
#: A reconcile skipped a plugin that was reloading: run one again once
|
||||
#: the reloads are done.
|
||||
_reconcile_after_reload = False
|
||||
|
||||
@property
|
||||
def _plugin_reload_pending(self) -> bool:
|
||||
"""A reload is waiting for the top of the loop, so the screen ends early.
|
||||
|
||||
Only the start of a reload waits there. The load runs on another
|
||||
thread while the screens carry on, and the new instance joins the
|
||||
rotation between two frames (_finish_plugin_reloads).
|
||||
"""
|
||||
return bool(self._pending_plugin_reloads)
|
||||
|
||||
def _apply_pending_plugin_reloads(self) -> None:
|
||||
"""Reload the plugins the control socket asked for. Render thread,
|
||||
top of the loop pass: no display() and no Vegas iteration on the stack.
|
||||
def _plugin_reloading(self, plugin_id: Optional[str]) -> bool:
|
||||
"""``plugin_id`` is out of the rotation while it is loaded again."""
|
||||
return any(job.plugin_id == plugin_id for job in self._plugin_reload_jobs)
|
||||
|
||||
The same steps as disabling and re-enabling the plugin live
|
||||
(_unregister_plugin, then load and _register_loaded_plugin), with the
|
||||
def _apply_pending_plugin_reloads(self) -> None:
|
||||
"""Start the plugin reloads the control socket asked for. Render
|
||||
thread, top of the loop pass: no display() and no Vegas iteration on
|
||||
the stack.
|
||||
|
||||
The same steps as disabling and re-enabling the plugin live, with the
|
||||
manifest re-read from disk, so the running set ends up as a restart
|
||||
would build it. A plugin that fails to load stays out of the
|
||||
rotation, as it would after a restart.
|
||||
would build it. Only taking the plugin out happens here. The old
|
||||
instance is torn down and the new one loaded on a plugin-reload
|
||||
thread, so the screens carry on meanwhile (_start_plugin_reload).
|
||||
Reloads that have finished are put back in the rotation first.
|
||||
"""
|
||||
self._finish_plugin_reloads()
|
||||
commands, self._pending_plugin_reloads = self._pending_plugin_reloads, ()
|
||||
for command in commands:
|
||||
try:
|
||||
self._reload_plugin_for_command(command)
|
||||
self._start_plugin_reload(command)
|
||||
except Exception: # pylint: disable=broad-except
|
||||
logger.exception("Plugin reload over the control socket failed")
|
||||
command.fail(ControlErrorCode.INTERNAL, 'the display failed to reload it')
|
||||
|
||||
def _reload_plugin_for_command(self, command: QueuedCommand) -> None:
|
||||
def _start_plugin_reload(self, command: QueuedCommand) -> None:
|
||||
"""Take the plugin out of the rotation and start loading it again.
|
||||
|
||||
Render thread. Everything here is quick: the controller's maps, the
|
||||
config subscription, and PluginManager.detach_plugin, after which
|
||||
nothing new calls the old instance (no update(), no Vegas fetch).
|
||||
The slow part runs on a plugin-reload thread: waiting for a Vegas
|
||||
render or an update() of the old instance to let go of its lock, the
|
||||
teardown, and the import and constructor of the new one. Meanwhile
|
||||
Vegas scrolls what its strip already holds of the plugin.
|
||||
"""
|
||||
args = command.args
|
||||
if not isinstance(args, PluginReloadArgs):
|
||||
command.fail(ControlErrorCode.INTERNAL, 'not a reload command')
|
||||
return
|
||||
plugin_id = args.plugin_id
|
||||
for job in self._plugin_reload_jobs:
|
||||
if job.plugin_id == plugin_id:
|
||||
# Updated again while loading: reload once more when this
|
||||
# one is done, so the newest files are the ones that run.
|
||||
job.followers.append(command)
|
||||
return
|
||||
if self.plugin_manager is None or plugin_id not in self.plugin_display_modes:
|
||||
command.fail(ControlErrorCode.NOT_LOADED, f'{plugin_id} is not running')
|
||||
return
|
||||
@@ -1832,23 +1924,80 @@ class DisplayController:
|
||||
previous_mode = self.current_display_mode
|
||||
previous_order = {mode: i for i, mode in enumerate(self.available_modes)}
|
||||
logger.info("Reloading plugin %s over the control socket", plugin_id)
|
||||
self._unregister_plugin(plugin_id, action='Unloaded')
|
||||
loaded = bool(self.plugin_manager.reload_plugin(plugin_id))
|
||||
modes: List[str] = []
|
||||
if loaded:
|
||||
modes = list(self._register_loaded_plugin(plugin_id))
|
||||
# Registering appends; put its modes back where they were in the
|
||||
# rotation (a mode the new version added goes last).
|
||||
self.available_modes.sort(
|
||||
key=lambda mode: previous_order.get(mode, len(previous_order)))
|
||||
self._unregister_plugin(plugin_id, action='Reloading', unload=False)
|
||||
old_instance = self.plugin_manager.detach_plugin(plugin_id)
|
||||
job = _PluginReloadJob(command, plugin_id, previous_order, old_instance)
|
||||
self._plugin_reload_jobs = self._plugin_reload_jobs + (job,)
|
||||
self._resync_mode_index_after_change(previous_mode)
|
||||
self._spawn_plugin_reload(job)
|
||||
|
||||
def _spawn_plugin_reload(self, job: _PluginReloadJob) -> None:
|
||||
"""Run ``job`` on its own thread. The run-loop harness replaces this
|
||||
to run it on its fake clock."""
|
||||
threading.Thread(target=job.run, args=(self.plugin_manager,), daemon=True,
|
||||
name=f'plugin-reload-{job.plugin_id}').start()
|
||||
|
||||
def _finish_plugin_reloads(self) -> None:
|
||||
"""Put the plugins whose reload has finished back in the rotation.
|
||||
|
||||
Render thread: the top of the loop and _service_pending_changes, so
|
||||
a new instance joins between two frames of whatever is showing. That
|
||||
is never the plugin itself, which left the rotation when its reload
|
||||
started. Its modes go back to their old places in the rotation, the
|
||||
current screen stays current, Vegas fetches its content again, and
|
||||
the command is answered with the outcome.
|
||||
"""
|
||||
jobs = self._plugin_reload_jobs
|
||||
if not jobs:
|
||||
return
|
||||
finished = tuple(job for job in jobs if job.done.is_set())
|
||||
if not finished:
|
||||
return
|
||||
self._plugin_reload_jobs = tuple(job for job in jobs if job not in finished)
|
||||
previous_mode = self.current_display_mode
|
||||
for job in finished:
|
||||
try:
|
||||
self._finish_plugin_reload(job)
|
||||
except Exception: # pylint: disable=broad-except
|
||||
logger.exception("Plugin reload over the control socket failed")
|
||||
job.command.fail(ControlErrorCode.INTERNAL, 'the display failed to reload it')
|
||||
if job.followers:
|
||||
self._pending_plugin_reloads = self._pending_plugin_reloads + tuple(job.followers)
|
||||
self._apply_plugin_rotation_order()
|
||||
self._resync_mode_index_after_change(previous_mode)
|
||||
if not loaded:
|
||||
if self._reconcile_after_reload and not self._plugin_reload_jobs:
|
||||
self._reconcile_after_reload = False
|
||||
with self._reconcile_flag_lock:
|
||||
self._pending_plugin_reconcile = True
|
||||
|
||||
def _finish_plugin_reload(self, job: _PluginReloadJob) -> None:
|
||||
plugin_id = job.plugin_id
|
||||
command = job.command
|
||||
if job.error is not None:
|
||||
logger.error("Plugin reload over the control socket failed",
|
||||
exc_info=(type(job.error), job.error, job.error.__traceback__))
|
||||
command.fail(ControlErrorCode.INTERNAL, 'the display failed to reload it')
|
||||
return
|
||||
if job.unload_failed:
|
||||
logger.error("Plugin %s: the old instance could not be unloaded, so the "
|
||||
"update was not loaded; it is out of the rotation until the "
|
||||
"display restarts", plugin_id)
|
||||
command.fail(ControlErrorCode.FAILED,
|
||||
f'{plugin_id}: the old version could not be unloaded; '
|
||||
f'restart the display to load the update')
|
||||
return
|
||||
if not job.loaded:
|
||||
logger.error("Plugin %s did not load after its update; it is out of the "
|
||||
"rotation until it loads", plugin_id)
|
||||
command.fail(ControlErrorCode.FAILED,
|
||||
f'{plugin_id} did not load; see the display log')
|
||||
return
|
||||
modes = list(self._register_loaded_plugin(plugin_id))
|
||||
# Registering appends; put its modes back where they were in the
|
||||
# rotation (a mode the new version added goes last).
|
||||
previous_order = job.previous_order
|
||||
self.available_modes.sort(
|
||||
key=lambda mode: previous_order.get(mode, len(previous_order)))
|
||||
vegas = getattr(self, 'vegas_coordinator', None)
|
||||
if vegas is not None:
|
||||
try:
|
||||
@@ -2215,6 +2364,13 @@ class DisplayController:
|
||||
"""Activate on-demand mode for a specific plugin display."""
|
||||
plugin_id = request.get('plugin_id')
|
||||
mode = request.get('mode')
|
||||
if plugin_id and self._plugin_reloading(plugin_id):
|
||||
# Out of the rotation for a moment while a store update loads it
|
||||
# again; loading it for on-demand now would load it twice.
|
||||
logger.warning("On-demand: plugin '%s' is reloading; try again in a moment",
|
||||
plugin_id)
|
||||
self._set_on_demand_error("plugin-reloading")
|
||||
return
|
||||
if (plugin_id and plugin_id not in self.plugin_display_modes
|
||||
and not self._load_plugin_for_on_demand(plugin_id)):
|
||||
return
|
||||
@@ -3287,9 +3443,11 @@ class DisplayController:
|
||||
self._service_pending_reconcile()
|
||||
|
||||
# Plugin reloads from the control socket (a store update),
|
||||
# here for the same reason: nothing of the plugin's is on the
|
||||
# stack. The screen that was showing ended early for them.
|
||||
if self._pending_plugin_reloads:
|
||||
# started here for the same reason: nothing of the plugin's
|
||||
# is on the stack. The screen that was showing ended early
|
||||
# for them. Reloads that have finished loading join the
|
||||
# rotation here too, if no frame got to them first.
|
||||
if self._pending_plugin_reloads or self._plugin_reload_jobs:
|
||||
self._apply_pending_plugin_reloads()
|
||||
|
||||
if not self.available_modes:
|
||||
@@ -4017,10 +4175,13 @@ class DisplayController:
|
||||
self._plugin_accepts_display_mode.pop(plugin_id, None)
|
||||
return display_modes
|
||||
|
||||
def _unregister_plugin(self, plugin_id: str, action: str = 'Disabled') -> None:
|
||||
def _unregister_plugin(self, plugin_id: str, action: str = 'Disabled',
|
||||
unload: bool = True) -> None:
|
||||
"""Remove a plugin's modes, config subscription and instance, then
|
||||
unload it. Used by live disable hot-reload, and by a reload
|
||||
(``action`` names which in the log line)."""
|
||||
(``action`` names which in the log line), which passes
|
||||
``unload=False``: it hands the instance to its plugin-reload thread
|
||||
to unload instead (_start_plugin_reload)."""
|
||||
with self._plugin_modes_lock:
|
||||
modes = self.plugin_display_modes.pop(plugin_id, [])
|
||||
for mode in modes:
|
||||
@@ -4047,10 +4208,11 @@ class DisplayController:
|
||||
self._plugin_accepts_display_mode.pop(plugin_id, None)
|
||||
|
||||
# Tear down the instance (cleanup + on_disable + module unload).
|
||||
try:
|
||||
self.plugin_manager.unload_plugin(plugin_id)
|
||||
except Exception as e:
|
||||
logger.error("Error unloading plugin %s: %s", plugin_id, e, exc_info=True)
|
||||
if unload:
|
||||
try:
|
||||
self.plugin_manager.unload_plugin(plugin_id)
|
||||
except Exception as e:
|
||||
logger.error("Error unloading plugin %s: %s", plugin_id, e, exc_info=True)
|
||||
|
||||
logger.info("%s plugin %s live (removed modes: %s)", action, plugin_id, modes)
|
||||
|
||||
@@ -4122,6 +4284,8 @@ class DisplayController:
|
||||
known = set(getattr(self.plugin_manager, 'plugin_manifests', ()) or ())
|
||||
with self._plugin_modes_lock:
|
||||
running = set(self.plugin_display_modes)
|
||||
# Out of plugin_display_modes only while a reload loads it again.
|
||||
running.update(job.plugin_id for job in self._plugin_reload_jobs)
|
||||
for key, value in new_config.items():
|
||||
if (key in known and isinstance(value, dict)
|
||||
and value.get('enabled', False) and key not in running):
|
||||
@@ -4160,9 +4324,18 @@ class DisplayController:
|
||||
p for p in discovered
|
||||
if isinstance(config.get(p), dict) and config.get(p, {}).get('enabled', False)
|
||||
}
|
||||
current = set(self.plugin_display_modes.keys())
|
||||
# A plugin being reloaded counts as running, so it is not loaded a
|
||||
# second time beside its plugin-reload thread. One disabled during
|
||||
# its reload is unloaded by a reconcile run after the reload is done.
|
||||
reloading = {job.plugin_id for job in self._plugin_reload_jobs}
|
||||
current = set(self.plugin_display_modes.keys()) | reloading
|
||||
to_add = desired - current
|
||||
to_remove = current - desired
|
||||
if to_remove & reloading:
|
||||
logger.info("Plugin reconcile: %s will be unloaded after its reload",
|
||||
sorted(to_remove & reloading))
|
||||
self._reconcile_after_reload = True
|
||||
to_remove -= reloading
|
||||
if not to_add and not to_remove:
|
||||
return True
|
||||
|
||||
|
||||
@@ -70,6 +70,14 @@ class PluginManager:
|
||||
# before tearing the instance down anyway.
|
||||
UNLOAD_LOCK_TIMEOUT = 5.0
|
||||
|
||||
# How long unload_detached_plugin() (a live reload, off the render thread)
|
||||
# waits for the old instance's lock. Longer than UNLOAD_LOCK_TIMEOUT
|
||||
# because nothing is blocked by the wait, and a Vegas content build of the
|
||||
# old instance can hold the lock for several seconds (5.9 s seen on
|
||||
# ledpi). Past it the reload is refused rather than tearing down an
|
||||
# instance a Vegas call may still be running in.
|
||||
DETACHED_UNLOAD_LOCK_TIMEOUT = 30.0
|
||||
|
||||
# How long the update worker and apply_config_change() wait for a
|
||||
# plugin's lock -- the same bound unload already uses for the same lock.
|
||||
# A display() frame holds it for milliseconds, so this only runs out when
|
||||
@@ -151,7 +159,9 @@ class PluginManager:
|
||||
#
|
||||
# Which thread runs each plugin hook, and what it holds:
|
||||
# __init__, on_enable the loading thread (main thread at startup,
|
||||
# the render thread on a live enable).
|
||||
# the render thread on a live enable, a
|
||||
# plugin-reload thread for a control socket
|
||||
# reload).
|
||||
# update() plugin-update-worker, under the plugin lock,
|
||||
# via PluginExecutor (whose daemon thread runs
|
||||
# the call; if it outlives the executor's
|
||||
@@ -170,8 +180,10 @@ class PluginManager:
|
||||
# plugin lock via apply_config_change(); if the
|
||||
# lock stays busy it is deferred to the update
|
||||
# worker, which applies it under the lock.
|
||||
# cleanup(), on_disable() whoever calls unload_plugin(), under the
|
||||
# lock with UNLOAD_LOCK_TIMEOUT.
|
||||
# cleanup(), on_disable() whoever calls unload_plugin() (or, for a
|
||||
# reload, unload_detached_plugin() on its
|
||||
# plugin-reload thread), under the lock with
|
||||
# UNLOAD_LOCK_TIMEOUT.
|
||||
# No wait on a plugin lock is unbounded, so one hung plugin can only
|
||||
# cost the worker PLUGIN_LOCK_TIMEOUT per attempt.
|
||||
self._update_queue: "queue.Queue[Union[None, Tuple[str, float], _DeferredConfigChange]]" = queue.Queue()
|
||||
@@ -752,14 +764,57 @@ class PluginManager:
|
||||
if lock_acquired:
|
||||
lock.release()
|
||||
|
||||
def _unload_plugin_locked(self, plugin_id: str) -> bool:
|
||||
"""Body of unload_plugin(); caller holds (or gave up on) the plugin lock."""
|
||||
if plugin_id not in self.plugins: # unloaded while we waited
|
||||
def detach_plugin(self, plugin_id: str) -> Optional[Any]:
|
||||
"""Take a loaded plugin out of ``plugins`` without tearing it down.
|
||||
|
||||
The first half of a reload that must not block its caller, the render
|
||||
thread (DisplayController._start_plugin_reload). Every new call into a
|
||||
plugin starts by looking it up in ``plugins``: the update scheduler,
|
||||
the update worker (which looks again under the plugin's lock) and
|
||||
Vegas's fetches. So once detached, nothing new reaches the instance.
|
||||
Work already running on it under its lock -- an update(), or a Vegas
|
||||
content render that can take seconds -- carries on;
|
||||
unload_detached_plugin() waits for it, on another thread.
|
||||
|
||||
Returns the instance, or None when the plugin was not loaded.
|
||||
"""
|
||||
return self.plugins.pop(plugin_id, None)
|
||||
|
||||
def unload_detached_plugin(self, plugin_id: str, plugin: Any) -> bool:
|
||||
"""Tear down an instance taken out by detach_plugin(): unload_plugin()
|
||||
for an instance that is no longer in ``plugins``.
|
||||
|
||||
Waits for the plugin's lock, bounded by DETACHED_UNLOAD_LOCK_TIMEOUT,
|
||||
so it belongs off the render thread. Call it before loading the plugin
|
||||
again: it drops the plugin's modules and lifecycle state along with the
|
||||
instance. Unlike unload_plugin() it never tears down without the lock:
|
||||
a call that took the lock before the detach (a Vegas content build)
|
||||
may still be running in this instance. Returns False then, and the
|
||||
caller must not load the plugin again over it.
|
||||
"""
|
||||
lock = self.get_plugin_lock(plugin_id)
|
||||
if not lock.acquire(timeout=self.DETACHED_UNLOAD_LOCK_TIMEOUT):
|
||||
self.logger.warning(
|
||||
"Plugin %s still busy after %.1fs; not unloading it while in use",
|
||||
plugin_id, self.DETACHED_UNLOAD_LOCK_TIMEOUT)
|
||||
return False
|
||||
try:
|
||||
return self._unload_plugin_locked(plugin_id, plugin)
|
||||
finally:
|
||||
lock.release()
|
||||
|
||||
def _unload_plugin_locked(self, plugin_id: str, detached: Optional[Any] = None) -> bool:
|
||||
"""Body of unload_plugin(); caller holds (or gave up on) the plugin lock.
|
||||
|
||||
``detached`` is an instance already taken out of ``plugins``
|
||||
(detach_plugin); without it, the loaded instance is unloaded.
|
||||
"""
|
||||
if detached is None and plugin_id not in self.plugins: # unloaded while we waited
|
||||
self.logger.warning("Plugin %s not loaded", plugin_id)
|
||||
return False
|
||||
|
||||
try:
|
||||
plugin = self.plugins[plugin_id]
|
||||
plugin = self.plugins[plugin_id] if detached is None else detached
|
||||
|
||||
# Call cleanup if available
|
||||
if hasattr(plugin, 'cleanup'):
|
||||
@@ -775,8 +830,9 @@ class PluginManager:
|
||||
except Exception as e:
|
||||
self.logger.warning("Error during plugin on_disable: %s", e)
|
||||
|
||||
# Remove from active plugins
|
||||
del self.plugins[plugin_id]
|
||||
# Remove from active plugins (a detached one already is)
|
||||
if detached is None:
|
||||
del self.plugins[plugin_id]
|
||||
with self._deferred_config_lock:
|
||||
self._deferred_config_changes.pop(plugin_id, None)
|
||||
with self._plugin_last_update_lock:
|
||||
|
||||
@@ -183,9 +183,27 @@ class PluginAdapter:
|
||||
"round", plugin_id, self.PLUGIN_LOCK_TIMEOUT
|
||||
)
|
||||
return None
|
||||
if not self._still_loaded(plugin, plugin_id):
|
||||
return None
|
||||
return self._fetch_content(plugin, plugin_id, restricted=False,
|
||||
keyed=keyed)
|
||||
|
||||
def _still_loaded(self, plugin: 'BasePlugin', plugin_id: str) -> bool:
|
||||
"""Whether ``plugin`` is still the loaded instance of ``plugin_id``.
|
||||
|
||||
Checked once the plugin's lock is held: a reload or a disable can
|
||||
take the instance out and tear it down while this fetch waited for
|
||||
the lock (PluginManager.detach_plugin), and a torn-down instance is
|
||||
not asked for content. True when the manager keeps no ``plugins``
|
||||
mapping to ask.
|
||||
"""
|
||||
plugins = getattr(self.plugin_manager, 'plugins', None)
|
||||
if not isinstance(plugins, dict) or plugins.get(plugin_id) is plugin:
|
||||
return True
|
||||
logger.debug("[%s] Unloaded or reloaded while waiting for its lock; "
|
||||
"skipping the old instance", plugin_id)
|
||||
return False
|
||||
|
||||
def is_live_capable(self, plugin: 'BasePlugin', plugin_id: str) -> bool:
|
||||
"""Whether to ask this plugin for live elements rather than pictures.
|
||||
|
||||
@@ -922,6 +940,8 @@ class PluginAdapter:
|
||||
return None
|
||||
epochs = self.live_epochs
|
||||
epoch = epochs.get(plugin_id) if epochs is not None else 0
|
||||
if not self._still_loaded(plugin, plugin_id):
|
||||
return epoch, {}
|
||||
render_width = self.resolve_render_width(plugin, plugin_id)
|
||||
plugin._vegas_render_width = render_width
|
||||
try:
|
||||
|
||||
@@ -333,8 +333,11 @@ class StreamManager:
|
||||
loaded = 0
|
||||
|
||||
if hasattr(self.plugin_manager, 'plugins'):
|
||||
loaded = len(self.plugin_manager.plugins)
|
||||
for plugin_id, plugin in self.plugin_manager.plugins.items():
|
||||
# A snapshot: a plugin reload adds and removes entries on its
|
||||
# own thread (DisplayController._start_plugin_reload).
|
||||
plugins = list(self.plugin_manager.plugins.items())
|
||||
loaded = len(plugins)
|
||||
for plugin_id, plugin in plugins:
|
||||
if not getattr(plugin, 'enabled', False):
|
||||
logger.debug("[%s] Vegas: skipped (not enabled)", plugin_id)
|
||||
continue
|
||||
|
||||
@@ -258,6 +258,15 @@ class FakePluginManager:
|
||||
self.plugins.pop(plugin_id, None)
|
||||
return True
|
||||
|
||||
def detach_plugin(self, plugin_id):
|
||||
return self.plugins.pop(plugin_id, None)
|
||||
|
||||
def unload_detached_plugin(self, plugin_id, plugin):
|
||||
return True
|
||||
|
||||
def reload_plugin(self, plugin_id):
|
||||
return False
|
||||
|
||||
def get_plugin_lock(self, plugin_id):
|
||||
if plugin_id in self.no_lock:
|
||||
return None # as when loading failed part-way
|
||||
@@ -549,7 +558,19 @@ class RunLoopHarness:
|
||||
self.sync = FakeSync(self)
|
||||
self.dm = self._display_manager()
|
||||
self._displayed_this_pass = False
|
||||
#: How long a plugin reload's own thread takes, on the fake clock.
|
||||
self.reload_seconds = 0.0
|
||||
self.controller = self._build()
|
||||
self.controller._spawn_plugin_reload = self._spawn_plugin_reload
|
||||
|
||||
def _spawn_plugin_reload(self, job) -> None:
|
||||
"""The plugin-reload thread, on the fake clock: the job runs
|
||||
``reload_seconds`` after it was started, meanwhile the render thread
|
||||
carries on (at once when that is 0)."""
|
||||
if self.reload_seconds <= 0:
|
||||
job.run(self.pm)
|
||||
else:
|
||||
self.clock.at(self.clock.rel() + self.reload_seconds, lambda: job.run(self.pm))
|
||||
|
||||
# -- event log -----------------------------------------------------------
|
||||
def log(self, kind: str, subject: Any = None, quiet: bool = False, **data):
|
||||
|
||||
@@ -4,8 +4,10 @@
|
||||
and answered with what the panel shows -- including when the dim schedule
|
||||
holds it lower, when the panel refuses it, and when the schedule has the
|
||||
display off;
|
||||
* ``plugin.reload`` is answered from the top of the loop pass, for every
|
||||
outcome: reloaded (new instance registered, Vegas told), not running,
|
||||
* ``plugin.reload`` starts at the top of the loop pass and is answered once
|
||||
its plugin-reload thread is done (test_plugin_reload_off_render_thread.py
|
||||
has the timing), for every outcome: reloaded (new instance registered,
|
||||
Vegas told), not running,
|
||||
loaded only for on-demand, failed to load, or raised;
|
||||
* the render thread wakes for a command in real time, not just on the fake
|
||||
clock (test_run_loop_socket_wake.py): within milliseconds on a static
|
||||
@@ -141,7 +143,17 @@ def running(dc):
|
||||
pm.plugin_manifests[pid] = {'version': '2.0.0'}
|
||||
return True
|
||||
|
||||
def detach(pid):
|
||||
return pm.plugins.pop(pid, None)
|
||||
|
||||
def unload_detached(pid, plugin):
|
||||
calls.append(('unload', pid))
|
||||
assert pid not in pm.plugins, "torn down while still loaded"
|
||||
return True
|
||||
|
||||
pm.unload_plugin = MagicMock(side_effect=unload)
|
||||
pm.detach_plugin = MagicMock(side_effect=detach)
|
||||
pm.unload_detached_plugin = MagicMock(side_effect=unload_detached)
|
||||
pm.reload_plugin = MagicMock(side_effect=reload)
|
||||
dc.plugin_manager = pm
|
||||
dc.plugin_display_modes = {'clock': ['clock_a', 'clock_b'], 'weather': ['weather']}
|
||||
@@ -159,8 +171,12 @@ class TestReload:
|
||||
dc._control_server = FakeServer(*commands)
|
||||
dc._poll_on_demand_requests() # the drain: queued, not applied
|
||||
assert dc._plugin_reload_pending
|
||||
dc._apply_pending_plugin_reloads() # the top of the next pass
|
||||
dc._apply_pending_plugin_reloads() # the top of the next pass: it starts
|
||||
assert not dc._plugin_reload_pending
|
||||
for job in dc._plugin_reload_jobs: # its plugin-reload thread
|
||||
assert job.done.wait(5)
|
||||
dc._finish_plugin_reloads() # between two frames
|
||||
assert not dc._plugin_reload_jobs
|
||||
|
||||
def test_reloaded(self, running):
|
||||
dc = running.dc
|
||||
|
||||
@@ -0,0 +1,527 @@
|
||||
"""A ``plugin.reload`` never stalls the render thread (#720 follow-up).
|
||||
|
||||
On ledpi a reload of football-scoreboard (a store update, 3.17.0 to 3.18.1)
|
||||
arrived while Vegas mode was running, and the panel froze for 3.0 s
|
||||
("Render stall over: no frame for 3043ms"). Vegas yielded at once, but the
|
||||
reload ran on the render thread, and its first step, unload_plugin(), waited
|
||||
for the plugin's lock. The strip's prefetch thread held that lock: it was
|
||||
rebuilding the old instance's Vegas content, which takes seconds for a
|
||||
scoreboard. The new instance was then loaded on the render thread too
|
||||
(0.47 s on ledpi).
|
||||
|
||||
Now the render thread only takes the plugin out of the rotation and out of
|
||||
the plugin manager (detach_plugin), and a plugin-reload thread waits for the
|
||||
lock, tears the old instance down and loads the new one. The new instance
|
||||
joins the rotation between two frames.
|
||||
|
||||
* Real threads, real PluginManager and PluginAdapter: frames keep coming
|
||||
(no gap over 100 ms) while a slow Vegas render holds the old instance's
|
||||
lock, and the reload still reports the real outcome. Before the fix the
|
||||
gap was the whole render.
|
||||
* The fake-clock run loop (test/_run_loop_harness.py): Vegas frames flow
|
||||
through a reload whose thread takes 3 s, the ticker never leaves, and
|
||||
the reload is answered when the new instance joins.
|
||||
* Thread safety: the old instance is torn down only after its render let
|
||||
go of the lock, is never asked for content again, and never gets an
|
||||
update() once the reload starts; the new one is loaded once.
|
||||
* The other reload cases still answer as before: a plugin that is on
|
||||
screen, one that is not, one that fails to load, and a second reload of
|
||||
a plugin that is still loading.
|
||||
"""
|
||||
|
||||
import json
|
||||
import os
|
||||
import threading
|
||||
import time
|
||||
from types import SimpleNamespace
|
||||
from unittest.mock import MagicMock
|
||||
|
||||
import pytest
|
||||
from PIL import Image
|
||||
|
||||
os.environ.setdefault("EMULATOR", "true")
|
||||
|
||||
from src.ipc.contract import Command, ErrorCode, PluginReloadArgs # noqa: E402
|
||||
from src.ipc.server import CommandOutcome, QueuedCommand # noqa: E402
|
||||
from src.plugin_system.base_plugin import BasePlugin # noqa: E402
|
||||
from src.plugin_system.plugin_manager import PluginManager # noqa: E402
|
||||
from src.vegas_mode.config import VegasModeConfig # noqa: E402
|
||||
from src.vegas_mode.plugin_adapter import PluginAdapter # noqa: E402
|
||||
from test._run_loop_harness import FakePlugin, RunLoopHarness # noqa: E402
|
||||
from test.test_vegas_elements_api import _DM # noqa: E402
|
||||
|
||||
#: How long the old instance's Vegas render holds its lock. ledpi's was 3 s
|
||||
#: (scripts in the PR body measure that); the gap scales with it.
|
||||
RENDER_SECONDS = 1.5
|
||||
FRAME = 0.008
|
||||
#: "A frame or two", with room for a slow CI runner.
|
||||
MAX_GAP = 0.1
|
||||
|
||||
|
||||
def _reload(plugin_id, request_id="r1"):
|
||||
return QueuedCommand(request_id=request_id, cmd=Command.PLUGIN_RELOAD,
|
||||
args=PluginReloadArgs(plugin_id), received_at=time.time(),
|
||||
outcome=CommandOutcome())
|
||||
|
||||
|
||||
class _Server:
|
||||
"""The ControlServer surface the controller drains."""
|
||||
|
||||
def __init__(self):
|
||||
self.commands = []
|
||||
|
||||
@property
|
||||
def has_pending(self):
|
||||
return bool(self.commands)
|
||||
|
||||
def drain(self):
|
||||
out, self.commands = self.commands, []
|
||||
return out
|
||||
|
||||
def close(self):
|
||||
pass
|
||||
|
||||
|
||||
class _Rig:
|
||||
"""A real PluginManager running one slow-rendering plugin, 'slow'."""
|
||||
|
||||
def __init__(self, tmp_path, render_seconds):
|
||||
self.events = []
|
||||
self.lock = threading.Lock()
|
||||
self.render_started = threading.Event()
|
||||
self.render_seconds = render_seconds
|
||||
self.generation = 0
|
||||
rig = self
|
||||
|
||||
class SlowVegas(BasePlugin):
|
||||
"""Draws its Vegas content slowly, as a scoreboard does on a Pi."""
|
||||
|
||||
def __init__(self, generation): # pylint: disable=super-init-not-called
|
||||
self.plugin_id = "slow"
|
||||
self.config = {"enabled": True}
|
||||
self.enabled = True
|
||||
self.modes = ["slow"]
|
||||
self.plugin_manager = None
|
||||
self.generation = generation
|
||||
|
||||
def get_update_interval(self):
|
||||
return 0.05
|
||||
|
||||
def update(self):
|
||||
rig.log("update", self.generation)
|
||||
|
||||
def display(self, force_clear=False):
|
||||
pass
|
||||
|
||||
def validate_config(self):
|
||||
return True
|
||||
|
||||
def get_vegas_content(self):
|
||||
rig.log("render-start", self.generation)
|
||||
rig.render_started.set()
|
||||
time.sleep(rig.render_seconds if self.generation == 1 else 0)
|
||||
rig.log("render-end", self.generation)
|
||||
return [Image.new("RGB", (64, 16), (255, 0, 0))]
|
||||
|
||||
def cleanup(self):
|
||||
rig.log("cleanup", self.generation)
|
||||
|
||||
def on_enable(self):
|
||||
pass
|
||||
|
||||
def on_disable(self):
|
||||
pass
|
||||
|
||||
def construct(**_kw):
|
||||
rig.generation += 1
|
||||
return SlowVegas(rig.generation), None
|
||||
|
||||
plugin_dir = tmp_path / "plugins" / "slow"
|
||||
plugin_dir.mkdir(parents=True)
|
||||
self.manifest_path = plugin_dir / "manifest.json"
|
||||
manifest = {"id": "slow", "version": "1.0.0", "display_modes": ["slow"]}
|
||||
self.manifest_path.write_text(json.dumps(manifest))
|
||||
pm = PluginManager(plugins_dir=str(tmp_path / "plugins"))
|
||||
pm.plugin_manifests["slow"] = manifest
|
||||
pm.schema_manager = MagicMock()
|
||||
pm.schema_manager.get_schema_path.return_value = None
|
||||
pm.schema_manager.prepare_plugin_config.side_effect = (
|
||||
lambda pid, cfg, schema=None, changed_paths=None: cfg)
|
||||
pm.plugin_loader = MagicMock()
|
||||
pm.plugin_loader.find_plugin_directory.return_value = plugin_dir
|
||||
pm.plugin_loader.load_plugin.side_effect = construct
|
||||
assert pm.load_plugin("slow")
|
||||
self.pm = pm
|
||||
self.adapter = PluginAdapter(_DM(), VegasModeConfig(), plugin_manager=pm)
|
||||
self.prefetched = []
|
||||
|
||||
def log(self, kind, generation):
|
||||
with self.lock:
|
||||
self.events.append((kind, generation))
|
||||
|
||||
def index(self, kind, generation):
|
||||
return self.events.index((kind, generation))
|
||||
|
||||
def start_vegas_render(self):
|
||||
"""The strip's prefetch thread rebuilding the old instance's content."""
|
||||
plugin = self.pm.plugins["slow"]
|
||||
|
||||
def fetch():
|
||||
self.prefetched.append(self.adapter.get_content(plugin, "slow", offscreen_only=True))
|
||||
thread = threading.Thread(target=fetch, name="vegas-strip-prefetch", daemon=True)
|
||||
thread.start()
|
||||
assert self.render_started.wait(2)
|
||||
return thread
|
||||
|
||||
|
||||
@pytest.fixture
|
||||
def dc(test_display_controller):
|
||||
c = test_display_controller
|
||||
c.display_manager.set_brightness = MagicMock(return_value=True)
|
||||
c.display_manager.update_display = MagicMock()
|
||||
c.config = {"timezone": "UTC", "display": {"hardware": {"brightness": 90}}}
|
||||
c._normal_brightness = 90
|
||||
c.current_brightness = 90
|
||||
c.is_display_active = True
|
||||
c._tz = None
|
||||
c.vegas_coordinator = MagicMock()
|
||||
return c
|
||||
|
||||
|
||||
def _with_rig(dc, tmp_path, render_seconds=None):
|
||||
rig = _Rig(tmp_path, RENDER_SECONDS if render_seconds is None else render_seconds)
|
||||
clock = SimpleNamespace(modes=["clock"])
|
||||
dc.plugin_manager = rig.pm
|
||||
dc.plugin_display_modes = {"clock": ["clock"]}
|
||||
dc.available_modes = ["clock"]
|
||||
dc.plugin_modes = {"clock": clock}
|
||||
dc.mode_to_plugin_id = {"clock": "clock"}
|
||||
dc._register_loaded_plugin("slow")
|
||||
dc.current_mode_index = 0
|
||||
dc.current_display_mode = "clock"
|
||||
dc._control_server = _Server()
|
||||
return rig
|
||||
|
||||
|
||||
def _render_frames(dc, rig, until, limit):
|
||||
"""What the render thread does while Vegas runs: one frame every 8 ms,
|
||||
servicing pending changes between frames (Vegas's interrupt check) and,
|
||||
when a screen-ending command is pending, the top of the loop pass.
|
||||
Returns the frame times."""
|
||||
frames = [time.perf_counter()]
|
||||
deadline = frames[0] + limit
|
||||
while not until():
|
||||
dc._service_pending_changes()
|
||||
if dc._plugin_reload_pending:
|
||||
dc._apply_pending_plugin_reloads() # Vegas yields; resumes next pass
|
||||
if len(frames) % 5 == 0:
|
||||
rig.pm.run_scheduled_updates() # the update tick
|
||||
time.sleep(FRAME)
|
||||
frames.append(time.perf_counter())
|
||||
assert frames[-1] < deadline, "the reload never finished"
|
||||
return frames
|
||||
|
||||
|
||||
def _max_gap(frames):
|
||||
return max(b - a for a, b in zip(frames, frames[1:]))
|
||||
|
||||
|
||||
class TestFramesKeepFlowing:
|
||||
def test_a_reload_during_a_slow_vegas_render(self, dc, tmp_path):
|
||||
rig = _with_rig(dc, tmp_path)
|
||||
old = rig.pm.plugins["slow"]
|
||||
prefetch = rig.start_vegas_render()
|
||||
rig.manifest_path.write_text(json.dumps(
|
||||
{"id": "slow", "version": "2.0.0", "display_modes": ["slow"]}))
|
||||
|
||||
command = _reload("slow")
|
||||
posted = time.perf_counter()
|
||||
dc._control_server.commands.append(command)
|
||||
frames = _render_frames(dc, rig, lambda: command.outcome.done, limit=10)
|
||||
answered = time.perf_counter() - posted
|
||||
prefetch.join(2)
|
||||
rig.pm.stop_update_worker()
|
||||
|
||||
gap = _max_gap(frames)
|
||||
print(f"\nlongest frame gap {gap * 1000:.0f} ms, answered after {answered:.2f} s "
|
||||
f"(the old instance's render held its lock {RENDER_SECONDS:.1f} s)")
|
||||
assert gap < MAX_GAP
|
||||
# The real outcome, once the new instance is in the rotation.
|
||||
assert command.outcome.result == {"plugin_id": "slow", "reloaded": True,
|
||||
"version": "2.0.0", "modes": ["slow"]}
|
||||
new = rig.pm.plugins["slow"]
|
||||
assert new is not old and new.generation == 2
|
||||
assert dc.plugin_modes["slow"] is new
|
||||
assert dc.available_modes == ["clock", "slow"]
|
||||
assert dc.current_display_mode == "clock"
|
||||
dc.vegas_coordinator.mark_plugin_updated.assert_called_once_with("slow")
|
||||
# The old instance finished its render before it was torn down, and
|
||||
# the strip got that render.
|
||||
assert rig.index("render-end", 1) < rig.index("cleanup", 1)
|
||||
assert rig.prefetched and rig.prefetched[0]
|
||||
# Loaded once; no update() of the old instance once it was torn
|
||||
# down, and none of the new one before.
|
||||
assert rig.generation == 2
|
||||
cleanup = rig.index("cleanup", 1)
|
||||
assert all(i < cleanup for i, e in enumerate(rig.events) if e == ("update", 1))
|
||||
assert all(i > cleanup for i, e in enumerate(rig.events) if e == ("update", 2))
|
||||
|
||||
def test_a_fetch_that_waited_out_the_reload_skips_the_old_instance(self, tmp_path):
|
||||
"""A Vegas fetch that looked the old instance up before the reload,
|
||||
and got its lock only after the teardown, does not run it."""
|
||||
rig = _Rig(tmp_path, 0)
|
||||
old = rig.pm.detach_plugin("slow")
|
||||
assert rig.adapter.get_content(old, "slow", offscreen_only=True) is None
|
||||
rig.pm.unload_detached_plugin("slow", old)
|
||||
assert rig.pm.reload_plugin("slow")
|
||||
assert rig.adapter.get_content(old, "slow", offscreen_only=True) is None
|
||||
assert ("render-start", 1) not in rig.events
|
||||
# The new instance is fetched as usual.
|
||||
assert rig.adapter.get_content(rig.pm.plugins["slow"], "slow", offscreen_only=True)
|
||||
assert ("render-start", 2) in rig.events
|
||||
|
||||
|
||||
class TestPluginManagerDetach:
|
||||
def test_teardown_waits_for_the_lock_and_leaves_plugins_alone(self, tmp_path):
|
||||
rig = _Rig(tmp_path, 0)
|
||||
pm = rig.pm
|
||||
old = pm.detach_plugin("slow")
|
||||
assert "slow" not in pm.plugins and old.generation == 1
|
||||
lock = pm.get_plugin_lock("slow")
|
||||
lock.acquire()
|
||||
done = threading.Event()
|
||||
threading.Thread(target=lambda: (pm.unload_detached_plugin("slow", old), done.set()),
|
||||
daemon=True).start()
|
||||
assert not done.wait(0.2) # a render of the old instance holds it
|
||||
assert ("cleanup", 1) not in rig.events
|
||||
lock.release()
|
||||
assert done.wait(5)
|
||||
assert ("cleanup", 1) in rig.events
|
||||
assert pm.reload_plugin("slow")
|
||||
assert pm.plugins["slow"].generation == 2
|
||||
|
||||
def test_teardown_is_refused_while_the_lock_stays_held(self, tmp_path):
|
||||
"""A Vegas call that took the lock before the detach may still be
|
||||
running in the old instance: never tear it down from under it."""
|
||||
rig = _Rig(tmp_path, 0)
|
||||
pm = rig.pm
|
||||
pm.DETACHED_UNLOAD_LOCK_TIMEOUT = 0.2
|
||||
old = pm.detach_plugin("slow")
|
||||
lock = pm.get_plugin_lock("slow")
|
||||
lock.acquire()
|
||||
try:
|
||||
assert pm.unload_detached_plugin("slow", old) is False
|
||||
assert ("cleanup", 1) not in rig.events
|
||||
finally:
|
||||
lock.release()
|
||||
|
||||
def test_detached_teardown_outwaits_the_ordinary_unload_bound(self):
|
||||
# A Vegas build of the old instance held the lock 5.9 s on ledpi.
|
||||
from src.plugin_system.plugin_manager import PluginManager
|
||||
assert PluginManager.DETACHED_UNLOAD_LOCK_TIMEOUT > 2 * PluginManager.UNLOAD_LOCK_TIMEOUT
|
||||
|
||||
def test_detaching_a_plugin_that_is_not_loaded(self, tmp_path):
|
||||
pm = _Rig(tmp_path, 0).pm
|
||||
assert pm.detach_plugin("nope") is None
|
||||
|
||||
|
||||
# -- the run loop on the fake clock ----------------------------------------
|
||||
|
||||
POSTED = 10.3
|
||||
|
||||
|
||||
def _with_reloadable(h, version="2.0.0", loads=True):
|
||||
new = FakePlugin("clock", ["clock"], duration=30)
|
||||
|
||||
def reload_plugin(plugin_id):
|
||||
h.log("reload", plugin_id)
|
||||
if not loads:
|
||||
return False
|
||||
new._h = h
|
||||
h.pm.plugins[plugin_id] = new
|
||||
h.pm.plugin_manifests[plugin_id] = {"version": version, "display_modes": ["clock"]}
|
||||
return True
|
||||
|
||||
h.pm.reload_plugin = reload_plugin
|
||||
return new
|
||||
|
||||
|
||||
def _vegas(h):
|
||||
h.add_plugin(FakePlugin("clock", ["clock"], duration=30))
|
||||
h.add_plugin(FakePlugin("weather", ["weather"], duration=30))
|
||||
h.enable_vegas(cycle=30)
|
||||
|
||||
|
||||
def _hold_lock(h, plugin_id, seconds):
|
||||
"""A Vegas render of ``plugin_id`` holds its lock for ``seconds`` from
|
||||
when the reload is asked for: the render thread would block that long in
|
||||
unload_plugin(), and the plugin-reload thread does instead."""
|
||||
real_unload = h.pm.unload_plugin
|
||||
|
||||
def unload_plugin(pid):
|
||||
if pid == plugin_id:
|
||||
h.clock.sleep(max(0.0, POSTED + seconds - h.clock.rel()))
|
||||
return real_unload(pid)
|
||||
h.pm.unload_plugin = unload_plugin
|
||||
h.reload_seconds = seconds
|
||||
|
||||
|
||||
def _vegas_frame_gaps(h):
|
||||
times = [e[0] for e in h.events if e[1] == "vegas-frame"]
|
||||
return max(b - a for a, b in zip(times, times[1:]))
|
||||
|
||||
|
||||
def test_vegas_keeps_scrolling_through_a_slow_reload(tmp_path):
|
||||
h = RunLoopHarness(tmp_path, horizon=40)
|
||||
_vegas(h)
|
||||
new = _with_reloadable(h)
|
||||
_hold_lock(h, "clock", 3.0)
|
||||
command = h.control_socket().post(POSTED, Command.PLUGIN_RELOAD, {"plugin_id": "clock"})
|
||||
trace = h.run()
|
||||
|
||||
# Frames every 8 ms throughout: before the fix, none for 3 s.
|
||||
assert _vegas_frame_gaps(h) <= 0.1
|
||||
# The new instance loaded 3 s later, on its own thread, and joined then.
|
||||
reload_at = next(e[0] for e in h.events if e[1] == "reload")
|
||||
assert reload_at == pytest.approx(POSTED + 3.0, abs=0.01)
|
||||
assert command.outcome.result == {"plugin_id": "clock", "reloaded": True,
|
||||
"version": "2.0.0", "modes": ["clock"]}
|
||||
assert h.controller.plugin_modes["clock"] is new
|
||||
assert h.controller.available_modes == ["clock", "weather"]
|
||||
# Only the start of the reload ended a Vegas iteration; the ticker
|
||||
# carried on through it.
|
||||
assert all(r[1] == "<vegas>" for r in trace["screens"] if r[0] >= POSTED)
|
||||
|
||||
|
||||
def test_a_reload_while_on_screen_lets_the_rotation_carry_on(tmp_path):
|
||||
h = RunLoopHarness(tmp_path, horizon=70)
|
||||
h.add_plugin(FakePlugin("clock", ["clock"], duration=30))
|
||||
h.add_plugin(FakePlugin("weather", ["weather"], duration=30))
|
||||
new = _with_reloadable(h)
|
||||
_hold_lock(h, "clock", 3.0)
|
||||
command = h.control_socket().post(POSTED, Command.PLUGIN_RELOAD, {"plugin_id": "clock"})
|
||||
trace = h.run()
|
||||
|
||||
# The clock screen ends when the reload is asked for, weather shows
|
||||
# while the clock loads, and the reloaded clock comes round next.
|
||||
assert trace["screens"][0][:3] == [0.0, "clock", POSTED]
|
||||
assert trace["screens"][1][:2] == [POSTED, "weather"]
|
||||
assert trace["screens"][2][1] == "clock"
|
||||
assert command.outcome.result["reloaded"] is True
|
||||
assert h.controller.plugin_modes["clock"] is new
|
||||
|
||||
|
||||
def test_a_reload_of_a_plugin_not_on_screen_keeps_its_place(tmp_path):
|
||||
h = RunLoopHarness(tmp_path, horizon=70)
|
||||
h.add_plugin(FakePlugin("clock", ["clock"], duration=30))
|
||||
h.add_plugin(FakePlugin("weather", ["weather"], duration=30))
|
||||
h.add_plugin(FakePlugin("news", ["news"], duration=30))
|
||||
new_weather = FakePlugin("weather", ["weather"], duration=30)
|
||||
|
||||
def reload_plugin(plugin_id):
|
||||
h.log("reload", plugin_id)
|
||||
new_weather._h = h
|
||||
h.pm.plugins[plugin_id] = new_weather
|
||||
h.pm.plugin_manifests[plugin_id] = {"version": "2.0.0"}
|
||||
return True
|
||||
h.pm.reload_plugin = reload_plugin
|
||||
h.reload_seconds = 3.0
|
||||
command = h.control_socket().post(POSTED, Command.PLUGIN_RELOAD, {"plugin_id": "weather"})
|
||||
h.run()
|
||||
|
||||
assert command.outcome.result["reloaded"] is True
|
||||
assert h.controller.available_modes == ["clock", "weather", "news"]
|
||||
assert h.controller.plugin_modes["weather"] is new_weather
|
||||
|
||||
|
||||
def test_a_plugin_that_fails_to_load_after_a_slow_teardown(tmp_path):
|
||||
h = RunLoopHarness(tmp_path, horizon=40)
|
||||
_vegas(h)
|
||||
_with_reloadable(h, loads=False)
|
||||
_hold_lock(h, "clock", 3.0)
|
||||
command = h.control_socket().post(POSTED, Command.PLUGIN_RELOAD, {"plugin_id": "clock"})
|
||||
h.run()
|
||||
|
||||
assert _vegas_frame_gaps(h) <= 0.1
|
||||
assert command.outcome.error_code == ErrorCode.FAILED
|
||||
assert "clock" not in h.controller.available_modes
|
||||
assert "clock" not in h.pm.plugins
|
||||
|
||||
|
||||
def test_a_failed_teardown_stops_the_reload(tmp_path):
|
||||
"""Loading over a half-unloaded plugin could reuse its old module and
|
||||
report a reload that never happened; report the failure instead."""
|
||||
h = RunLoopHarness(tmp_path, horizon=40)
|
||||
_vegas(h)
|
||||
reloads = []
|
||||
h.pm.unload_detached_plugin = lambda plugin_id, instance: False
|
||||
h.pm.reload_plugin = lambda plugin_id: reloads.append(plugin_id) or True
|
||||
command = h.control_socket().post(POSTED, Command.PLUGIN_RELOAD, {"plugin_id": "clock"})
|
||||
h.run()
|
||||
|
||||
assert reloads == []
|
||||
assert command.outcome.error_code == ErrorCode.FAILED
|
||||
assert "restart the display" in command.outcome.error_message
|
||||
assert "clock" not in h.controller.available_modes
|
||||
assert _vegas_frame_gaps(h) <= 0.1
|
||||
|
||||
|
||||
def test_a_second_reload_while_loading_runs_after_the_first(tmp_path):
|
||||
h = RunLoopHarness(tmp_path, horizon=40)
|
||||
_vegas(h)
|
||||
loads = []
|
||||
|
||||
def reload_plugin(plugin_id):
|
||||
plugin = FakePlugin("clock", ["clock"], duration=30)
|
||||
plugin._h = h
|
||||
loads.append(plugin)
|
||||
h.log("reload", plugin_id)
|
||||
h.pm.plugins[plugin_id] = plugin
|
||||
h.pm.plugin_manifests[plugin_id] = {"version": f"{len(loads)}.0.0"}
|
||||
return True
|
||||
h.pm.reload_plugin = reload_plugin
|
||||
h.reload_seconds = 3.0
|
||||
server = h.control_socket()
|
||||
first = server.post(POSTED, Command.PLUGIN_RELOAD, {"plugin_id": "clock"}, "a")
|
||||
second = server.post(POSTED + 1, Command.PLUGIN_RELOAD, {"plugin_id": "clock"}, "b")
|
||||
h.run()
|
||||
|
||||
# The second starts once the first has joined the rotation (within a
|
||||
# quarter second of loading), and takes its own 3 s.
|
||||
loaded = [e[0] for e in h.events if e[1] == "reload"]
|
||||
assert len(loaded) == 2
|
||||
assert loaded[0] == pytest.approx(POSTED + 3.0, abs=0.05)
|
||||
assert 3.0 <= loaded[1] - loaded[0] <= 3.5
|
||||
assert first.outcome.result["version"] == "1.0.0"
|
||||
assert second.outcome.result["version"] == "2.0.0"
|
||||
assert h.controller.plugin_modes["clock"] is loads[-1]
|
||||
assert _vegas_frame_gaps(h) <= 0.1
|
||||
|
||||
|
||||
def test_a_reconcile_during_a_reload_does_not_load_it_twice(dc):
|
||||
"""The config watcher sees an enabled plugin missing from the rotation
|
||||
while it reloads; the reconcile must not load it beside the reload."""
|
||||
pm = MagicMock()
|
||||
pm.discover_plugins.return_value = ["slow"]
|
||||
dc.plugin_manager = pm
|
||||
dc.config_service = MagicMock()
|
||||
dc.config_service.get_config.return_value = {"slow": {"enabled": True}}
|
||||
dc.plugin_display_modes = {}
|
||||
dc._plugin_reload_jobs = (SimpleNamespace(plugin_id="slow"),)
|
||||
assert dc._reconcile_enabled_plugins() is True
|
||||
pm.load_plugin.assert_not_called()
|
||||
assert not dc._enabled_plugin_not_running({"slow": {"enabled": True}})
|
||||
|
||||
# Disabled while it reloads: unloaded by a reconcile after the reload.
|
||||
dc.config_service.get_config.return_value = {"slow": {"enabled": False}}
|
||||
assert dc._reconcile_enabled_plugins() is True
|
||||
pm.unload_plugin.assert_not_called()
|
||||
assert dc._reconcile_after_reload is True
|
||||
|
||||
|
||||
def test_on_demand_for_a_reloading_plugin_is_refused(dc):
|
||||
dc._plugin_reload_jobs = (SimpleNamespace(plugin_id="slow"),)
|
||||
dc._load_plugin_for_on_demand = MagicMock()
|
||||
dc._activate_on_demand({"plugin_id": "slow"})
|
||||
dc._load_plugin_for_on_demand.assert_not_called()
|
||||
assert dc.on_demand_last_error == "plugin-reloading"
|
||||
Reference in New Issue
Block a user