Compare commits

..
Author SHA1 Message Date
ChuckBuilds 8d1e43c15a perf(vegas): trace the content path at DEBUG instead of INFO
plugin_adapter narrates every step of acquiring content from every plugin --
"Has get_vegas_content", "Native: calling get_vegas_content()", "Native
content returned None", "Has scroll_helper", per-item sizes -- once per plugin
per cycle, all at INFO.

Measured on a live rig: 13,408 log lines an hour, of which 13,366 were INFO
and 35 were WARNING. Roughly 223 lines a minute of string formatting on a Pi
that is also driving the panel, written through journald to the SD card, with
the 35 lines that actually indicate a problem buried among them.

Top repeated messages in that hour:

    717  Scroll progress: elapsed=... total_scrolled=.../... px
    399  [plugin] --> INCLUDED in Vegas scroll
    323  [plugin] content_type=static, display_mode=fixed
    195  [plugin] Has get_vegas_content: True
    195  [plugin] Native: calling get_vegas_content()
    168  [plugin] Native: get_vegas_content() returned None
    168  [plugin] Native content returned None        <- the same fact, twice

54 logger.info calls in plugin_adapter become logger.debug, along with the
per-frame scroll-progress line in scroll_helper. Together those are 3,174 of
the 13,408 lines an hour, a 23% cut, and the ~3,600 odds-manager lines are
addressed separately by ledmatrix-plugins#300.

Nothing is lost: the 19 warning/error/exception calls in the module are
untouched, so real failures still surface at their own level. This is a
logging-level change only -- no control flow, no behaviour.

One INFO call is deliberate and stays. The padding-strip message picks its
level at runtime (`logger.warning if (left and right) else logger.info`) and
test_vegas_plugin_adapter.py pins that choice; it survives because it is not a
direct logger.info call site. That test still passes.

Mutation-checked both ways: reintroducing a single INFO trace fails the guard,
and demoting the warning/error calls along with the trace fails a second guard
written for exactly that mistake. 537 vegas and scroll tests pass.

(cherry picked from commit e496d95dfe)
2026-08-19 20:49:31 -04:00
ChuckBuilds 0f77bd2345 perf(health): stop rewriting a health record on every healthy cycle
Every successful plugin update called record_success(), which persisted the
record unconditionally. In steady state the only fields that had changed were
total_successes and last_success_time -- a counter and a timestamp that
health_monitor surfaces for display and that nothing reads back after a
restart. Nothing alerts on the age of last_successful_update; it is carried in
the metrics dataclass and shown.

Measured on a rig running 24 plugins, all steady-state (0 consecutive
failures, circuit closed): a five-minute sample caught 22 health-file
rewrites, about 4.4 a minute or 6,300 a day. Each write is ~400 bytes through
cache_manager.set(), which writes a file per call, so each one costs a
filesystem block plus an ext4 journal write.

That lands on an SD card, where the unit of cost is an erase-block cycle
rather than the bytes involved, and where wear is what eventually kills the
card. Two cards have already failed on the other rig with the same
signature -- unreadable block device, EIO on exec, sshd unable to read its
host keys.

The circuit breaker still has to survive a restart, so the write is kept for
exactly the fields it is rebuilt from: consecutive_failures, circuit_state,
circuit_opened_time, half_open_start_time. A failure, a circuit opening and a
recovery are all still written the moment they happen. In-memory state is
updated every time either way, so the health API and web UI show what they
always did.

Tested: 100 healthy cycles now perform zero writes after the first, the
counters remain accurate in memory, and a failure, a recovery and a
half-open-to-closed transition each still reach disk. One test kills and
rebuilds the tracker from the cache to prove the breaker's state genuinely
survives what is no longer written.

Mutation-checked both ways: persisting unconditionally again fails the
steady-state test, and widening _DURABLE_FIELDS to include last_success_time
fails it too. The 46 existing health tests pass.

(cherry picked from commit 14abea2d24)
2026-08-19 20:49:31 -04:00
ChuckandGitHub cf0a551f7b fix(web): stop checkbox groups posting back options they cannot show (#465)
The enum that lets a checkbox group draw its options is also what validates
the saved value. When an option goes away -- a league retires a team code, a
schema drops a choice -- a config still holding the old value has no checkbox
to render for it, but the value stayed in the hidden _data input anyway:
that input is seeded from the stored array and only rebuilt by
updateCheckboxGroupData() on change.

So the stale value was posted back on every save the user did not happen to
touch that widget for. The schema rejected it and the save endpoint returned
400 CONFIG_VALIDATION_FAILED, which blocks editing *any* field on that
plugin until the user works out which invisible entry is at fault -- with
nothing on screen naming it, because the offending value is precisely the one
with no checkbox.

Runtime was never affected: load_plugin() treats schema violations as
warn/degrade, and a retired code already matched nothing. Only the web UI
blocked.

Values not in the enum are now dropped before the hidden input is seeded, and
listed above the group so the selection is not lost silently. Only when the
widget has options -- an empty enum means there is nothing to check against,
and filtering on it would wipe the field.

This is not hypothetical. ledmatrix-plugins #212 ("correct team abbreviations
so config save no longer 400s") and #234 (removed the retired NHL code UTA
from a picker across four plugins) are both this failure mode, fixed one
league at a time. Nine shipped plugins use checkbox-group today; all of them
get the fix.

Tested by rendering the checkbox-group block lifted out of the shipped
template, following test_enum_option_labels.py, so the tests exercise the
production expression rather than a copy. Mutation-checked: removing the
filter fails 2 tests, filtering unconditionally fails the empty-enum test,
and dropping the notice fails the one asserting the value is named.
2026-08-19 17:40:52 -04:00
9018fa23cd fix(web): verify the onboarding timezone step, don't compare it to the default (#462)
* fix(web): verify the onboarding timezone step, don't compare it to the default

The Getting Started card's timezone step ticked when the saved timezone
differed from the value config.template.json ships (America/New_York),
OR-ed with the saved city differing from Tampa. Both halves were wrong.

"Differs from the default" answers "did somebody edit this?", but what the
checklist needs to know is whether the value is right. A user genuinely in
America/New_York could never satisfy it, so the card nagged forever with
four of five steps done -- the case that prompted this, on a panel whose
timezone was correct all along.

The city half was worse than useless: the saved city says nothing about
whether the timezone is set, and because the two were OR-ed, saving a city
ticked the step off with the timezone still wrong. That is the direction
that actually breaks displays, since event times then render in the wrong
zone.

The browser already knows its own zone, so compare against that. No new
persisted state, no network, and it catches the reverse case the old test
got backwards: a panel still set to the old zone after a move now stays
unticked, where before it ticked the moment the value stopped being the
default. Zones are compared by the wall-clock time they produce for one
instant rather than by identifier, so aliases (Asia/Calcutta vs
Asia/Kolkata, Europe/Kiev vs Europe/Kyiv) don't read as a mismatch. When
they genuinely differ the step names the browser's zone, so an unticked box
says why. Configs with no timezone, an unparseable zone, or a browser
without Intl leave the step open for the existing manual tick.

The step still deep-links to the General tab, and the location value stays
visible in its label -- it just no longer votes on whether the timezone is
configured.

Tests render the partial across configured zones and both cities: the step
never pre-ticks server-side, carries the configured zone for the client to
check, is unmoved by the city, and the panel-size step still resolves
server-side. Reverting the template fails 9 of the 11.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW

* fix(web): compare zones on fields Intl has always had

dateStyle/timeStyle are late additions to Intl -- Firefox shipped them in
91 -- and an implementation that does not know them ignores them and
formats the date alone. The comparison would then read New York, Chicago
and Madrid as the same zone and tick the step for a timezone that is
plainly wrong, which is the failure the check exists to catch. Silent, and
only on older browsers.

Explicit numeric fields (year/month/day/hour/minute) have been in Intl
since ECMA-402 v1, so there is nothing left to degrade to.

The options look like a stylistic choice, so a test pins them: it reads the
comparison with comments stripped -- the comment names dateStyle to explain
why it is not used -- and fails if either style option comes back or a
time field is dropped.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW

* fix(web): sample both sides of DST when comparing zones

CodeRabbit caught this and it is right: comparing the wall clock at one
instant treats zones that merely coincide right now as the same one.
America/New_York and America/Lima hold the same offset all winter, so a
panel set to the wrong one of the two ticked the step in January and then
ran an hour off from March -- a silent false pass, which is the failure the
whole check exists to prevent. Same shape as the dateStyle problem in the
previous commit: a comparison coarser than it looks.

Three instants now, all of which must agree: now, and mid-January and
mid-July of the current year. Those sit either side of DST in both
hemispheres, so only zones that agree year-round match. Toronto still
matches New York, which is correct -- either renders the same times.

Two tests. A static one asserts the comparison samples more than the
current instant, since reverting to `[now]` looks like a simplification.
And a table pinning which pairs must count as the same zone: aliases and
same-rule zones equal, seasonal coincidences (New York/Lima,
Phoenix/Los_Angeles, Sydney/Guadalcanal) not. That table mirrors the
algorithm rather than executing the shipped JS -- there is no JS runtime
here and the repo has no JS test infra -- so it records the verdicts the
browser code has to reach, and the static guard keeps the two aligned.

Mutation-checked: reverting to a single instant fails the static guard.

Also documented what the city test compares. CodeRabbit read it as always
failing, on the grounds that the label differs between Tampa and Seattle.
It does, but timezone_step() returns the opening tag only, so the
comparison is over data-done and data-tz and the label is not in it. The
assertion is left as an equality over the whole tag, which is stronger than
checking the two attributes by name; the docstring now says so.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW

---------

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-08-19 12:49:46 -04:00
0c5b9c57d3 fix: keep low-memory boards reachable under load (#464)
* fix(service): survive corrupt health cache and clean exits

Three independent failure modes that each end with a dark panel and no
automatic recovery.

1. PluginHealthTracker._load_health_state returned the cached value
   verbatim. If that value is not a dict, every caller raises
   AttributeError: 'list' object has no attribute 'get' — during
   DisplayController.__init__, so the process dies before the display
   loop starts. systemd restarts it, the same bad entry is read back
   from disk, and it dies again: an unattended restart loop that
   survives reboots because the cause is persisted. Observed in the
   field with plugin_health:<id> holding an unrelated plugin's list
   payload. Now non-dict entries are discarded with a warning and the
   defaults are rebuilt.

2. ledmatrix.service used Restart=on-failure, so any exit with status 0
   left the unit stopped and the panel dark indefinitely — systemd
   treats it as success and never brings it back. Restart=always.

3. ledmatrix-wifi-monitor.service used StandardOutput=syslog, which
   systemd has marked obsolete; it warns and rewrites it to journal on
   every load.

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

* perf(memory): size the cache to the board and stop reinstalling deps

On a 1GB Pi 3B+ the display process settles around 600MB RSS of 905MB
total. When the remaining headroom runs out the failure is not a clean
crash: fork() starts returning ENOMEM, so sshd accepts connections and
closes them before its banner, timer jobs stop running, and the panel
goes dark, while already-resident processes keep serving normally. The
board looks healthy from outside and cannot be logged into. Only a power
cycle clears it.

Three contributing causes:

- MemoryCache had a fixed 1000-entry ceiling. Entries are parsed API
  payloads of tens of KB, so one ceiling cannot serve both a 512MB Zero
  2 W and an 8GB Pi 5. Now scaled from MemTotal (150 entries at <=1GB,
  1500 at >=8GB), overridable with LEDMATRIX_CACHE_MAX_ENTRIES.

- requirements_are_satisfied() returned False for any requirement with
  extras, so a plugin depending on python-socketio[client] re-ran pip on
  every single start: ~8s, a network dependency, and a 100-200MB spike
  at the least convenient moment. During a restart loop it repeats for
  each restart. Extras are now resolved one level deep against installed
  metadata, keeping the conservative "anything unverifiable falls
  through to pip" contract.

- ledmatrix.service had no memory ceiling. MemoryMax=85% expressed as a
  percentage so one unit file suits every board. Note this needs the
  memory cgroup controller, which Pi firmware disables by default;
  first_time_install.sh now adds cgroup_enable=memory to cmdline.txt,
  and the unit file documents how to verify it took effect.

first_time_install.sh also enables persistent journald storage (capped
at 64M). Default storage is volatile, so every reboot destroys the logs
that would explain why the board rebooted.

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

* docs: guidance for 512MB and 1GB boards

Documents the memory ceiling on small boards and, more usefully, what
running into it actually looks like: sshd accepting connections and
closing them before the banner, the web UI still responding normally,
clean ping, a dark panel, and a wrong clock after the next boot. None of
those read as "out of memory", which makes the failure hard to identify
from the symptoms.

Cross-referenced from SSH_UNAVAILABLE_AFTER_INSTALL.md, since "I can't
SSH in any more" is how most people will first meet this.

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

* fix: address review findings on the low-memory work

Nine CodeRabbit findings, five in code.

**Health state (the one that matters).** The non-dict guard did not cover a
dict missing fields the callers index directly, which is the shape actually
seen in the wild: a record carrying only circuit_state produced
`plugin clock-simple operation failed: 'circuit_state'` about fifty times a
minute with the panel frozen. The record is now completed against the
defaults per field rather than trusted or discarded wholesale. Per field
matters: a first pass rejected any incomplete record outright, which reset a
tripped breaker and real failure counts to healthy because one optional
field was absent -- an existing test caught it. Values of the wrong type
(a counter persisted as a string, an unknown circuit_state) fall back
individually, valid neighbours survive, and newer fields the schema has
grown since (degraded, degraded_reason) are carried through untouched.

**Cache ceiling.** MemoryCache.set() accepted entries without bound between
cleanup sweeps, which run every 300s by default, so a burst could take the
cache far past max_size -- the unbounded growth the limit exists to stop.
Eviction now runs under the same lock on every write, sharing one helper
with the periodic sweep so the two cannot drift.

**Installer, cgroups.** Only cgroup_enable=memory was checked, so a board
carrying that without cgroup_memory=1 reported success and got no change,
leaving MemoryMax= inert. Each parameter is now checked and appended
independently; verified against all four combinations, single line preserved.

**Installer, journald.** Persistence was inferred from /var/log/journal being
non-empty, which proves neither Storage=persistent nor a size cap -- the
directory survives a switch back to volatile. The effective configuration is
read instead (systemd-analyze cat-config, falling back to the conf files),
and an explicitly configured SystemMaxUse is preserved rather than
overwritten. Verified across volatile, persistent-without-cap,
persistent-with-user-cap, cap-without-storage, and commented-only configs.

**Dependency extras.** _extras_are_satisfied stopped at one level, so a
gated dependency that itself requests an extra (requests[socks]) passed on
the base distribution's version while the extra's own dependency was
missing, and pip was skipped. It now recurses, with a visited
(distribution, extras) set so a cycle terminates.

Docs: both kernel command-line paths documented (the installer falls back to
/boot/cmdline.txt), daemon-reload and restart added after the systemd
override example, memory exhaustion added to the SSH summary with its
power-cycle-only recovery, and a language on the fenced block for MD040.

Tests: five for the health-state repair including the exact wild shape and
that record_failure/record_success no longer raise against it, and one for
the cache ceiling. Both mutation-checked. Full suite 2927 passed, with the
one pre-existing tmpfs failure that also fails on main.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW

* fix: harden the health-state repair and confirm journald took effect

Second review round; all three findings were valid and two were bugs in the
repair added last commit.

The repair could raise out of itself. An unhashable circuit_state (a list or
dict on disk) hit `value in {...}` and raised TypeError -- from the code
whose whole job is to stop a malformed record crashing the caller. It now
requires a str before the membership test.

bool is a subclass of int, so True passed the timestamp check and then
compared as 1.0: enough to expire a cooldown the instant the breaker opened,
while False would stop the elapsed check firing at all. Timestamps now
exclude bool explicitly.

The regression test for the original crash was seeded with a record that
*contained* circuit_state, so it passed against the old raw-return behaviour
too -- the counters are read with .get(), so circuit_state is the only field
whose absence used to raise. Reseeded to omit it, and it now fails against
raw-return as intended.

journald: drop-ins apply in lexical order, so a local file sorting after
ledmatrix-persistent.conf still wins and writing ours proves nothing. The
effective Storage is re-read afterwards and a warning naming the diagnostic
command is printed if persistence is still not active, rather than reporting
a success that was not verified.

Full suite 2934 passed, same single pre-existing tmpfs failure.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW

---------

Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
2026-08-19 12:28:22 -04:00
17 changed files with 1184 additions and 118 deletions
+115
View File
@@ -0,0 +1,115 @@
# Running on Low-Memory Boards
Applies to the Pi Zero 2 W (512 MB), Pi 3 / 3B+ (1 GB), and the 1 GB Pi 4.
If your board has 2 GB or more you can skip this document.
## The failure this prevents
The display process is the largest thing on the board. On a 1 GB Pi 3B+ with
around 20 plugins enabled it settles near **600 MB of 905 MB usable**, leaving
under 200 MB of headroom for everything else.
When that headroom runs out, the board does not crash cleanly. `fork()` starts
failing, and because a new process is needed to do almost anything, the
symptoms look nothing like "out of memory":
| What you see | Why |
|---|---|
| SSH accepts the connection then closes it instantly, before any banner | `sshd` forks a session per connection; the fork fails |
| The web UI still responds quickly | Already running, serves from existing threads, forks nothing |
| Ping is perfect, 0% loss | Handled entirely in the kernel |
| The panel is dark | The display process was killed and cannot be respawned |
| The clock is wrong after the next boot | `fake-hwclock`'s periodic save is a scheduled job, and it cannot fork either |
The board looks healthy from the outside and cannot be logged into. Only a
power cycle clears it. If you are here because SSH stopped working, also see
[SSH_UNAVAILABLE_AFTER_INSTALL.md](SSH_UNAVAILABLE_AFTER_INSTALL.md), which
covers the more common cause (AP mode).
## Check your headroom
```bash
free -m
ps -eo rss,comm --sort=-rss | head -5
```
If `MemAvailable` is under ~150 MB while the display is running, you are close
to the edge. To watch it over time:
```bash
watch -n 30 'free -m | head -2'
```
Available memory that falls steadily rather than holding flat means you will
reach the wall; it is a question of when.
## What to do
**1. Enable the memory cgroup controller.** Without it, the `MemoryMax=85%` in
`systemd/ledmatrix.service` is accepted by systemd and silently ignored, so the
service has no ceiling and a runaway takes the whole board down instead of just
restarting. Raspberry Pi firmware disables this controller by default.
`first_time_install.sh` does this for you. To check it took effect:
```bash
grep memory /sys/fs/cgroup/cgroup.controllers
```
If that prints nothing, add `cgroup_enable=memory cgroup_memory=1` to the
kernel command line and reboot. Edit whichever file your image uses —
`/boot/firmware/cmdline.txt` on current Raspberry Pi OS, `/boot/cmdline.txt` on
older layouts (the installer checks the first and falls back to the second).
Everything must stay on a single line.
This changes the failure mode from "the board becomes unreachable" to "the
display service restarts". It is a safety net, not a fix.
**2. Run fewer plugins.** This is the actual remedy. Every enabled plugin costs
memory permanently — its module, its parsed config, and its cached API
responses. On a 512 MB or 1 GB board, keep the enabled set small and prefer
plugins that poll infrequently.
**3. Lower the cache ceiling.** The in-memory cache is sized from total RAM
(150 entries at 1 GB and below, up to 1500 at 8 GB). To go lower still:
```ini
# /etc/systemd/system/ledmatrix.service.d/override.conf
[Service]
Environment=LEDMATRIX_CACHE_MAX_ENTRIES=75
```
Writing the file does not change the running service. Reload systemd and
restart it:
```bash
sudo systemctl daemon-reload
sudo systemctl restart ledmatrix
```
Fewer entries means more API calls, so lower this only while you are actually
short of memory.
**4. Consider `MemoryHigh`.** `MemoryMax` kills and restarts. `MemoryHigh`
throttles and reclaims instead, which is gentler — but on a board where the
process genuinely wants more than the limit, sustained reclaim can stall the
render loop and show as visible stutter on the panel. Add it only if you prefer
degraded output to a restart:
```ini
[Service]
MemoryHigh=70%
```
## Keep your logs
These images default to volatile journald storage, so every reboot destroys the
logs — including the ones explaining why the board rebooted. `first_time_install.sh`
enables persistent storage capped at 64 MB. To confirm:
```bash
journalctl --list-boots
```
More than one boot listed means logs are surviving reboots. If only one is
listed, journald is still writing to `/run` (tmpfs).
+1
View File
@@ -14,6 +14,7 @@ the one-shot installer. The pages here go deeper.
5. [TROUBLESHOOTING.md](TROUBLESHOOTING.md) — common issues and fixes 5. [TROUBLESHOOTING.md](TROUBLESHOOTING.md) — common issues and fixes
6. [SSH_UNAVAILABLE_AFTER_INSTALL.md](SSH_UNAVAILABLE_AFTER_INSTALL.md) — recovering SSH after install 6. [SSH_UNAVAILABLE_AFTER_INSTALL.md](SSH_UNAVAILABLE_AFTER_INSTALL.md) — recovering SSH after install
7. [CONFIG_DEBUGGING.md](CONFIG_DEBUGGING.md) — diagnosing config problems 7. [CONFIG_DEBUGGING.md](CONFIG_DEBUGGING.md) — diagnosing config problems
8. [LOW_MEMORY_BOARDS.md](LOW_MEMORY_BOARDS.md) — Pi Zero 2 W / 3B+ / 1GB Pi 4 memory limits
## I want to write a plugin ## I want to write a plugin
+29 -2
View File
@@ -20,7 +20,22 @@ The installation script:
- Installs and configures `dnsmasq` (DHCP server for AP mode) - Installs and configures `dnsmasq` (DHCP server for AP mode)
- These services can interfere with normal WiFi client mode - These services can interfere with normal WiFi client mode
### 3. Reboot After Installation ### 3. The Board Ran Out of Memory
On a 512MB or 1GB board, memory exhaustion stops `sshd` being able to fork a
session process. The connection is accepted and then closed immediately, before
any banner:
```text
kex_exchange_identification: Connection closed by remote host
```
The giveaway is that the board is otherwise healthy — ping is clean and the web
UI still responds — but nothing that needs to start a new process works, and
the panel is usually dark. Only a power cycle clears it. See
[LOW_MEMORY_BOARDS.md](LOW_MEMORY_BOARDS.md).
### 4. Reboot After Installation
If the script reboots the Pi (which it recommends), network services may restart in a different state, potentially triggering AP mode. If the script reboots the Pi (which it recommends), network services may restart in a different state, potentially triggering AP mode.
@@ -190,11 +205,23 @@ The web interface allows you to:
## Summary ## Summary
**SSH becomes unavailable because**: **SSH becomes unavailable because** — two unrelated causes, and they need
different responses:
*AP mode (most common):*
- WiFi monitor service enables AP mode when WiFi disconnects - WiFi monitor service enables AP mode when WiFi disconnects
- AP mode switches WiFi from client to access point mode - AP mode switches WiFi from client to access point mode
- Pi loses connection to your original network - Pi loses connection to your original network
*Memory exhaustion (low-memory boards):*
- The board runs out of memory, so `sshd` cannot fork a session process
- The connection is accepted and closed before any banner
- Ping still answers and the web UI still responds, so it looks healthy
- The panel is usually dark and the service cannot restart
- **Only a power cycle clears this** — there is no remote recovery, because
every remote route needs a new process
- Prevention and tuning: [LOW_MEMORY_BOARDS.md](LOW_MEMORY_BOARDS.md)
**To regain SSH**: **To regain SSH**:
1. Connect to **LEDMatrix-Setup** AP network (password: `ledmatrix123`) 1. Connect to **LEDMatrix-Setup** AP network (password: `ledmatrix123`)
2. SSH to `192.168.4.1` 2. SSH to `192.168.4.1`
+63 -12
View File
@@ -1694,12 +1694,24 @@ fi
# a runaway takes the whole board down (sshd can no longer fork, the panel goes # a runaway takes the whole board down (sshd can no longer fork, the panel goes
# dark) rather than just restarting the one service. # dark) rather than just restarting the one service.
if [ "$SKIP_PERF" != "1" ] && [ -f "$CMDLINE_FILE" ]; then if [ "$SKIP_PERF" != "1" ] && [ -f "$CMDLINE_FILE" ]; then
if grep -q 'cgroup_enable=memory' "$CMDLINE_FILE"; then # Both parameters are required for the memory controller, and they can get
echo "cgroup_enable=memory already present in $CMDLINE_FILE" # separated -- an image, another tool or a half-applied earlier run can
# leave one without the other. Checking only cgroup_enable=memory would
# report success while MemoryMax= silently does nothing, so each is checked
# and appended independently.
cgroup_missing=""
for cgroup_param in cgroup_enable=memory cgroup_memory=1; do
if ! grep -qw "$cgroup_param" "$CMDLINE_FILE"; then
cgroup_missing="$cgroup_missing $cgroup_param"
fi
done
if [ -z "$cgroup_missing" ]; then
echo "cgroup memory parameters already present in $CMDLINE_FILE"
else else
echo "Adding cgroup_enable=memory to $CMDLINE_FILE..." echo "Adding${cgroup_missing} to $CMDLINE_FILE..."
cp "$CMDLINE_FILE" "$CMDLINE_FILE.bak" 2>/dev/null || true cp "$CMDLINE_FILE" "$CMDLINE_FILE.bak" 2>/dev/null || true
sed -i '1 s/$/ cgroup_enable=memory cgroup_memory=1/' "$CMDLINE_FILE" # The kernel command line must stay on one line.
sed -i "1 s|\$|${cgroup_missing}|" "$CMDLINE_FILE"
echo " Takes effect after reboot. Verify with:" echo " Takes effect after reboot. Verify with:"
echo " grep memory /sys/fs/cgroup/cgroup.controllers" echo " grep memory /sys/fs/cgroup/cgroup.controllers"
fi fi
@@ -1709,20 +1721,59 @@ fi
# These images default to volatile storage: journald keeps everything in /run # These images default to volatile storage: journald keeps everything in /run
# (tmpfs), so every reboot destroys the logs — including the ones that would # (tmpfs), so every reboot destroys the logs — including the ones that would
# explain why the board rebooted. Capped so an SD card is not worn out by logs. # explain why the board rebooted. Capped so an SD card is not worn out by logs.
if [ -d /var/log/journal ] && [ -n "$(ls -A /var/log/journal 2>/dev/null)" ]; then # A non-empty /var/log/journal does not prove journald is configured the way
echo "Persistent journald storage already enabled" # this needs: the directory survives a switch back to volatile storage, and it
# says nothing about whether a size cap is set. Read the effective
# configuration instead, and only write the keys the user has not set
# themselves so an explicit local limit is preserved.
journald_effective() {
# systemd-analyze merges journald.conf with every drop-in; grep is the
# fallback for images that ship without it.
if command -v systemd-analyze >/dev/null 2>&1 &&
systemd-analyze cat-config systemd/journald.conf >/dev/null 2>&1; then
systemd-analyze cat-config systemd/journald.conf 2>/dev/null
else
cat /etc/systemd/journald.conf /etc/systemd/journald.conf.d/*.conf 2>/dev/null
fi
}
journald_conf="$(journald_effective)"
journald_storage="$(printf '%s\n' "$journald_conf" | grep -E '^[[:space:]]*Storage=' | tail -n1 | cut -d= -f2 | tr -d '[:space:]')"
journald_cap="$(printf '%s\n' "$journald_conf" | grep -E '^[[:space:]]*SystemMaxUse=' | tail -n1 | cut -d= -f2 | tr -d '[:space:]')"
if [ "$journald_storage" = "persistent" ] && [ -n "$journald_cap" ]; then
echo "Persistent journald storage already configured (SystemMaxUse=$journald_cap)"
else else
echo "Enabling persistent journald storage..." echo "Enabling persistent journald storage..."
mkdir -p /etc/systemd/journald.conf.d mkdir -p /etc/systemd/journald.conf.d
cat > /etc/systemd/journald.conf.d/ledmatrix-persistent.conf <<'JOURNALD' {
# Installed by LEDMatrix first_time_install.sh echo "# Installed by LEDMatrix first_time_install.sh"
[Journal] echo "[Journal]"
Storage=persistent echo "Storage=persistent"
SystemMaxUse=64M if [ -n "$journald_cap" ]; then
JOURNALD echo "# SystemMaxUse left to your existing setting ($journald_cap)"
else
# Capped so logs cannot wear out or fill an SD card.
echo "SystemMaxUse=64M"
fi
} > /etc/systemd/journald.conf.d/ledmatrix-persistent.conf
mkdir -p /var/log/journal mkdir -p /var/log/journal
systemd-tmpfiles --create --prefix /var/log/journal >/dev/null 2>&1 || true systemd-tmpfiles --create --prefix /var/log/journal >/dev/null 2>&1 || true
systemctl restart systemd-journald >/dev/null 2>&1 || true systemctl restart systemd-journald >/dev/null 2>&1 || true
# Drop-ins are applied in lexical order, so a locally added file that sorts
# after ledmatrix-persistent.conf (zz-local.conf and friends) still wins.
# Writing the file is not evidence it took effect -- re-read and say so
# plainly rather than reporting success we cannot confirm.
journald_now="$(journald_effective | grep -E '^[[:space:]]*Storage=' | tail -n1 | cut -d= -f2 | tr -d '[:space:]')"
if [ "$journald_now" = "persistent" ]; then
echo " Persistent journald storage active"
else
echo " WARNING: journald storage is still '${journald_now:-unset}' after"
echo " writing /etc/systemd/journald.conf.d/ledmatrix-persistent.conf."
echo " Another drop-in that sorts later is overriding it. Check:"
echo " systemd-analyze cat-config systemd/journald.conf | grep -n Storage="
echo " Logs will not survive a reboot until that is resolved."
fi
fi fi
# Ensure dtparam=audio=off in config.txt (idempotent) # Ensure dtparam=audio=off in config.txt (idempotent)
+28 -16
View File
@@ -134,6 +134,32 @@ class MemoryCache:
with self._lock: with self._lock:
self._cache[key] = value self._cache[key] = value
self._timestamps[key] = time.time() self._timestamps[key] = time.time()
# Enforce the ceiling here rather than leaving it to the periodic
# cleanup, which only runs every cleanup_interval seconds (300 by
# default). A burst of inserts between two sweeps could otherwise
# take the cache far past _max_size, which is the memory growth this
# limit exists to prevent -- and on a 1GB board that is the
# difference between a bounded cache and an unreachable Pi.
self._evict_over_limit_locked()
def _evict_over_limit_locked(self) -> int:
"""Drop oldest entries until the cache is within _max_size.
Caller must hold self._lock. Returns the number of entries removed.
"""
excess = len(self._cache) - self._max_size
if excess <= 0:
return 0
oldest = sorted(
self._timestamps.items(),
key=lambda item: float(item[1]) if isinstance(item[1], (int, float)) else 0.0
)
removed = 0
for key, _ in oldest[:excess]:
self._cache.pop(key, None)
self._timestamps.pop(key, None)
removed += 1
return removed
def clear(self, key: Optional[str] = None) -> None: def clear(self, key: Optional[str] = None) -> None:
""" """
@@ -190,22 +216,8 @@ class MemoryCache:
self._timestamps.pop(key, None) self._timestamps.pop(key, None)
removed_count += 1 removed_count += 1
# Enforce size limit by removing oldest entries if cache is too large # Same ceiling enforcement set() uses, so the two cannot drift.
if len(self._cache) > self._max_size: removed_count += self._evict_over_limit_locked()
# Sort by timestamp (oldest first)
sorted_entries = sorted(
self._timestamps.items(),
key=lambda x: float(x[1]) if isinstance(x[1], (int, float)) else 0
)
# Remove oldest entries until we're under the limit
excess_count = len(self._cache) - self._max_size
for i in range(excess_count):
if i < len(sorted_entries):
key = sorted_entries[i][0]
self._cache.pop(key, None)
self._timestamps.pop(key, None)
removed_count += 1
self._last_cleanup = current_time self._last_cleanup = current_time
+1 -1
View File
@@ -328,7 +328,7 @@ class ScrollHelper:
elapsed_time = current_time - (self.scroll_start_time or current_time) elapsed_time = current_time - (self.scroll_start_time or current_time)
# The image already includes display_width padding, so we only need total_scroll_width # The image already includes display_width padding, so we only need total_scroll_width
required_total_distance = self.total_scroll_width required_total_distance = self.total_scroll_width
self.logger.info( self.logger.debug(
"Scroll progress: elapsed=%.2fs, target=%.2fs, total_scrolled=%.0f/%d px (%.1f%%)", "Scroll progress: elapsed=%.2fs, target=%.2fs, total_scrolled=%.0f/%d px (%.1f%%)",
elapsed_time, elapsed_time,
self.calculated_duration, self.calculated_duration,
+104 -15
View File
@@ -7,7 +7,7 @@ and circuit breaker state. Provides automatic recovery mechanisms.
import time import time
import logging import logging
from typing import Dict, Optional, Any from typing import Dict, Optional, Any, Tuple
from enum import Enum from enum import Enum
@@ -65,20 +65,47 @@ class PluginHealthTracker:
) )
if isinstance(cached, dict) and cached: if isinstance(cached, dict) and cached:
return cached # Complete it rather than trusting it: a persisted record can be
# missing fields the callers index directly (a partial write, a
# restored backup, an older schema), and returning it verbatim makes
# record_success / record_failure raise KeyError, which takes the
# display down in a restart loop that survives reboots because the
# bad entry is on disk.
state, repaired = self._repair_health_state(cached)
if repaired:
self.logger.warning(
f"Repaired health state for {plugin_id}: "
f"{sorted(repaired)} missing or invalid, using defaults for those."
)
return state
# A cache entry that is not a dict means the persisted state was written # Not a dict at all: written by something other than
# by something other than _save_health_state (a key collision, a partial # _save_health_state (a key collision, a corrupted entry). Nothing to
# write, a restored backup). Returning it verbatim makes every caller # salvage.
# blow up on .get(), which takes the display down in a restart loop that
# survives reboots because the bad entry is on disk. Discard and rebuild.
if cached is not None and not isinstance(cached, dict): if cached is not None and not isinstance(cached, dict):
self.logger.warning( self.logger.warning(
f"Discarding malformed health state for {plugin_id}: expected " f"Discarding malformed health state for {plugin_id}: expected "
f"dict, got {type(cached).__name__}. Falling back to defaults." f"dict, got {type(cached).__name__}. Falling back to defaults."
) )
# Default state return self._default_health_state()
def _save_health_state(self, plugin_id: str, state: Dict[str, Any]) -> None:
"""Save health state to cache."""
cache_key = self._get_health_key(plugin_id)
self.cache_manager.set(cache_key, state) # Persist indefinitely
self._health_state[plugin_id] = state
# The fields callers index directly (state['circuit_state'] and friends).
# A cached dict missing any of them raises KeyError deep in record_success /
# record_failure, so the value is completed before it is handed out.
_COUNTER_FIELDS = ('consecutive_failures', 'total_failures', 'total_successes')
_TIMESTAMP_FIELDS = ('last_success_time', 'last_failure_time',
'circuit_opened_time', 'half_open_start_time')
@staticmethod
def _default_health_state() -> Dict[str, Any]:
"""A fresh state with every field the callers expect."""
return { return {
'consecutive_failures': 0, 'consecutive_failures': 0,
'total_failures': 0, 'total_failures': 0,
@@ -88,14 +115,55 @@ class PluginHealthTracker:
'circuit_state': CircuitState.CLOSED.value, 'circuit_state': CircuitState.CLOSED.value,
'circuit_opened_time': None, 'circuit_opened_time': None,
'half_open_start_time': None, 'half_open_start_time': None,
'last_error': None 'last_error': None,
} }
def _save_health_state(self, plugin_id: str, state: Dict[str, Any]) -> None: @classmethod
"""Save health state to cache.""" def _repair_health_state(cls, cached: Dict[str, Any]) -> Tuple[Dict[str, Any], list]:
cache_key = self._get_health_key(plugin_id) """Return `cached` completed against the defaults, plus what was repaired.
self.cache_manager.set(cache_key, state) # Persist indefinitely
self._health_state[plugin_id] = state Per-field rather than all-or-nothing: a record that has real failure
counts but is missing `last_error` should keep the counts, not be reset
to healthy. Only values that are absent or the wrong type fall back to
the default, so a partial or older-schema record survives with whatever
it does carry, while every field the callers index is guaranteed present
and of a usable type.
"""
state = cls._default_health_state()
repaired = []
for field, default in state.items():
if field not in cached:
repaired.append(field)
continue
value = cached[field]
if field in cls._COUNTER_FIELDS:
ok = isinstance(value, int) and not isinstance(value, bool) and value >= 0
elif field in cls._TIMESTAMP_FIELDS:
# bool is a subclass of int, so True would pass as a timestamp
# and then compare as 1.0 -- expiring a cooldown the instant it
# opens, or (False) making the elapsed check never fire.
ok = value is None or (
isinstance(value, (int, float)) and not isinstance(value, bool)
)
elif field == 'circuit_state':
# Membership first requires the value to be hashable: a list or
# dict here would raise TypeError out of the repair itself,
# which is the crash this whole path exists to prevent.
ok = isinstance(value, str) and value in {
member.value for member in CircuitState
}
else: # last_error
ok = value is None or isinstance(value, str)
if ok:
state[field] = value
else:
repaired.append(field)
# Anything the schema has since grown (degraded, degraded_reason) is
# read with .get() by its callers, so carry it through untouched.
for field, value in cached.items():
if field not in state:
state[field] = value
return state, repaired
def get_health_state(self, plugin_id: str, force_reload: bool = False) -> Dict[str, Any]: def get_health_state(self, plugin_id: str, force_reload: bool = False) -> Dict[str, Any]:
"""Get current health state for a plugin. """Get current health state for a plugin.
@@ -110,10 +178,20 @@ class PluginHealthTracker:
) )
return self._health_state[plugin_id] return self._health_state[plugin_id]
# Fields the circuit breaker is rebuilt from after a restart. Everything
# else in a health record is reporting, read only for display.
_DURABLE_FIELDS = ('consecutive_failures', 'circuit_state',
'circuit_opened_time', 'half_open_start_time')
def _durable(self, state: Dict[str, Any]) -> tuple:
"""The part of a health record whose loss would change behaviour."""
return tuple(state.get(field) for field in self._DURABLE_FIELDS)
def record_success(self, plugin_id: str) -> None: def record_success(self, plugin_id: str) -> None:
"""Record a successful plugin execution.""" """Record a successful plugin execution."""
state = self.get_health_state(plugin_id) state = self.get_health_state(plugin_id)
current_time = time.time() current_time = time.time()
durable_before = self._durable(state)
# Reset consecutive failures # Reset consecutive failures
state['consecutive_failures'] = 0 state['consecutive_failures'] = 0
@@ -131,7 +209,18 @@ class PluginHealthTracker:
state['circuit_state'] = CircuitState.CLOSED.value state['circuit_state'] = CircuitState.CLOSED.value
state['circuit_opened_time'] = None state['circuit_opened_time'] = None
self._save_health_state(plugin_id, state) # A healthy plugin reports success every cycle, and in that steady state
# the only fields changed above are a counter and a timestamp that
# nothing reads back after a restart. Persisting them anyway rewrites a
# small file per plugin per cycle: on a rig running 24 plugins, a
# five-minute sample measured 22 rewrites, about 4.4 a minute or 6,300 a
# day. Those land on an SD card, where the cost is an erase-block cycle
# rather than the 400 bytes involved, and where wear is what eventually
# kills the card.
# In-memory state is still updated every time, so the health API and web
# UI show exactly what they did before; only the write is skipped.
if self._durable(state) != durable_before:
self._save_health_state(plugin_id, state)
def record_failure(self, plugin_id: str, error: Optional[Exception] = None) -> None: def record_failure(self, plugin_id: str, error: Optional[Exception] = None) -> None:
"""Record a failed plugin execution.""" """Record a failed plugin execution."""
+23 -5
View File
@@ -75,14 +75,30 @@ def _extra_dependencies(dist_name: str, extras) -> Optional[List[Requirement]]:
return gated return gated
def _extras_are_satisfied(req: Requirement) -> bool: def _extras_are_satisfied(req: Requirement, _visited: Optional[set] = None) -> bool:
"""Check the dependencies pulled in by req's extras are installed. """Check the dependencies pulled in by req's extras are installed.
One level deep, not transitive: enough to tell "the extra was installed" Follows extras through nested extras. A gated dependency can itself request
from "the extra was never installed", which is all the caller needs to one (`requests[socks]`), and checking only that `requests` is installed at
decide whether pip has work to do. Anything unreadable returns False, so an acceptable version says nothing about whether the socks extra's own
the caller still falls through to pip. dependency is there -- so the caller would skip pip and the plugin would
fail at import instead. Plain dependencies are still checked one level
deep, which is all that is needed to tell "the extra was installed" from
"the extra was never installed".
`_visited` carries the (distribution, extras) pairs already seen, so a
dependency cycle between extras terminates instead of recursing forever.
Anything unreadable returns False, so the caller still falls through to pip.
""" """
if _visited is None:
_visited = set()
marker = (req.name.lower(), frozenset(e.lower() for e in req.extras))
if marker in _visited:
# Already accounted for higher up the chain; treating a cycle as
# satisfied here is safe because the outer frame still has to pass.
return True
_visited.add(marker)
gated = _extra_dependencies(req.name, req.extras) gated = _extra_dependencies(req.name, req.extras)
if gated is None: if gated is None:
return False return False
@@ -94,6 +110,8 @@ def _extras_are_satisfied(req: Requirement) -> bool:
return False return False
if dep.specifier and not dep.specifier.contains(dep_version, prereleases=True): if dep.specifier and not dep.specifier.contains(dep_version, prereleases=True):
return False return False
if dep.extras and not _extras_are_satisfied(dep, _visited):
return False
return True return True
+54 -54
View File
@@ -83,7 +83,7 @@ class PluginAdapter:
# into unrelated headlines once the strip refreshed to 9,505px. # into unrelated headlines once the strip refreshed to 9,505px.
self._offset_shapes: dict = {} self._offset_shapes: dict = {}
logger.info( logger.debug(
"PluginAdapter initialized: display=%dx%d", "PluginAdapter initialized: display=%dx%d",
self.display_width, self.display_height self.display_width, self.display_height
) )
@@ -109,7 +109,7 @@ class PluginAdapter:
Returns: Returns:
List of PIL Images representing plugin content, or None if no content List of PIL Images representing plugin content, or None if no content
""" """
logger.info( logger.debug(
"[%s] Getting content (class=%s)", "[%s] Getting content (class=%s)",
plugin_id, plugin.__class__.__name__ plugin_id, plugin.__class__.__name__
) )
@@ -118,7 +118,7 @@ class PluginAdapter:
cached = self._get_cached(plugin_id) cached = self._get_cached(plugin_id)
if cached is not None: if cached is not None:
total_width = sum(img.width for img in cached) total_width = sum(img.width for img in cached)
logger.info( logger.debug(
"[%s] Using cached content: %d images, %dpx total", "[%s] Using cached content: %d images, %dpx total",
plugin_id, len(cached), total_width plugin_id, len(cached), total_width
) )
@@ -126,46 +126,46 @@ class PluginAdapter:
# Try native Vegas content method first # Try native Vegas content method first
has_native = hasattr(plugin, 'get_vegas_content') has_native = hasattr(plugin, 'get_vegas_content')
logger.info("[%s] Has get_vegas_content: %s", plugin_id, has_native) logger.debug("[%s] Has get_vegas_content: %s", plugin_id, has_native)
if has_native: if has_native:
content = self._get_native_content(plugin, plugin_id, offscreen_only) content = self._get_native_content(plugin, plugin_id, offscreen_only)
if content: if content:
total_width = sum(img.width for img in content) total_width = sum(img.width for img in content)
logger.info( logger.debug(
"[%s] Native content SUCCESS: %d images, %dpx total", "[%s] Native content SUCCESS: %d images, %dpx total",
plugin_id, len(content), total_width plugin_id, len(content), total_width
) )
return self._finalize(content, plugin_id, 'native', plugin) return self._finalize(content, plugin_id, 'native', plugin)
logger.info("[%s] Native content returned None", plugin_id) logger.debug("[%s] Native content returned None", plugin_id)
# Try to get scroll_helper's cached image (for scrolling plugins like stocks/odds) # Try to get scroll_helper's cached image (for scrolling plugins like stocks/odds)
has_scroll_helper = hasattr(plugin, 'scroll_helper') has_scroll_helper = hasattr(plugin, 'scroll_helper')
logger.info("[%s] Has scroll_helper: %s", plugin_id, has_scroll_helper) logger.debug("[%s] Has scroll_helper: %s", plugin_id, has_scroll_helper)
content = self._get_scroll_helper_content(plugin, plugin_id, offscreen_only) content = self._get_scroll_helper_content(plugin, plugin_id, offscreen_only)
if content: if content:
total_width = sum(img.width for img in content) total_width = sum(img.width for img in content)
logger.info( logger.debug(
"[%s] ScrollHelper content SUCCESS: %d images, %dpx total", "[%s] ScrollHelper content SUCCESS: %d images, %dpx total",
plugin_id, len(content), total_width plugin_id, len(content), total_width
) )
return self._finalize(content, plugin_id, 'scroll_helper', plugin) return self._finalize(content, plugin_id, 'scroll_helper', plugin)
if has_scroll_helper: if has_scroll_helper:
logger.info("[%s] ScrollHelper content returned None", plugin_id) logger.debug("[%s] ScrollHelper content returned None", plugin_id)
if offscreen_only: if offscreen_only:
# Display capture needs the shared canvas; leave it to the caller. # Display capture needs the shared canvas; leave it to the caller.
logger.info( logger.debug(
"[%s] Needs display capture, deferring to the render thread", "[%s] Needs display capture, deferring to the render thread",
plugin_id plugin_id
) )
return None return None
# Fall back to display capture # Fall back to display capture
logger.info("[%s] Trying fallback display capture...", plugin_id) logger.debug("[%s] Trying fallback display capture...", plugin_id)
content = self._capture_display_content(plugin, plugin_id) content = self._capture_display_content(plugin, plugin_id)
if content: if content:
total_width = sum(img.width for img in content) total_width = sum(img.width for img in content)
logger.info( logger.debug(
"[%s] Fallback capture SUCCESS: %d images, %dpx total", "[%s] Fallback capture SUCCESS: %d images, %dpx total",
plugin_id, len(content), total_width plugin_id, len(content), total_width
) )
@@ -226,7 +226,7 @@ class PluginAdapter:
kept.append(result.image) kept.append(result.image)
if not kept: if not kept:
logger.info( logger.debug(
"[%s] All %d image(s) from %s were blank — contributing nothing", "[%s] All %d image(s) from %s were blank — contributing nothing",
plugin_id, len(images), source plugin_id, len(images), source
) )
@@ -235,14 +235,14 @@ class PluginAdapter:
trimmed_width = sum(img.width for img in kept) trimmed_width = sum(img.width for img in kept)
if trimmed_width < self.config.min_plugin_width: if trimmed_width < self.config.min_plugin_width:
logger.info( logger.debug(
"[%s] Trimmed content %dpx is below min_plugin_width %dpx — skipping", "[%s] Trimmed content %dpx is below min_plugin_width %dpx — skipping",
plugin_id, trimmed_width, self.config.min_plugin_width plugin_id, trimmed_width, self.config.min_plugin_width
) )
return None return None
if trimmed_width != original_width or dropped_blank: if trimmed_width != original_width or dropped_blank:
logger.info( logger.debug(
"[%s] Trimmed %s content: %dpx -> %dpx (%.0f%% reclaimed), " "[%s] Trimmed %s content: %dpx -> %dpx (%.0f%% reclaimed), "
"%d image(s) kept, %d blank dropped", "%d image(s) kept, %d blank dropped",
plugin_id, source, original_width, trimmed_width, plugin_id, source, original_width, trimmed_width,
@@ -431,7 +431,7 @@ class PluginAdapter:
""" """
if self._offset_shapes.get(plugin_id) != shape: if self._offset_shapes.get(plugin_id) != shape:
if plugin_id in self._item_offsets: if plugin_id in self._item_offsets:
logger.info( logger.debug(
"[%s] Content is %s now, was %s — restarting the rotation " "[%s] Content is %s now, was %s — restarting the rotation "
"rather than resuming at a position that no longer means " "rather than resuming at a position that no longer means "
"anything", plugin_id, shape, "anything", plugin_id, shape,
@@ -579,7 +579,7 @@ class PluginAdapter:
consumed += 1 consumed += 1
if mode == 'truncate': if mode == 'truncate':
logger.info( logger.debug(
"[%s] Width budget %dpx: showing the first %d of %d row(s) " "[%s] Width budget %dpx: showing the first %d of %d row(s) "
"(%dpx incl. gaps); the rest are not shown (overflow=truncate)", "(%dpx incl. gaps); the rest are not shown (overflow=truncate)",
plugin_id, budget, len(selected), len(images), used plugin_id, budget, len(selected), len(images), used
@@ -587,7 +587,7 @@ class PluginAdapter:
else: else:
self._record_offset( self._record_offset(
plugin_id, (start + consumed) % len(images), shape) plugin_id, (start + consumed) % len(images), shape)
logger.info( logger.debug(
"[%s] Width budget %dpx: showing %d of %d row(s) (%dpx incl. gaps) " "[%s] Width budget %dpx: showing %d of %d row(s) (%dpx incl. gaps) "
"from offset %d; remainder deferred to a later cycle", "from offset %d; remainder deferred to a later cycle",
plugin_id, budget, len(selected), len(images), used, start plugin_id, budget, len(selected), len(images), used, start
@@ -636,7 +636,7 @@ class PluginAdapter:
if mode != 'truncate': if mode != 'truncate':
self._record_offset( self._record_offset(
plugin_id, 0 if end >= img.width else end, shape) plugin_id, 0 if end >= img.width else end, shape)
logger.info( logger.debug(
"[%s] Width budget %dpx: cropped continuous %dpx image to " "[%s] Width budget %dpx: cropped continuous %dpx image to "
"[%d:%d] (no item gaps of %dpx+ to align to)%s", "[%d:%d] (no item gaps of %dpx+ to align to)%s",
plugin_id, budget, img.width, offset, end, min_run, plugin_id, budget, img.width, offset, end, min_run,
@@ -674,7 +674,7 @@ class PluginAdapter:
self._record_offset( self._record_offset(
plugin_id, 0 if end >= img.width else end_index, shape) plugin_id, 0 if end >= img.width else end_index, shape)
logger.info( logger.debug(
"[%s] Width budget %dpx: cropped single %dpx image to [%d:%d] " "[%s] Width budget %dpx: cropped single %dpx image to [%d:%d] "
"(%dpx) at item boundaries %d-%d of %d, %s", "(%dpx) at item boundaries %d-%d of %d, %s",
plugin_id, budget, img.width, start, end, end - start, plugin_id, budget, img.width, start, end, end - start,
@@ -698,7 +698,7 @@ class PluginAdapter:
List of images or None List of images or None
""" """
try: try:
logger.info("[%s] Native: calling get_vegas_content()", plugin_id) logger.debug("[%s] Native: calling get_vegas_content()", plugin_id)
# Tell the plugin how much width the ticker wants it to use, and # Tell the plugin how much width the ticker wants it to use, and
# narrow the canvas for the duration of the call. A plugin that # narrow the canvas for the duration of the call. A plugin that
@@ -707,7 +707,7 @@ class PluginAdapter:
# be explicit can read get_vegas_render_width(). # be explicit can read get_vegas_render_width().
render_width = self.resolve_render_width(plugin, plugin_id) render_width = self.resolve_render_width(plugin, plugin_id)
if render_width != self.display_width: if render_width != self.display_width:
logger.info( logger.debug(
"[%s] Native: requesting %dpx instead of %dpx", "[%s] Native: requesting %dpx instead of %dpx",
plugin_id, render_width, self.display_width plugin_id, render_width, self.display_width
) )
@@ -735,19 +735,19 @@ class PluginAdapter:
plugin._vegas_render_width = None plugin._vegas_render_width = None
if result is None: if result is None:
logger.info("[%s] Native: get_vegas_content() returned None", plugin_id) logger.debug("[%s] Native: get_vegas_content() returned None", plugin_id)
return None return None
# Normalize to list # Normalize to list
if isinstance(result, Image.Image): if isinstance(result, Image.Image):
images = [result] images = [result]
logger.info( logger.debug(
"[%s] Native: got single Image %dx%d", "[%s] Native: got single Image %dx%d",
plugin_id, result.width, result.height plugin_id, result.width, result.height
) )
elif isinstance(result, (list, tuple)): elif isinstance(result, (list, tuple)):
images = list(result) images = list(result)
logger.info( logger.debug(
"[%s] Native: got %d items in list/tuple", "[%s] Native: got %d items in list/tuple",
plugin_id, len(images) plugin_id, len(images)
) )
@@ -768,14 +768,14 @@ class PluginAdapter:
) )
continue continue
logger.info( logger.debug(
"[%s] Native: item[%d] is %dx%d, mode=%s", "[%s] Native: item[%d] is %dx%d, mode=%s",
plugin_id, i, img.width, img.height, img.mode plugin_id, i, img.width, img.height, img.mode
) )
# Ensure correct height # Ensure correct height
if img.height != self.display_height: if img.height != self.display_height:
logger.info( logger.debug(
"[%s] Native: resizing item[%d]: %dx%d -> %dx%d", "[%s] Native: resizing item[%d]: %dx%d -> %dx%d",
plugin_id, i, img.width, img.height, plugin_id, i, img.width, img.height,
img.width, self.display_height img.width, self.display_height
@@ -793,13 +793,13 @@ class PluginAdapter:
if valid_images: if valid_images:
total_width = sum(img.width for img in valid_images) total_width = sum(img.width for img in valid_images)
logger.info( logger.debug(
"[%s] Native: SUCCESS - %d images, %dpx total width", "[%s] Native: SUCCESS - %d images, %dpx total width",
plugin_id, len(valid_images), total_width plugin_id, len(valid_images), total_width
) )
return valid_images return valid_images
logger.info("[%s] Native: no valid images after validation", plugin_id) logger.debug("[%s] Native: no valid images after validation", plugin_id)
return None return None
except (AttributeError, TypeError, ValueError, OSError) as e: except (AttributeError, TypeError, ValueError, OSError) as e:
@@ -833,20 +833,20 @@ class PluginAdapter:
logger.debug("[%s] No scroll_helper attribute", plugin_id) logger.debug("[%s] No scroll_helper attribute", plugin_id)
return None return None
logger.info( logger.debug(
"[%s] Found scroll_helper: %s", "[%s] Found scroll_helper: %s",
plugin_id, type(scroll_helper).__name__ plugin_id, type(scroll_helper).__name__
) )
cached_image = getattr(scroll_helper, 'cached_image', None) cached_image = getattr(scroll_helper, 'cached_image', None)
if cached_image is None: if cached_image is None:
logger.info( logger.debug(
"[%s] scroll_helper.cached_image is None, triggering content generation", "[%s] scroll_helper.cached_image is None, triggering content generation",
plugin_id plugin_id
) )
if offscreen_only: if offscreen_only:
# Generating it calls display(), which needs the canvas. # Generating it calls display(), which needs the canvas.
logger.info( logger.debug(
"[%s] scroll_helper cache empty; deferring generation " "[%s] scroll_helper cache empty; deferring generation "
"to the render thread", plugin_id "to the render thread", plugin_id
) )
@@ -859,13 +859,13 @@ class PluginAdapter:
return None return None
if not isinstance(cached_image, Image.Image): if not isinstance(cached_image, Image.Image):
logger.info( logger.debug(
"[%s] scroll_helper.cached_image is not an Image: %s", "[%s] scroll_helper.cached_image is not an Image: %s",
plugin_id, type(cached_image).__name__ plugin_id, type(cached_image).__name__
) )
return None return None
logger.info( logger.debug(
"[%s] scroll_helper.cached_image found: %dx%d, mode=%s", "[%s] scroll_helper.cached_image found: %dx%d, mode=%s",
plugin_id, cached_image.width, cached_image.height, cached_image.mode plugin_id, cached_image.width, cached_image.height, cached_image.mode
) )
@@ -888,7 +888,7 @@ class PluginAdapter:
# Ensure correct height # Ensure correct height
if img.height != self.display_height: if img.height != self.display_height:
logger.info( logger.debug(
"[%s] Resizing scroll_helper content: %dx%d -> %dx%d", "[%s] Resizing scroll_helper content: %dx%d -> %dx%d",
plugin_id, img.width, img.height, plugin_id, img.width, img.height,
img.width, self.display_height img.width, self.display_height
@@ -902,7 +902,7 @@ class PluginAdapter:
if img.mode != 'RGB': if img.mode != 'RGB':
img = img.convert('RGB') img = img.convert('RGB')
logger.info( logger.debug(
"[%s] ScrollHelper content ready: %dx%d", "[%s] ScrollHelper content ready: %dx%d",
plugin_id, img.width, img.height plugin_id, img.width, img.height
) )
@@ -1002,7 +1002,7 @@ class PluginAdapter:
with self._capture(): with self._capture():
# Method 1: Try _create_scrolling_display (stocks pattern) # Method 1: Try _create_scrolling_display (stocks pattern)
if hasattr(plugin, '_create_scrolling_display'): if hasattr(plugin, '_create_scrolling_display'):
logger.info( logger.debug(
"[%s] Triggering via _create_scrolling_display()", "[%s] Triggering via _create_scrolling_display()",
plugin_id plugin_id
) )
@@ -1010,7 +1010,7 @@ class PluginAdapter:
plugin._create_scrolling_display() plugin._create_scrolling_display()
cached_image = getattr(scroll_helper, 'cached_image', None) cached_image = getattr(scroll_helper, 'cached_image', None)
if cached_image is not None and isinstance(cached_image, Image.Image): if cached_image is not None and isinstance(cached_image, Image.Image):
logger.info( logger.debug(
"[%s] _create_scrolling_display() SUCCESS: %dx%d", "[%s] _create_scrolling_display() SUCCESS: %dx%d",
plugin_id, cached_image.width, cached_image.height plugin_id, cached_image.width, cached_image.height
) )
@@ -1022,7 +1022,7 @@ class PluginAdapter:
# Method 2: Try display(force_clear=True) which typically builds scroll content # Method 2: Try display(force_clear=True) which typically builds scroll content
if hasattr(plugin, 'display'): if hasattr(plugin, 'display'):
logger.info( logger.debug(
"[%s] Triggering via display(force_clear=True)", "[%s] Triggering via display(force_clear=True)",
plugin_id plugin_id
) )
@@ -1031,12 +1031,12 @@ class PluginAdapter:
plugin.display(force_clear=True) plugin.display(force_clear=True)
cached_image = getattr(scroll_helper, 'cached_image', None) cached_image = getattr(scroll_helper, 'cached_image', None)
if cached_image is not None and isinstance(cached_image, Image.Image): if cached_image is not None and isinstance(cached_image, Image.Image):
logger.info( logger.debug(
"[%s] display(force_clear=True) SUCCESS: %dx%d", "[%s] display(force_clear=True) SUCCESS: %dx%d",
plugin_id, cached_image.width, cached_image.height plugin_id, cached_image.width, cached_image.height
) )
return cached_image return cached_image
logger.info( logger.debug(
"[%s] display(force_clear=True) did not populate cached_image", "[%s] display(force_clear=True) did not populate cached_image",
plugin_id plugin_id
) )
@@ -1045,7 +1045,7 @@ class PluginAdapter:
"[%s] display(force_clear=True) failed", plugin_id "[%s] display(force_clear=True) failed", plugin_id
) )
logger.info( logger.debug(
"[%s] Could not trigger scroll content generation", "[%s] Could not trigger scroll content generation",
plugin_id plugin_id
) )
@@ -1077,15 +1077,15 @@ class PluginAdapter:
try: try:
# Save current display state # Save current display state
original_image = self.display_manager.image.copy() original_image = self.display_manager.image.copy()
logger.info("[%s] Fallback: saved original display state", plugin_id) logger.debug("[%s] Fallback: saved original display state", plugin_id)
# Ensure plugin has fresh data before capturing # Ensure plugin has fresh data before capturing
has_update_data = hasattr(plugin, 'update_data') has_update_data = hasattr(plugin, 'update_data')
logger.info("[%s] Fallback: has update_data=%s", plugin_id, has_update_data) logger.debug("[%s] Fallback: has update_data=%s", plugin_id, has_update_data)
if has_update_data: if has_update_data:
try: try:
plugin.update_data() plugin.update_data()
logger.info("[%s] Fallback: update_data() called", plugin_id) logger.debug("[%s] Fallback: update_data() called", plugin_id)
except (AttributeError, RuntimeError, OSError): except (AttributeError, RuntimeError, OSError):
logger.exception("[%s] Fallback: update_data() failed", plugin_id) logger.exception("[%s] Fallback: update_data() failed", plugin_id)
@@ -1097,41 +1097,41 @@ class PluginAdapter:
# arrangement rather than one that has to be cropped afterwards. # arrangement rather than one that has to be cropped afterwards.
render_width = self.resolve_render_width(plugin, plugin_id) render_width = self.resolve_render_width(plugin, plugin_id)
if render_width != self.display_width: if render_width != self.display_width:
logger.info( logger.debug(
"[%s] Fallback: rendering at %dpx instead of %dpx", "[%s] Fallback: rendering at %dpx instead of %dpx",
plugin_id, render_width, self.display_width plugin_id, render_width, self.display_width
) )
with self._capture(), self._render_at(render_width): with self._capture(), self._render_at(render_width):
self.display_manager.clear() self.display_manager.clear()
logger.info("[%s] Fallback: display cleared, calling display()", plugin_id) logger.debug("[%s] Fallback: display cleared, calling display()", plugin_id)
# First try without force_clear (some plugins behave better this way) # First try without force_clear (some plugins behave better this way)
try: try:
plugin.display() plugin.display()
logger.info("[%s] Fallback: display() called successfully", plugin_id) logger.debug("[%s] Fallback: display() called successfully", plugin_id)
except TypeError: except TypeError:
# Plugin may require force_clear argument # Plugin may require force_clear argument
logger.info("[%s] Fallback: display() failed, trying with force_clear=True", plugin_id) logger.debug("[%s] Fallback: display() failed, trying with force_clear=True", plugin_id)
plugin.display(force_clear=True) plugin.display(force_clear=True)
# Capture the result # Capture the result
captured = self.display_manager.image.copy() captured = self.display_manager.image.copy()
logger.info( logger.debug(
"[%s] Fallback: captured frame %dx%d, mode=%s", "[%s] Fallback: captured frame %dx%d, mode=%s",
plugin_id, captured.width, captured.height, captured.mode plugin_id, captured.width, captured.height, captured.mode
) )
# Check if captured image has content (not all black) # Check if captured image has content (not all black)
is_blank, bright_ratio = self._is_blank_image(captured, return_ratio=True) is_blank, bright_ratio = self._is_blank_image(captured, return_ratio=True)
logger.info( logger.debug(
"[%s] Fallback: brightness check - %.3f%% bright pixels (threshold=0.5%%)", "[%s] Fallback: brightness check - %.3f%% bright pixels (threshold=0.5%%)",
plugin_id, bright_ratio * 100 plugin_id, bright_ratio * 100
) )
if is_blank: if is_blank:
logger.info( logger.debug(
"[%s] Fallback: first capture blank, retrying with force_clear", "[%s] Fallback: first capture blank, retrying with force_clear",
plugin_id plugin_id
) )
@@ -1142,7 +1142,7 @@ class PluginAdapter:
captured = self.display_manager.image.copy() captured = self.display_manager.image.copy()
is_blank, bright_ratio = self._is_blank_image(captured, return_ratio=True) is_blank, bright_ratio = self._is_blank_image(captured, return_ratio=True)
logger.info( logger.debug(
"[%s] Fallback: retry brightness - %.3f%% bright pixels", "[%s] Fallback: retry brightness - %.3f%% bright pixels",
plugin_id, bright_ratio * 100 plugin_id, bright_ratio * 100
) )
@@ -1159,7 +1159,7 @@ class PluginAdapter:
if captured.mode != 'RGB': if captured.mode != 'RGB':
captured = captured.convert('RGB') captured = captured.convert('RGB')
logger.info( logger.debug(
"[%s] Fallback: SUCCESS - captured %dx%d", "[%s] Fallback: SUCCESS - captured %dx%d",
plugin_id, captured.width, captured.height plugin_id, captured.width, captured.height
) )
+23
View File
@@ -458,3 +458,26 @@ class TestDiskCacheWriteEconomy:
cache = DiskCache(cache_dir=str(tmp_path)) cache = DiskCache(cache_dir=str(tmp_path))
cache.set("k", {"when": datetime(2026, 7, 12, 10, 30)}) cache.set("k", {"when": datetime(2026, 7, 12, 10, 30)})
assert cache.get("k") == {"when": "2026-07-12T10:30:00"} assert cache.get("k") == {"when": "2026-07-12T10:30:00"}
# --- the ceiling has to hold between cleanup sweeps ---------------------------
def test_memory_cache_enforces_ceiling_on_every_write():
"""_cleanup_memory_cache only runs every cleanup_interval seconds (300 by
default). If set() accepted entries without bound in between, a burst could
take the cache far past max_size -- which is the unbounded growth the limit
exists to prevent, and on a 1GB board the difference between a bounded cache
and a Pi that cannot fork.
"""
from src.cache.memory_cache import MemoryCache
cache = MemoryCache(max_size=150, cleanup_interval=300.0)
for i in range(1000):
cache.set(f"k{i}", {"v": i})
assert len(cache._cache) <= 150
# The timestamp map has to be evicted alongside the values, or it becomes
# the leak instead.
assert len(cache._timestamps) <= 150
assert cache.get("k999") is not None, "the newest write must survive"
assert cache.get("k0") is None, "the oldest must be the one evicted"
+113
View File
@@ -0,0 +1,113 @@
"""A checkbox group must not post back options it cannot show.
The enum that lets the widget draw checkboxes is also what validates the
saved value. When a league retires a team code -- OAK for the Athletics, ARI
for the Coyotes -- or a schema drops an option, a config that still holds the
old value has nothing to render for it. The value stayed in the hidden
``_data`` input regardless, because that input is seeded from the stored array
and only rebuilt by ``updateCheckboxGroupData()`` on change. Editing any other
field on that plugin therefore posted the stale value back, the schema
rejected it, and the save endpoint returned 400
``CONFIG_VALIDATION_FAILED`` -- so the whole plugin became uneditable until
the user worked out which invisible entry was at fault.
Runtime was never affected: plugin loading treats schema violations as
warn/degrade, and the stale code already matched no team. Only the web UI
blocked.
These tests render the checkbox-group block lifted *out of the shipped
template*, following test_enum_option_labels.py, so they exercise the
production expression rather than a copy that could drift from it.
"""
import json
import re
from pathlib import Path
from jinja2 import DictLoader, Environment
PROJECT_ROOT = Path(__file__).resolve().parent.parent
CONFIG_FORM = (PROJECT_ROOT / 'web_interface' / 'templates' / 'v3' / 'partials'
/ 'plugin_config.html')
# The checkbox-group branch: from its `{% elif %}` guard through the sentinel
# hidden input that closes it. Anchored on the guard so the match cannot run on
# into a neighbouring widget branch.
BLOCK_RE = re.compile(
r"\{%\s*elif x_widget == 'checkbox-group'\s*%\}(.*?)"
r"<input type=\"hidden\" name=\"\{\{ full_key \}\}\[\]\" value=\"\">",
re.S,
)
def _shipped_block() -> str:
"""Return the live checkbox-group block lifted from plugin_config.html."""
source = CONFIG_FORM.read_text(encoding='utf-8')
match = BLOCK_RE.search(source)
assert match, (
'could not find the checkbox-group block in plugin_config.html — the '
'template changed shape and this guard needs updating'
)
block = match.group(1)
assert 'data-option-value' in block, 'extracted the wrong branch'
assert '{% elif' not in block, 'extraction ran past the checkbox-group branch'
return block
def _render(prop: dict, value=None) -> str:
env = Environment(loader=DictLoader({'f': _shipped_block()}), autoescape=True)
return env.get_template('f').render(
prop=prop, value=value, field_id='fid', full_key='k'
)
def _submitted(html: str) -> list:
"""The array the form will actually post: the hidden _data input."""
match = re.search(r'id="fid_data"[^>]*\svalue=\'([^\']*)\'', html)
assert match, f'hidden _data input not found in:\n{html}'
return json.loads(match.group(1).replace('&#39;', "'"))
def _checked(html: str) -> list:
return re.findall(r'data-option-value="([^"]+)"[^>]*checked', html)
MLB = {'type': 'array', 'items': {'type': 'string', 'enum': ['NYY', 'BOS', 'ATH']},
'x-widget': 'checkbox-group'}
def test_a_retired_code_is_not_posted_back() -> None:
"""The regression: OAK became ATH, and OAK used to ride along on save."""
html = _render(MLB, ['NYY', 'OAK'])
assert _submitted(html) == ['NYY'], 'stale value would still be submitted'
def test_the_dropped_value_is_named_rather_than_vanishing() -> None:
html = _render(MLB, ['NYY', 'OAK'])
assert 'OAK' in html
assert 'data-stale-options' in html
def test_valid_values_are_untouched_and_still_checked() -> None:
html = _render(MLB, ['NYY', 'ATH'])
assert _submitted(html) == ['NYY', 'ATH']
assert sorted(_checked(html)) == ['ATH', 'NYY']
assert 'data-stale-options' not in html
def test_an_all_stale_selection_clears_rather_than_blocking() -> None:
html = _render(MLB, ['OAK', 'SD'])
assert _submitted(html) == []
def test_an_empty_enum_leaves_the_value_alone() -> None:
"""No options means nothing to validate against — filtering would wipe it."""
prop = {'type': 'array', 'items': {'type': 'string'}, 'x-widget': 'checkbox-group'}
html = _render(prop, ['ANYTHING', 'GOES'])
assert _submitted(html) == ['ANYTHING', 'GOES']
def test_unset_value_falls_back_to_the_default() -> None:
prop = dict(MLB, default=['BOS'])
html = _render(prop, None)
assert _submitted(html) == ['BOS']
assert _checked(html) == ['BOS']
+110
View File
@@ -0,0 +1,110 @@
"""A healthy plugin must not rewrite its health record every cycle.
Every successful plugin update called record_success(), which persisted the
record unconditionally. In steady state the only fields that had changed were
total_successes and last_success_time -- a counter and a timestamp that
health_monitor reads for display and that nothing reads back after a restart.
Measured on a rig running 24 plugins: about 17 health-file rewrites a minute,
roughly 25,000 a day. Each is ~400 bytes, but they land on an SD card where
the unit of cost is an erase-block cycle, not the byte count, and where wear is
what eventually kills the card.
The circuit breaker still needs its own state to survive a restart, so the
write is kept for exactly the fields it is rebuilt from -- and a failure, a
circuit opening, or a recovery must still be written the moment it happens.
"""
import time
import pytest
from src.plugin_system.plugin_health import PluginHealthTracker, CircuitState
class _Cache:
"""Counts writes; serves back whatever was last written."""
def __init__(self):
self.store = {}
self.writes = 0
def set(self, key, data, ttl=None, **kwargs):
self.writes += 1
self.store[key] = data
def get(self, key, max_age=None, memory_ttl=None, **kwargs):
return self.store.get(key)
@pytest.fixture
def tracker():
cache = _Cache()
t = PluginHealthTracker(cache_manager=cache)
return t, cache
def test_steady_state_success_stops_writing(tracker):
"""The regression: 100 healthy cycles used to be 100 SD writes."""
t, cache = tracker
t.record_success("weather")
first = cache.writes
for _ in range(100):
t.record_success("weather")
assert cache.writes == first, (
f"{cache.writes - first} redundant writes across 100 healthy cycles"
)
def test_the_counters_are_still_accurate_in_memory(tracker):
"""Skipping the write must not skip the bookkeeping."""
t, _ = tracker
for _ in range(10):
t.record_success("weather")
state = t.get_health_state("weather")
assert state["total_successes"] == 10
assert state["last_success_time"] is not None
assert state["last_success_time"] <= time.time()
def test_a_failure_is_written_immediately(tracker):
t, cache = tracker
t.record_success("weather")
before = cache.writes
t.record_failure("weather", RuntimeError("boom"))
assert cache.writes > before, "a failure must reach disk"
def test_recovery_after_failure_is_written(tracker):
"""consecutive_failures returning to 0 is durable state changing."""
t, cache = tracker
t.record_failure("weather", RuntimeError("boom"))
before = cache.writes
t.record_success("weather")
assert cache.writes > before, "recovery must reach disk"
assert t.get_health_state("weather")["consecutive_failures"] == 0
def test_a_closing_circuit_is_written(tracker):
"""Success in half-open closes the circuit -- that must survive a restart."""
t, cache = tracker
state = t.get_health_state("weather")
state["circuit_state"] = CircuitState.HALF_OPEN.value
state["half_open_start_time"] = time.time()
before = cache.writes
t.record_success("weather")
assert cache.writes > before, "a circuit transition must reach disk"
assert t.get_health_state("weather")["circuit_state"] == CircuitState.CLOSED.value
def test_durable_state_survives_a_restart(tracker):
"""What is skipped must genuinely not matter to the breaker."""
t, cache = tracker
for _ in range(3):
t.record_failure("weather", RuntimeError("boom"))
for _ in range(50):
t.record_success("weather")
revived = PluginHealthTracker(cache_manager=cache)
state = revived.get_health_state("weather")
assert state["consecutive_failures"] == 0
assert state["circuit_state"] == CircuitState.CLOSED.value
+241
View File
@@ -0,0 +1,241 @@
"""
Getting Started checklist: what the server decides, and what it must not.
The timezone step used to tick server-side when the saved timezone differed
from the shipped default, OR-ed with the saved city. That made the step
unsatisfiable for anyone genuinely in the default zone (the card nagged
forever), and let a saved city tick it off while the timezone was still wrong.
The step is now verified in the browser against its own zone, so the server's
only job is to hand over the configured value and stay out of the decision.
These tests pin that contract: the panel-size step still reflects config, the
timezone step never pre-ticks, it carries the configured zone, and the city
has no influence on it.
"""
import copy
import re
import sys
from pathlib import Path
from unittest.mock import MagicMock
import pytest
from flask import Flask
PROJECT_ROOT = Path(__file__).parent.parent
sys.path.insert(0, str(PROJECT_ROOT))
BASE_CONFIG = {
"timezone": "America/New_York",
"location": {"city": "Tampa", "state": "Florida", "country": "US"},
"display": {
"hardware": {"rows": 32, "cols": 64, "chain_length": 2, "parallel": 1},
"runtime": {},
"double_sided": {"enabled": False},
"vegas_scroll": {"plugin_order": [], "excluded_plugins": []},
"plugin_rotation_order": [],
},
"plugin_system": {},
"schedule": {},
"dim_schedule": {},
"sync": {},
}
def render(config):
"""Render the overview partial against one config, as app.py would."""
base = PROJECT_ROOT / "web_interface"
app = Flask(
__name__,
template_folder=str(base / "templates"),
static_folder=str(base / "static"),
)
app.config["TESTING"] = True
from web_interface.blueprints import pages_v3 as pv
# pages_v3 is a module-level singleton shared across the test process;
# restore whatever the previous test left on it.
original_cm = getattr(pv.pages_v3, "config_manager", None)
original_pm = getattr(pv.pages_v3, "plugin_manager", None)
mock_cm = MagicMock()
mock_cm.load_config.return_value = config
mock_cm.get_raw_file_content.return_value = config
pv.pages_v3.config_manager = mock_cm
mock_pm = MagicMock()
mock_pm.plugins = {}
mock_pm.get_all_plugin_info.return_value = []
mock_pm.get_plugin_display_modes.side_effect = lambda pid: []
pv.pages_v3.plugin_manager = mock_pm
app.register_blueprint(pv.pages_v3, url_prefix="")
try:
resp = app.test_client().get("/partials/overview")
assert resp.status_code == 200, resp.status_code
return resp.get_data(as_text=True)
finally:
pv.pages_v3.config_manager = original_cm
pv.pages_v3.plugin_manager = original_pm
def timezone_step(body):
"""The checklist <button> for the timezone step."""
match = re.search(r"<button[^>]*data-check=\"timezone\"[^>]*>", body)
assert match, "timezone step not found in the rendered checklist"
return match.group(0)
def config_with(**overrides):
config = copy.deepcopy(BASE_CONFIG)
for key, value in overrides.items():
config[key] = value
return config
@pytest.mark.parametrize(
"timezone",
["America/New_York", "America/Los_Angeles", "Europe/Madrid", "Asia/Kolkata"],
)
def test_timezone_step_never_pre_ticks_server_side(timezone):
"""The browser owns this decision; the server must not pre-empt it.
The default zone is in the list deliberately: that is the case the old
default-comparison could never tick.
"""
step = timezone_step(render(config_with(timezone=timezone)))
assert 'data-done="0"' in step, step
@pytest.mark.parametrize(
"timezone",
["America/New_York", "Europe/Madrid", "Pacific/Auckland"],
)
def test_timezone_step_carries_the_configured_zone(timezone):
"""JS compares data-tz against the browser, so it has to be the real value."""
assert f'data-tz="{timezone}"' in timezone_step(render(config_with(timezone=timezone)))
def test_city_does_not_influence_the_timezone_step():
"""The coupling this change removes: city said nothing about the timezone,
and OR-ing it let a saved city tick the step off with the zone still wrong.
timezone_step() returns the opening tag only, so this compares the state
the step is in -- data-done and data-tz -- and not the label, which does
still show the configured city as context and so differs between the two.
"""
tampa = timezone_step(render(config_with(
location={"city": "Tampa", "state": "Florida", "country": "US"})))
seattle = timezone_step(render(config_with(
location={"city": "Seattle", "state": "Washington", "country": "US"})))
assert tampa == seattle
def test_missing_timezone_leaves_the_step_open():
"""Nothing saved means nothing to verify: the step stays unticked and the
JS bails on the empty value rather than comparing against ''."""
step = timezone_step(render(config_with(timezone="")))
assert 'data-tz=""' in step
assert 'data-done="0"' in step
def test_zone_comparison_asks_for_the_time_of_day():
"""Guard on the Intl options, which look like a stylistic choice.
dateStyle/timeStyle are late additions (Firefox shipped them in 91). An
implementation that does not know them ignores them and formats the date
alone -- which compares New York, Chicago and Madrid as equal and ticks
the step for a timezone that is plainly wrong. Explicit numeric fields
have been in Intl since ECMA-402 v1.
"""
template = (PROJECT_ROOT / "web_interface" / "templates" / "v3"
/ "partials" / "overview.html").read_text()
body = template[template.index("function sameZone"):]
body = body[:body.index("}())")]
# The comment above the options names dateStyle/timeStyle to explain why
# they are not used, so match on code only.
body = "\n".join(line for line in body.splitlines()
if not line.lstrip().startswith("//"))
assert "dateStyle" not in body and "timeStyle" not in body, (
"zone comparison must not depend on dateStyle/timeStyle")
for field in ("hour:", "minute:", "year:", "month:", "day:"):
assert field in body, f"zone comparison dropped {field!r}"
def test_zone_comparison_samples_both_sides_of_dst():
"""One instant is not enough, and the shortfall is invisible for months.
America/New_York and America/Lima hold the same offset all winter, so a
check against now alone ticks the step in January for a panel that runs an
hour off from March. The comparison has to sample instants either side of
DST -- mid-January and mid-July, which covers both hemispheres.
"""
template = (PROJECT_ROOT / "web_interface" / "templates" / "v3"
/ "partials" / "overview.html").read_text()
body = template[template.index("function sameZone"):]
body = body[:body.index("}())")]
code = "\n".join(line for line in body.splitlines()
if not line.lstrip().startswith("//"))
assert "Date.UTC" in code, (
"zone comparison samples only the current instant, so zones that "
"coincide seasonally would read as equal")
assert code.count("Date.UTC") >= 2, "expected an instant either side of DST"
def _stamp(zone, instant):
"""The JS comparison's algorithm, for pinning what it must decide.
There is no JS runtime here (and the repo has no JS test infra), so this
mirrors sameZone rather than executing it: same instants, same wall-clock
equality. It records the verdicts the shipped code has to reach.
"""
from zoneinfo import ZoneInfo
return instant.astimezone(ZoneInfo(zone)).strftime("%m/%d/%Y %H:%M")
@pytest.mark.parametrize(
"left,right,equivalent",
[
# Aliases: one zone under two names.
("Asia/Calcutta", "Asia/Kolkata", True),
("Europe/Kiev", "Europe/Kyiv", True),
# Same rules year-round: either renders the same times, so a panel set
# to one and browsed from the other is correctly configured.
("America/New_York", "America/Toronto", True),
# Coincide in winter only -- the case a single-instant check gets wrong.
("America/New_York", "America/Lima", False),
("America/Phoenix", "America/Los_Angeles", False),
("Australia/Sydney", "Pacific/Guadalcanal", False),
# Plainly different.
("America/New_York", "America/Chicago", False),
("America/New_York", "Europe/Madrid", False),
],
)
def test_which_zone_pairs_must_count_as_the_same(left, right, equivalent):
from datetime import datetime
from zoneinfo import ZoneInfo
year = 2026
instants = [datetime(year, 1, 15, 12, tzinfo=ZoneInfo("UTC")),
datetime(year, 7, 15, 12, tzinfo=ZoneInfo("UTC"))]
matched = all(_stamp(left, at) == _stamp(right, at) for at in instants)
assert matched is equivalent, (
f"{left} vs {right}: sampling both seasons gave {matched}")
@pytest.mark.parametrize(
"hardware,expected",
[
({"rows": 32, "cols": 64, "chain_length": 2, "parallel": 1}, "1"),
({"rows": 0, "cols": 0, "chain_length": 0, "parallel": 1}, "0"),
],
)
def test_panel_size_step_still_reflects_config(hardware, expected):
"""Regression guard: the hardware step is still decided server-side."""
config = config_with()
config["display"]["hardware"] = hardware
body = render(config)
match = re.search(r"<button[^>]*data-tab=\"display\"[^>]*>", body)
assert match, "panel-size step not found"
assert f'data-done="{expected}"' in match.group(0), match.group(0)
+98
View File
@@ -91,3 +91,101 @@ def test_force_reload_refreshes_stale_in_memory_snapshot():
# and it asked the cache to bypass the in-memory tier (memory_ttl=0). # and it asked the cache to bypass the in-memory tier (memory_ttl=0).
assert any(c.kwargs.get("memory_ttl") == 0 for c in cache.get.call_args_list) assert any(c.kwargs.get("memory_ttl") == 0 for c in cache.get.call_args_list)
# --- persisted state that does not match the current schema -------------------
#
# A record on disk can be missing fields the callers index directly: a partial
# write, a restored backup, or a state written by an older schema. Returning it
# verbatim raises KeyError inside record_success / record_failure, which takes
# the display down in a restart loop that survives reboots, because the bad
# entry is on disk and gets read again on the way back up. Observed in the wild
# as `plugin clock-simple operation failed: 'circuit_state'`, repeating ~50x a
# minute with the panel frozen.
_INDEXED_FIELDS = (
"consecutive_failures", "total_failures", "total_successes",
"last_success_time", "last_failure_time", "circuit_state",
"circuit_opened_time", "half_open_start_time", "last_error",
)
def _tracker_reading(persisted):
cache = _cache()
cache.get.return_value = persisted
return PluginHealthTracker(cache)
def test_partial_state_is_completed_not_returned_raw():
"""The shape seen in the wild: one field, everything else absent."""
state = _tracker_reading({"circuit_state": "closed"}).get_health_state("p")
for field in _INDEXED_FIELDS:
assert field in state, f"{field} missing; callers index it directly"
def test_repair_keeps_real_failure_history():
"""A record with genuine counts must not be reset to healthy just because
an optional field is absent -- that would clear a tripped breaker."""
state = _tracker_reading({
"consecutive_failures": 5,
"total_failures": 5,
"circuit_state": "open",
}).get_health_state("p")
assert state["consecutive_failures"] == 5
assert state["total_failures"] == 5
assert state["circuit_state"] == "open"
def test_wrong_types_fall_back_per_field():
"""A counter persisted as a string would pass a membership check and then
fail on the first += 1; an unknown circuit_state would take a branch the
breaker has no handling for."""
state = _tracker_reading({
"consecutive_failures": "3",
"circuit_state": "melted",
"total_failures": 7,
}).get_health_state("p")
assert state["consecutive_failures"] == 0
assert state["circuit_state"] == CircuitState.CLOSED.value
assert state["total_failures"] == 7, "valid neighbours must survive"
def test_newer_fields_are_carried_through():
"""degraded/degraded_reason are read with .get() and are not part of the
indexed set; repairing must not drop them."""
state = _tracker_reading({
"circuit_state": "closed", "degraded": True, "degraded_reason": "x",
}).get_health_state("p")
assert state["degraded"] is True
assert state["degraded_reason"] == "x"
def test_recording_against_a_repaired_state_does_not_raise():
"""The actual failure: record_failure indexing a field that was not there.
The seed deliberately omits circuit_state. Seeding a record that *has* it
would pass against the old raw-return behaviour too -- the counters are
read with .get(), so circuit_state is the only field whose absence used to
raise.
"""
tracker = _tracker_reading({"total_failures": 2, "total_successes": 1})
tracker.record_failure("p", Exception("boom"))
tracker.record_success("p")
def test_unhashable_or_boolean_values_are_repaired():
"""Values that break the repair itself rather than a later caller.
An unhashable circuit_state raises TypeError inside a set membership test,
and bool is a subclass of int, so True would pass as a timestamp and then
compare as 1.0 -- expiring a cooldown the moment it opens.
"""
for bad_state in ({"circuit_state": []}, {"circuit_state": {}}):
state = _tracker_reading(bad_state).get_health_state("p")
assert state["circuit_state"] == CircuitState.CLOSED.value
state = _tracker_reading({
"circuit_opened_time": True, "last_success_time": False,
}).get_health_state("p")
assert state["circuit_opened_time"] is None
assert state["last_success_time"] is None
+63
View File
@@ -0,0 +1,63 @@
"""The Vegas content path must trace at DEBUG, not INFO.
plugin_adapter narrates every step of acquiring content from every plugin --
"Has get_vegas_content", "Native: calling get_vegas_content()", "Native content
returned None", "Has scroll_helper", the per-item sizes -- and it does that for
each plugin on each cycle.
Measured on a live rig: 13,408 log lines an hour, of which 13,366 were INFO and
35 were WARNING. plugin_adapter alone produced 2,457 of them. That is ~223
lines a minute of string formatting on a Pi that is also driving the panel, all
of it written through journald to the SD card, and it buries the 35 lines that
actually indicate a problem.
Nothing is lost by moving it to DEBUG: the 19 warning/error/exception calls in
the module are untouched, so real failures still surface at their own level.
One INFO call is deliberate and stays -- the padding-strip message chooses its
level at runtime (`logger.warning if (left and right) else logger.info`) and
test_vegas_plugin_adapter.py pins it.
"""
import ast
from pathlib import Path
import pytest
ADAPTER = (Path(__file__).resolve().parent.parent / "src" / "vegas_mode"
/ "plugin_adapter.py")
def _info_calls(path):
"""Direct logger.info(...) call sites in a module."""
tree = ast.parse(path.read_text(encoding="utf-8"))
found = []
for node in ast.walk(tree):
if (isinstance(node, ast.Call)
and isinstance(node.func, ast.Attribute)
and node.func.attr == "info"
and getattr(node.func.value, "id", None) == "logger"):
found.append(node.lineno)
return found
def test_the_content_path_does_not_trace_at_info():
calls = _info_calls(ADAPTER)
assert not calls, (
"plugin_adapter should trace at DEBUG; found logger.info at lines "
f"{calls}. This path runs per plugin per cycle and its output goes to "
"the SD card via journald."
)
def test_real_failures_still_have_a_level_of_their_own():
"""Demoting the trace must not have swept up the error reporting."""
source = ADAPTER.read_text(encoding="utf-8")
loud = sum(source.count(f"logger.{level}(")
for level in ("warning", "error", "exception"))
assert loud >= 15, f"only {loud} warning/error/exception calls remain"
def test_the_deliberate_runtime_chosen_level_survives():
"""The padding-strip message picks its level at runtime; leave it alone."""
source = ADAPTER.read_text(encoding="utf-8")
assert "logger.warning if (left and right) else logger.info" in source
@@ -63,13 +63,13 @@
<!-- Getting Started checklist: non-gating, dismissible (localStorage), items <!-- Getting Started checklist: non-gating, dismissible (localStorage), items
auto-check from existing config/endpoints — no new persisted state. auto-check from existing config/endpoints — no new persisted state.
Known heuristic limits (acceptable, disclosed): values left at legitimate The timezone step is verified against the browser's own zone rather than
defaults (e.g. a user actually in Tampa) read as "not done". --> compared to the shipped default; see the data-check="timezone" block below
for why. -->
{% set _hw = main_config.display.hardware if main_config and main_config.display else {} %} {% set _hw = main_config.display.hardware if main_config and main_config.display else {} %}
{% set _hw_done = (_hw.rows or 0) > 0 and (_hw.cols or 0) > 0 and (_hw.chain_length or 0) > 0 %} {% set _hw_done = (_hw.rows or 0) > 0 and (_hw.cols or 0) > 0 and (_hw.chain_length or 0) > 0 %}
{% set _loc = main_config.location if main_config and main_config.location else {} %} {% set _loc = main_config.location if main_config and main_config.location else {} %}
{% set _loc_done = (main_config.timezone and main_config.timezone != 'America/New_York') {% set _tz = (main_config.timezone if main_config else '') or '' %}
or (_loc.city and _loc.city != 'Tampa') %}
<div id="getting-started-card" class="bg-blue-50 border border-blue-200 rounded-lg p-4 mb-4" style="display:none" role="region" aria-label="Getting started checklist"> <div id="getting-started-card" class="bg-blue-50 border border-blue-200 rounded-lg p-4 mb-4" style="display:none" role="region" aria-label="Getting started checklist">
<div class="flex items-start justify-between"> <div class="flex items-start justify-between">
<div class="flex-1"> <div class="flex-1">
@@ -78,8 +78,8 @@
<ul class="space-y-1 text-sm" id="getting-started-items"> <ul class="space-y-1 text-sm" id="getting-started-items">
<li><button type="button" class="gs-item text-left w-full" data-done="{{ '1' if _hw_done else '0' }}" data-tab="display"> <li><button type="button" class="gs-item text-left w-full" data-done="{{ '1' if _hw_done else '0' }}" data-tab="display">
<i class="far fa-square mr-2"></i>Set your panel size (Display tab)</button></li> <i class="far fa-square mr-2"></i>Set your panel size (Display tab)</button></li>
<li><button type="button" class="gs-item text-left w-full" data-done="{{ '1' if _loc_done else '0' }}" data-tab="general"> <li><button type="button" class="gs-item text-left w-full" data-done="0" data-check="timezone" data-tz="{{ _tz }}" data-tab="general">
<i class="far fa-square mr-2"></i>Set your timezone and location (General tab)</button></li> <i class="far fa-square mr-2"></i>Set your timezone{% if _tz %} — currently {{ _tz }}{% if _loc.city %}, {{ _loc.city }}{% endif %}{% endif %} (General tab)<span data-gs-tz-note class="text-xs"></span></button></li>
<li><button type="button" class="gs-item text-left w-full" data-done="0" data-check="installed" data-tab="plugins"> <li><button type="button" class="gs-item text-left w-full" data-done="0" data-check="installed" data-tab="plugins">
<i class="far fa-square mr-2"></i>Install a plugin from the Plugin Store</button></li> <i class="far fa-square mr-2"></i>Install a plugin from the Plugin Store</button></li>
<li><button type="button" class="gs-item text-left w-full" data-done="0" data-check="enabled" data-tab="plugins"> <li><button type="button" class="gs-item text-left w-full" data-done="0" data-check="enabled" data-tab="plugins">
@@ -165,6 +165,91 @@
}); });
maybeAutoHide(); maybeAutoHide();
// Timezone: verified against the browser's own zone.
//
// This step used to tick when the saved timezone differed from the value
// config.template.json ships (America/New_York), with the saved city
// OR-ed in. Two things were wrong with that. "Differs from the default"
// answers "did somebody edit this?", but what the checklist needs to know
// is whether the value is RIGHT — so anyone who genuinely lives in the
// default zone could never satisfy it and the card nagged forever. And
// the city has no bearing on whether the timezone is set: because the two
// were OR-ed, saving a city ticked the step off with the timezone still
// wrong, which is the direction that actually breaks displays (event
// times render in the wrong zone).
//
// The browser already knows its zone, so compare against that: no new
// persisted state, no network, and it catches the reverse case too — a
// panel still set to the old zone after a move now stays unticked, where
// the old test ticked it the moment the value stopped being the default.
function sameZone(a, b) {
if (a === b) return true;
// Compare the wall-clock time each zone yields, not the identifiers:
// aliases (Asia/Calcutta vs Asia/Kolkata, Europe/Kiev vs Europe/Kyiv)
// name one zone and must not read as a mismatch.
//
// Sampled at three instants, all of which have to agree. Checking only
// now is not enough: America/New_York and America/Lima hold the same
// offset all winter, so a panel set to the wrong one of those would
// tick in January and then run an hour off from March. Mid-January and
// mid-July sit either side of DST in both hemispheres, so only zones
// that agree year-round match -- while Toronto still matches New York,
// which is right, since either renders the same times.
try {
var now = new Date();
var year = now.getUTCFullYear();
var instants = [now,
new Date(Date.UTC(year, 0, 15, 12)),
new Date(Date.UTC(year, 6, 15, 12))];
var stamp = function (tz, at) {
// Explicit numeric fields rather than dateStyle/timeStyle:
// those are late additions to Intl (Firefox shipped them in
// 91), and an implementation that does not know them ignores
// them and formats the date alone. That would compare
// New York, Chicago and Madrid as equal and tick the step for
// a timezone that is plainly wrong -- the exact failure this
// check exists to catch. These options have been in Intl
// since ECMA-402 v1.
return new Intl.DateTimeFormat('en-US', {
timeZone: tz, year: 'numeric', month: '2-digit',
day: '2-digit', hour: '2-digit', minute: '2-digit',
hour12: false
}).format(at);
};
for (var i = 0; i < instants.length; i++) {
if (stamp(a, instants[i]) !== stamp(b, instants[i])) {
return false;
}
}
return true;
} catch (e) {
// An unparseable zone in the config is worth surfacing, not hiding.
return false;
}
}
(function () {
var tzBtn = card.querySelector('[data-check="timezone"]');
if (!tzBtn) return;
var configured = tzBtn.dataset.tz || '';
if (!configured) return; // nothing saved yet: leave it open
var local = '';
try {
local = (Intl.DateTimeFormat().resolvedOptions().timeZone) || '';
} catch (e) {
return; // no Intl: leave it to the manual tick
}
if (!local) return;
if (sameZone(configured, local)) {
markDone(tzBtn);
return;
}
// Unticked on its own says "wrong" without saying why; name the zone
// the browser is in so the step is actionable.
var note = tzBtn.querySelector('[data-gs-tz-note]');
if (note) note.textContent = ' — this browser is in ' + local;
}());
// Plugin-derived states from the existing installed-plugins endpoint. // Plugin-derived states from the existing installed-plugins endpoint.
fetch('/api/v3/plugins/installed') fetch('/api/v3/plugins/installed')
.then(function (r) { return r.json(); }) .then(function (r) { return r.json(); })
@@ -296,6 +296,26 @@
{% set enum_items = items_schema.get('enum') or [] %} {% set enum_items = items_schema.get('enum') or [] %}
{% set x_options = prop.get('x-options') or {} %} {% set x_options = prop.get('x-options') or {} %}
{% set labels = x_options.get('labels') or {} %} {% set labels = x_options.get('labels') or {} %}
{# A saved value that is no longer one of the options -- a team
code the league retired, an option dropped from the schema --
has no checkbox to render, so it would sit unseen in the
hidden input below and be posted back on save. The schema
rejects it and the save endpoint returns 400, which blocks
editing any other field on the plugin until the stale entry
is found and removed. Drop them here instead, and say which,
so the value is not lost silently. Only when the widget
actually has options: an empty enum means nothing to check
against, and filtering on it would wipe the field. #}
{% set stale_values = (array_value | reject('in', enum_items) | list) if enum_items else [] %}
{% set array_value = (array_value | select('in', enum_items) | list) if enum_items else array_value %}
{% if stale_values %}
<div class="mt-1 mb-2 rounded border border-amber-300 bg-amber-50 px-3 py-2 text-sm text-amber-800"
data-stale-options="{{ field_id }}">
No longer offered, and will be removed when you save:
<span class="font-mono">{{ stale_values | join(', ') }}</span>.
</div>
{% endif %}
<div class="mt-1 space-y-2"> <div class="mt-1 space-y-2">
{% for option in enum_items %} {% for option in enum_items %}