Compare commits

...
Author SHA1 Message Date
ChuckBuildsandClaude Opus 5 b7cf94f20a perf(vegas): report the frame rate when it is worth reporting
Vegas logged an FPS line at INFO every five seconds for the whole of
every run. Measured over two hours on a rig: 1410 samples, 98.5% of them
within 10% of target. The 1.5% that were not included a reading of
8.6fps against a target of 60 -- a real stall, completely invisible
inside 1389 lines reading "59.6". INFO is now reserved for a shortfall,
the recovery from one, and a slow heartbeat so a healthy marquee still
shows a pulse. Scroll-progress tracing drops to DEBUG for the same
reason: it runs for the whole of every scroll and is what you turn debug
on to watch.

Three review findings, all fixed here.

1. Per-frame timing used the wall clock (critical). The loop sleeps the
   remainder of each frame budget:

       frame_elapsed = <now> - frame_started
       time.sleep(max(0.0, frame_interval - frame_elapsed))

   These devices have no RTC, so the clock jumps by however wrong boot
   time was when NTP first syncs. A backward step makes frame_elapsed
   negative, `frame_interval - frame_elapsed` then exceeds the whole
   budget, and the render loop stalls for the size of the correction. A
   forward step instead inflates the p99 and worst-frame figures this
   telemetry exists to report. Both per-frame timestamps are monotonic
   now. start_time stays wall-clock: it is only used for the iteration
   duration report, where a human-readable clock is the point.

2. FPS health state reset every iteration. last_fps_health_log and
   was_degraded were locals of run_iteration(), which is called once per
   cycle. Starting at 0.0 against a monotonic clock, `due` was true on
   the first sample of every iteration, so the 300s heartbeat degenerated
   into one report per cycle -- reintroducing the noise this change is
   about. A recovery that crossed an iteration boundary was never
   reported either, since was_degraded had already gone back to False.
   Both now live on the coordinator and reset in start().

3. The degraded threshold read as an off-by-one. 90% of target is
   deliberate -- a marquee jitters constantly, so "anything below target"
   would report forever and mean nothing -- but nothing said so, leaving
   55fps-against-60 looking like a missed case. The constant now states
   the band and gives that exact example.

Also drops two soccer logo PNGs that a `git add -A` had swept into the
first commit. They are unreferenced, unrelated to frame-rate telemetry,
and 210KB.

Verified: each fix mutation-checked -- restoring the wall clock on either
per-frame timestamp, or making the health state local again, fails the
new tests. 566 passed across the vegas, coordinator and scroll suites.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW
2026-08-21 16:18:14 -04:00
ChuckandClaude Opus 5 863e4a1ecd consolidate(perf): cut SD writes, log volume, and metrics churn (#486)
* fix(plugins): one bad metrics cache entry should not stop every plugin

Caught live on a rig: every plugin failing, once each, continuously.

    ERROR - src.plugin_system.plugin_manager - plugin geochron operation failed:
    ResourceMetrics.__init__() got an unexpected keyword argument
    'consecutive_failures'

    ERROR - ... plugin text-display operation failed: ...
    ERROR - ... plugin news operation failed: ...
    ERROR - ... plugin odds-ticker operation failed: ...

with /api/v3/health reporting plugin_system: not_initialized while the display
process itself kept running and updating the panel.

`consecutive_failures` is a plugin_health field, not a metrics one.
get_metrics() does ResourceMetrics(**cached), which raises TypeError on a
single unrecognised key, and that exception escapes into plugin_manager and is
reported per plugin. One malformed cache entry takes the whole plugin system
down.

How a health-shaped record came to sit under a plugin_metrics key on that
machine is not established, and I could not finish the diagnosis: the rig went
back into its EIO failure mode partway through -- SSH resetting pre-banner,
systemctl unexecutable -- while the web API kept answering from RAM. Checked
before that: the cache files on disk are correctly shaped and separate, and
CacheManager.get() returns the right record for each key, so it is not a live
key collision. A restored backup mixing two machines' caches is the likeliest
explanation, and that rig had one restored onto it.

Either way the loader should not be brittle enough for the answer to matter.
plugin_health already repairs its records field by field rather than trusting
what is on disk; this does the same. Known fields are kept, unknown ones are
dropped and named once in the log so a genuine schema change stays visible
rather than being silently discarded, and a non-mapping entry no longer raises.

Keeping the known fields matters: discarding the record wholesale would throw
away real call counts and timings because of an unrelated stray key.

Mutation-checked: restoring ResourceMetrics(**cached) fails 6 checks, dropping
the whole record fails the field-preservation check, and dropping unknown
fields silently fails the logging check. 28 tests pass across the resource
monitor and plugin health suites.

* 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)
(cherry picked from commit 0f77bd2345)

* 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)
(cherry picked from commit 8d1e43c15a)

* fix(logging): give the journal the real severity of each line

Everything this process writes to stdout reaches the journal as PRIORITY=6,
whatever the Python level was, because journald has nothing else to go on.
Measured on a live rig over 24 hours:

    lines containing " - ERROR - "      55
    lines containing " - WARNING - "    13
    journald PRIORITY recorded          6, for every one of them

So `journalctl -p err -u ledmatrix` returns nothing while errors are being
logged, and `-p warning` likewise. Triage falls back to grepping message text,
which is slower and unreliable: during this audit a search for "oom" matched
the radar logging "zoom=9" twenty-four times and briefly looked like the OOM
killer had been firing.

systemd reads a leading "<N>" on each stdout line and takes it as the priority
(sd-daemon(3)), so a formatter that prefixes one costs no dependency. Every
line of a multi-line record is tagged, not just the first -- the journal splits
them, and an untagged continuation reverts to the default, which would leave
the body of a traceback filed as informational while its first line was an
error.

Applied only when JOURNAL_STREAM is set, which systemd sets for services whose
output it captures. Run from a terminal, in the emulator or under pytest the
prefixes would be literal noise, and the file handler keeps the plain
formatter for the same reason.

Mutation-checked three ways: prefixing unconditionally fails the
outside-systemd test, prefixing only the first line fails the multi-line test,
and mapping ERROR to 6 fails the level mapping. 39 tests pass across the
logging suites.

(cherry picked from commit 780fca6365)

* fix(logging): let callers see through the journald formatter wrapper

CI caught what local testing could not: two existing tests in
test_logging_config.py assert that setup_logging() selected a
StructuredFormatter or a ContextualFormatter, by checking the console
handler's formatter directly. Wrapping that formatter to tag each line with
its syslog priority makes those assertions false.

They passed locally and failed on the runner because the wrapper is applied
only when JOURNAL_STREAM is set -- absent in a terminal, present in CI. An
environment-dependent break, which is the kind that gets shipped.

The wrapper now exposes the formatter it delegates to, and those two tests
look through it. They are about which formatter format_type selects, and that
behaviour is unchanged; only the object they have to reach for moved.

Verified both ways this time: 39 tests pass with JOURNAL_STREAM set and with
it unset.

* perf(plugins): stop rewriting a plugin's metrics file on every call

Plugin metrics were persisted to the cache inside monitor_call, so every
call by every plugin rewrote a small JSON file. Measured on a running rig:
one plugin's plugin_metrics file changed nine times a minute, with fourteen
such files active. Each is around 350 bytes, which on ext4 costs a 4KB block
plus a journal entry, so the cost is dominated by the write itself rather
than the payload. Cache writes accounted for essentially all of that device's
2.4 MB/min of SD traffic, on a card that wears out and has already failed
twice on the other rig.

Metrics cannot be de-duplicated the way health state can, because call_count
changes on every call and the timings usually do too. So they are rate-limited
instead: at most one write per plugin per 30 seconds.

The in-memory copy stays authoritative and exact -- a plugin's call_count is
still precise the instant after it runs. Only the cross-process snapshot the
web UI reads is delayed, and telemetry up to half a minute old is still a fair
description of a long-running plugin.

reset_metrics clears the throttle timestamp, so a reset is not left showing a
deleted key for the rest of the interval.

Extrapolating the sampled rate, this takes metric writes from roughly 126 a
minute to 28. Health persistence, the other half of the churn, is handled
separately in #475.

Verified by reverting the throttle: the churn test then reports 50 writes for
50 calls. 88 tests pass across resource monitor, plugin system and web API.

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

* fix: use a monotonic clock and only mark metrics persisted once written

Two review findings on the throttle, both right.

The interval compared wall-clock timestamps. These devices have no RTC, so
the clock jumps by however far off boot-time was the moment NTP first syncs
-- a forward jump would allow an early write, a backward one would stall the
snapshot well past the interval. time.monotonic() is not subject to either.

The timestamp was also recorded before cache_manager.set(). A set() that
raised would buy the next interval's silence without leaving a snapshot
behind, which is the one case where skipping the write is least affordable.
Recorded after the write lands instead, so a failure is retried on the next
call.

Verified by restoring the original ordering: the new test then reports one
write where two are expected.

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

* Address all six review findings on the perf consolidation

CodeRabbit reported six; this is all six, checked against its own
"Actionable comments posted: 6" rather than against what I happened to
scroll past.

Three are real defects in the code:

1. _under_systemd() trusted the presence of JOURNAL_STREAM.

systemd publishes JOURNAL_STREAM as "dev:ino", and every child process
inherits it -- including one whose stdout has been redirected to a pipe
or a file. The variable outlives the descriptor it describes, so a
subprocess would decide it was talking to the journal and emit the "<N>"
priority prefixes as literal noise into that captured output. That is
exactly the noise the function exists to prevent. It now parses the pair
and fstats stdout, per systemd's own guidance, and returns False for
missing, malformed, mismatched, or unusable descriptors.

2. Cached metrics were not type-checked.

A dataclass does not enforce its annotations, so
ResourceMetrics(call_count="not a number") builds happily and only
fails later, deep inside monitor_call:

    TypeError: can only concatenate str (not "int") to str

Values are now coerced to their declared type at load, where there is
still a cache key to name in the warning, and a value that cannot be
coerced starts the plugin fresh instead of arming a delayed failure.
A numeric string is accepted rather than discarded -- a JSON round-trip
can widen an int, and that is recoverable.

3. The first metrics snapshot was skipped for the first 30s of uptime.

_persist_metrics used 0.0 as the "never written" default. monotonic() is
time since boot on Linux and systemd starts this service at boot, so
`now - 0.0 < 30` was true for the first half-minute of every run: the
throttle swallowed the very first write, the one that matters most after
a restart. The sentinel is now None and the interval is only applied when
a previous write exists.

Three are tests that could pass without testing anything:

4. test_health_write_churn's fake cache stored by reference, so the
   tracker kept mutating the object already in the store -- a record
   could look persisted when no write had happened, which is precisely
   what test_durable_state_survives_a_restart exists to detect. Both
   directions now deep-copy, like a cache that serialises to a file.
   Verified: disabling the one real cache write now fails three tests.

5. test_values_of_the_wrong_type_do_not_raise asserted only that a
   dataclass had been constructed, which was true with the bad value
   still in it. It now asserts the loaded metrics are usable -- the
   field is numeric, and arithmetic on it does not raise -- across four
   kinds of bad value.

6. test_vegas_log_volume counted "logger.error(" in the source text,
   which also matches comments, docstrings and string literals --
   including that module's own docstring, which names those levels. A
   real error call could be demoted with the tally unmoved. It now walks
   the AST, reusing the helper already in the file. Verified: demoting
   all 18 warning/error/exception calls now fails the test.

Verified: every fix mutation-checked by reverting it and confirming the
matching test fails.

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-21 15:50:55 -04:00
ChuckandClaude Opus 5 9c0c0dc851 consolidate(web): credential exposure, secret loss, and the update path (#485)
* fix(web): stop /config/main handing out every credential it holds

The endpoint returned the raw config to anyone who could reach the port, and
this web interface has no authentication of any kind. An unauthenticated
request against a live rig returned:

    github.api_token                40 chars
    incoming-packages.ha_token     183 chars
    jellyfin-now-playing.api_key    32 chars
    ledmatrix-weather.api_key       32 chars
    on-air.mqtt_password             8 chars
    youtube.api_key                 20 chars
    youtube-stats.api_key           39 chars

A GitHub token and a Home Assistant long-lived token among them. Anything on
that LAN could read them.

The x-secret masking the plugin config endpoints use does not reach here: this
route never consults a schema, and core keys such as github.api_token have no
schema to carry the marker. Several of the fields above *are* tagged x-secret
in their plugin's schema and were still returned in full, which is what rules
out the schema route as the fix for this endpoint.

Credential-named fields are now blanked. Matching on the name is blunt, and
for a whole-config dump that is the right default: anything named like a
credential should not leave the process, and a new plugin adding a
differently-shaped secret is covered without anyone remembering to tag it.

Blanked rather than removed, and safe to blank: POST /config/main merges into
the freshly loaded config and writes only the keys it was given, so a client
that round-trips this response cannot erase a secret it never saw. The web API
suites confirm it -- 81 passing, unchanged.

On the test that matters: the first version of this suite exercised the two
helpers and nothing else, and reverting the single line that wires the
redactor into the route passed all thirty of them. A property asserted on a
helper is not a property asserted on the endpoint, and it is the endpoint that
is exposed to the network. The added test goes through the view function, and
it does fail on that revert.

This also corrects an earlier claim of mine. I reported that GET /api/v3/config
did not expose these values; that path 404s, so the check proved nothing. The
real route is /config/main and it exposed all of them.

* fix(web): stop an unrelated config edit from erasing a plugin's secret

Saving any field on a plugin's config form destroyed that plugin's stored
credential. On a rig with a weather API key, changing the city silently
emptied the key, and the plugin stopped working at the next fetch with no
indication why.

The path had no guard at any step. The config partial masks secrets before
rendering (pages_v3.py:740), so the browser posts them back blank; _parse_value
deliberately preserves "" for optional string fields; separate_secrets routes
that "" into secrets_config, which is a truthy dict; deep_merge writes it over
the stored value; save_raw_file_content persists it.

The blank does not even need the round-trip. merge_with_defaults injects the
schema's api_key default ("") into every save, so a client that never sends
the field at all still erases it. test_secret_count_message_counts_top_level_keys
was counting exactly that injected blank as a saved secret field -- the visible
edge of the bug, pinned as expected behaviour.

remove_empty_secrets() already existed for this, with seven unit tests and a
docstring describing this precise scenario ("clients will send those empty
strings back ... so that existing stored secrets are not overwritten with
blanks"). It was never wired into a call site. This wires it into both save
paths that merge into the secrets file.

A blank now means "unchanged" rather than "delete", which is the same contract
the helper's tests already describe. The cost is that a secret can no longer be
cleared by emptying the field; clearing needs its own affordance, since a
control that erases credentials as a side effect of ordinary edits is not one.

Verified by reverting the guard: the new round-trip test then fails with the
stored key read back as ''. 262 web tests pass with it.

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

* fix(web): stop dumping the config and request headers to the journal

save_main_config logged its entire POST body and the full request headers at
ERROR on every save. The body is the configuration itself, and the headers
carry the session cookie, so a routine settings change wrote both to the
journal -- at a level that guarantees they survive any sane log filter.

The lines are leftover debug output: they say "DEBUG:" in the message while
calling logging.error, and they went through the root logger rather than the
module logger, bypassing the level configured for this blueprint.

Replaced with a debug-level line recording the shape of the request, which is
the part with diagnostic value. The local `import logging` went with them; it
shadowed a module-level import that was already there.

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

* fix(web): stop /config/secrets handing out every credential it holds

GET /api/v3/config/secrets returned config_secrets.json in full to anyone who
could reach the port, and this interface has no authentication. Probed against
a real rig it produced six populated credential fields: a 40-character GitHub
token, a 183-character Home Assistant token, and Jellyfin and weather API keys.
This is the second door onto the same credentials; #477 closes the first.

Masking the response alone would have been worse than the leak. The only
client fetches every secret, edits one field and posts all of them back, and
save_raw_file_content replaces the file wholesale -- so a masked GET followed
by the client's own save would write the mask over every credential the user
had not touched. That is why this was left open when the leak was found; it
needs both halves.

Read side: mask_all_secret_values(), which already existed for exactly this
endpoint -- its docstring names it -- and had never been wired to a call site.
It leaves empty values and YOUR_* placeholders alone, so a client can still
tell "set" from "not set" without being told the secret.

Write side: strip the echoed mask and blanks from the submission, then merge
onto what is stored, so "unchanged" means unchanged. The cost is that a secret
can no longer be cleared by blanking it; that wants its own affordance, since
a control that erases credentials as a side effect of saving an unrelated one
is not one.

Browser side: the token field is now left empty rather than filled from the
response. Filling it with the mask would have stored eight bullet characters
as the token the next time the user pressed Save, and filling it with the real
value is the thing being fixed. It reports whether a token is saved instead.

Verified end to end through the Flask endpoints, not the helpers. Reverting
the masking fails the leak tests; reverting the merge fails the preservation
tests; both halves are independently guarded. 278 web tests pass.

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

* fix(web): stop reporting "no update" when the update check could not run

check-update returned update_available=False whenever git failed. The banner
is the only route to the update button, so a checkout git refuses to touch
looked exactly like a current one -- permanently, with nothing on screen to
act on and only a log line recording why.

The common cause is an install performed as root. scripts/install/one-shot-install.sh
clones into ${HOME}/LEDMatrix, never consults SUDO_USER, and contains no chown
at all, while its own error text suggests running the whole thing under sudo.
The result is a root-owned checkout, and on a rig this is what every git
command in it does:

    fatal: detected dubious ownership in repository at '...'

including the fetch this endpoint runs. Verified on real hardware rather than
assumed.

A failed check now reports check_failed with a message the user can act on --
for dubious ownership, the chown that fixes it. The banner shows that message
instead of hiding itself, with the update button suppressed since updating
cannot work until the cause is fixed. The success path is untouched.

This does not fix the installer, which is the real cause; it stops the symptom
being invisible. The installer needs SUDO_USER handling and a chown, and its
suggestion to run as root should go.

Reverting the endpoint change fails four of the five new tests; the fifth
guards the success path and correctly does not move.

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

* fix(web): stop the installer chmod stripping exec bits on every update

git tracks five scripts as mode 644 that first_time_install.sh then chmods to
755 (start_display.sh, stop_display.sh, the two install_*_service.sh, and
one-shot-install.sh does the same to first_time_install.sh). With
core.fileMode true, the default on Linux, git reports all five as modified
from then on, in files the user never touched.

The update button stashes local changes before pulling, so it is not blocked
by this. But it never pops that stash -- stash pop and stash apply appear
nowhere in the update flow -- so the mode change is stashed away and left
there, and the files revert:

    === file modes after the update button's stash ===
      664  first_time_install.sh      <- installer had made these 755
      664  start_display.sh
      664  stop_display.sh
      664  scripts/install/install_service.sh

So every web-UI update silently strips the executable bit from the installer's
own scripts, and leaves a stash entry holding the difference. start_display.sh
and stop_display.sh stop working from the shell afterwards.

A manual `git pull --rebase` over SSH fails outright, since nothing stashes for
it: "cannot pull with rebase: You have unstaged changes". That is the likely
source of the reports, since plenty of people update that way.

Tracking the five as 755 -- what they should always have been, as the
installer chmodding them attests -- removes the spurious mode change
entirely: nothing to stash, nothing stripped, no stash entry, and manual
pulls work.

The pull also passes --autostash, for the case the code explicitly tolerates:
when the stash fails it logs a warning and pulls anyway, and that pull is what
then fails. Autostash also pops what it stashes, which the manual stash does
not.

Note that `git add -A` after `git update-index --chmod=+x` silently reverts
the index to the on-disk mode, so the modes here were set by chmodding the
files themselves.

Regression test asserts the five stay tracked executable; reverting any one
of them fails it.

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

* fix(web): ask for the restart that makes an update take effect

The update button pulls new code and restarts nothing. There is no systemctl,
restart, reload or reboot anywhere in the 172-line git_pull handler -- it
stashes, pulls, installs changed requirements, re-removes plugins the user had
uninstalled, and returns "Code updated successfully."

Meanwhile both services go on running the code they loaded at boot. So the
display keeps rendering the old build, the web interface keeps serving the old
build, and the user is told the update worked. Nothing on screen suggests
otherwise, and the next reboot is what actually applies it -- whenever that is.

The affordance for this already exists: the restart-pending banner, raised
after main-config saves, with a Restart Now button wired to the display
service. A code update is a stronger reason to show it than a config save is.

The response now reports restart_required, and applyUpdate raises the banner
with wording for a code update rather than a config save. The banner's message
became a parameter and is persisted next to the flag, since it outlives the
page that raised it.

restart_required is only true when the pull actually moved HEAD. "Already up
to date" is a success too, and prompting after a no-op would train users to
dismiss the prompt unread.

This covers the display service, which is what the Restart Now button drives
and what users notice. The web interface still picks up its own new code on
its next restart; restarting it from inside a request it is serving is a
larger change than this one.

Reverting the flag fails the test that a pull which moved HEAD asks for a
restart. 290 tests pass.

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

* Mask list-shaped secrets element-wise, close two vacuous tests

mask_all_secret_values treated any non-empty list as a scalar, so a
secrets file holding

  "accounts": [{"name": "a", "token": "tok-a"}, {...}]

came back as a single "••••••••". The caller could not see how many
entries existed, and the raw editor was handed a string where the file
holds an array. Recurse into lists in both _mask_value and _contains_mask.

Lists merge by replacement, not key-wise, so strip_masked_values now
drops a list outright if any element still carries the mask -- storing a
half-masked list would discard the untouched entries.

Two tests could pass without exercising what they claim to check:

- test_git_pull_resolution asserted modes only for paths git ls-files
  returned. A renamed or deleted installer target is simply absent from
  that output, so its mode was never checked. Assert every CHMODDED path
  is tracked first.
- test_config_secrets_masking never checked the POST status. A 500
  leaves the old file in place, which satisfies every assertion that
  follows. Assert 200 before reading the file back.

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-21 14:30:29 -04:00
ChuckandClaude Opus 5 71739d85d1 harden: cap malloc arenas, warn on unit drift, and grant the portal's sudo commands (#476)
* perf(systemd): cap glibc malloc arenas on the display service

Measured on a live rig 2.5 hours after start:

    RSS                          1030 MB
    Private_Dirty                 988 MB
    anonymous mappings > 10 MB       23
    largest        104, 79, 66, 63, 63 MB, on 64 MB-aligned addresses
    threads                           9
    cores                             3   -> glibc ceiling = 8 x 3 = 24 arenas

23 against a ceiling of 24, all 64 MB-aligned: these are glibc's per-thread
malloc arenas, not live objects. The data the process was actually holding
accounts for perhaps 15 MB -- the widest scroll strip observed was 35,746 x 64,
about 7 MB as RGB and the same again for its numpy mirror.

It is bloat rather than a leak: sampled four times over 135 seconds, RSS sat
between 990 and 1030 MB rather than climbing. glibc gives each allocating
thread its own arena, grows them to hold peak demand, and never gives them
back. A process that builds and drops large images across several threads is
exactly the shape that produces this.

The device had 59 MB free at the time, on 1845 MB total.

MALLOC_ARENA_MAX=2 trades a little allocator concurrency for that resident
memory. It is a tuning knob rather than a fix for a defect, so the rationale
and the measurements sit next to it in the unit file, and a test asserts they
stay there -- a bare environment variable invites removal by whoever meets it
next.

Two things this is NOT, both checked rather than assumed:

- Not an OOM problem today. A grep for "oom" in the service journal returned
  24 matches, all of which were the radar logging zoom=9 and zoom=7. The kernel
  OOM killer has not fired: dmesg has zero matches.
- Not currently capped by the unit's MemoryMax=85% either. That directive is in
  this file but absent from the unit actually installed on the rig, which
  reports MemoryMax=infinity, so nothing is enforcing a ceiling there.

The saving is unmeasured on hardware: applying it needs a service restart,
which blanks the panel, so that is the user's call rather than something to do
mid-audit. If p99 frame time regresses -- it sits at 18.4 ms against a 16.7 ms
budget for 60 FPS, so there is not much headroom -- raise the value rather than
remove it.

(cherry picked from commit 446207ffbc)

* test(systemd): pin the arena value instead of accepting a range

Review follow-up. The range check accepted 1, 3 and 4, so a change to 4 --
which hands most of the resident saving back -- passed a test whose whole
purpose is to notice that.

Pinned to the value the unit ships, in one named constant. Raising it is still
a legitimate response to a frame-time regression, but it should be a visible
edit here rather than silent drift, and the failure message says so.

Mutation-checked: changing the unit to 4 now fails.
(cherry picked from commit 73fff8d2d5)

* fix(startup): warn when an installed systemd unit has drifted from the repo's

Nothing re-applies systemd units after the first install. `git pull` -- which
is what the web UI's update button runs -- brings a new template into the
checkout, but no code in web_interface/ or src/ copies it to
/etc/systemd/system, and nothing anywhere runs `systemctl daemon-reload`. The
unit that actually runs is whatever first_time_install.sh wrote on day one.

So every hardening added to a unit is inert on existing installs, silently.
Measured on a live rig:

    installed  /etc/systemd/system/ledmatrix.service   2026-08-06
    template   systemd/ledmatrix.service               2026-08-19
    contents                                           differ

with the practical result that the MemoryMax=85% the repo's template specifies
was not being enforced at all -- `systemctl show` reported
MemoryMax=infinity. Anyone reading the template would reasonably believe the
service was capped.

Startup now compares each installed unit against its substituted template and
warns when they differ, naming install_service.sh as the remedy.

A warning, not an error, and deliberately not a silent rewrite: editing files
under /etc and restarting services is the installer's job, not something a
display process should do to a machine while it is booting. Making it fatal
would also brick every development checkout whose unit is legitimately absent
or hand-edited.

Comparison ignores comments, blank lines and ordering. The template carries
explanatory comments the installed copy will not have, and systemd does not
care about order within a section, so a literal comparison would warn on every
boot and be ignored within a week.

Mutation-checked three ways: never reporting drift fails, making it fatal
fails, and -- after the first attempt missed it -- comparing raw text now fails
too. That last gap is worth noting: the comment-insensitivity tests originally
exercised the helper directly, so a comparison that stopped calling the helper
passed them all. The test that catches it goes through _validate_systemd_units.

29 startup-validator tests pass.

(cherry picked from commit cf521bdfd8)

* fix(install): grant the sudo commands the captive portal actually runs

The installers write two allow-lists, /etc/sudoers.d/ledmatrix_web and
ledmatrix_wifi. Anything the code runs under sudo that is not in one of them
needs a password, which a service cannot supply, so the call fails.

Five commands were being run and none of them granted:

    sysctl -w net.ipv4.ip_forward=0|1     wifi_manager.py:788, 883
    nft add|delete table ip ledmatrix     wifi_manager.py:835, 895
    rfkill unblock wifi                   wifi_manager.py:1811
    iptables ...                          wifi_manager.py:796, 813, 818, 871
    mkdir -p .../dnsmasq-shared.d         wifi_manager.py:922

Together these are the captive portal: unblock the radio, bring up the AP,
add the redirect, turn on forwarding, and undo all of it afterwards. Without
the grants a hardened install would associate clients to the access point and
then fail to route them.

Why it has gone unnoticed: a stock Raspberry Pi image ships
/etc/sudoers.d/010_pi-nopasswd granting the default user

    <user> ALL=(ALL) NOPASSWD: ALL

which satisfies every one of these regardless of what the allow-lists say.
Confirmed on a live rig -- `sudo -n -l` permits sysctl there, and the blanket
rule is why. The allow-lists are effectively decorative on a default image and
only start mattering once that rule is removed or the service runs as another
user.

test_sudo_allowlist_covers_calls.py extracts every argv-style sudo call in
src/ and web_interface/ and asserts an installer grants it, so the next command
added without a rule fails here rather than on someone's hardened box.

Getting that test honest took three passes, each worth recording:

- Matching the literal "systemctl" against rules written as
  `$SYSTEMCTL_PATH enable ...` reported six gaps that did not exist. Binary
  path variables are now normalised before comparing.
- Scanning the whole installer let `NFT_PATH=$(command -v nft)` -- a variable
  definition, not a grant -- satisfy the check on its own, so deleting the
  actual nft rules still passed. Only NOPASSWD lines are considered now.
- `sudo -n <tool>` reported "-n" as the binary. sudo's own flags are skipped.

Each of the five grants is individually mutation-checked: removing any one
fails the suite.

(cherry picked from commit a372b43cd1)

* fix(install): drop the iptables wildcard, and pin each grant properly

Review follow-up. Two findings, both right, and the first is a hole I opened
myself.

`NOPASSWD: iptables *` is a root shell for the web user by another name.
`iptables --modprobe=/path/to/anything` runs that path as root, so a wildcard
grant on iptables escalates rather than restricts. I added that rule while
fixing a permissions gap, which is a worse outcome than the gap. It is gone,
and a test now fails on any trailing-wildcard grant to a tool that can execute
another program -- iptables, nft, tcpdump, find, awk, sed, perl, python, env.

The other finding: checking only the binary made the coverage test far weaker
than it looked. With `sysctl` present anywhere in the allow-list, deleting the
`net.ipv4.ip_forward=0` grant still passed -- and the portal would then be
unable to restore forwarding on teardown. Each required command is now matched
in full, and each is mutation-checked individually, including that exact
single-line case.

Scope pulled in deliberately. The first version of this test tried to assert
that *every* sudo call in the codebase is granted. Run honestly, it showed the
portal also runs iptables, nft, `ip addr`, `ip link` and `cp` with arguments
built at runtime -- an interface name, a port. Those cannot be granted safely
in a sudoers file: the rule needs a trailing wildcard, and that is the
escalation above. Closing that half needs a privileged helper that builds the
rules itself and takes only an interface and a port, granted the way
safe_plugin_rm.sh already is. That is a design decision, not a one-line grant,
so the test now pins the four commands this change actually grants and the
docstring says plainly what it does not cover.

Better a narrow test that is true than a broad one that is not.

(cherry picked from commit 500cfbc9f4)

* fix(install): pin PATH, keep unit order, and tighten the sudoers assertions

Three review findings, all correct.

The installer resolved binaries through an inherited PATH and wrote whatever
it found into sudoers as NOPASSWD grants. first_time_install.sh re-execs
itself with `sudo -E`, which preserves the caller's environment, so a writable
directory early in PATH turned a compromise of the low-privilege web user into
permanent root -- via a file the installer itself wrote. PATH is now pinned to
the system directories before anything is resolved, and every resolved binary
must be root-owned and unwritable by anyone else before it reaches the
sudoers file.

_unit_body() sorted a unit's lines before comparing. Order is not noise in a
systemd unit: repeated ExecStartPre=/ExecStartPost= run in the order they
appear, and a directive that moves between [Unit], [Service] and [Install]
means something different where it lands. The drift check reported no drift
for units that had genuinely changed. Order is preserved now.

Two of that check's own tests asserted the wrong thing --
test_reordered_directives_are_not_drift said so in its name -- and are
inverted, with a second covering a directive moved between sections. The
cosmetic-difference test now varies comments, blank lines and indentation,
which is what the installer actually drops, rather than reversing the file.

The sudoers assertions matched command prefixes, so
`sysctl -w net.ipv4.ip_forward=0 *` satisfied the requirement while granting
the caller arbitrary trailing arguments as root. They are exact now. The
wildcard check also normalises ${NFT_PATH} the same way as $NFT_PATH; the
brace is not a word boundary, so that spelling was skipped entirely.

Verified by reintroducing each: a widened required grant fails the exact
match, `${NFT_PATH} *` fails the wildcard check, and require_trusted_binary
refuses a non-root-owned, world-writable, or missing binary.

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-21 14:29:45 -04:00
ChuckandClaude Opus 5 cc258aaffd fix(install): tag the secondary installer's journalctl grants too (#491)
Review was right on all three counts, and the first is the one that matters:
scripts/install/configure_web_sudo.sh writes the same three wildcard
journalctl rules as first_time_install.sh and none of them carried NOEXEC. So
this PR closed the pager escape on one installer path and left it open on the
other, which is close to no fix at all -- a rig configured through that script
still hands out a root shell via less's "!command".

The test could not have caught it, for two independent reasons. INSTALLERS
did not list the file. And even listed, _grant_lines() kept the raw source
line: that installer echoes its rules, so each one ends in a quote rather
than the wildcard, and the trailing-* check skipped every one of them. Either
alone would have hidden it.

Both fixed: the file is covered, and an echoed rule is unwrapped to the
sudoers line it actually emits.

The selector test now covers -t ledmatrix as well. It asserted only the two
-u forms, so deleting the -t rule would have passed.

Verified by removing NOEXEC again from the secondary installer: four of the
six tests fail, where before the suite passed with the vulnerability present.


Claude-Session: https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-08-21 14:28:23 -04:00
38 changed files with 2385 additions and 147 deletions
Binary file not shown.

After

Width:  |  Height:  |  Size: 467 B

Regular → Executable
View File
+8 -3
View File
@@ -100,10 +100,15 @@ TEMP_SUDOERS="/tmp/ledmatrix_web_sudoers_$$"
echo "$WEB_USER ALL=(ALL) NOPASSWD: $SYSTEMCTL_PATH restart ledmatrix-web.service"
# Optional: journalctl (non-critical — skip if not found)
#
# NOEXEC, matching first_time_install.sh. These rules end in a wildcard and
# journalctl starts a pager, so without it the caller can reach a shell:
# less runs "!command" as the user the pager belongs to, which here is
# root. NOEXEC stops the granted command executing anything of its own.
if [ -n "$JOURNALCTL_PATH" ]; then
echo "$WEB_USER ALL=(ALL) NOPASSWD: $JOURNALCTL_PATH -u ledmatrix.service *"
echo "$WEB_USER ALL=(ALL) NOPASSWD: $JOURNALCTL_PATH -u ledmatrix *"
echo "$WEB_USER ALL=(ALL) NOPASSWD: $JOURNALCTL_PATH -t ledmatrix *"
echo "$WEB_USER ALL=(ALL) NOPASSWD:NOEXEC: $JOURNALCTL_PATH -u ledmatrix.service *"
echo "$WEB_USER ALL=(ALL) NOPASSWD:NOEXEC: $JOURNALCTL_PATH -u ledmatrix *"
echo "$WEB_USER ALL=(ALL) NOPASSWD:NOEXEC: $JOURNALCTL_PATH -t ledmatrix *"
fi
# Required: python3, bash
+79 -2
View File
@@ -25,9 +25,44 @@ if [ "$EUID" -eq 0 ]; then
exit 1
fi
# Resolve command paths against a fixed PATH, and check what we resolved.
#
# Every path found here is written into a sudoers file as a NOPASSWD grant, so
# whoever controls the binary at that path controls root. first_time_install.sh
# re-execs itself with `sudo -E`, which preserves the invoking user's
# environment -- PATH included -- so without pinning it, `which nmcli` can
# resolve to anything on that PATH: a writable directory early in it turns a
# compromise of the low-privilege web user into permanent root.
PATH=/usr/sbin:/usr/bin:/sbin:/bin
export PATH
# A binary named in a sudoers rule must be root-owned and writable by nobody
# else, or the grant hands root to whoever can rewrite it.
require_trusted_binary() {
local label="$1" path="$2"
if [ ! -x "$path" ]; then
echo "$label: $path is not an executable file"
exit 1
fi
local owner perms
owner=$(stat -c '%u' "$path") || exit 1
perms=$(stat -c '%a' "$path") || exit 1
if [ "$owner" != "0" ]; then
echo "$label: $path is not owned by root (uid $owner); refusing to"
echo " grant it NOPASSWD sudo."
exit 1
fi
# Group- or world-writable means someone other than root can replace it.
case "$perms" in
*[2367]) echo "$label: $path is writable by group or other ($perms);"
echo " refusing to grant it NOPASSWD sudo."
exit 1 ;;
esac
}
# Get the full paths to commands
NMCLI_PATH=$(which nmcli || echo "/usr/bin/nmcli")
SYSTEMCTL_PATH=$(which systemctl)
NMCLI_PATH=$(command -v nmcli || echo "/usr/bin/nmcli")
SYSTEMCTL_PATH=$(command -v systemctl)
echo "Command paths:"
echo " nmcli: $NMCLI_PATH"
@@ -37,6 +72,18 @@ echo " systemctl: $SYSTEMCTL_PATH"
echo ""
echo "Step 1: Configuring sudo permissions for nmcli..."
SUDOERS_FILE="/etc/sudoers.d/ledmatrix_wifi"
SYSCTL_PATH=$(command -v sysctl || echo /usr/sbin/sysctl)
NFT_PATH=$(command -v nft || echo /usr/sbin/nft)
RFKILL_PATH=$(command -v rfkill || echo /usr/sbin/rfkill)
MKDIR_PATH=$(command -v mkdir || echo /usr/bin/mkdir)
# Checked before any of them reaches the sudoers file.
require_trusted_binary "nmcli" "$NMCLI_PATH"
require_trusted_binary "systemctl" "$SYSTEMCTL_PATH"
require_trusted_binary "sysctl" "$SYSCTL_PATH"
require_trusted_binary "nft" "$NFT_PATH"
require_trusted_binary "rfkill" "$RFKILL_PATH"
require_trusted_binary "mkdir" "$MKDIR_PATH"
# Create a temporary sudoers file using mktemp (handles permissions better)
TEMP_SUDOERS=$(mktemp) || {
@@ -62,6 +109,36 @@ $WEB_USER ALL=(ALL) NOPASSWD: $SYSTEMCTL_PATH start dnsmasq
$WEB_USER ALL=(ALL) NOPASSWD: $SYSTEMCTL_PATH stop dnsmasq
$WEB_USER ALL=(ALL) NOPASSWD: $SYSTEMCTL_PATH restart dnsmasq
$WEB_USER ALL=(ALL) NOPASSWD: $SYSTEMCTL_PATH restart NetworkManager
# The captive portal turns IP forwarding on while the access point is up and
# restores the previous value when it comes down (wifi_manager._setup_iptables_
# redirect / _teardown_iptables_redirect). Without this rule that sudo call
# needs a password, so forwarding stays off and clients associate to the AP but
# cannot route. It goes unnoticed on a stock Raspberry Pi image, where
# /etc/sudoers.d/010_pi-nopasswd grants the default user blanket NOPASSWD and
# masks every gap in this file -- it only bites once that blanket rule is
# removed.
$WEB_USER ALL=(ALL) NOPASSWD: $SYSCTL_PATH -w net.ipv4.ip_forward=0
$WEB_USER ALL=(ALL) NOPASSWD: $SYSCTL_PATH -w net.ipv4.ip_forward=1
# The portal's redirect lives in its own nftables table, created when the AP
# comes up and deleted when it goes down, and the radio has to be unblocked
# before the AP can start at all. Same story as the sysctl rules above: called
# with sudo, never granted here, and invisible on a stock Pi image.
$WEB_USER ALL=(ALL) NOPASSWD: $NFT_PATH add table ip ledmatrix
$WEB_USER ALL=(ALL) NOPASSWD: $NFT_PATH delete table ip ledmatrix
$WEB_USER ALL=(ALL) NOPASSWD: $RFKILL_PATH unblock wifi
# NetworkManager's dnsmasq drop-in directory, exact path.
$WEB_USER ALL=(ALL) NOPASSWD: $MKDIR_PATH -p /etc/NetworkManager/dnsmasq-shared.d
#
# iptables is deliberately NOT granted here. Its rules are built from the live
# interface name and port, so a rule covering them needs a trailing wildcard --
# and `iptables --modprobe=/path/to/anything` runs that path as root, so
# `NOPASSWD: iptables *` is a root shell for the web user by another name. That
# is a worse outcome than the gap it would close, which today is masked anyway
# by the blanket NOPASSWD rule on stock Pi images.
#
# Closing it safely means a wrapper script that builds the rules itself and
# takes only an interface and a port, granted the way safe_plugin_rm.sh already
# is. That belongs in its own change rather than being smuggled into this one.
# Allow copying hostapd and dnsmasq config files into place
$WEB_USER ALL=(ALL) NOPASSWD: /usr/bin/cp /tmp/hostapd.conf /etc/hostapd/hostapd.conf
View File
View File
+5 -1
View File
@@ -328,7 +328,11 @@ class ScrollHelper:
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
required_total_distance = self.total_scroll_width
self.logger.info(
# Progress telemetry, emitted every few seconds for the whole of
# every scroll. It says how far along a marquee is, which is what
# you turn debug on to watch and not something an operator needs
# in the journal on a device that scrolls all day.
self.logger.debug(
"Scroll progress: elapsed=%.2fs, target=%.2fs, total_scrolled=%.0f/%d px (%.1f%%)",
elapsed_time,
self.calculated_duration,
+84 -1
View File
@@ -130,7 +130,12 @@ def setup_logging(
# Console handler (always add)
console_handler = logging.StreamHandler(sys.stdout)
console_handler.setLevel(level)
console_handler.setFormatter(formatter)
# Under systemd, tag each line so the journal records the real severity
# rather than filing everything as informational. The file handler below
# keeps the plain formatter: the prefix is meaningful to journald and noise
# anywhere else.
console_handler.setFormatter(
JournalPriorityFormatter(formatter) if _under_systemd() else formatter)
root_logger.addHandler(console_handler)
# File handler (if specified)
@@ -145,6 +150,84 @@ def setup_logging(
sys.stderr.write(f"Warning: Could not set up file logging to {log_file}: {e}\n")
#: syslog priorities, which is what systemd parses from a "<N>" prefix on
#: stdout. Mapped from Python's levels.
_SYSLOG_PRIORITY = {
logging.CRITICAL: 2, # LOG_CRIT
logging.ERROR: 3, # LOG_ERR
logging.WARNING: 4, # LOG_WARNING
logging.INFO: 6, # LOG_INFO
logging.DEBUG: 7, # LOG_DEBUG
}
class JournalPriorityFormatter(logging.Formatter):
"""Wraps a formatter, prefixing each line with its syslog priority.
Under systemd everything this process writes to stdout lands in the journal
as PRIORITY=6, whatever the Python level was. Measured on a live rig: 55
ERROR lines and 13 WARNING lines in a day, every one of them recorded as
informational, so `journalctl -p err -u ledmatrix` returned nothing at all
while errors were being logged. Anyone triaging has to grep the message
text instead, which is both slower and wrong -- a search for "oom" matches
the radar logging "zoom=9".
systemd reads a leading "<N>" on each line and uses it as the priority
(sd-daemon(3)), so this needs no extra dependency. Multi-line records get
the prefix on every line, since the journal splits them and an unprefixed
continuation would fall back to the default.
"""
def __init__(self, inner: logging.Formatter):
super().__init__()
self._inner = inner
@property
def inner(self) -> logging.Formatter:
"""The formatter doing the actual work.
Whether journald tagging is applied depends on JOURNAL_STREAM, so it is
on under systemd and off in a terminal -- and anything asserting which
formatter setup_logging() selected would otherwise get a different
answer in CI than on a developer's machine. Exposing the inner one lets
those checks stay about format_type, which is what they mean.
"""
return self._inner
def format(self, record: logging.LogRecord) -> str:
text = self._inner.format(record)
prefix = f"<{_SYSLOG_PRIORITY.get(record.levelno, 6)}>"
return "\n".join(prefix + line for line in text.split("\n"))
def _under_systemd() -> bool:
"""True when stdout really is the journal.
systemd sets JOURNAL_STREAM to "dev:ino" for services whose output it
captures. Presence alone is not enough to act on: the variable is
inherited by child processes and survives redirection, so a subprocess
whose stdout is a pipe or a file still sees it and would emit the "<N>"
priority prefixes as literal noise into that output. systemd's own
guidance is to fstat the descriptor and compare st_dev/st_ino, which is
what distinguishes "the journal is somewhere in my ancestry" from "my
stdout is the journal".
"""
declared = os.environ.get("JOURNAL_STREAM")
if not declared:
return False
try:
dev_text, ino_text = declared.split(":", 1)
declared_ids = (int(dev_text), int(ino_text))
except (ValueError, AttributeError):
return False
try:
stat_result = os.fstat(sys.stdout.fileno())
except (OSError, ValueError, AttributeError):
# No usable stdout: captured by pytest, detached, or already closed.
return False
return (stat_result.st_dev, stat_result.st_ino) == declared_ids
class PluginLoggerAdapter(logging.LoggerAdapter):
"""LoggerAdapter that stamps every record with its plugin_id.
+22 -1
View File
@@ -178,10 +178,20 @@ class PluginHealthTracker:
)
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:
"""Record a successful plugin execution."""
state = self.get_health_state(plugin_id)
current_time = time.time()
durable_before = self._durable(state)
# Reset consecutive failures
state['consecutive_failures'] = 0
@@ -199,7 +209,18 @@ class PluginHealthTracker:
state['circuit_state'] = CircuitState.CLOSED.value
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:
"""Record a failed plugin execution."""
+123 -14
View File
@@ -9,7 +9,7 @@ import time
import logging
import threading
from typing import Dict, Optional, Any, Callable
from dataclasses import dataclass, field
from dataclasses import dataclass, field, fields
try:
import psutil
@@ -49,6 +49,20 @@ class ResourceMetrics:
self.total_execution_time = self.total_execution_time / self.call_count
#: How often a plugin's metrics are written to the cache, in seconds.
#:
#: Persisting on every call meant a small file rewritten roughly nine times a
#: minute per plugin. On a rig with fourteen active plugins that was ~126
#: writes a minute for metrics alone, and since each ~350-byte file costs a
#: 4KB block plus an ext4 journal entry, it dominated the device's write
#: volume -- on an SD card, which wears out.
#:
#: The in-memory copy stays authoritative and exact; only the cross-process
#: snapshot the web UI reads is delayed, and telemetry up to half a minute old
#: is still a fair description of a long-running plugin.
_METRICS_PERSIST_INTERVAL = 30.0
class PluginResourceMonitor:
"""
Monitors resource usage for plugins.
@@ -75,6 +89,10 @@ class PluginResourceMonitor:
# Resource metrics per plugin
self._metrics: Dict[str, ResourceMetrics] = {}
self._limits: Dict[str, ResourceLimits] = {}
# When each plugin's metrics last reached the cache. Metrics change on
# every call, so they cannot be de-duplicated the way health state can;
# they are rate-limited instead. See _METRICS_PERSIST_INTERVAL.
self._metrics_persisted_at: Dict[str, float] = {}
# Thread-local storage for execution tracking
self._local = threading.local()
@@ -102,6 +120,66 @@ class PluginResourceMonitor:
"psutil not available - resource monitoring will be limited to execution time only"
)
def _metrics_from_cache(self, plugin_id: str, cached: Any) -> "ResourceMetrics":
"""Build metrics from a cached record, ignoring anything unrecognised.
ResourceMetrics(**cached) raises TypeError on a single unexpected key,
and that exception escapes into plugin_manager, which reports it as
"plugin <id> operation failed". Every plugin fails, and the plugin
system never finishes initialising.
Seen on a live rig: every plugin failing with
ResourceMetrics.__init__() got an unexpected keyword argument
'consecutive_failures'
which is a plugin_health field, not a metrics one. How a health-shaped
record came to sit under a plugin_metrics key on that machine is not
established -- a restored backup that mixed two machines' caches is the
likeliest explanation -- but the loader should not be brittle enough for
it to matter. plugin_health already repairs its records field by field
rather than trusting whatever is on disk; this does the same.
Unknown keys are dropped and named once, so a genuine schema change is
visible in the log instead of silently discarded.
"""
if not isinstance(cached, dict):
self.logger.warning(
"Ignoring cached metrics for %s: expected a mapping, got %s",
plugin_id, type(cached).__name__)
return ResourceMetrics()
known = {f.name for f in fields(ResourceMetrics)}
unknown = sorted(set(cached) - known)
if unknown:
self.logger.warning(
"Dropping unrecognised field(s) from cached metrics for %s: %s",
plugin_id, ", ".join(unknown))
# A dataclass does not enforce its annotations, so
# ResourceMetrics(call_count="not a number") builds happily and only
# blows up later, deep inside monitor_call ("can only concatenate str
# (not \"int\") to str"). Coerce here, where there is still a cache
# key to name in the warning.
declared = {f.name: f.type for f in fields(ResourceMetrics)}
usable = {}
for key, value in cached.items():
if key not in known:
continue
try:
usable[key] = int(value) if declared[key] in ('int', int) else float(value)
except (TypeError, ValueError):
self.logger.warning(
"Cached metrics for %s have a bad %s (%r); starting fresh",
plugin_id, key, value)
return ResourceMetrics()
try:
return ResourceMetrics(**usable)
except (TypeError, ValueError) as e:
self.logger.warning(
"Cached metrics for %s unusable (%s); starting fresh",
plugin_id, e)
return ResourceMetrics()
def _get_metrics_key(self, plugin_id: str) -> str:
"""Get cache key for plugin metrics."""
return f"plugin_metrics:{plugin_id}"
@@ -126,7 +204,7 @@ class PluginResourceMonitor:
cache_key, max_age=None, memory_ttl=0 if force_reload else None
)
if cached:
metrics = ResourceMetrics(**cached)
metrics = self._metrics_from_cache(plugin_id, cached)
else:
metrics = ResourceMetrics()
self._metrics[plugin_id] = metrics
@@ -232,18 +310,8 @@ class PluginResourceMonitor:
# CPU is harder to measure per-call, so we track it separately
metrics.cpu_percent = self._get_process_cpu_percent()
# Persist metrics
cache_key = self._get_metrics_key(plugin_id)
self.cache_manager.set(cache_key, {
'memory_mb': metrics.memory_mb,
'cpu_percent': metrics.cpu_percent,
'execution_time': metrics.execution_time,
'call_count': metrics.call_count,
'total_execution_time': metrics.total_execution_time,
'max_execution_time': metrics.max_execution_time,
'min_execution_time': metrics.min_execution_time if metrics.min_execution_time != float('inf') else 0.0,
'last_update_time': metrics.last_update_time
})
# Persist metrics, at most once per interval per plugin.
self._persist_metrics(plugin_id, metrics)
# Check limits
if limits:
@@ -363,6 +431,44 @@ class PluginResourceMonitor:
summaries[plugin_id] = self.get_metrics_summary(plugin_id)
return summaries
def _persist_metrics(self, plugin_id: str, metrics: ResourceMetrics,
force: bool = False) -> None:
"""Write a plugin's metrics to the cache, at most once per interval.
Caller must hold ``self._lock``.
"""
# Monotonic, not wall clock: these devices have no RTC, so the clock
# jumps by however far off boot-time was the moment NTP first syncs.
# A forward jump would allow an early write, a backward one would
# stall the snapshot well past the interval.
#
# The sentinel for "never written" is None, not 0.0. monotonic() is
# time since boot on Linux, and systemd starts this service *at* boot,
# so `now - 0.0 < 30` was true for the first half-minute of every
# single run -- the throttle swallowed the very first snapshot, which
# is the one that matters most after a restart.
now = time.monotonic()
last_written = self._metrics_persisted_at.get(plugin_id)
if (not force and last_written is not None
and now - last_written < _METRICS_PERSIST_INTERVAL):
return
cache_key = self._get_metrics_key(plugin_id)
self.cache_manager.set(cache_key, {
'memory_mb': metrics.memory_mb,
'cpu_percent': metrics.cpu_percent,
'execution_time': metrics.execution_time,
'call_count': metrics.call_count,
'total_execution_time': metrics.total_execution_time,
'max_execution_time': metrics.max_execution_time,
'min_execution_time': (metrics.min_execution_time
if metrics.min_execution_time != float('inf')
else 0.0),
'last_update_time': metrics.last_update_time,
})
# Only after the write lands. Marking it first would mean a failed
# set() bought the next interval's silence without leaving a snapshot.
self._metrics_persisted_at[plugin_id] = now
def reset_metrics(self, plugin_id: str) -> None:
"""Reset metrics for a plugin."""
with self._lock:
@@ -370,4 +476,7 @@ class PluginResourceMonitor:
self._metrics[plugin_id] = ResourceMetrics()
cache_key = self._get_metrics_key(plugin_id)
self.cache_manager.delete(cache_key)
# Let the next call persist immediately rather than leaving the
# deleted key absent for the rest of the interval.
self._metrics_persisted_at.pop(plugin_id, None)
+77
View File
@@ -63,6 +63,9 @@ class StartupValidator:
if self.plugin_manager:
self._validate_plugins()
# Warn when the running systemd unit no longer matches the repo's
self._validate_systemd_units()
is_valid = len(self.errors) == 0
if is_valid:
@@ -74,6 +77,80 @@ class StartupValidator:
return (is_valid, self.errors.copy(), self.warnings.copy())
#: Units this project installs, and where each is installed to.
_UNITS = (
("systemd/ledmatrix.service", "/etc/systemd/system/ledmatrix.service"),
("systemd/ledmatrix-web.service", "/etc/systemd/system/ledmatrix-web.service"),
)
def _validate_systemd_units(self) -> None:
"""Warn when an installed unit has drifted from the repo's template.
Nothing re-applies these after the first install. `git pull` -- which is
what the web UI's update button runs -- brings a new template into the
checkout, but nothing copies it to /etc/systemd/system and nothing runs
`systemctl daemon-reload`, so the unit that actually runs is whatever
first_time_install.sh wrote on day one.
That makes every hardening added to a unit inert on existing installs.
Measured on one rig: the installed unit was thirteen days older than the
repo's and differed in content, so a MemoryMax the repo had specified
was not being enforced at all -- `systemctl show` reported
MemoryMax=infinity.
A warning rather than an error, and certainly not a silent rewrite:
editing files under /etc and restarting services is the installer's job,
not something a display process should do to a machine while it boots.
The remedy is to re-run scripts/install/install_service.sh.
"""
try:
project_root = Path(__file__).resolve().parent.parent
for template_rel, installed_path in self._UNITS:
template = project_root / template_rel
installed = Path(installed_path)
if not template.is_file() or not installed.is_file():
continue
# The template carries placeholders the installer substitutes,
# so compare the substituted form rather than the raw file.
expected = template.read_text(encoding="utf-8")
expected = expected.replace("__PROJECT_ROOT_DIR__", str(project_root))
expected = expected.replace("__USER__", "root")
try:
actual = installed.read_text(encoding="utf-8")
except PermissionError:
continue
if self._unit_body(expected) != self._unit_body(actual):
self.warnings.append(
f"{installed.name} differs from {template_rel}; the "
"installed unit is not refreshed by an update, so "
"settings added to the template are not in effect. "
"Re-run scripts/install/install_service.sh to apply them."
)
except OSError as e:
self.logger.debug("Could not compare systemd units: %s", e)
@staticmethod
def _unit_body(text: str) -> str:
"""A unit's meaningful lines, in order: no comments, no blanks.
Order is preserved deliberately. This used to sort, which made the
comparison insensitive to two changes that matter in a systemd unit:
repeated directives such as ExecStartPre= and ExecStartPost= run in
the order they appear, and a directive that moves between [Unit],
[Service] and [Install] means something different -- or nothing --
where it lands. A drift check that normalises those away reports no
drift for a unit that has genuinely changed.
"""
lines = []
for line in text.splitlines():
line = line.strip()
if line and not line.startswith("#"):
lines.append(line)
return "\n".join(lines)
def _validate_config(self) -> None:
"""Validate configuration files."""
try:
+75 -11
View File
@@ -31,6 +31,18 @@ if TYPE_CHECKING:
logger = logging.getLogger(__name__)
#: Degradation threshold, as a fraction of target_fps. A marquee jitters a
#: little all the time, so "anything under target" would report constantly and
#: mean nothing; 90% of target is the point where a shortfall is real. At a
#: 60fps target that is 54fps -- 55fps is a normal wobble and stays at DEBUG,
#: which is deliberate, not an off-by-one.
_FPS_HEALTHY_FRACTION = 0.9
#: A healthy marquee still reports this often, so silence means stopped
#: rather than fine.
_FPS_HEARTBEAT_INTERVAL = 300.0
def _percentile(ordered: List[float], fraction: float) -> float:
"""Nearest-rank percentile of an already-sorted list.
@@ -96,6 +108,11 @@ class VegasModeCoordinator:
self._is_active = False
self._is_paused = False
self._should_stop = False
# Frame-rate health, tracked across run_iteration() calls so the
# heartbeat is one-per-interval rather than one-per-cycle, and so a
# recovery spanning two cycles is still reported. Reset on start().
self._fps_last_health_log = 0.0
self._fps_was_degraded = False
self._state_lock = threading.Lock()
# Live priority tracking
@@ -248,6 +265,11 @@ class VegasModeCoordinator:
self._is_active = True
self._should_stop = False
self._start_time = time.time()
# A fresh run starts with a clean health slate: no stale
# "was degraded" from the previous run, and a heartbeat that is
# due immediately so the first sample confirms the marquee is up.
self._fps_last_health_log = 0.0
self._fps_was_degraded = False
# Line up the next group immediately, so the first extension is already
# warm rather than stalling the scroll to fetch it.
@@ -395,8 +417,18 @@ class VegasModeCoordinator:
duration = self.render_pipeline.get_dynamic_duration()
start_time = time.time()
frame_count = 0
fps_log_interval = 5.0 # Log FPS every 5 seconds
last_fps_log_time = start_time
fps_log_interval = 5.0 # Sample FPS every 5 seconds
# Health state lives on the coordinator, not here: run_iteration() is
# called once per cycle, so locals reset every few seconds. That made
# `last_fps_health_log = 0.0` fire the "heartbeat" on the first sample
# of every iteration rather than once per interval, and a recovery
# that crossed an iteration boundary was never reported at all --
# was_degraded had already gone back to False.
# Monotonic, and deliberately not start_time: start_time is wall
# clock and is used below to report the iteration's duration. Mixing
# the two here would make every delta hugely negative and silence the
# frame-rate reporting altogether.
last_fps_log_time = time.monotonic()
fps_frame_count = 0
# A mean hides stutter completely. At 120fps a five-second window is
# ~600 frames, so a 200ms freeze -- plainly visible on a marquee --
@@ -408,7 +440,13 @@ class VegasModeCoordinator:
logger.info("Starting Vegas iteration for %.1fs", duration)
while True:
frame_started = time.time()
# Monotonic, like the FPS window below. These devices have no RTC,
# so the wall clock jumps by however wrong boot time was the moment
# NTP first syncs. A backward jump makes frame_elapsed negative,
# and `frame_interval - frame_elapsed` then sleeps for longer than
# the whole budget -- the render loop stalls for the size of the
# correction. A forward jump inflates p99 and worst-frame instead.
frame_started = time.monotonic()
# Check for STATIC mode plugin that should pause scroll
static_plugin = self._check_static_plugin_trigger()
@@ -436,7 +474,7 @@ class VegasModeCoordinator:
# quarter of the budget spent not rendering. Subtracting the work
# already done keeps the pacing target while reclaiming that time,
# and yields the GIL either way so other threads still run.
frame_elapsed = time.time() - frame_started
frame_elapsed = time.monotonic() - frame_started
time.sleep(max(0.0, frame_interval - frame_elapsed))
# Measured before the sleep: time spent working, not pacing.
@@ -448,16 +486,42 @@ class VegasModeCoordinator:
frame_count += 1
fps_frame_count += 1
# Periodic FPS logging
current_time = time.time()
# Periodic FPS logging. Reported at INFO only when the frame rate
# is actually worth an operator's attention -- a shortfall against
# target, or the recovery from one -- with a slow heartbeat so a
# healthy marquee still shows a pulse.
#
# Measured over two hours on a running rig: 1410 samples, 98.5%
# of them within 10% of target. The 1.5% that were not included a
# reading of 8.6fps against a target of 60 -- a real stall, and
# completely invisible inside 1389 lines reading "59.6".
# Monotonic: every use of this value in the block below is a
# duration, and these devices have no RTC, so the wall clock jumps
# by however wrong boot time was the moment NTP first syncs. That
# would not only mis-fire the heartbeat, it would corrupt the
# frame rate itself, since fps is frames divided by this delta.
current_time = time.monotonic()
if current_time - last_fps_log_time >= fps_log_interval:
fps = fps_frame_count / (current_time - last_fps_log_time)
p99 = _percentile(sorted(frame_times), 0.99)
logger.info(
"Vegas FPS: %.1f (target: %d, frames: %d) p99 %.1fms worst %.1fms",
fps, self.vegas_config.target_fps, fps_frame_count,
p99 * 1000.0, frame_worst * 1000.0
)
target = self.vegas_config.target_fps
degraded = target > 0 and fps < target * _FPS_HEALTHY_FRACTION
due = (current_time - self._fps_last_health_log
>= _FPS_HEARTBEAT_INTERVAL)
if degraded or self._fps_was_degraded or due:
logger.info(
"Vegas FPS: %.1f (target: %d, frames: %d) p99 %.1fms worst %.1fms",
fps, target, fps_frame_count,
p99 * 1000.0, frame_worst * 1000.0
)
self._fps_last_health_log = current_time
else:
logger.debug(
"Vegas FPS: %.1f (target: %d, frames: %d) p99 %.1fms worst %.1fms",
fps, target, fps_frame_count,
p99 * 1000.0, frame_worst * 1000.0
)
self._fps_was_degraded = degraded
last_fps_log_time = current_time
fps_frame_count = 0
frame_worst = 0.0
+54 -54
View File
@@ -83,7 +83,7 @@ class PluginAdapter:
# into unrelated headlines once the strip refreshed to 9,505px.
self._offset_shapes: dict = {}
logger.info(
logger.debug(
"PluginAdapter initialized: display=%dx%d",
self.display_width, self.display_height
)
@@ -109,7 +109,7 @@ class PluginAdapter:
Returns:
List of PIL Images representing plugin content, or None if no content
"""
logger.info(
logger.debug(
"[%s] Getting content (class=%s)",
plugin_id, plugin.__class__.__name__
)
@@ -118,7 +118,7 @@ class PluginAdapter:
cached = self._get_cached(plugin_id)
if cached is not None:
total_width = sum(img.width for img in cached)
logger.info(
logger.debug(
"[%s] Using cached content: %d images, %dpx total",
plugin_id, len(cached), total_width
)
@@ -126,46 +126,46 @@ class PluginAdapter:
# Try native Vegas content method first
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:
content = self._get_native_content(plugin, plugin_id, offscreen_only)
if content:
total_width = sum(img.width for img in content)
logger.info(
logger.debug(
"[%s] Native content SUCCESS: %d images, %dpx total",
plugin_id, len(content), total_width
)
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)
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)
if content:
total_width = sum(img.width for img in content)
logger.info(
logger.debug(
"[%s] ScrollHelper content SUCCESS: %d images, %dpx total",
plugin_id, len(content), total_width
)
return self._finalize(content, plugin_id, 'scroll_helper', plugin)
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:
# Display capture needs the shared canvas; leave it to the caller.
logger.info(
logger.debug(
"[%s] Needs display capture, deferring to the render thread",
plugin_id
)
return None
# 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)
if content:
total_width = sum(img.width for img in content)
logger.info(
logger.debug(
"[%s] Fallback capture SUCCESS: %d images, %dpx total",
plugin_id, len(content), total_width
)
@@ -226,7 +226,7 @@ class PluginAdapter:
kept.append(result.image)
if not kept:
logger.info(
logger.debug(
"[%s] All %d image(s) from %s were blank — contributing nothing",
plugin_id, len(images), source
)
@@ -235,14 +235,14 @@ class PluginAdapter:
trimmed_width = sum(img.width for img in kept)
if trimmed_width < self.config.min_plugin_width:
logger.info(
logger.debug(
"[%s] Trimmed content %dpx is below min_plugin_width %dpx — skipping",
plugin_id, trimmed_width, self.config.min_plugin_width
)
return None
if trimmed_width != original_width or dropped_blank:
logger.info(
logger.debug(
"[%s] Trimmed %s content: %dpx -> %dpx (%.0f%% reclaimed), "
"%d image(s) kept, %d blank dropped",
plugin_id, source, original_width, trimmed_width,
@@ -431,7 +431,7 @@ class PluginAdapter:
"""
if self._offset_shapes.get(plugin_id) != shape:
if plugin_id in self._item_offsets:
logger.info(
logger.debug(
"[%s] Content is %s now, was %s — restarting the rotation "
"rather than resuming at a position that no longer means "
"anything", plugin_id, shape,
@@ -579,7 +579,7 @@ class PluginAdapter:
consumed += 1
if mode == 'truncate':
logger.info(
logger.debug(
"[%s] Width budget %dpx: showing the first %d of %d row(s) "
"(%dpx incl. gaps); the rest are not shown (overflow=truncate)",
plugin_id, budget, len(selected), len(images), used
@@ -587,7 +587,7 @@ class PluginAdapter:
else:
self._record_offset(
plugin_id, (start + consumed) % len(images), shape)
logger.info(
logger.debug(
"[%s] Width budget %dpx: showing %d of %d row(s) (%dpx incl. gaps) "
"from offset %d; remainder deferred to a later cycle",
plugin_id, budget, len(selected), len(images), used, start
@@ -636,7 +636,7 @@ class PluginAdapter:
if mode != 'truncate':
self._record_offset(
plugin_id, 0 if end >= img.width else end, shape)
logger.info(
logger.debug(
"[%s] Width budget %dpx: cropped continuous %dpx image to "
"[%d:%d] (no item gaps of %dpx+ to align to)%s",
plugin_id, budget, img.width, offset, end, min_run,
@@ -674,7 +674,7 @@ class PluginAdapter:
self._record_offset(
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] "
"(%dpx) at item boundaries %d-%d of %d, %s",
plugin_id, budget, img.width, start, end, end - start,
@@ -698,7 +698,7 @@ class PluginAdapter:
List of images or None
"""
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
# 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().
render_width = self.resolve_render_width(plugin, plugin_id)
if render_width != self.display_width:
logger.info(
logger.debug(
"[%s] Native: requesting %dpx instead of %dpx",
plugin_id, render_width, self.display_width
)
@@ -735,19 +735,19 @@ class PluginAdapter:
plugin._vegas_render_width = 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
# Normalize to list
if isinstance(result, Image.Image):
images = [result]
logger.info(
logger.debug(
"[%s] Native: got single Image %dx%d",
plugin_id, result.width, result.height
)
elif isinstance(result, (list, tuple)):
images = list(result)
logger.info(
logger.debug(
"[%s] Native: got %d items in list/tuple",
plugin_id, len(images)
)
@@ -768,14 +768,14 @@ class PluginAdapter:
)
continue
logger.info(
logger.debug(
"[%s] Native: item[%d] is %dx%d, mode=%s",
plugin_id, i, img.width, img.height, img.mode
)
# Ensure correct height
if img.height != self.display_height:
logger.info(
logger.debug(
"[%s] Native: resizing item[%d]: %dx%d -> %dx%d",
plugin_id, i, img.width, img.height,
img.width, self.display_height
@@ -793,13 +793,13 @@ class PluginAdapter:
if valid_images:
total_width = sum(img.width for img in valid_images)
logger.info(
logger.debug(
"[%s] Native: SUCCESS - %d images, %dpx total width",
plugin_id, len(valid_images), total_width
)
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
except (AttributeError, TypeError, ValueError, OSError) as e:
@@ -833,20 +833,20 @@ class PluginAdapter:
logger.debug("[%s] No scroll_helper attribute", plugin_id)
return None
logger.info(
logger.debug(
"[%s] Found scroll_helper: %s",
plugin_id, type(scroll_helper).__name__
)
cached_image = getattr(scroll_helper, 'cached_image', None)
if cached_image is None:
logger.info(
logger.debug(
"[%s] scroll_helper.cached_image is None, triggering content generation",
plugin_id
)
if offscreen_only:
# Generating it calls display(), which needs the canvas.
logger.info(
logger.debug(
"[%s] scroll_helper cache empty; deferring generation "
"to the render thread", plugin_id
)
@@ -859,13 +859,13 @@ class PluginAdapter:
return None
if not isinstance(cached_image, Image.Image):
logger.info(
logger.debug(
"[%s] scroll_helper.cached_image is not an Image: %s",
plugin_id, type(cached_image).__name__
)
return None
logger.info(
logger.debug(
"[%s] scroll_helper.cached_image found: %dx%d, mode=%s",
plugin_id, cached_image.width, cached_image.height, cached_image.mode
)
@@ -888,7 +888,7 @@ class PluginAdapter:
# Ensure correct height
if img.height != self.display_height:
logger.info(
logger.debug(
"[%s] Resizing scroll_helper content: %dx%d -> %dx%d",
plugin_id, img.width, img.height,
img.width, self.display_height
@@ -902,7 +902,7 @@ class PluginAdapter:
if img.mode != 'RGB':
img = img.convert('RGB')
logger.info(
logger.debug(
"[%s] ScrollHelper content ready: %dx%d",
plugin_id, img.width, img.height
)
@@ -1002,7 +1002,7 @@ class PluginAdapter:
with self._capture():
# Method 1: Try _create_scrolling_display (stocks pattern)
if hasattr(plugin, '_create_scrolling_display'):
logger.info(
logger.debug(
"[%s] Triggering via _create_scrolling_display()",
plugin_id
)
@@ -1010,7 +1010,7 @@ class PluginAdapter:
plugin._create_scrolling_display()
cached_image = getattr(scroll_helper, 'cached_image', None)
if cached_image is not None and isinstance(cached_image, Image.Image):
logger.info(
logger.debug(
"[%s] _create_scrolling_display() SUCCESS: %dx%d",
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
if hasattr(plugin, 'display'):
logger.info(
logger.debug(
"[%s] Triggering via display(force_clear=True)",
plugin_id
)
@@ -1031,12 +1031,12 @@ class PluginAdapter:
plugin.display(force_clear=True)
cached_image = getattr(scroll_helper, 'cached_image', None)
if cached_image is not None and isinstance(cached_image, Image.Image):
logger.info(
logger.debug(
"[%s] display(force_clear=True) SUCCESS: %dx%d",
plugin_id, cached_image.width, cached_image.height
)
return cached_image
logger.info(
logger.debug(
"[%s] display(force_clear=True) did not populate cached_image",
plugin_id
)
@@ -1045,7 +1045,7 @@ class PluginAdapter:
"[%s] display(force_clear=True) failed", plugin_id
)
logger.info(
logger.debug(
"[%s] Could not trigger scroll content generation",
plugin_id
)
@@ -1077,15 +1077,15 @@ class PluginAdapter:
try:
# Save current display state
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
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:
try:
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):
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.
render_width = self.resolve_render_width(plugin, plugin_id)
if render_width != self.display_width:
logger.info(
logger.debug(
"[%s] Fallback: rendering at %dpx instead of %dpx",
plugin_id, render_width, self.display_width
)
with self._capture(), self._render_at(render_width):
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)
try:
plugin.display()
logger.info("[%s] Fallback: display() called successfully", plugin_id)
logger.debug("[%s] Fallback: display() called successfully", plugin_id)
except TypeError:
# 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)
# Capture the result
captured = self.display_manager.image.copy()
logger.info(
logger.debug(
"[%s] Fallback: captured frame %dx%d, mode=%s",
plugin_id, captured.width, captured.height, captured.mode
)
# Check if captured image has content (not all black)
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%%)",
plugin_id, bright_ratio * 100
)
if is_blank:
logger.info(
logger.debug(
"[%s] Fallback: first capture blank, retrying with force_clear",
plugin_id
)
@@ -1142,7 +1142,7 @@ class PluginAdapter:
captured = self.display_manager.image.copy()
is_blank, bright_ratio = self._is_blank_image(captured, return_ratio=True)
logger.info(
logger.debug(
"[%s] Fallback: retry brightness - %.3f%% bright pixels",
plugin_id, bright_ratio * 100
)
@@ -1159,7 +1159,7 @@ class PluginAdapter:
if captured.mode != 'RGB':
captured = captured.convert('RGB')
logger.info(
logger.debug(
"[%s] Fallback: SUCCESS - captured %dx%d",
plugin_id, captured.width, captured.height
)
+74 -9
View File
@@ -143,6 +143,12 @@ def mask_secret_fields(config: Dict[str, Any], schema_properties: Dict[str, Any]
return result
#: What a masked secret looks like on the wire. Named because the write path
#: has to recognise it coming back: a client that renders the mask and posts
#: it unchanged must not store the mask as if it were the secret.
SECRET_MASK = '\u2022' * 8
def mask_all_secret_values(config: Dict[str, Any]) -> Dict[str, Any]:
"""Blanket-mask every non-empty value in a secrets config dict.
@@ -156,15 +162,25 @@ def mask_all_secret_values(config: Dict[str, Any]) -> Dict[str, Any]:
Returns:
A copy with all real values replaced by ``'••••••••'``.
"""
masked: Dict[str, Any] = {}
for k, v in config.items():
if isinstance(v, dict):
masked[k] = mask_all_secret_values(v)
elif v not in (None, '') and not (isinstance(v, str) and v.startswith('YOUR_')):
masked[k] = '••••••••'
else:
masked[k] = v
return masked
return {k: _mask_value(v) for k, v in config.items()}
def _mask_value(value: Any) -> Any:
"""Mask one value, recursing through dicts and lists.
A list used to be masked as though it were a scalar, so
``accounts: [{"name": "a", "token": "..."}]`` came back as a single
``'••••••••'``. Nothing leaked, but the caller could no longer see how
many entries there were or any of their non-secret fields, and the raw
editor was shown a string where the file holds an array.
"""
if isinstance(value, dict):
return {k: _mask_value(v) for k, v in value.items()}
if isinstance(value, list):
return [_mask_value(item) for item in value]
if value in (None, '') or (isinstance(value, str) and value.startswith('YOUR_')):
return value
return SECRET_MASK
def remove_empty_secrets(secrets: Dict[str, Any]) -> Dict[str, Any]:
@@ -189,3 +205,52 @@ def remove_empty_secrets(secrets: Dict[str, Any]) -> Dict[str, Any]:
elif v is not None and not (isinstance(v, str) and v.strip() == ''):
result[k] = v
return result
def strip_masked_values(secrets: Dict[str, Any]) -> Dict[str, Any]:
"""Remove values a client echoed back rather than changed.
The counterpart to :func:`mask_all_secret_values`. A client that GETs the
masked secrets, edits one field and POSTs the whole object back is sending
``SECRET_MASK`` for every field it did not touch. Storing those would
replace each untouched credential with eight bullet characters.
Drops the mask and, like :func:`remove_empty_secrets`, blank values -- so
the caller can merge the result onto what is already stored and have
"unchanged" mean unchanged. Empty nested dicts are pruned.
"""
result: Dict[str, Any] = {}
for k, v in secrets.items():
if isinstance(v, dict):
nested = strip_masked_values(v)
if nested:
result[k] = nested
elif isinstance(v, list):
# A list is merged by replacement, not element by element -- there
# is no identity to match entries on -- so a list that still holds
# a mask cannot be merged safely: keeping it would store bullets,
# and keeping the submitted entries alone would drop whichever the
# client did not send back. Dropping the key leaves the stored
# list untouched, which is what an untouched list should do.
#
# The consequence, deliberately: editing one secret inside a list
# through this endpoint requires sending real values for all of
# them. Sending some masks leaves the whole list as it was.
if not _contains_mask(v):
result[k] = v
elif v is None:
continue
elif isinstance(v, str) and (v.strip() == '' or v == SECRET_MASK):
continue
else:
result[k] = v
return result
def _contains_mask(value: Any) -> bool:
"""True when a mask sentinel survives anywhere inside ``value``."""
if isinstance(value, dict):
return any(_contains_mask(v) for v in value.values())
if isinstance(value, list):
return any(_contains_mask(item) for item in value)
return value == SECRET_MASK
Regular → Executable
View File
Regular → Executable
View File
+12
View File
@@ -8,6 +8,18 @@ Type=simple
User=root
WorkingDirectory=__PROJECT_ROOT_DIR__
Environment=PYTHONDONTWRITEBYTECODE=1
# glibc gives each allocating thread its own malloc arena, up to 8 x CPU count,
# and an arena that has grown is never handed back to the OS. This process runs
# 9 threads on a 3-core Pi, so the ceiling is 24 arenas -- and a rig measured at
# 1030 MB resident held 23 large anonymous mappings on 64 MB-aligned addresses,
# 920 MB of them, while the live data it was actually holding (widest scroll
# strip seen: 35,746 x 64) accounts for roughly 15 MB. That gap is arena bloat,
# not leaked objects: RSS was flat across repeated sampling, not climbing.
#
# Capping the arenas trades a little allocator concurrency for a large amount of
# resident memory on a device that has neither to spare. 2 is the usual value;
# raise it if frame times regress.
Environment=MALLOC_ARENA_MAX=2
ExecStart=/usr/bin/python3 __PROJECT_ROOT_DIR__/run.py
# Restart=always, not on-failure: run.py exiting 0 (a clean shutdown path taken
# for a reason that no longer applies, e.g. a config reload) would otherwise leave
+143
View File
@@ -0,0 +1,143 @@
"""GET /config/main must not hand out credentials.
The endpoint returned the raw config to anyone who could reach the port, and
this web interface has no authentication of any kind. Measured against a live
rig, an unauthenticated request returned:
github.api_token 40 chars
incoming-packages.ha_token 183 chars
jellyfin-now-playing.api_key 32 chars
ledmatrix-weather.api_key 32 chars
on-air.mqtt_password 8 chars
youtube.api_key 20 chars
youtube-stats.api_key 39 chars
A GitHub token and a Home Assistant long-lived token among them.
The x-secret masking the plugin config endpoints use does not apply here: this
endpoint never consults a schema, and core keys such as github.api_token have
no schema to carry the marker. Several of those fields *are* tagged x-secret in
their plugin's schema and were still returned in full, which is what makes the
schema route the wrong one to rely on for this endpoint.
Matching on field name is blunt. For a whole-config dump it is the right
default: anything named like a credential should not leave the process, and a
new plugin that adds a differently-shaped secret is covered without anyone
remembering to tag it.
"""
import pytest
from web_interface.blueprints.api_v3 import (
_looks_like_a_credential,
_redact_credentials,
)
@pytest.mark.parametrize("name", [
"password", "mqtt_password", "opensky_password", "passwd",
"api_key", "apikey", "API_KEY", "flightaware_api_key",
"token", "ha_token", "api_token", "access_token",
"secret", "client_secret", "spotify_client_secret",
"access_key", "private_key",
])
def test_credential_names_are_recognised(name):
assert _looks_like_a_credential(name)
@pytest.mark.parametrize("name", [
"timezone", "city", "brightness", "enabled", "update_interval",
"favorite_teams", "display_duration", "keyword",
])
def test_ordinary_names_are_left_alone(name):
assert not _looks_like_a_credential(name)
def test_the_measured_leak_is_closed():
"""The exact shape taken off the rig."""
config = {
"github": {"api_token": "ghp_" + "x" * 36},
"incoming-packages": {"ha_token": "y" * 183, "enabled": True},
"jellyfin-now-playing": {"api_key": "z" * 32},
"on-air": {"mqtt_password": "hunter22"},
"youtube": {"api_key": "k" * 20},
"timezone": "America/New_York",
}
out = _redact_credentials(config)
assert out["github"]["api_token"] == ""
assert out["incoming-packages"]["ha_token"] == ""
assert out["jellyfin-now-playing"]["api_key"] == ""
assert out["on-air"]["mqtt_password"] == ""
assert out["youtube"]["api_key"] == ""
# Everything else survives, or the config editor breaks.
assert out["timezone"] == "America/New_York"
assert out["incoming-packages"]["enabled"] is True
def test_nested_and_listed_credentials_are_reached():
config = {"a": {"b": {"c": {"password": "p"}}},
"feeds": [{"name": "x", "api_key": "k"}, {"name": "y"}]}
out = _redact_credentials(config)
assert out["a"]["b"]["c"]["password"] == ""
assert out["feeds"][0]["api_key"] == ""
assert out["feeds"][0]["name"] == "x"
def test_the_original_is_not_mutated():
"""The caller holds the live config; redaction must not edit it in place."""
config = {"github": {"api_token": "keepme"}}
_redact_credentials(config)
assert config["github"]["api_token"] == "keepme"
def test_a_credential_shaped_container_is_still_walked():
"""`secrets: {...}` is a section name, not a value to blank."""
config = {"secrets": {"api_key": "k", "note": "keep"}}
out = _redact_credentials(config)
assert out["secrets"]["api_key"] == ""
assert out["secrets"]["note"] == "keep"
def test_non_dict_input_passes_through():
assert _redact_credentials("plain") == "plain"
assert _redact_credentials(7) == 7
assert _redact_credentials(None) is None
def test_the_endpoint_itself_redacts():
"""Through the view function, not the helper.
The helper tests above all passed with the route still returning
`config` -- reverting the one line that calls the redactor changed
nothing, because nothing exercised the route. A property asserted on a
helper is not a property asserted on the endpoint, and it is the endpoint
that is exposed to the network.
"""
import json as _json
from unittest.mock import MagicMock
import flask
from web_interface.blueprints import api_v3 as mod
raw = {"github": {"api_token": "ghp_secret_value"},
"timezone": "America/New_York"}
manager = MagicMock()
manager.load_config.return_value = raw
previous = getattr(mod.api_v3, "config_manager", None)
mod.api_v3.config_manager = manager
app = flask.Flask(__name__)
try:
with app.test_request_context("/config/main"):
response = mod.get_main_config()
payload = response.get_json() if hasattr(response, "get_json") else _json.loads(response[0].data)
finally:
mod.api_v3.config_manager = previous
data = payload["data"]
assert data["github"]["api_token"] == "", (
"the endpoint returned the token; the redactor is not wired in")
assert data["timezone"] == "America/New_York"
# And the config the manager handed over is untouched.
assert raw["github"]["api_token"] == "ghp_secret_value"
+44 -3
View File
@@ -58,7 +58,7 @@ def repos(tmp_path):
def test_branch_with_upstream_uses_a_plain_pull(repos):
args, note, error = resolve_pull_command(str(repos))
assert error is None
assert args == ['git', 'pull', '--rebase']
assert args == ['git', 'pull', '--rebase', '--autostash']
assert note == ''
@@ -73,7 +73,7 @@ def test_branch_without_upstream_falls_back_to_origin_branch(repos):
args, note, error = resolve_pull_command(str(repos))
assert error is None
assert args == ['git', 'pull', '--rebase', 'origin', 'audit']
assert args == ['git', 'pull', '--rebase', '--autostash', 'origin', 'audit']
assert 'audit' in note
@@ -155,7 +155,7 @@ def test_switching_attaches_tracking_so_pull_needs_no_fallback(repos):
args, note, error = resolve_pull_command(str(repos))
assert error is None
assert args == ['git', 'pull', '--rebase']
assert args == ['git', 'pull', '--rebase', '--autostash']
assert note == ''
@@ -200,3 +200,44 @@ def test_stash_option_lets_the_switch_through_and_keeps_the_work(repos):
assert _git('branch', '--show-current', cwd=repos).stdout.strip() == 'other'
# The edit is not lost — it is on the stash.
assert 'switch to other' in _git('stash', 'list', cwd=repos).stdout
class TestInstallerDoesNotBlockTheUpdateButton:
"""first_time_install.sh chmods scripts that git tracked as 644.
With core.fileMode true -- the default on Linux -- that leaves five
permanently modified tracked files on every machine that ran the
installer, and `git pull --rebase` refuses to start:
error: cannot pull with rebase: You have unstaged changes.
Tracking them as executable makes the installer's chmod a no-op.
"""
CHMODDED = [
'first_time_install.sh',
'start_display.sh',
'stop_display.sh',
'scripts/install/install_service.sh',
'scripts/install/install_web_service.sh',
]
def test_scripts_the_installer_chmods_are_tracked_executable(self):
import subprocess
from pathlib import Path
root = Path(__file__).resolve().parent.parent
out = subprocess.run(['git', 'ls-files', '-s', *self.CHMODDED],
capture_output=True, text=True, cwd=str(root)).stdout
modes = {line.split()[3]: line.split()[0] for line in out.strip().split('\n') if line}
# git ls-files says nothing about a path it does not track, so a
# renamed or deleted script would simply be absent here and the mode
# check below would pass over it silently.
untracked = sorted(set(self.CHMODDED) - set(modes))
assert not untracked, (
f"{untracked} are chmodded by the installer but not tracked by "
"git, so their mode cannot be asserted at all")
non_exec = sorted(f for f, m in modes.items() if m != '100755')
assert not non_exec, (
f"{non_exec} are chmodded by the installer but tracked non-executable, "
"so every install leaves the working tree dirty and the update "
"button cannot pull")
+119
View File
@@ -0,0 +1,119 @@
"""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 copy
import pytest
from src.plugin_system.plugin_health import PluginHealthTracker, CircuitState
class _Cache:
"""Counts writes; serves back whatever was last written.
Both directions deep-copy, so this behaves like a real cache that
serialises through a file. Storing by reference let the tracker keep
mutating the object already in the store, so a record could appear to
have been persisted when no write ever happened -- which is precisely
what test_durable_state_survives_a_restart is supposed to detect.
"""
def __init__(self):
self.store = {}
self.writes = 0
def set(self, key, data, ttl=None, **kwargs):
self.writes += 1
self.store[key] = copy.deepcopy(data)
def get(self, key, max_age=None, memory_ttl=None, **kwargs):
return copy.deepcopy(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
+137
View File
@@ -0,0 +1,137 @@
"""Log lines must reach the journal with their real severity.
Everything this process writes to stdout lands in the journal as PRIORITY=6,
whatever the Python level was, because journald has no other signal. Measured
on a live rig over 24 hours: 55 lines containing " - ERROR - " and 13
containing " - WARNING - ", every one of them recorded as informational. So
journalctl -p err -u ledmatrix
returned nothing while errors were being logged, and anyone triaging has to
grep the message text instead. That is slower and it is wrong: a search for
"oom" also matches the radar logging "zoom=9", which is exactly the false
positive it produced during this audit.
systemd reads a leading "<N>" on each stdout line and uses it as the priority
(sd-daemon(3)), so this needs no extra dependency -- and it must only be
applied when systemd is actually reading, or the prefixes become literal noise
in a terminal, the emulator, and test output.
"""
import logging
import os
import sys
from unittest.mock import patch
import pytest
from src.logging_config import JournalPriorityFormatter, _SYSLOG_PRIORITY, _under_systemd
class _Plain(logging.Formatter):
def format(self, record):
return record.getMessage()
def _record(level, msg="hello"):
return logging.LogRecord("t", level, "f.py", 1, msg, None, None)
@pytest.mark.parametrize("level,expected", [
(logging.CRITICAL, 2),
(logging.ERROR, 3),
(logging.WARNING, 4),
(logging.INFO, 6),
(logging.DEBUG, 7),
])
def test_each_level_maps_to_its_syslog_priority(level, expected):
out = JournalPriorityFormatter(_Plain()).format(_record(level))
assert out.startswith(f"<{expected}>"), out
assert _SYSLOG_PRIORITY[level] == expected
def test_error_and_info_are_distinguishable():
"""The whole point: journalctl -p err must be able to tell them apart."""
fmt = JournalPriorityFormatter(_Plain())
assert fmt.format(_record(logging.ERROR))[:3] != fmt.format(_record(logging.INFO))[:3]
def test_every_line_of_a_multiline_record_is_tagged():
"""The journal splits them, and an untagged continuation loses its level.
A traceback is the case that matters -- it is the most important thing in
the log and the longest.
"""
out = JournalPriorityFormatter(_Plain()).format(
_record(logging.ERROR, "Traceback:\nline one\nline two"))
lines = out.split("\n")
assert len(lines) == 3
assert all(line.startswith("<3>") for line in lines), lines
def test_the_message_survives_intact():
out = JournalPriorityFormatter(_Plain()).format(_record(logging.WARNING, "disk full"))
assert out == "<4>disk full"
def test_an_unknown_level_falls_back_to_info():
out = JournalPriorityFormatter(_Plain()).format(_record(25))
assert out.startswith("<6>")
def _stdout_ids():
"""The dev:ino systemd would publish for this process's stdout."""
st = os.fstat(sys.stdout.fileno())
return f"{st.st_dev}:{st.st_ino}"
def test_prefixing_is_off_outside_systemd():
"""Otherwise a terminal run, the emulator and pytest all show `<6>`."""
with patch.dict(os.environ, {}, clear=True):
assert not _under_systemd()
with patch.dict(os.environ, {"JOURNAL_STREAM": _stdout_ids()}):
assert _under_systemd()
def test_an_inherited_journal_stream_does_not_count():
"""The variable outlives the descriptor it describes.
systemd sets JOURNAL_STREAM for the service, and every child inherits it
-- including one whose stdout has been redirected to a pipe or a file.
Trusting the variable alone put literal "<6>" prefixes into that captured
output. Only a descriptor whose dev:ino actually matches is the journal.
"""
with patch.dict(os.environ, {"JOURNAL_STREAM": "8:12345"}):
assert not _under_systemd(), \
"a stale inherited JOURNAL_STREAM was treated as the journal"
@pytest.mark.parametrize("value", ["", "not-a-pair", "8", "8:", ":12345",
"eight:12345", "8:12345:9"])
def test_a_malformed_journal_stream_is_not_the_journal(value):
with patch.dict(os.environ, {"JOURNAL_STREAM": value}):
assert not _under_systemd()
def test_a_closed_stdout_is_not_the_journal():
"""os.fstat raises rather than answers; that must not propagate."""
with patch.dict(os.environ, {"JOURNAL_STREAM": "8:12345"}), \
patch("src.logging_config.sys.stdout") as fake_stdout:
fake_stdout.fileno.side_effect = ValueError("I/O operation on closed file")
assert not _under_systemd()
def test_setup_uses_the_wrapper_only_under_systemd():
from src.logging_config import setup_logging
for env, expect_wrapped in (({}, False),
({"JOURNAL_STREAM": _stdout_ids()}, True)):
with patch.dict(os.environ, env, clear=True):
setup_logging()
handlers = [h for h in logging.getLogger().handlers
if isinstance(h, logging.StreamHandler)]
assert handlers, "no stream handler installed"
wrapped = any(isinstance(h.formatter, JournalPriorityFormatter)
for h in handlers)
assert wrapped is expect_wrapped, (
f"JOURNAL_STREAM={env}: wrapped={wrapped}, expected {expect_wrapped}")
logging.getLogger().handlers.clear()
+16 -4
View File
@@ -183,15 +183,27 @@ class TestSetupLogging:
setup_logging()
assert len(logging.getLogger().handlers) == 1
@staticmethod
def _selected_formatter():
"""The formatter setup_logging() chose, past any journald wrapper.
Under systemd the console handler's formatter is wrapped so each line
carries its syslog priority. That wrapper is applied only when
JOURNAL_STREAM is set, which is true in CI and false in a terminal, so
asserting on the handler's formatter directly passes locally and fails
on the runner. These tests are about which formatter format_type
selects, so they look through the wrapper.
"""
formatter = logging.getLogger().handlers[0].formatter
return getattr(formatter, "inner", formatter)
def test_json_format_selects_structured_formatter(self):
setup_logging(format_type="json")
assert isinstance(
logging.getLogger().handlers[0].formatter, StructuredFormatter)
assert isinstance(self._selected_formatter(), StructuredFormatter)
def test_readable_format_selects_contextual_formatter(self):
setup_logging(format_type="readable")
assert isinstance(
logging.getLogger().handlers[0].formatter, ContextualFormatter)
assert isinstance(self._selected_formatter(), ContextualFormatter)
def test_log_file_adds_file_handler(self, tmp_path):
log_file = tmp_path / "test.log"
+128
View File
@@ -0,0 +1,128 @@
"""A malformed metrics cache entry must not take every plugin down with it.
`ResourceMetrics(**cached)` raises TypeError on a single unexpected key, and
that exception escapes into plugin_manager, which reports it per plugin as
"plugin <id> operation failed". Every plugin fails and the plugin system never
finishes initialising -- the health endpoint reports
`plugin_system: not_initialized` while the display itself keeps running.
Seen on a live rig, once per plugin, continuously:
ERROR - src.plugin_system.plugin_manager - plugin geochron operation failed:
ResourceMetrics.__init__() got an unexpected keyword argument
'consecutive_failures'
`consecutive_failures` belongs to plugin_health, not to metrics. How a
health-shaped record came to sit under a plugin_metrics key on that machine is
not established -- a restored backup that mixed two machines' caches is the
likeliest explanation, and the same rig had one restored onto it -- but a
loader that turns one bad cache entry into a total outage is the part worth
fixing. plugin_health already repairs its own records field by field rather
than trusting what is on disk.
"""
import logging
from dataclasses import fields
from unittest.mock import MagicMock
import pytest
from src.plugin_system.resource_monitor import PluginResourceMonitor, ResourceMetrics
class _Cache:
def __init__(self, payload=None):
self.payload = payload
def get(self, key, max_age=None, memory_ttl=None, **kwargs):
return self.payload
def set(self, key, data, ttl=None, **kwargs):
pass
def _monitor(payload):
m = PluginResourceMonitor(cache_manager=_Cache(payload))
m.logger = logging.getLogger("test")
return m
#: What the rig actually had under the metrics key.
HEALTH_SHAPED = {
"consecutive_failures": 0, "circuit_state": "closed",
"circuit_opened_time": None, "half_open_start_time": None,
"last_error": None, "last_failure_time": None,
"last_success_time": 1_700_000_000.0, "total_failures": 0,
"total_successes": 42,
}
def test_a_health_record_under_the_metrics_key_does_not_raise():
"""The exact failure: it must degrade, not take the plugin system down."""
monitor = _monitor(HEALTH_SHAPED)
metrics = monitor.get_metrics(" plugin-a".strip())
assert isinstance(metrics, ResourceMetrics)
def test_recognised_fields_in_a_mixed_record_are_kept():
"""Dropping the record wholesale would lose real history unnecessarily."""
mixed = dict(HEALTH_SHAPED, call_count=7, memory_mb=12.5)
metrics = _monitor(mixed).get_metrics("plugin-b")
assert metrics.call_count == 7
assert metrics.memory_mb == 12.5
def test_a_clean_record_still_loads_unchanged():
clean = {f.name: 3 for f in fields(ResourceMetrics)}
metrics = _monitor(clean).get_metrics("plugin-c")
for name in (f.name for f in fields(ResourceMetrics)):
assert getattr(metrics, name) == 3
def test_unknown_fields_are_named_in_the_log(caplog):
"""Silently discarding them would hide a real schema change."""
with caplog.at_level(logging.WARNING):
_monitor(HEALTH_SHAPED).get_metrics("plugin-d")
# getMessage(), not .message: the latter is only populated once a handler
# formats the record, so the obvious spelling silently never matches.
assert any("consecutive_failures" in r.getMessage() for r in caplog.records), \
caplog.text
@pytest.mark.parametrize("payload", ["a string", 42, ["a", "list"]])
def test_a_non_mapping_cache_entry_does_not_raise(payload):
metrics = _monitor(payload).get_metrics("plugin-e")
assert isinstance(metrics, ResourceMetrics)
@pytest.mark.parametrize("bad", [
{"call_count": "not a number"},
{"memory_mb": None},
{"execution_time": {"nested": "junk"}},
{"min_execution_time": ["a", "list"]},
])
def test_values_of_the_wrong_type_fall_back_to_usable_defaults(bad):
"""isinstance() alone was not enough.
A dataclass does not enforce its annotations, so the bad value was simply
stored and the old assertion passed -- then monitor_call() raised
"can only concatenate str (not \"int\") to str" on the next call. The
metrics must come back *usable*, not merely constructed.
"""
monitor = _monitor(bad)
metrics = monitor.get_metrics("plugin-f")
assert isinstance(metrics, ResourceMetrics)
field_name = next(iter(bad))
assert isinstance(getattr(metrics, field_name), (int, float)), \
f"{field_name} came back as {getattr(metrics, field_name)!r}"
# The real proof: arithmetic on the loaded metrics must not explode.
metrics.call_count += 1
metrics.total_execution_time += 0.5
metrics.update_average_execution_time()
def test_a_numeric_string_is_accepted_rather_than_discarded():
"""JSON round-trips can widen an int to a string; that is recoverable."""
metrics = _monitor({"call_count": "7"}).get_metrics("plugin-g")
assert metrics.call_count == 7
+85 -1
View File
@@ -11,7 +11,7 @@ Focus areas:
import time
import pytest
from unittest.mock import MagicMock
from unittest.mock import MagicMock, patch
from src.plugin_system.resource_monitor import (
PluginResourceMonitor,
@@ -127,3 +127,87 @@ class TestForceReload:
fresh = mon.get_metrics_summary("p", force_reload=True)
assert fresh["call_count"] == 7
assert any(c.kwargs.get("memory_ttl") == 0 for c in cache.get.call_args_list)
class TestMetricsPersistenceChurn:
"""Metrics are telemetry; writing them on every call wore the SD card.
Each write is a ~350-byte file, which on ext4 costs a 4KB block plus a
journal entry. At roughly nine calls a minute per plugin across fourteen
plugins it dominated the device's write volume.
"""
def test_the_first_snapshot_is_written_even_seconds_after_boot(self):
"""The throttle must key off "have we written?", not process uptime.
time.monotonic() is time since boot on Linux, and systemd starts this
service at boot. With 0.0 as the missing-timestamp default,
`now - 0.0 < 30` was true for the first half-minute of every run, so
the very first metrics write -- the one that matters most after a
restart -- was silently skipped.
"""
import src.plugin_system.resource_monitor as rm
cache = _cache()
mon = PluginResourceMonitor(cache, enable_monitoring=False)
# 12 seconds after boot: inside the interval, but nothing written yet.
with patch.object(rm.time, "monotonic", return_value=12.0):
mon.monitor_call("p", lambda: None)
writes = [c for c in cache.set.call_args_list
if "plugin_metrics:" in str(c)]
assert writes, \
"the first snapshot was dropped because the process was young"
def test_repeated_calls_persist_once_per_interval(self):
cache = _cache()
mon = PluginResourceMonitor(cache, enable_monitoring=False)
for _ in range(50):
mon.monitor_call("p", lambda: None)
writes = [c for c in cache.set.call_args_list
if c.args and str(c.args[0]).startswith("plugin_metrics:")]
assert len(writes) == 1, (
f"50 calls produced {len(writes)} metric writes; expected 1")
def test_the_interval_elapsing_allows_the_next_write(self, monkeypatch):
import src.plugin_system.resource_monitor as rm
cache = _cache()
mon = PluginResourceMonitor(cache, enable_monitoring=False)
mon.monitor_call("p", lambda: None)
# pretend the interval has passed
mon._metrics_persisted_at["p"] -= rm._METRICS_PERSIST_INTERVAL + 1
mon.monitor_call("p", lambda: None)
writes = [c for c in cache.set.call_args_list
if c.args and str(c.args[0]).startswith("plugin_metrics:")]
assert len(writes) == 2
def test_in_memory_metrics_stay_exact_while_writes_are_skipped(self):
mon = PluginResourceMonitor(_cache(), enable_monitoring=False)
for _ in range(20):
mon.monitor_call("p", lambda: None)
assert mon.get_metrics("p").call_count == 20
def test_reset_lets_the_next_call_persist_immediately(self):
cache = _cache()
mon = PluginResourceMonitor(cache, enable_monitoring=False)
mon.monitor_call("p", lambda: None)
mon.reset_metrics("p")
mon.monitor_call("p", lambda: None)
writes = [c for c in cache.set.call_args_list
if c.args and str(c.args[0]).startswith("plugin_metrics:")]
assert len(writes) == 2, "reset should clear the throttle timestamp"
def test_a_failed_write_does_not_buy_the_next_interval_of_silence(self):
"""A set() that raises must not count as having persisted.
Marking the timestamp before the write would leave no snapshot in the
cache and still suppress the next 30 seconds of attempts.
"""
cache = _cache()
cache.set.side_effect = [OSError("disk full"), None]
mon = PluginResourceMonitor(cache, enable_monitoring=False)
with pytest.raises(OSError):
mon.monitor_call("p", lambda: None)
# the very next call must try again rather than skip the interval
mon.monitor_call("p", lambda: None)
writes = [c for c in cache.set.call_args_list
if c.args and str(c.args[0]).startswith("plugin_metrics:")]
assert len(writes) == 2, "a failed write should be retried, not skipped"
+147
View File
@@ -0,0 +1,147 @@
"""The captive portal's fixed-argument sudo calls must be granted.
The installers write two allow-lists, /etc/sudoers.d/ledmatrix_web and
ledmatrix_wifi. A sudo call absent from both needs a password, which a service
cannot supply, so it fails.
Four such calls were ungranted, all of them captive-portal teardown/setup:
sysctl -w net.ipv4.ip_forward=0|1 wifi_manager.py:788, 883
nft add|delete table ip ledmatrix wifi_manager.py:835, 895
rfkill unblock wifi wifi_manager.py:1811
mkdir -p .../dnsmasq-shared.d wifi_manager.py:922
It goes unnoticed because a stock Raspberry Pi image ships
/etc/sudoers.d/010_pi-nopasswd granting the default user
`ALL=(ALL) NOPASSWD: ALL`, which satisfies every gap in both files. It only
bites once that blanket rule is removed or the service runs as another user.
Scope, deliberately narrow: this pins the four commands above, each of which
can be written out literally. The portal makes further sudo calls whose
arguments are built at runtime -- iptables and nft rules carrying an interface
name and a port, `ip addr`, `ip link` -- and those cannot be granted safely
here. A rule covering them needs a trailing wildcard, and
`iptables --modprobe=/path/to/anything` runs that path as root, so
`NOPASSWD: iptables *` is a root shell for the web user by another name.
Closing that half needs a privileged helper that builds the rules itself and
takes only an interface and a port, granted the way safe_plugin_rm.sh already
is. That is a design decision, not a one-line grant, and belongs in its own
change.
"""
import re
from pathlib import Path
import pytest
ROOT = Path(__file__).resolve().parent.parent
INSTALLERS = (
ROOT / "first_time_install.sh",
ROOT / "scripts" / "install" / "configure_wifi_permissions.sh",
)
#: Commands this change grants, each fully literal in the source.
REQUIRED = (
("sysctl", "-w", "net.ipv4.ip_forward=0"),
("sysctl", "-w", "net.ipv4.ip_forward=1"),
("nft", "add", "table", "ip", "ledmatrix"),
("nft", "delete", "table", "ip", "ledmatrix"),
("rfkill", "unblock", "wifi"),
("mkdir", "-p", "/etc/NetworkManager/dnsmasq-shared.d"),
)
#: Tools with an option that executes a program of the caller's choosing.
#: A trailing wildcard on any of these is a privilege escalation.
EXEC_CAPABLE = ("iptables", "ip6tables", "nft", "tcpdump", "find", "awk",
"sed", "perl", "python", "python3", "env")
def _grant_lines():
lines = []
for installer in INSTALLERS:
if not installer.is_file():
continue
for line in installer.read_text(encoding="utf-8", errors="replace").splitlines():
if "NOPASSWD:" in line:
lines.append(line.split("NOPASSWD:", 1)[1])
return lines
def _normalise(rule):
"""One rule with binary-path variables reduced to bare tool names.
Rules are written as `$SYSCTL_PATH -w ...` or `${NFT_PATH} ...`, so
matching the literal "sysctl" finds nothing and every rule looks absent --
which is exactly how an earlier version of this test reported six gaps
that did not exist. Both spellings are handled: shell expands them
identically, and a check that understood only one silently skipped the
other.
"""
rule = re.sub(r"\$\{?([A-Z][A-Z0-9_]*)_PATH\}?",
lambda m: m.group(1).lower(), rule)
return re.sub(r"/usr/(?:s?bin)/", "", rule)
def _granted_commands():
"""The command each NOPASSWD rule actually grants, normalised.
_grant_lines() already returns everything after "NOPASSWD:", so what
arrives here is the command, possibly preceded by the NOEXEC tag and
possibly still carrying the closing quote of an `echo "..."` that wrote
it. Both are stripped so the result is comparable to a plain command.
"""
commands = []
for rule in _grant_lines():
command = _normalise(rule).strip()
command = re.sub(r"^NOEXEC:\s*", "", command)
command = command.rstrip('"').rstrip("'").strip()
if command:
commands.append(" ".join(command.split()))
return commands
def test_the_installers_are_present():
missing = [str(p.relative_to(ROOT)) for p in INSTALLERS if not p.is_file()]
assert not missing, f"installer(s) missing: {missing}"
@pytest.mark.parametrize("command", REQUIRED, ids=lambda c: " ".join(c))
def test_the_command_is_granted(command):
"""Whole command, not just the binary.
Checking only the binary made this far weaker than it looked: with
`sysctl` present anywhere, deleting the ip_forward=0 grant still passed,
and the portal would then be unable to restore forwarding on teardown.
"""
wanted = " ".join(command)
granted = _granted_commands()
# Exact match, not a prefix. A substring search was satisfied by
# `sysctl -w net.ipv4.ip_forward=0 *`, and that trailing wildcard lets the
# caller append whatever they like to a command running as root -- a far
# wider grant than the one this test is meant to be confirming.
assert wanted in granted, (
f"no installer grants exactly `{wanted}`; closest matches: "
+ str([g for g in granted if g.startswith(command[0])])[:200])
def test_no_wildcard_on_a_tool_that_can_exec():
"""`NOPASSWD: iptables *` hands the web user root.
iptables --modprobe=/path runs that path as root. This caught a grant added
in this very change, which is why it is here.
"""
offenders = []
for rule in _grant_lines():
rule = rule.strip()
if not rule.endswith("*"):
continue
# Normalised the same way as everything else: `${NFT_PATH} *` left a
# brace before the tool name, and the word-boundary check below does
# not treat "{" as a boundary, so that spelling slipped through.
haystack = _normalise(rule).lower()
for tool in EXEC_CAPABLE:
if re.search(rf"(^|/|\s|\$){tool}(\s|$)", haystack):
offenders.append(rule)
break
assert not offenders, (
"wildcard grant on a tool that can execute another program:\n "
+ "\n ".join(offenders))
+18 -6
View File
@@ -30,6 +30,10 @@ ROOT = Path(__file__).resolve().parent.parent
INSTALLERS = (
ROOT / "first_time_install.sh",
ROOT / "scripts" / "install" / "configure_wifi_permissions.sh",
# Writes the same journalctl grants as first_time_install.sh. It was
# missing here, and because of that this suite passed while three
# ungranted wildcard rules sat in it.
ROOT / "scripts" / "install" / "configure_web_sudo.sh",
)
#: Commands that will start another program of their own accord -- a pager, an
@@ -44,8 +48,14 @@ def _grant_lines():
continue
for line in installer.read_text(encoding="utf-8", errors="replace").splitlines():
stripped = line.strip()
if "NOPASSWD" in stripped and not stripped.startswith("#"):
lines.append(stripped)
if "NOPASSWD" not in stripped or stripped.startswith("#"):
continue
# Installers emit rules two ways: written literally into a heredoc,
# or echoed into a file. An echoed rule ends in a quote, so the
# trailing-wildcard check below would skip it and the rule would
# never be examined at all.
echoed = re.fullmatch(r"""echo\s+(['"])(.*)\1""", stripped)
lines.append(echoed.group(2) if echoed else stripped)
return lines
@@ -78,10 +88,12 @@ def test_journalctl_is_granted_at_all():
"no journalctl grant remains; the web interface reads logs through it")
@pytest.mark.parametrize("unit", ["ledmatrix.service", "ledmatrix"])
def test_each_journalctl_rule_is_tagged(unit):
@pytest.mark.parametrize("selector", ["-u ledmatrix.service", "-u ledmatrix",
"-t ledmatrix"])
def test_each_journalctl_rule_is_tagged(selector):
"""Every selector, so removing one cannot pass by the others' presence."""
matching = [r for r in _grant_lines()
if "JOURNALCTL_PATH" in r and f"-u {unit} " in r]
assert matching, f"no journalctl rule for -u {unit}"
if "JOURNALCTL_PATH" in r and f"{selector} " in r]
assert matching, f"no journalctl rule for {selector}"
untagged = [r for r in matching if "NOEXEC" not in r]
assert not untagged, f"untagged journalctl rule(s): {untagged}"
+95
View File
@@ -0,0 +1,95 @@
"""The display unit must cap glibc's malloc arenas.
glibc hands each allocating thread its own malloc arena, up to 8 x CPU count,
and an arena that has grown is never returned to the OS. This process runs
threads for the render loop, the update workers and the background fetchers, so
on a 3-core Pi the ceiling is 24 arenas.
Measured on a live rig, 2.5 hours in:
RSS 1030 MB
Private_Dirty 988 MB
anonymous mappings > 10 MB 23 (ceiling is 8 x 3 = 24)
largest few 104, 79, 66, 63, 63 MB, on 64 MB-aligned addresses
against live data that accounts for perhaps 15 MB -- the widest scroll strip
observed was 35,746 x 64, about 7 MB as RGB and the same again for its numpy
mirror. Repeated sampling showed RSS flat between 990 and 1030 MB rather than
climbing, so this is arena bloat rather than a leak: memory Python has freed
but glibc is holding per-arena.
The device had 59 MB free at the time.
Capping the arena count trades a little allocator concurrency for that resident
memory. The render loop is latency-sensitive, so if p99 frame time regresses the
right response is to raise this rather than remove it.
"""
import re
from pathlib import Path
import pytest
UNIT = (Path(__file__).resolve().parent.parent / "systemd" / "ledmatrix.service")
#: The value the unit is expected to carry. 2 is the usual choice for a
#: threaded Python process; 1-4 all keep some of the saving, but only one of
#: them is what this project ships.
EXPECTED_ARENA_MAX = 2
def _environment(unit_text):
return dict(
line.split("=", 2)[1:3] if line.count("=") >= 2 else (line.split("=", 1)[1], "")
for line in unit_text.splitlines()
if line.startswith("Environment=")
)
def test_the_unit_exists():
assert UNIT.is_file(), f"{UNIT} is missing"
def test_malloc_arena_max_is_capped():
env = _environment(UNIT.read_text(encoding="utf-8"))
assert "MALLOC_ARENA_MAX" in env, (
"the display unit does not cap glibc arenas; on a 3-core Pi the default "
"ceiling is 24 and a measured rig held 23 of them, 920 MB"
)
value = int(env["MALLOC_ARENA_MAX"])
# Pinned, not a range. A range let a change to 4 -- which hands most of the
# saving back -- pass unnoticed, which was the point of the finding that
# prompted this. Raising it is a legitimate response to a frame-time
# regression, but it should be a visible edit here rather than a silent
# drift, so the number lives in one place and changing it shows up in
# review.
assert value == EXPECTED_ARENA_MAX, (
f"MALLOC_ARENA_MAX={value}, expected {EXPECTED_ARENA_MAX}. If this was "
"raised deliberately because frame times regressed, update "
"EXPECTED_ARENA_MAX here and say so in the commit."
)
def test_the_reason_is_recorded_next_to_it():
"""A bare tuning knob invites removal by whoever meets it next."""
text = UNIT.read_text(encoding="utf-8")
index = text.index("Environment=MALLOC_ARENA_MAX")
preamble = text[:index].splitlines()[-12:]
comment = "\n".join(line for line in preamble if line.startswith("#"))
assert "arena" in comment.lower(), "no explanation precedes the setting"
assert re.search(r"\d", comment), (
"the explanation cites no measurement, so a reader cannot tell whether "
"it still applies to their hardware"
)
@pytest.mark.parametrize("unit", ["ledmatrix.service"])
def test_the_unit_still_parses_as_ini(unit):
"""systemd will refuse a malformed unit, and the panel stays dark."""
import configparser
path = UNIT.parent / unit
parser = configparser.ConfigParser(strict=False)
# systemd allows repeated keys; ConfigParser needs them merged, not rejected.
parser.read_string(path.read_text(encoding="utf-8"))
assert parser.has_section("Service")
assert parser.has_option("Service", "ExecStart")
+152
View File
@@ -0,0 +1,152 @@
"""An installed unit that no longer matches the repo's must be reported.
Nothing re-applies systemd units after the first install. `git pull` -- what
the web UI's update button runs -- brings a new template into the checkout, but
no code in web_interface/ or src/ copies it to /etc/systemd/system or runs
`systemctl daemon-reload`. The unit that actually runs is whatever
first_time_install.sh wrote on day one.
So every hardening added to a unit is inert on existing installs. Measured on a
live rig: the installed unit was dated 2026-08-06 and the repo's 2026-08-19,
and they differed -- with the result that a MemoryMax=85% present in the repo's
template was not being enforced at all. `systemctl show` reported
MemoryMax=infinity.
This is a warning, not an error, and deliberately not a silent rewrite:
editing files under /etc and restarting services is the installer's job, not
something a display process should do to a machine while it boots.
"""
import logging
from pathlib import Path
from unittest.mock import MagicMock
import pytest
from src.startup_validator import StartupValidator
@pytest.fixture
def validator():
v = StartupValidator(config_manager=MagicMock())
v.logger = logging.getLogger("test")
v.warnings = []
v.errors = []
return v
def test_a_matching_unit_produces_no_warning(validator, tmp_path):
"""The installed unit, substituted exactly as the installer would."""
project_root = Path("src/startup_validator.py").resolve().parent.parent
template_rel = "systemd/ledmatrix.service"
template = project_root / template_rel
if not template.is_file():
pytest.skip("repo unit template not present")
installed = tmp_path / "ledmatrix.service"
installed.write_text(
template.read_text(encoding="utf-8")
.replace("__PROJECT_ROOT_DIR__", str(project_root))
.replace("__USER__", "root"),
encoding="utf-8")
validator._UNITS = ((template_rel, str(installed)),)
validator._validate_systemd_units()
assert not validator.warnings, f"a matching unit warned: {validator.warnings}"
assert not validator.errors
def test_comments_and_blank_lines_are_not_drift():
"""Otherwise every comment the repo adds would look like a changed unit."""
a = "[Service]\n# explains a setting\nExecStart=/x\nRestart=always\n"
b = "[Service]\nExecStart=/x\n\nRestart=always\n"
assert StartupValidator._unit_body(a) == StartupValidator._unit_body(b)
def test_a_changed_directive_is_drift():
a = "[Service]\nExecStart=/x\nMemoryMax=85%\n"
b = "[Service]\nExecStart=/x\n"
assert StartupValidator._unit_body(a) != StartupValidator._unit_body(b)
def test_reordered_directives_are_drift():
"""Order is not noise in a systemd unit.
Repeated directives -- ExecStartPre=, ExecStartPost= -- run in the order
they appear, and a directive that moves between [Unit], [Service] and
[Install] means something different, or nothing, where it lands. This
check used to sort the lines before comparing, which reported no drift for
a unit that had genuinely changed.
"""
a = "[Service]\nExecStartPre=/first\nExecStartPre=/second\n"
b = "[Service]\nExecStartPre=/second\nExecStartPre=/first\n"
assert StartupValidator._unit_body(a) != StartupValidator._unit_body(b), (
"swapping two ExecStartPre= lines changes what runs first, and was "
"being normalised away")
def test_a_directive_moved_between_sections_is_drift():
a = "[Unit]\nDescription=x\n[Service]\nExecStart=/x\n"
b = "[Unit]\nDescription=x\nExecStart=/x\n[Service]\n"
assert StartupValidator._unit_body(a) != StartupValidator._unit_body(b), (
"ExecStart= in [Unit] is not the same unit, and sorting hid it")
def test_cosmetic_differences_do_not_warn(validator, tmp_path):
"""Through the real comparison, not the helper.
The repo's template carries explanatory comments the installed copy may not
have, and the installer does not preserve ordering or blank lines. If those
counted as drift, every boot would warn and the warning would be ignored.
Asserting this on _unit_body alone would not catch a comparison that stopped
calling it -- which is exactly what a careless edit does.
"""
project_root = Path("src/startup_validator.py").resolve().parent.parent
template_rel = "systemd/ledmatrix.service"
template = project_root / template_rel
if not template.is_file():
pytest.skip("repo unit template not present")
substituted = (template.read_text(encoding="utf-8")
.replace("__PROJECT_ROOT_DIR__", str(project_root))
.replace("__USER__", "root"))
# Cosmetic means comments, blank lines and stray indentation -- the things
# the installer really does drop. Not reordering: that changes the unit,
# and is asserted as drift above.
directives = [line.strip() for line in substituted.splitlines()
if line.strip() and not line.strip().startswith("#")]
installed = tmp_path / "ledmatrix.service"
installed.write_text(
"\n\n".join(" " + d for d in directives) + "\n", encoding="utf-8")
validator._UNITS = ((template_rel, str(installed)),)
validator._validate_systemd_units()
assert not validator.warnings, (
f"cosmetic-only difference reported as drift: {validator.warnings}")
def test_drift_is_reported_as_a_warning(validator, tmp_path):
"""The whole point: a real difference must surface, and only as a warning."""
installed = tmp_path / "ledmatrix.service"
installed.write_text("[Service]\nExecStart=/usr/bin/python3 /x/run.py\n")
project_root = Path("src/startup_validator.py").resolve().parent.parent
template_rel = "systemd/ledmatrix.service"
template = project_root / template_rel
if not template.is_file():
pytest.skip("repo unit template not present")
validator._UNITS = ((template_rel, str(installed)),)
validator._validate_systemd_units()
assert validator.warnings, "a differing unit produced no warning"
assert "install_service.sh" in validator.warnings[0], (
"the warning does not tell the user how to fix it")
assert not validator.errors, "drift must not be fatal at startup"
def test_a_missing_installed_unit_is_silent(validator, tmp_path):
"""Development checkouts have no /etc/systemd unit; that is not drift."""
validator._UNITS = (("systemd/ledmatrix.service", str(tmp_path / "absent.service")),)
validator._validate_systemd_units()
assert not validator.warnings
assert not validator.errors
+85
View File
@@ -0,0 +1,85 @@
"""A check that could not run must not be reported as "up to date".
check-update returned update_available=False whenever git failed. The banner
is the only route to the update button, so a checkout git refuses to touch
looked exactly like a current one -- permanently, and with nothing for the
user to act on. The usual cause is an install performed as root, after which
every git command fails with "detected dubious ownership".
"""
import subprocess
import sys
from pathlib import Path
from unittest.mock import patch
import pytest
from flask import Flask
sys.path.insert(0, str(Path(__file__).resolve().parent.parent))
from web_interface.blueprints import api_v3 as mod # noqa: E402
from web_interface.blueprints.api_v3 import api_v3 # noqa: E402
DUBIOUS = ("fatal: detected dubious ownership in repository at "
"'/home/pi/LEDMatrix'\nTo add an exception for this directory, call:\n"
"\tgit config --global --add safe.directory /home/pi/LEDMatrix\n")
@pytest.fixture
def client():
app = Flask(__name__)
app.config['TESTING'] = True
app.register_blueprint(api_v3, url_prefix='/api/v3')
mod._update_check_cache['result'] = None
mod._update_check_cache['ts'] = 0
return app.test_client()
def _fetch_fails(stderr: bytes):
def fake_run(args, **kwargs):
if args[:2] == ['git', 'fetch']:
return subprocess.CompletedProcess(args, 1, stdout=b'', stderr=stderr)
return subprocess.CompletedProcess(args, 0, stdout='', stderr='')
return fake_run
class TestFailedCheckIsNotSilence:
def test_dubious_ownership_is_reported_not_swallowed(self, client):
with patch.object(mod.subprocess, 'run', _fetch_fails(DUBIOUS.encode())):
data = client.get('/api/v3/system/check-update').get_json()
assert data['check_failed'] is True, (
"a git failure was reported as a successful 'no update' check")
assert data['update_available'] is False
def test_the_message_tells_the_user_what_to_do(self, client):
with patch.object(mod.subprocess, 'run', _fetch_fails(DUBIOUS.encode())):
data = client.get('/api/v3/system/check-update').get_json()
assert 'chown' in data['error'], (
"dubious ownership is unactionable without the fix command")
assert 'root' in data['error']
def test_an_ordinary_git_failure_still_surfaces(self, client):
with patch.object(mod.subprocess, 'run',
_fetch_fails(b'fatal: some other git problem\n')):
data = client.get('/api/v3/system/check-update').get_json()
assert data['check_failed'] is True
assert 'some other git problem' in data['error']
def test_offline_reads_as_offline(self, client):
with patch.object(mod.subprocess, 'run',
_fetch_fails(b'fatal: could not resolve host: github.com\n')):
data = client.get('/api/v3/system/check-update').get_json()
assert 'Could not reach GitHub' in data['error']
class TestSuccessPathUnchanged:
def test_up_to_date_carries_no_failure_flag(self, client):
def fake_run(args, **kwargs):
if args[:2] == ['git', 'fetch']:
return subprocess.CompletedProcess(args, 0, stdout=b'', stderr=b'')
if args[:2] == ['git', 'rev-parse']:
return subprocess.CompletedProcess(args, 0, stdout='abc123\n', stderr='')
return subprocess.CompletedProcess(args, 0, stdout='0\n', stderr='')
with patch.object(mod.subprocess, 'run', fake_run):
data = client.get('/api/v3/system/check-update').get_json()
assert data['update_available'] is False
assert not data.get('check_failed'), "a healthy check must not look like a failure"
+84
View File
@@ -0,0 +1,84 @@
"""A pull that changed nothing on the running system is not an applied update.
git_pull replaces files on disk and restarts nothing -- there is no systemctl
call anywhere in the handler. The display and web services keep running the
code they loaded at boot, so the user is told "Code updated successfully" and
sees no change until they happen to reboot. The response now says whether a
restart is owed, and the UI raises the existing restart-pending banner.
"""
import subprocess
import sys
from pathlib import Path
from unittest.mock import patch
import pytest
from flask import Flask
sys.path.insert(0, str(Path(__file__).resolve().parent.parent))
from web_interface.blueprints import api_v3 as mod # noqa: E402
from web_interface.blueprints.api_v3 import api_v3 # noqa: E402
@pytest.fixture
def client():
app = Flask(__name__)
app.config['TESTING'] = True
app.register_blueprint(api_v3, url_prefix='/api/v3')
# The handler consults these after a successful pull; None is the
# "not wired up" case it already guards for.
api_v3.plugin_store_manager = None
api_v3.config_manager = None
return app.test_client()
def _git(heads, pull_rc=0, pull_out='Updating a1b2c3..d4e5f6\n'):
"""Fake git. `heads` are the successive answers to rev-parse HEAD."""
seq = list(heads)
def run(args, **kwargs):
def ok(stdout='', rc=0, b=False):
return subprocess.CompletedProcess(
args, rc, stdout=(stdout.encode() if b else stdout),
stderr=(b'' if b else ''))
if args[:2] == ['git', 'rev-parse'] and args[-1] == 'HEAD':
return ok(seq.pop(0) + '\n' if seq else 'deadbeef\n')
if 'symbolic-full-name' in args or '@{u}' in args:
return ok('origin/main\n')
if args[:2] == ['git', 'status']:
return ok('')
if args[:2] == ['git', 'diff']:
return ok('')
if args[:2] == ['git', 'pull']:
return ok(pull_out, pull_rc)
return ok('')
return run
def _pull(client):
return client.post('/api/v3/system/action',
json={'action': 'git_pull'}).get_json()
class TestRestartIsRequestedWhenCodeChanged:
def test_a_pull_that_moved_head_asks_for_a_restart(self, client):
with patch.object(mod.subprocess, 'run', _git(['aaa111', 'bbb222'])):
data = _pull(client)
assert data['status'] == 'success'
assert data['restart_required'] is True, (
"new code on disk, services still running the old code, and "
"nothing told the user to restart")
def test_already_up_to_date_does_not(self, client):
with patch.object(mod.subprocess, 'run',
_git(['aaa111', 'aaa111'], pull_out='Already up to date.\n')):
data = _pull(client)
assert data['status'] == 'success'
assert data['restart_required'] is False, (
"prompting after a no-op update trains users to ignore the prompt")
def test_a_failed_pull_does_not(self, client):
with patch.object(mod.subprocess, 'run', _git(['aaa111'], pull_rc=1)):
data = _pull(client)
assert data['status'] == 'error'
assert data['restart_required'] is False
+99
View File
@@ -0,0 +1,99 @@
"""Frame pacing and FPS health reporting must not depend on the wall clock.
These devices have no RTC, so the system clock jumps by however wrong boot
time was the moment NTP first syncs. The render loop sleeps the *remainder*
of each frame budget:
frame_elapsed = <now> - frame_started
time.sleep(max(0.0, frame_interval - frame_elapsed))
With a wall-clock `now`, a backward jump makes frame_elapsed negative, so
`frame_interval - frame_elapsed` exceeds the whole budget and the render loop
stalls for the size of the correction. A forward jump instead inflates the
p99 and worst-frame numbers the telemetry reports.
"""
import ast
import sys
from pathlib import Path
sys.path.insert(0, str(Path(__file__).resolve().parent.parent))
COORD = (Path(__file__).resolve().parent.parent
/ "src" / "vegas_mode" / "coordinator.py")
TREE = ast.parse(COORD.read_text(encoding="utf-8"))
def _assignments_of(name):
"""Every `name = <expr>` in the module, as unparsed source."""
out = []
for node in ast.walk(TREE):
if isinstance(node, ast.Assign):
for target in node.targets:
if isinstance(target, ast.Name) and target.id == name:
out.append((node.lineno, ast.unparse(node.value)))
return out
def test_per_frame_timestamps_are_monotonic():
for name in ("frame_started", "frame_elapsed"):
assigns = _assignments_of(name)
assert assigns, f"{name} is no longer assigned -- has the loop changed?"
for lineno, expr in assigns:
assert "time.time()" not in expr, (
f"{name} at line {lineno} uses the wall clock ({expr!r}). A "
"backward NTP step makes the per-frame delta negative and the "
"loop then sleeps longer than the whole frame budget.")
assert "time.monotonic()" in expr, (
f"{name} at line {lineno} is {expr!r}, expected monotonic")
def test_the_fps_window_is_monotonic():
for lineno, expr in _assignments_of("current_time"):
assert "time.monotonic()" in expr, (
f"current_time at line {lineno} is {expr!r}; fps is frames divided "
"by this delta, so a clock step would corrupt the rate itself")
def test_health_state_is_not_reset_every_iteration():
"""run_iteration() runs once per cycle -- locals here reset every few seconds.
As locals, `last_fps_health_log = 0.0` made the 300s heartbeat fire on the
first sample of every iteration, and a recovery spanning two iterations was
never reported because was_degraded had already gone back to False.
"""
run_iteration = next(
(n for n in ast.walk(TREE)
if isinstance(n, ast.FunctionDef) and n.name == "run_iteration"), None)
assert run_iteration is not None, "run_iteration() not found"
local_names = {t.id for n in ast.walk(run_iteration)
if isinstance(n, ast.Assign)
for t in n.targets if isinstance(t, ast.Name)}
for leaked in ("last_fps_health_log", "was_degraded"):
assert leaked not in local_names, (
f"{leaked} is a local of run_iteration() again, so it resets every "
"cycle -- the heartbeat degenerates to once per iteration")
body = ast.unparse(run_iteration)
assert "self._fps_last_health_log" in body and "self._fps_was_degraded" in body, (
"the health state should live on the coordinator, across iterations")
def test_start_clears_stale_health_state():
"""A new run must not inherit "was degraded" from the previous one."""
start = next((n for n in ast.walk(TREE)
if isinstance(n, ast.FunctionDef) and n.name == "start"), None)
assert start is not None, "start() not found"
body = ast.unparse(start)
assert "self._fps_last_health_log" in body and "self._fps_was_degraded" in body, (
"start() does not reset the FPS health state")
def test_the_degraded_threshold_is_documented():
"""The 90% band is deliberate; say so where the constant is defined."""
source = COORD.read_text(encoding="utf-8")
idx = source.index("_FPS_HEALTHY_FRACTION = ")
preamble = source[max(0, idx - 700):idx]
assert "90%" in preamble or "0.9" in preamble, (
"the degradation threshold is not explained at its definition, so "
"'below target' reads as a bug rather than a deliberate band")
+73
View File
@@ -0,0 +1,73 @@
"""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 _logger_calls(path, *levels):
"""Direct logger.<level>(...) 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 in levels
and getattr(node.func.value, "id", None) == "logger"):
found.append(node.lineno)
return found
def _info_calls(path):
"""Direct logger.info(...) call sites in a module."""
return _logger_calls(path, "info")
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.
Counted from the AST rather than with source.count(): the text form also
matches comments, docstrings and string literals -- including this
module's own docstring, which names these levels -- so a real
logger.error() could be demoted while the tally stayed put.
"""
loud = _logger_calls(ADAPTER, "warning", "error", "exception")
assert len(loud) >= 15, \
f"only {len(loud)} warning/error/exception calls remain: {loud}"
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
@@ -194,15 +194,46 @@ class TestSavePluginConfig:
def test_secret_count_message_counts_top_level_keys(self, env):
# Pinned: the "(N secret field(s))" message counts TOP-LEVEL keys of
# the separated secrets dict. Here that is 2: the posted accounts
# array (all its item tokens count as ONE key) plus the schema's
# api_key default ("") that merge_with_defaults adds before
# separation.
# the separated secrets dict. Here that is 1: the posted accounts
# array, whose item tokens all count as ONE key.
#
# It was 2 before blank secrets were dropped, the second being the
# schema's api_key default (""), which merge_with_defaults adds to
# every save. Counting it was the visible edge of a real bug: that
# injected blank was merged over the stored api_key, so saving any
# unrelated field destroyed the credential. See
# test_an_unrelated_edit_does_not_erase_a_stored_secret.
resp = self._save(env, {
"accounts": [{"name": "a", "token": "t"}],
})
message = resp.get_json()["message"]
assert "(2 secret field(s) saved to config_secrets.json)" in message
assert "(1 secret field(s) saved to config_secrets.json)" in message
def test_an_unrelated_edit_does_not_erase_a_stored_secret(self, env):
"""Editing one field must not wipe the plugin's API key.
The config form renders secrets masked, so the browser posts them
back blank; merge_with_defaults injects a blank api_key even when
the client omits it entirely. Either way a "" reached the secrets
file and deep_merge wrote it over the stored credential.
"""
assert self._save(env, {"api_key": "REAL-KEY-0123456789",
"city": "Austin"}).status_code == 200
assert _on_disk(env.secrets_file)[PLUGIN_ID]["api_key"] == \
"REAL-KEY-0123456789"
# the user changes the city; the masked api_key rides along blank
assert self._save(env, {"api_key": "", "city": "Dallas"}).status_code == 200
assert _on_disk(env.secrets_file)[PLUGIN_ID]["api_key"] == \
"REAL-KEY-0123456789", "an unrelated edit destroyed the API key"
assert env.fresh_load()[PLUGIN_ID]["city"] == "Dallas"
def test_a_secret_can_still_be_changed(self, env):
"""Dropping blanks must not stop a real new value from being saved."""
self._save(env, {"api_key": "first-key"})
self._save(env, {"api_key": "second-key"})
assert _on_disk(env.secrets_file)[PLUGIN_ID]["api_key"] == "second-key"
def test_resave_replaces_stored_secrets_list_wholesale(self, env):
# Characterized: api_v3's deep_merge intentionally replaces lists,
@@ -0,0 +1,123 @@
"""GET /config/secrets must not hand out credentials, and the client's
read-modify-write cycle must not destroy them.
This interface has no authentication. The endpoint returned the whole
config_secrets.json to anyone who could reach the port; on one rig that was a
40-character GitHub token, a 183-character Home Assistant token and three API
keys. Masking it alone is not enough: the only client fetches every secret,
edits one field and posts all of them back, so the write path has to treat an
echoed mask as "unchanged".
"""
import json
import sys
from pathlib import Path
sys.path.insert(0, str(Path(__file__).parent))
from test_api_v3_secret_roundtrip import env, _on_disk # noqa: F401,E402
from src.web_interface.secret_helpers import SECRET_MASK # noqa: E402
STORED = {
"github": {"api_token": "ghp_" + "x" * 36},
"ledmatrix-weather": {"api_key": "w" * 32},
"incoming-packages": {"ha_token": "h" * 183},
"unset-plugin": {"api_key": ""},
"placeholder-plugin": {"api_key": "YOUR_API_KEY_HERE"},
}
def _seed(env):
env.secrets_file.write_text(json.dumps(STORED))
def _get(env):
r = env.client.get("/api/v3/config/secrets")
assert r.status_code == 200, r.get_data(as_text=True)[:200]
return r.get_json()["data"]
def test_no_credential_leaves_the_process(env):
_seed(env)
body = json.dumps(_get(env))
for secret in ("ghp_" + "x" * 36, "w" * 32, "h" * 183):
assert secret not in body, "endpoint returned a stored credential"
def test_set_and_unset_remain_distinguishable(env):
_seed(env)
data = _get(env)
assert data["github"]["api_token"] == SECRET_MASK
assert data["unset-plugin"]["api_key"] == ""
assert data["placeholder-plugin"]["api_key"] == "YOUR_API_KEY_HERE"
def test_the_clients_read_modify_write_preserves_every_other_secret(env):
"""What the GitHub-token save button actually does."""
_seed(env)
secrets = _get(env) # everything arrives masked
secrets["github"]["api_token"] = "ghp_" + "n" * 36 # user changes one
r = env.client.post("/api/v3/config/raw/secrets", json=secrets)
assert r.status_code == 200, r.get_data(as_text=True)[:200]
on_disk = _on_disk(env.secrets_file)
assert on_disk["github"]["api_token"] == "ghp_" + "n" * 36, "new token not saved"
assert on_disk["ledmatrix-weather"]["api_key"] == "w" * 32
assert on_disk["incoming-packages"]["ha_token"] == "h" * 183
def test_a_mask_echoed_back_is_never_stored(env):
_seed(env)
# Assert the write succeeded. A 500 leaves the old file in place, so the
# assertions below would hold without the write path running at all.
resp = env.client.post("/api/v3/config/raw/secrets", json=_get(env))
assert resp.status_code == 200, resp.get_data(as_text=True)[:200]
on_disk = _on_disk(env.secrets_file)
assert SECRET_MASK not in json.dumps(on_disk), "the mask was stored as a secret"
assert on_disk["github"]["api_token"] == "ghp_" + "x" * 36
def test_a_brand_new_secret_can_still_be_added(env):
_seed(env)
env.client.post("/api/v3/config/raw/secrets",
json={"new-plugin": {"api_key": "brand-new"}})
on_disk = _on_disk(env.secrets_file)
assert on_disk["new-plugin"]["api_key"] == "brand-new"
assert on_disk["github"]["api_token"] == "ghp_" + "x" * 36
def test_a_list_of_secrets_keeps_its_shape(env):
"""A list must not be masked as though it were one scalar.
accounts: [{...}, {...}] came back as a single '••••••••', so a caller
could not see how many entries existed, and the raw editor was shown a
string where the file holds an array.
"""
env.secrets_file.write_text(json.dumps({
"myplugin": {"accounts": [{"name": "a", "token": "tok-a"},
{"name": "b", "token": "tok-b"}]}}))
accounts = _get(env)["myplugin"]["accounts"]
assert isinstance(accounts, list), "the list was flattened to a scalar"
assert len(accounts) == 2, "entries were lost"
assert all(isinstance(a, dict) for a in accounts), "entry shape was lost"
assert "tok-a" not in json.dumps(accounts), "a token survived masking"
def test_a_list_posted_back_unchanged_is_left_alone(env):
"""Lists merge by replacement, so a half-masked list must not be stored."""
original = {"myplugin": {"accounts": [{"name": "a", "token": "tok-a"},
{"name": "b", "token": "tok-b"}]}}
env.secrets_file.write_text(json.dumps(original))
resp = env.client.post("/api/v3/config/raw/secrets", json=_get(env))
assert resp.status_code == 200, resp.get_data(as_text=True)[:200]
assert _on_disk(env.secrets_file)["myplugin"]["accounts"] == \
original["myplugin"]["accounts"], "round-tripping the mask damaged the list"
def test_a_fully_supplied_list_still_saves(env):
env.secrets_file.write_text(json.dumps(
{"myplugin": {"accounts": [{"name": "a", "token": "old"}]}}))
body = _get(env)
body["myplugin"]["accounts"] = [{"name": "a", "token": "new"}]
resp = env.client.post("/api/v3/config/raw/secrets", json=body)
assert resp.status_code == 200, resp.get_data(as_text=True)[:200]
assert _on_disk(env.secrets_file)["myplugin"]["accounts"][0]["token"] == "new"
+135 -17
View File
@@ -21,7 +21,9 @@ logger = logging.getLogger(__name__)
# Import new infrastructure
from src.web_interface.api_helpers import success_response, error_response, validate_request_json
from src.web_interface.errors import ErrorCode
from src.web_interface.secret_helpers import find_secret_fields, separate_secrets
from src.web_interface.secret_helpers import (find_secret_fields, mask_all_secret_values,
remove_empty_secrets, separate_secrets,
strip_masked_values)
from src.web_interface.error_handler import describe_exception, redact_text
from src.plugin_system.operation_types import OperationType
from src.web_interface.validators import (
@@ -262,15 +264,54 @@ def _stop_display_service():
result['status'] = status
return result
#: Field names whose value is a credential. Matched by name because this
#: endpoint returns the whole config, core keys included, and core config has
#: no schema to carry x-secret markers.
_CREDENTIAL_NAME_PARTS = ("password", "passwd", "secret", "token", "api_key",
"apikey", "access_key", "private_key", "client_secret")
def _looks_like_a_credential(name: str) -> bool:
lowered = name.lower()
return any(part in lowered for part in _CREDENTIAL_NAME_PARTS)
def _redact_credentials(value):
"""A copy of `value` with credential-named fields blanked.
/config/main returned the raw config to anyone who could reach the port,
and this interface has no authentication. On one rig that meant a 40-char
GitHub token, a 183-char Home Assistant token and five API keys were
readable by anything on the LAN.
The x-secret masking used by the plugin config endpoints does not help
here: this endpoint never consults a schema, and core keys such as
github.api_token have no schema to mark. Matching on the field name is
blunt, but for a whole-config dump the right default is that anything
named like a credential does not leave the process.
Blanked rather than removed, and safe to blank: POST /config/main merges
into the loaded config and only writes the keys it was given, so a client
that round-trips this response cannot erase a secret it never saw.
"""
if isinstance(value, dict):
return {k: ("" if _looks_like_a_credential(k) and not isinstance(v, (dict, list))
else _redact_credentials(v))
for k, v in value.items()}
if isinstance(value, list):
return [_redact_credentials(item) for item in value]
return value
@api_v3.route('/config/main', methods=['GET'])
def get_main_config():
"""Get main configuration"""
"""Get main configuration, with credentials redacted."""
try:
if not api_v3.config_manager:
return jsonify({'status': 'error', 'message': 'Config manager not initialized'}), 500
config = api_v3.config_manager.load_config()
return jsonify({'status': 'success', 'data': config})
return jsonify({'status': 'success', 'data': _redact_credentials(config)})
except Exception as e:
logger.error('Unhandled exception', exc_info=True)
return jsonify({'status': 'error', 'message': 'An error occurred; see logs for details', 'details': describe_exception(e)}), 500
@@ -715,10 +756,12 @@ def save_main_config():
if not data:
return jsonify({'status': 'error', 'message': 'No data provided'}), 400
import logging
logging.error(f"DEBUG: save_main_config received data: {data}")
logging.error(f"DEBUG: Content-Type header: {request.content_type}")
logging.error(f"DEBUG: Headers: {dict(request.headers)}")
# What arrives here is the config itself, and the headers carry the
# session cookie -- neither belongs in the journal, least of all at
# ERROR on every save. The shape of the request is the part with
# diagnostic value, so log that, at the level it deserves.
logger.debug("save_main_config: %s, %d top-level key(s)",
request.content_type or 'no content-type', len(data))
# Merge with existing config (similar to original implementation)
current_config = api_v3.config_manager.load_config()
@@ -1216,6 +1259,11 @@ def save_main_config():
# Separate secrets from regular config (same logic as save_plugin_config)
regular_config, secrets_config = separate_secrets(plugin_config, secret_fields)
# The config form renders secrets masked, so every save posts
# them back blank. Without this the blank is merged over the
# stored value and the credential is destroyed by the act of
# changing an unrelated setting. A blank means "unchanged".
secrets_config = remove_empty_secrets(secrets_config)
# PRE-PROCESSING: Preserve 'enabled' state if not in regular_config
# This prevents overwriting the enabled state when saving config from a form that doesn't include the toggle
@@ -1333,7 +1381,12 @@ def get_secrets_config():
return jsonify({'status': 'error', 'message': 'Config manager not initialized'}), 500
config = api_v3.config_manager.get_raw_file_content('secrets')
return jsonify({'status': 'success', 'data': config})
# This interface has no authentication, and this file is nothing but
# credentials. It was handing all of them to anyone who could reach
# the port. Values are masked; empty and YOUR_* placeholders are left
# alone so a client can still tell "set" from "not set".
return jsonify({'status': 'success',
'data': mask_all_secret_values(config)})
except Exception as e:
logger.error('Unhandled exception', exc_info=True)
return jsonify({'status': 'error', 'message': 'An error occurred; see logs for details', 'details': describe_exception(e)}), 500
@@ -1401,8 +1454,19 @@ def save_raw_secrets_config():
if not data:
return jsonify({'status': 'error', 'message': 'No data provided'}), 400
# Save the secrets config
api_v3.config_manager.save_raw_file_content('secrets', data)
# The GET above masks what it returns, and this endpoint's only client
# reads the whole file, edits one field and posts all of it back. So
# most of what arrives here is the mask, echoed rather than changed --
# storing it verbatim would replace every untouched credential with
# eight bullets. Strip those, then merge onto what is already stored,
# which makes "unchanged" mean unchanged.
#
# The cost is that a secret can no longer be cleared by blanking it.
# That needs its own affordance; a control that erases credentials as
# a side effect of saving an unrelated one is not it.
current = api_v3.config_manager.get_raw_file_content('secrets') or {}
merged = deep_merge(current, strip_masked_values(data))
api_v3.config_manager.save_raw_file_content('secrets', merged)
# Reload GitHub token in plugin store manager if it exists
if api_v3.plugin_store_manager:
@@ -1660,13 +1724,22 @@ def resolve_pull_command(project_dir):
backup, or following an install guide that names one. The update button
then reports a failure the user cannot act on.
``--autostash`` is passed for the same reason. Rebase refuses to start
when any tracked file is modified, and on these installs something always
is: first_time_install.sh chmods five scripts that git tracked as 644, so
every machine that ran the installer carries five permanent mode changes
and the update button reports "cannot pull with rebase: You have unstaged
changes". Those modes are corrected in this commit, but a user cannot pull
the correction while the pull is what is blocked, and any other local edit
would reproduce it anyway. Autostash reapplies the changes afterwards.
Returns ``(args, note, error)``. When ``origin/<branch>`` exists the pull
is made explicit against it, so the update proceeds and the branch is
given tracking information afterwards.
"""
upstream = _git_upstream(project_dir)
if upstream:
return ['git', 'pull', '--rebase'], '', None
return ['git', 'pull', '--rebase', '--autostash'], '', None
branch = _git_current_branch(project_dir)
if not branch:
@@ -1676,7 +1749,7 @@ def resolve_pull_command(project_dir):
)
if _git_remote_branch_exists(project_dir, branch):
return (
['git', 'pull', '--rebase', 'origin', branch],
['git', 'pull', '--rebase', '--autostash', 'origin', branch],
f"Branch '{branch}' had no upstream; pulled from origin/{branch} and set it as the upstream.",
None,
)
@@ -1824,6 +1897,33 @@ def get_system_version():
_update_check_cache: Dict[str, Any] = {'result': None, 'ts': 0.0}
_UPDATE_CHECK_TTL = 300 # 5 minutes — avoids a git fetch on every page load
def _update_check_failed(detail: str) -> Dict[str, Any]:
"""A check that could not run is not the same as being up to date.
Reporting update_available=False on a git failure hides the banner, and
the banner is the only route to the update button -- so a checkout git
refuses to touch looks exactly like a current one, permanently. The most
common cause is an install performed as root: git then reports "dubious
ownership" and every command fails, including the fetch here.
"""
return {'update_available': False, 'remote_sha': 'unknown',
'commits_behind': 0, 'check_failed': True, 'error': detail}
def _describe_git_failure(stderr: str) -> str:
"""Turn git's stderr into something the user can act on."""
text = (stderr or '').strip()
if 'dubious ownership' in text or 'detected dubious ownership' in text:
return ("This checkout is owned by a different user than the one "
"running the web interface, so git refuses to use it. It is "
"usually the result of installing as root. Fix the ownership "
"and the update will work: sudo chown -R $USER:$USER "
+ str(PROJECT_ROOT))
if 'could not resolve host' in text.lower() or 'network is unreachable' in text.lower():
return "Could not reach GitHub to check for updates."
return "Could not check for updates: " + (text.splitlines()[0] if text else "git failed")
@api_v3.route('/system/check-update', methods=['GET'])
def check_for_update():
"""Check whether a newer LEDMatrix commit is available on origin/main."""
@@ -1839,12 +1939,13 @@ def check_for_update():
capture_output=True, timeout=10, cwd=cwd,
)
if fetch_result.returncode != 0:
stderr = fetch_result.stderr.decode(errors='replace').strip()
logger.warning("check-update: git fetch failed (rc=%d): %s",
fetch_result.returncode,
fetch_result.stderr.decode(errors='replace').strip())
_update_check_cache['result'] = _safe
fetch_result.returncode, stderr)
failed = _update_check_failed(_describe_git_failure(stderr))
_update_check_cache['result'] = failed
_update_check_cache['ts'] = now
return jsonify(_safe)
return jsonify(failed)
local = subprocess.run(
['git', 'rev-parse', 'HEAD'],
capture_output=True, text=True, timeout=5, cwd=cwd,
@@ -1872,7 +1973,8 @@ def check_for_update():
return jsonify(result)
except Exception as e:
logger.warning("check-update failed: %s", e)
return jsonify(_safe)
return jsonify(_update_check_failed(
"Could not check for updates; see logs for details."))
@api_v3.route('/system/action', methods=['POST'])
def execute_system_action():
@@ -1999,6 +2101,11 @@ def execute_system_action():
except subprocess.TimeoutExpired:
logger.warning("git rev-parse timed out before pull")
# Whether the pull actually brought new code in. "Already up to
# date" is a success too, and prompting for a restart then would
# train users to ignore the prompt.
code_changed = False
# Perform the git pull. Branches without an upstream were given
# an explicit "origin <branch>" above so the update still works.
result = subprocess.run(
@@ -2042,6 +2149,7 @@ def execute_system_action():
capture_output=True, text=True, timeout=10, cwd=project_dir)
new_head = _post.stdout.strip() if _post.returncode == 0 else None
if old_head and new_head and old_head != new_head:
code_changed = True
diff = subprocess.run(
['git', 'diff', '--name-only', f'{old_head}..{new_head}'],
capture_output=True, text=True, timeout=15, cwd=project_dir)
@@ -2101,9 +2209,14 @@ def execute_system_action():
if ln.strip()), '')
pull_message = f"Update failed: {detail}" if detail else "Update failed; check logs for details"
# Nothing here restarts anything: the pull replaces files on
# disk while the display and web services keep running the code
# they loaded at boot. Without this the user is told the update
# succeeded and sees no change until they happen to reboot.
return jsonify({
'status': 'success' if result.returncode == 0 else 'error',
'message': pull_message,
'restart_required': bool(result.returncode == 0 and code_changed),
})
elif action == 'checkout_branch':
# Switch branches from the Tools tab. Needed because a checkout
@@ -5617,6 +5730,11 @@ def save_plugin_config():
# Separate secrets from regular config (handles nested configs and
# array-item secrets — see src/web_interface/secret_helpers.py)
regular_config, secrets_config = separate_secrets(plugin_config, secret_fields)
# The config form renders secrets masked, so every save posts
# them back blank. Without this the blank is merged over the
# stored value and the credential is destroyed by the act of
# changing an unrelated setting. A blank means "unchanged".
secrets_config = remove_empty_secrets(secrets_config)
# Get current configs
current_config = api_v3.config_manager.load_config()
+17 -3
View File
@@ -116,14 +116,25 @@ document.body.addEventListener('htmx:afterRequest', function(event) {
// ===== Restart-pending banner =====
// Shown after restart-requiring saves; persists across tab switches (and
// reloads, via sessionStorage) until the display restarts or it's dismissed.
window.showRestartPending = function() {
try { sessionStorage.setItem('ledmatrix-restart-pending', '1'); } catch { /* private browsing */ }
window.showRestartPending = function(message) {
try {
sessionStorage.setItem('ledmatrix-restart-pending', '1');
// Persisted alongside the flag: a code update and a config save want
// different wording, and the banner outlives the page that raised it.
if (message) sessionStorage.setItem('ledmatrix-restart-pending-text', message);
else sessionStorage.removeItem('ledmatrix-restart-pending-text');
} catch { /* private browsing */ }
const banner = document.getElementById('restart-pending-banner');
const text = document.getElementById('restart-pending-text');
if (text && message) text.textContent = message;
if (banner) banner.style.display = 'block';
};
window.dismissRestartPending = function() {
try { sessionStorage.removeItem('ledmatrix-restart-pending'); } catch { /* no-op */ }
try {
sessionStorage.removeItem('ledmatrix-restart-pending');
sessionStorage.removeItem('ledmatrix-restart-pending-text');
} catch { /* no-op */ }
const banner = document.getElementById('restart-pending-banner');
if (banner) banner.style.display = 'none';
};
@@ -151,6 +162,9 @@ document.addEventListener('DOMContentLoaded', function() {
try {
if (sessionStorage.getItem('ledmatrix-restart-pending') === '1') {
const banner = document.getElementById('restart-pending-banner');
const saved = sessionStorage.getItem('ledmatrix-restart-pending-text');
const text = document.getElementById('restart-pending-text');
if (text && saved) text.textContent = saved;
if (banner) banner.style.display = 'block';
}
} catch { /* no-op */ }
+8 -6
View File
@@ -4622,15 +4622,17 @@ window.loadGithubToken = function() {
// Handle empty data (secrets file doesn't exist) - API returns {} in this case
const secrets = data.data || {};
const token = secrets.github?.api_token || '';
const configured = token && token !== 'YOUR_GITHUB_PERSONAL_ACCESS_TOKEN';
if (input) {
if (token && token !== 'YOUR_GITHUB_PERSONAL_ACCESS_TOKEN') {
// Token exists and is valid
input.value = token;
showNotification('GitHub token loaded successfully', 'success');
// The endpoint masks what it returns, so this never holds
// the real token -- and the field is deliberately left
// empty rather than filled with the mask, which would be
// saved verbatim the next time the user pressed Save.
input.value = '';
if (configured) {
showNotification('A GitHub token is saved. Enter a new one to replace it.', 'success');
} else {
// No token configured or placeholder value
input.value = '';
showNotification('No GitHub token configured. Enter a new token to save.', 'info');
}
}
+25 -3
View File
@@ -413,7 +413,8 @@
<div class="flex items-center justify-between">
<div class="flex items-center space-x-3">
<i class="fas fa-rotate text-lg"></i>
<span class="text-sm font-medium" aria-live="polite">
<span class="text-sm font-medium" aria-live="polite"
id="restart-pending-text">
Configuration saved &mdash; restart the display to apply the changes
</span>
</div>
@@ -1107,15 +1108,29 @@
fetch('/api/v3/system/check-update')
.then(function(r) { return r.json(); })
.then(function(data) {
var banner = document.getElementById('update-banner');
var btn = document.getElementById('update-banner-btn');
if (data.check_failed) {
// A check that could not run is not the same as being up
// to date. Hiding the banner here made a checkout git
// refuses to touch look permanently current, with no
// route to the update button and nothing to act on.
document.getElementById('update-banner-text').textContent =
data.error || 'Could not check for updates.';
if (btn) btn.style.display = 'none';
banner.style.display = '';
return;
}
if (btn) btn.style.display = '';
if (data.update_available && getDismissedSha() !== data.remote_sha) {
var n = data.commits_behind || 0;
var msg = 'A new LEDMatrix update is available';
if (n > 0) msg += ' (' + n + ' commit' + (n > 1 ? 's' : '') + ')';
document.getElementById('update-banner-text').textContent = msg;
document.getElementById('update-banner').style.display = '';
banner.style.display = '';
try { sessionStorage.setItem('update-sha', data.remote_sha); } catch(e) {}
} else {
document.getElementById('update-banner').style.display = 'none';
banner.style.display = 'none';
}
})
.catch(function() {});
@@ -1146,6 +1161,13 @@
if (data.status === 'success') {
document.getElementById('update-banner').style.display = 'none';
try { sessionStorage.removeItem('update-sha-dismissed'); } catch(e) {}
// The pull replaced files on disk; the running services still
// hold the code they loaded at boot. Ask for the restart that
// makes the update actually take effect.
if (data.restart_required && typeof window.showRestartPending === 'function') {
window.showRestartPending(
'Update installed \u2014 restart the display to run the new code');
}
}
if (typeof showNotification === 'function') {
showNotification(data.message || 'Update complete', data.status || 'success');