镜像站点 · 本页由第三方 GitHub 只读镜像提供,非 GitHub 官方站点,不接受任何登录或凭据输入。前往 github.com
Skip to content

fix(plugins): one hung plugin no longer stops every plugin from updating - #677

Merged
ChuckBuilds merged 6 commits into
mainfrom
claude/plugin-hang-containment
Sep 30, 2026
Merged

ChuckBuilds merged 6 commits into
mainfrom
claude/plugin-hang-containment

Conversation

@ChuckBuilds

@ChuckBuilds ChuckBuilds commented Sep 29, 2026 •

Copy link
Copy Markdown
Owner

Problem

PluginManager._update_worker_loop() is the only thread that runs scheduled update() calls. It took each plugin's lock with a blocking lock.acquire(), with no timeout. The render thread holds that same lock while it runs the plugin's display(). If one plugin's display() never returns, the worker blocks on that acquire forever and no plugin updates again. The display keeps scrolling, but scores, weather and clocks go stale. The same thing happens when a screen's first frame outlives PluginExecutor's 30s timeout: its lingering daemon thread keeps the lock indefinitely.

Related gaps:

  • After a screen's first frame, display() calls were not timed at all.
  • A first frame that timed out was still recorded as a health success.
  • An update() still running after its timeout left the plugin in RUNNING state with nothing recorded.
  • on_config_change() (overridden by ~45 plugins) ran on the config watcher thread without the plugin lock, so it could interleave with update() on the worker.

Fix

This PR only contains hangs inside the process. It does not change the systemd units or the installer.

  • Bounded lock wait on the worker. The worker waits at most PluginManager.PLUGIN_LOCK_TIMEOUT (5s), which is UNLOAD_LOCK_TIMEOUT, the bound unload already uses for this lock. A display() frame holds the lock for milliseconds, but a Vegas prefetch holds it for the plugin's whole content render, which on a slow Pi can outlast 5s. When the wait runs out, _skip_busy_update():

    • drops the pending slot;
    • returns the plugin to ENABLED with PluginBusyError error info (the existing _record_update_failure bookkeeping, with count_failure=False);
    • stamps the last-update time, so the retry waits a full interval;
    • logs it, rate-limited to once a minute per plugin;
    • records it in health as a busy skip (busy_skip_count, last_busy_skip, via the new PluginHealthTracker.record_busy_skip).

    A busy skip is report-only (owner decision): it never touches the failure streak, last_error or the circuit breaker, so a healthy plugin whose lock a Vegas render holds is never pulled from rotation. Only real hangs count toward the breaker: display() or update() running past the executor timeout (below). The other plugins keep updating. If the plugin is unloaded while the worker waits, nothing is resurrected. Busy-skip persistence shares the slow-call throttle: the first one is saved at once (so the web process's health API sees it), then at most once a minute per plugin.

  • display() timing. DisplayController._display_once times every frame with two time.monotonic() reads. The first-frame dispatch is timed too. Both report to PluginManager.note_display_duration():

    • Under PluginExecutor.SLOW_DISPLAY_SECONDS (2s): one compare, nothing else.
    • 2s or more: logged at most once a minute per plugin, with a count of suppressed repeats. Counted in health as slow_call_count / last_slow_call. This is reporting only and does not affect the circuit breaker. It is saved to disk at most once a minute per plugin (SD wear).
    • At or past the executor timeout: recorded as a hang, via PluginHealthTracker.record_hang → record_failure.
    • A first frame still running when the executor gives up is recorded as a hang, not a success.
  • Hung update(). When the executor stops waiting on the async path, the plugin is recorded as hung and a warning is logged. If the late update() eventually returns, record_success clears the failure streak.

  • on_config_change serialised. The hot-reload callback now calls PluginManager.apply_config_change(). It runs on_config_change on the calling thread while holding the plugin's lock, with the same timed acquire. If the lock stays busy, the change is parked (latest one wins) and a _DeferredConfigChange item is queued. The worker applies it under the lock as soon as the lock is free, and at the latest just before the plugin's next update(). A parked change meant for an instance that has since been reloaded is dropped. Exceptions on the immediate path still reach the caller as before.

  • The plugin-facing API is unchanged. Health summaries gain six fields: hang_count, last_hang, slow_call_count, last_slow_call, busy_skip_count, last_busy_skip.

Thread model (also in a comment in PluginManager.__init__)

Hook Thread Lock
__init__, on_enable loading thread (main at startup, render thread on live enable) none
update() plugin-update-worker via PluginExecutor (a lingering thread keeps the lock past the timeout) held, bounded wait
update(), startup pass / synchronous_updates kill switch main thread / render thread none (unchanged)
display() render thread (first frame via the executor); Vegas adapter/coordinator try-lock (skip frame) / bounded wait
on_config_change() ConfigService watcher thread, else deferred to the update worker held, bounded wait
cleanup(), on_disable() unload_plugin() caller UNLOAD_LOCK_TIMEOUT

Tests

New test/test_plugin_hang_containment.py has 24 tests and runs in about 10s, using timeouts of 0.1–0.3s. It covers:

  • A fake plugin's display() blocks on an Event while holding its lock. Another plugin's update() keeps running on schedule, and the worker stays alive.
  • The timed-out acquire is recorded as a busy skip (busy_skip_count, last_busy_skip, PluginBusyError in the state error info) with no failure, hang or last_error. Nine busy skips in a row (3x the threshold) leave the breaker closed, and the plugin updates normally once the lock frees. Busy skips do not extend an existing hang streak. Repeated real hangs still open the breaker after exactly failure_threshold, with busy skips interleaved. The skip is logged once per interval. Unloading during the wait does not resurrect the plugin. Busy-skip persistence is rate-limited and breaker-free.
  • An update() that outlives the executor timeout is recorded as a hang and cleared once it returns.
  • display() timing: fast frames record nothing; slow frames are recorded and warned about once, with the suppressed count shown on the next warning; frames past the timeout count as hangs; _display_once passes each frame's duration on and does not time skipped frames.
  • on_config_change does not run concurrently with update() and runs holding the lock. When the lock is busy, the latest change is deferred and applied before the next update(), or by the worker once the lock frees. Stale changes are dropped after a reload. Exceptions still reach the caller.
  • record_slow_call saves to disk at most once a minute, and hang records survive a restart.

Mutation check (report-only): with _skip_busy_update counting the skip as a failure again, the four busy-skip/real-hang tests fail. Mutation check: with the worker's acquire changed back to a blocking lock.acquire(), the three worker tests fail. With the fix they pass; three consecutive runs showed no flakes.

test/test_plugin_config_preparation.py: the two hot-reload tests now delegate the mocked manager's apply_config_change to a real PluginManager, so they still check that the plugin receives the prepared config.

Full suite vs baseline (Windows, Python 3.14, Pillow 12.3.0 before and after, pytest -m "not hardware" test/ --ignore=test/plugins), rerun after the report-only change at 089a177. The baseline is a separate worktree of c4c46d3 (the branch's merge base with main), with the same config.json copied in.

  • Baseline: 59 failed, 6068 passed, 136 skipped, 6 errors.
  • Branch: 59 failed, 6092 passed, 136 skipped, 6 errors.
  • Diff of the ^(FAILED|ERROR) test/ IDs: identical (65 each, none new, none fixed); all are pre-existing Windows failures.
  • Plugin-system tests (test/test_plugin_*.py, async updates, health API, Vegas adapter, display-controller toggle, base plugin): 400 passed.
  • mypy ratchet (scripts/check_types.py): at the first commit plugin_executor.py and plugin_health.py were clean (only the existing src/deprecation.py error, from a newer local mypy). mypy is not installed on the host used for the report-only follow-up, so it was not re-run; pyflakes is clean on the changed files. plugin_manager.py is not on the ratchet.

Hardware soak (ledpi, 2026-09-29)

Pi 4, 2x96x48 chain (192x48), pwm_bits 9, gpio_slowdown 8, cap 120 Hz, stock binding. scripts/frame_soak.py --preview --duration 300 after a fresh restart of both services and a 120s warm-up, run in the order main / branch / main / branch (main = c4c46d3, this branch's merge base; branch = 089a177). Workload: baseball + football scoreboards switched to scroll display mode, plus news (ticker) and clock-simple (1s update interval, so the update worker is busy); Vegas runs the same with vegas_scroll.enabled. The rig's config was restored byte-identical afterwards.

run build mode late missed refreshes freezes >=250ms
1 main rotation 0.094% (14/14,828) 20 9
2 branch rotation 0.088% (13/14,825) 18 9
3 main rotation 0.101% (15/14,821) 29 9
4 branch rotation 0.088% (13/14,824) 22 9
1 main Vegas 0.526% (38/7,219) * 39 0
2 branch Vegas 0.527% (38/7,216) * 43 0
3 main Vegas 0.527% (38/7,215) 65 0
4 branch Vegas 0.526% (38/7,223) * 47 0

* the soak graded these NOT LOCKED (frames measured at ~126 Hz against a 120 Hz cap: Vegas asks for 125 fps), so the Vegas late count is only comparable between builds, not graded. The same holds on main.

  • No measurable frame cost from the per-frame display() timing: rotation late rate 0.088% / 0.088% on the branch vs 0.094% / 0.101% on main; freezes identical (9 per run, the same 5 render stalls per run on both builds, from content fetched on the render thread).
  • Plugin health (/api/v3/plugins/health after every run, and the journal): no plugin had a hang, a slow display(), a busy skip or an open circuit on either build. busy_skip_count stayed 0 in all Vegas runs, so the prefetch never held a lock for 5s on this rig. The only non-closed circuit was countdown (disabled, not in the workload), left open by an earlier deliberate-failure test on the rig on both builds.
  • Not exercised on this rig: a Vegas render long enough to cause a busy skip. The unit tests cover that path (report-only, breaker stays closed).

Follow-up (not in this PR)

A render thread that is itself stuck inside display() can only be caught from outside the process. Planned follow-up:

  • the display loop pets an sd_notify watchdog (WatchdogSec= in ledmatrix.service) and writes a heartbeat under /run;
  • systemd restarts the service when the loop stops.

That changes the unit files and the installer, so it needs Linux/installer proof (root and non-root installs) before merge.

🤖 Generated with Claude Code

The single update worker took each plugin's lock with a blocking acquire(),
and the render thread holds that lock while it runs the plugin's display().
A display() that never returned -- or a first frame still running on the
executor's lingering thread after its 30s timeout -- parked the worker for
good, and no plugin updated again.

- The worker waits at most PLUGIN_LOCK_TIMEOUT (5s, the bound unload_plugin
  already uses), skips the busy plugin and records it through the normal
  update-failure path as a hang (PluginBusyError), so repeats open its
  circuit breaker. Log lines about it are rate-limited per plugin.
- display() is timed on every frame (two monotonic reads). Calls of 2s or
  more are logged once a minute and counted in plugin health
  (slow_call_count, last_slow_call); calls past the executor timeout, and a
  first frame still running at it, are recorded as hangs (hang_count,
  last_hang) and no longer as successes. An update() still running after
  its timeout is recorded as a hang too.
- on_config_change() runs under the plugin's lock via
  PluginManager.apply_config_change(); if the lock stays busy the latest
  change is deferred to the update worker, applied as soon as the lock
  frees and before the plugin's next update() at the latest. The plugin API
  is unchanged. Which thread runs each hook is documented in
  PluginManager.__init__.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@coderabbitai

coderabbitai Bot commented Sep 29, 2026 •

Copy link
Copy Markdown
Contributor

Warning

Review limit reached

You've used all free OSS reviews for now. Wait for the free limit to reset to keep reviewing this public repository.

Next included review available in 28 minutes.

Check out review usage here.

View limit details

Limit details: You’ve used the included review currently available.

Learn how review limits work.

Review configuration:

⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Advanced

Run ID: 3e9735e9-f7d8-4acd-ad14-40cea5c5f525

📥 Commits

Reviewing files that changed from the base of the PR and between e3c85ce and 3561708.

📒 Files selected for processing (10)
  • CHANGELOG.md
  • docs/ARCHITECTURE.md
  • docs/PLUGIN_API_REFERENCE.md
  • src/display_controller.py
  • src/plugin_system/plugin_executor.py
  • src/plugin_system/plugin_health.py
  • src/plugin_system/plugin_manager.py
  • test/test_on_demand_disabled_plugin.py
  • test/test_plugin_config_preparation.py
  • test/test_plugin_hang_containment.py

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

Comment @coderabbitai help to get the list of available commands.

@codacy-production

codacy-production Bot commented Sep 29, 2026 •

Copy link
Copy Markdown

Up to standards ✅

🟢 Issues 0 issues

Results:
0 new issues

View in Codacy

🟢 Metrics 53 complexity

Metric Results
Complexity 53

View in Codacy

NEW Get contextual insights on your PRs based on Codacy's metrics, along with PR and Jira context, without leaving GitHub. Enable AI reviewer
TIP This summary will be updated as you push new changes.

ChuckBuilds and others added 3 commits September 29, 2026 16:55
The getattr/callable fallback guarded against a tracker without
record_hang, but the core tracker always has it. Clears Codacy's Pylint
E1102 (not-callable) false positive.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
… failure

When the update worker gives up waiting for a plugin's lock
(PLUGIN_LOCK_TIMEOUT, 5s) the skip was recorded as a hang, so three in a
row opened the circuit breaker. Vegas prefetch holds a plugin's lock for
its whole content render, which on a slow Pi can outlast 5s, so a healthy
plugin could be pulled from rotation.

The skip is now report-only: still logged (rate-limited) and still left as
PluginBusyError state error info with last-update stamped, but in health it
is counted as a busy skip (busy_skip_count / last_busy_skip, via the new
PluginHealthTracker.record_busy_skip) and never touches the failure streak,
last_error or the breaker. Only real hangs -- display() or update() running
past the executor timeout -- still count toward the breaker.

Busy-skip persistence shares the slow-call throttle (first one saved at
once so the web process sees it, then at most once a minute per plugin).
Tests prove repeated busy skips never open the breaker and repeated real
hangs still do, with busy skips interleaved.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
ChuckBuilds and others added 2 commits September 29, 2026 19:31
Conflict with #678 in the plugin config-change callback: keep #678's
override (a plugin loaded for on-demand sees enabled: True) and apply the
result through the locked apply_config_change. The #678 test now asserts
on that call, which delivers the override to on_config_change.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@ChuckBuilds
ChuckBuilds merged commit c0d97e4 into main Sep 30, 2026
10 of 11 checks passed
@ChuckBuilds
ChuckBuilds deleted the claude/plugin-hang-containment branch September 30, 2026 13:10
ChuckBuilds added a commit that referenced this pull request Sep 30, 2026
Conflicts:
- src/display_controller.py: _display_once keeps the watchdog beat and
  #677's per-call display() timing (note_display_duration).
- docs/REST_API_REFERENCE.md: health documents both checks.display_loop and
  #683's minimal unauthenticated answer, which a stalled loop still degrades.
- CHANGELOG.md: both sides' Unreleased entries kept.

Adds a test that a stale heartbeat turns the minimal (not logged in)
/api/v3/health answer to degraded without leaking checks.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant