Compare commits

...
Author SHA1 Message Date
ChuckandClaude Opus 5 bdced206dc fix(plugins): retain state history by age, with the count as a ceiling (#502)
* fix(plugins): retain state history by age, with the count as a ceiling

Follow-up to the cap in this PR. A flat entry count answers the wrong
question: what a reader wants from this history is "the last couple of
hours", and how many transitions that is depends entirely on the plugin's
update interval. On a real board those span 2s to 3600s, so 200 entries is

    interval   200 entries covers
        2s          3.3 minutes     (flights, live)
       10s         16.7 minutes     (jellyfin)
       60s          1.7 hours       (default)
      300s          8.3 hours       (news)
     3600s          4.2 days

-- the plugin churning hardest, the one worth looking at, keeps the least.

So transitions are now trimmed by AGE first
(STATE_HISTORY_MAX_AGE_SECONDS, two hours), which makes the retained window
comparable whatever the cadence, and the count cap becomes purely a memory
ceiling for pollers fast enough to exceed it inside that window. The
ceiling rises 200 -> 2000: at ~230 bytes an entry that is ~0.5MB per plugin
worst case, and only plugins updating faster than roughly every 4s can
reach it. Steady-state memory is unchanged for everything slower, since the
age trim binds first.

Two details worth stating:

  - The trim reads time.monotonic(), stored alongside each transition,
    rather than the datetime already inside it. A DST shift or an NTP step
    would otherwise make every entry look ancient and flush the history in
    one go. The human-readable timestamp is untouched and still what
    get_state_history() returns.

  - Trimming happens on append, so a plugin that goes quiet keeps its last
    window until it writes again. That is deliberate: it is bounded either
    way, and a lazy trim costs nothing on the hot scheduling path. The
    guarantee is therefore about the SPAN of retained history, not its age
    against the current clock, and the test asserts it that way.

The public shape is unchanged: get_state_history() still returns the same
list of transition dicts, and state_history_count is still the lifetime
total.

test_plugin_state_history_retention.py adds 7 tests. Verified against this
branch with only the age trim removed: 4 fail, 3 pass -- the three that
survive are testing the count ceiling and the monotonic clock, which this
commit does not change. Full suite 3753 passed, 60 skipped.

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

* fix(plugins): build get_state_info() as one locked snapshot

Every field was read under its own lock, so an unload running concurrently
could be observed half-done: 'state' read before clear_state() removed it
and 'state_history_count' read after, handing PluginManager.get_plugin_info()
a plugin that is ENABLED with zero transitions.

The whole payload is now built in one critical section. _lock is an RLock,
so the helpers called inside it can still take it.

The regression test runs a reader against a thread that repeatedly fills and
clears the same plugin, and fails on the first torn snapshot. Verified by
removing only the lock: fails on 3 of 3 runs, passes on 3 of 3 with it.

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-26 08:56:45 -04:00
Ron PierceandClaude Opus 5 39e7f8cbe0 fix(plugins): cap the per-plugin state transition history (#501)
* fix(plugins): cap the per-plugin state transition history

PluginStateManager recorded every state transition in a per-plugin list
and never trimmed it. The only code that removed entries was
clear_state(), called solely from PluginManager.unload_plugin(), so a
plugin that stays loaded -- normal operation -- never released one.

The list is written on the hot scheduling path. Every update cycle
appends twice: _reserve_for_update() sets RUNNING and _finish() sets
ENABLED back again. At the default 60s update interval that is 2,880
entries per plugin per day, and nothing reads them -- get_state_info()
only takes their len(). Pure dead weight.

Measured against the unpatched class, ten plugins on a 60s interval:

    sim uptime   history entries   heap growth
          1 day           28,810        7.7 MB
          7 days         201,610       53.9 MB
         30 days         864,010      230.9 MB   (still climbing)

With the cap it is flat at 2,000 entries / 0.5 MB from day one.

On a 1 GB board 231 MB of garbage is fatal on its own, and the failure
is not a clean OOM: once MemAvailable falls far enough fork() starts
returning ENOMEM, so sshd accepts connections and closes them before its
banner while the kernel still answers pings. The board looks like a
hardware fault and needs a power cycle. Same family as the ceilings
added in #464.

Retain the most recent 200 transitions per plugin in a deque and let the
rest age out. state_history_count is surfaced through the web API, so
the lifetime total is tracked separately rather than plateauing at the
cap. get_state_history() now returns a copy under the lock; it was
handing out the manager's own list, which a caller could mutate.

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

* fix(plugins): copy history entries out, lock clear_state

Review follow-ups on the transition history.

get_state_history() copied only the outer list, so a caller holding a
returned transition could rewrite the manager's record of what happened
-- which contradicted the defensive-copy guarantee in its own docstring.
Copy each entry too. Every value in a transition is immutable, so a
shallow copy per entry is enough. test_get_state_history_entries_are_copies
pins it; without the change it fails with 'tampered' == 'enabled'.

clear_state() mutated five shared dicts without holding _lock, while
every other mutator takes it. A concurrent set_state() could interleave
and leave a plugin with history but no state. Drop the five as one unit.

This does not close the wider unload-vs-worker race, which lives in
PluginManager.unload_plugin() and predates this change: an update worker
still in flight can call set_state() after clear_state() returns and
recreate the entry. Serialising that needs the per-plugin lock held
across worker join in unload_plugin(), which is a separate change.

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

---------

Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
2026-08-25 09:45:17 -04:00
ChuckandClaude Opus 5 f90638a9ec feat(web): show available memory in Tools diagnostics (#500)
* feat(web): show available memory in Tools diagnostics

System Diagnostics reported memory as used-percent plus used/total GB.
Neither distinguishes a healthy board from one about to fail, because
page cache counts as used and is reclaimable on demand -- a Pi can read
70% used and be fine, or read the same and be minutes from trouble.

MemAvailable is the kernel's own estimate of what a new allocation can
actually obtain, and it is the number that tracked the failure on a 1GB
Pi 3B+: healthy running sat above 500MB, and the crash came at 73MB. By
that point fork() was failing, so sshd could not spawn a session and
systemd could not respawn the display, while the kernel carried on
answering pings at 0% loss. Used-percent gave no warning at any point on
the way there; available memory fell steadily for hours.

/api/v3/system/status now returns memory_available_mb from
psutil.virtual_memory().available, and Tools renders it as its own tile,
coloured against the thresholds that failure implies: red under 150MB,
amber under 300MB, green above.

The existing memory tile is left alone -- used/total is still what you
want when sizing a workload; this answers the different question of how
much room is left right now.

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

* fix(web): round available memory once, so the tile agrees with itself

The colour was classified from the raw value while the label was rounded,
and the API sends one decimal place. At the boundaries the two disagreed:
149.6 rendered as "150 MB" in red, and 299.6 as "300 MB" in amber -- each
contradicting the threshold its own colour claims to apply ("red under
150MB"). A reader checking the tile against the documented thresholds would
conclude the readout was broken.

Rounding once and using that number for both restores agreement. It moves
those two boundary cases up a band, which does not matter: the thresholds
come from a measured failure at 73MB, so which side of the line a spare
0.4MB falls on carries no information. The tile agreeing with itself does.

Null handling and the thresholds themselves are unchanged.

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

---------

Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
2026-08-25 08:40:28 -04:00
ChuckandClaude Opus 5 333fd17d28 fix(memory): release fetched payloads once they have been delivered (#499)
* fix(memory): release fetched payloads once they have been delivered

BackgroundDataService kept the fetched body on the FetchResult it filed
in completed_requests, which is swept hourly and capped at 500 entries
by count. For a status record that costs nothing; for a season schedule
it costs a tenth of the board.

Measured on a 1GB Pi 3B+ with a 1-second RSS profile: the display
process sat at 404MB after plugin load, then stepped +21MB when NFL
fetched its season and +90MB when NCAA football fetched 946 games for
2026 -- and stayed at 494MB. Not a leak; a staircase that never came
down. When a later fetch landed while headroom was low, available memory
reached ~70MB, fork() began failing, and the board stopped being able to
start a process at all: sshd accepted connections and closed them before
its banner, systemd could not respawn the display, and the panel went
dark while the kernel carried on answering pings.

The cache-hit path was the worse of the two. It runs once per update
interval per sport, mints a fresh request_id each time, and files
whatever the cache returned. The memory tier is capped at 150 entries on
a 1GB board, so a miss re-parses the payload from disk into a genuinely
new object -- separate copies accumulating toward the 500-entry cap,
not shared references.

Releasing is safe: the payload is written to the cache under the
request's cache_key before the result is built, the callback is handed
the object directly, and consumers read it back from the cache
afterwards (the plugins' callbacks use it only in passing, to log a
count, before reading the cache). Nothing is lost -- it moves from RAM
to the disk cache that was already holding it.

Requests submitted without a callback keep their payload, since polling
get_result() is then the only way to collect it. That keeps the existing
contract, and the existing tests covering it, intact.

Not addressed here: max_workers=3 allows three concurrent fetches, so
three large parses can peak at once, and there is no in-flight dedupe by
cache_key -- a second submit for a key already being fetched starts a
second fetch. Both bound the transient peak rather than what stays
resident, and both are behaviour changes worth their own review.

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

* fix(memory): file the cache-hit result before running its callback

Restores the original ordering. Releasing the payload after the callback
meant filing the result after it too, so a callback that queried
get_result() or is_request_complete() for its own request would not have
found it -- a behaviour change unrelated to the memory fix.

The dict holds a reference to the same object, so releasing after filing
still clears the payload.

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

* test: wait for the payload release, not just the filing

The callback test waited on is_request_complete(), which goes true as soon
as the worker files the result in completed_requests. The worker then runs
the cleanup pass, then the callback, then releases the payload. Both of the
test's assertions therefore raced the worker: `seen` is populated by the
callback, and `data is None` only after the release that follows it.

It passes today because a one-line callback usually finishes inside the
20ms poll interval. Confirmed by making the callback sleep 0.4s: _wait()
returns with seen == {} and the payload still resident.

_wait_for_release() polls for the released payload instead. Release happens
strictly after the callback returns, so a released payload also means the
callback has finished and one wait covers both assertions. Verified against
the same 0.4s callback.

_wait() stays for the other three fetch-path tests, which assert only what
is already true when the result is filed -- the success flag, the error,
and the cache write that happened during the fetch itself. Its docstring
now says so, so the next reader picks the right one.

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

---------

Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
2026-08-25 08:32:08 -04:00
ChuckandClaude Opus 5 a4a55a23fc fix(web): reject non-finite JSON numbers instead of raising (#497)
* fix(web): reject non-finite JSON numbers instead of raising

POST /api/v3/config/dim-schedule with {"dim_brightness": Infinity} answered
500. So did /api/v3/errors/clear with max_age_hours, and /api/v3/config/main
with multiplexing or row_address_type.

json.loads accepts Infinity/-Infinity/NaN by default -- they are not valid
JSON, but Python's parser emits them -- and Flask's get_json passes them
straight through. int(float('inf')) raises OverflowError, which is neither
ValueError nor TypeError, so validation blocks that carefully caught those let
it past and Flask turned it into a 500.

The status code was not the real damage. dim-schedule answered with
CONFIG_SAVE_FAILED and suggested "Check file permissions on config directory"
and "Check available disk space" for what was an invalid number. Every one of
these sites already had a correct 400 response written; they just never
reached it.

NaN already returned 400, because int(nan) raises ValueError. That is why this
only ever showed up for the infinities, and why it survived: the obvious test
case passes.

OverflowError is now caught alongside ValueError/TypeError at the 27 sites in
this file whose try block performs a numeric coercion. An AST sweep confirms
no int()/float() of request-derived data is left outside a block that catches
it.

Verified end to end through Flask's test client rather than by reasoning about
the parser: all four routes returned 500 before and 400 after.

Tests: five Infinity cases (which fail against the previous except tuples),
two NaN cases pinned so narrowing the tuple cannot quietly break them, and a
check that ordinary input is not rejected by the widened guard.

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

* test(web): assert 400 exactly, and prove valid input is accepted

Both review points were right, and the first is the failure mode this file
exists to catch.

Accepting any 4xx meant a 404 would have passed. Renaming one of these routes
would have left the test green while it tested nothing -- the same "looks like
coverage, points somewhere safe" shape that hid the composer injections. Now
asserts exactly 400.

Both infinity signs are exercised for every route. int() raises OverflowError
either way, but only +Infinity was in the original report, and a guard that
special-cased the sign would have passed a one-sided test.

The valid-input test previously asserted "not a 400", which did not show what
it claimed: the mocked save path fails for any input, so that assertion held
whether or not validation had accepted the value. It now gives load_config a
real dict and stubs _save_config_atomic, so the endpoint reaches its success
response and the test can assert 200 -- which only happens if the value passed
validation.

8 of the 11 checks fail with OverflowError removed from the except tuples.

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-23 11:44:23 -04:00
ChuckandClaude Opus 5 085fb93a87 test(logging): stop the location assertion matching the clock (#496)
test_location_toggle asserted that ":42" -- a bare colon plus the record's
hardcoded lineno -- is absent from a line formatted with include_location=False.
But every formatted line starts with an HH:MM:SS.mmm timestamp, so ":42" also
matches the clock whenever the minute or the second is 42. The test fails for
roughly 3% of runs with nothing wrong:

  2026-08-22 08:05:42.274 - INFO - test.logger - hello
                     ^^^ matches ":42"

Assert on the whole "module.funcName:lineno" token the format string actually
emits ('%(module)s.%(funcName)s:%(lineno)d') instead of a fragment of it. That
cannot collide with a timestamp, and it checks the thing the test is named for.

Confirmed by formatting a record stamped 08:42:42 -- both minute and second
colliding: the old assertion fails, the new one passes.


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

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-08-23 11:44:00 -04:00
ChuckandClaude Opus 5 c321b94085 fix(display): retry a plugin that is enabled but failed to load (#495)
* fix(display): retry a plugin that is enabled but failed to load

A plugin whose validate_config() returns False is treated as a hard load
failure. The API then reports enabled=true, loaded=false, error=null: the
plugin is simply absent, with nothing saying why. hockey-scoreboard sat in
that state on a live rig for four days.

The recovery path existed but could not be reached. _reconcile_enabled_plugins
computes to_add = desired - current, and a plugin that failed to load is never
in current, so it stays in to_add and would be retried. But the reconcile is
queued by _enabled_set_changed(), which compares only top-level `enabled`
flags -- and the edit that actually fixes such a plugin (enabling a league,
filling in an API key) is nested inside the plugin's own config section. No
top-level flag changes, so no reconcile is queued, and the save that should
have fixed it does nothing. Only toggling some unrelated plugin -- which does
change a top-level flag -- queues the global reconcile that recovers it.

Add a second gate: queue a reconcile when a discovered plugin is enabled in
config but absent from the running set.

It is deliberately narrow rather than "reconcile on any config change".
Reconcile calls discover_plugins(), a ~39-manifest filesystem scan, and it
runs on the render thread; doing that on every config save would trade this
bug for a frame hitch. Gating on plugin_manifests also keeps non-plugin
sections that carry their own `enabled` flag (schedule, display) from
queueing a reconcile they can never satisfy. In the steady state -- every
enabled plugin loaded -- the new check is False and costs nothing.

The same valid-but-unconfigured => hard-fail shape still exists in
text-display, youtube-stats, birdnet-go, ledmatrix-flights and
mqtt-notifications; this makes all of them recoverable without a restart.

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

* fix(display): snapshot the plugin mappings under their locks

Addresses the review finding on the cross-thread reads.

_enabled_plugin_not_running runs on the config-watcher thread and read two
mappings the render thread mutates. Catching RuntimeError was not a fix: it
turned a torn read into a coin flip between an unnecessary discovery scan and
a missed retry, which is the bug this PR exists to remove.

Both reads are now snapshots taken under the lock that guards their writes:

- plugin_manifests via a new PluginManager.discovered_plugin_ids(), which
  copies the ids while holding the existing _discovery_lock. Discovery
  rebuilds that mapping entry by entry, so an unsynchronised reader can see
  it half-populated.
- plugin_display_modes under a new controller lock, taken at the only two
  sites that mutate it (_register_loaded_plugin / _unregister_plugin).

The locks are never nested -- each snapshot is taken and released before the
next -- so this cannot deadlock against discovery, which holds _discovery_lock
while it rebuilds.

No cost on the per-frame path. Both mutation sites run during reconcile, which
is rare, and every hot-path read of plugin_display_modes is on the render
thread itself, same thread as the writes, so those stay lock-free.

Tests: the accessor returns a snapshot rather than a live view, and actually
takes the discovery lock (proved from a second thread, since an RLock is
reentrant on the owning one) so a later refactor cannot quietly drop it.

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

* fix(display): consume the reconcile request before serving it

Addresses the second review finding: a lost update on
_pending_plugin_reconcile.

The flag was cleared after a successful reconcile. Reconcile has already read
its config by that point, so a config change arriving mid-flight set a flag
that the trailing clear then erased -- a request that was never served, and
the newest config never reconciled. That is the same "my save did nothing"
symptom this PR exists to remove, so leaving it would have undercut the fix.

Consume the request before running it instead, and re-arm only on a retryable
failure. A change that lands during reconcile now stays set and is picked up
on the next pass.

The per-frame read stays lock-free. It is a fast path that can only produce a
false negative -- the watcher setting the flag just after it is read is seen
on the next iteration -- never a false positive that loses a request. The lock
is taken only when a reconcile is actually pending or a config change arrives.

Extracted _service_pending_reconcile() so the sequence is testable rather than
buried in run()'s loop; the review asked for a regression test that invokes
the subscriber during reconciliation, which is not reachable otherwise.

Tests: 4 new, covering a request racing in mid-reconcile, the quiet success,
the retryable-failure re-arm, and not reconciling when nothing is pending.
Two of them fail against the previous clear-after-success semantics.

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-23 11:43:39 -04:00
ChuckandClaude Opus 5 5a1f121e6b Stop array-item secrets being wiped, and logging them (#493)
Three review findings from #485 that I missed when addressing that PR;
it has since merged, so they land here.

1. Array-item secrets destroyed by any unrelated save (data loss).

remove_empty_secrets recursed into dicts but let a list fall through to
the scalar branch and kept it verbatim. Lists merge by *replacement*, so
the blanks the masked form posts back went straight over the stored
array:

    stored   [{"name":"a","token":"REAL-A"}, {"name":"b","token":"REAL-B"}]
    posted   [{"name":"a","token":""},       {"name":"b","token":""}]
    merged   [{"name":"a","token":""},       {"name":"b","token":""}]
             -> both credentials gone

Same failure as the scalar api_key case fixed earlier, one container
deeper. Lists now prune element-wise, and a list with nothing real in it
is dropped so the stored one is left alone. Where one entry does change,
the new merge_secrets merges by index instead of replacing.

Two details the first attempt got wrong, both caught by existing tests:

- An emptied dict item must stay {}, not None. ConfigManager's
  _strip_secrets_recursive treats a secrets list as *parallel* to the
  regular one ({} = "item i has no secrets"); a None makes it stop
  looking parallel, and it then drops the whole key from the main config
  -- silently deleting the items' non-secret fields too.
- The incoming list's length wins. The regular config's list is
  authoritative about how many items exist, so preserving surplus stored
  entries would let the two fall out of step and make deleting an entry
  impossible.

2. Submitted credentials written to the journal (security).

save_plugin_config logged `Full config: {plugin_config}` at INFO and
`Config that failed: {plugin_config}` at ERROR. Both run before
separate_secrets, so plugin_config still held the values just typed into
the form. Now keys only. Swept the rest of web_interface/ and src/ for
the same shape -- these were the only two.

3. Restart banner kept stale wording.

showRestartPending() cleared the stored custom text but left the DOM
element alone, so a config save could show the previous update's
message. The default is read back from the server-rendered copy rather
than duplicated in JS, so the template stays the one owner of the string.

Verified: 556 passed, 1 skipped across the web suite. Mutation-checked --
reverting api_v3 fails the logging guard and the array-merge test;
reverting either half of the secret_helpers change fails the unit tests.
New end-to-end coverage drives the real endpoint, not just the helpers.


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

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-08-23 11:43:08 -04:00
ChuckandClaude Opus 5 6138a3cbef test(install): stop assuming pytest's tmp_path is on disk (#492)
test_returns_nothing_when_tmpdir_is_already_disk_backed asserted that
lm_disk_backed_tmpdir prints nothing when TMPDIR is already disk-backed,
and used pytest's tmp_path as the "disk-backed" directory:

    # tmp_path is on the regular filesystem, so the default must be kept.
    assert call("lm_disk_backed_tmpdir", env={"TMPDIR": str(tmp_path)}) == ""

That premise is false on the platform the helper was written for. Debian
13 mounts /tmp as tmpfs -- which is the entire reason lm_disk_backed_tmpdir
exists -- and pytest puts tmp_path under /tmp. So on the target platform
TMPDIR is memory-backed, the helper correctly answers /var/tmp, and the
test fails:

    E  AssertionError: assert '/var/tmp' == ''

The helper is right; the test was wrong. Reproduced on a box where
/tmp is tmpfs and / is ext4.

The test now looks for a directory whose backing store is actually disk
-- tmp_path, else a scratch dir under /var/tmp, else beside the library
-- using the same findmnt lookup the helper itself uses, and skips only
if no disk-backed directory exists anywhere. An earlier version of this
fix skipped whenever tmp_path was tmpfs, which made it skip on every
machine with a tmpfs /tmp; that is barely better than asserting the
wrong thing, so it now searches instead of giving up.

Verified: 31 passed, 0 skipped. Mutation-checked -- deleting the
"is the current TMPDIR memory-backed?" guard from lm_disk_backed_tmpdir
fails this test, so it still catches the regression it is there for.


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

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-08-23 11:42:51 -04:00
ChuckandClaude Opus 5 568cb6d77f perf(vegas): report the frame rate when it is worth reporting (#487)
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.


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

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-08-23 11:42:33 -04:00
23 changed files with 1754 additions and 94 deletions
+38 -4
View File
@@ -57,7 +57,15 @@ class FetchRequest:
@dataclass @dataclass
class FetchResult: class FetchResult:
"""Result of a background fetch operation.""" """Result of a background fetch operation.
``data`` survives on the stored result only for requests submitted without
a ``callback``, where polling ``get_result()`` is the sole way to collect
it. When a callback was given, the payload has already been delivered and
the service releases it -- see :meth:`BackgroundDataService._release_payload`.
Either way the data remains in the cache under the request's ``cache_key``,
which is where consumers read it from.
"""
request_id: str request_id: str
success: bool success: bool
data: Optional[Any] = None data: Optional[Any] = None
@@ -191,14 +199,19 @@ class BackgroundDataService:
cached=True, cached=True,
fetch_time=0.0 fetch_time=0.0
) )
# Filed before the callback runs, as it always was: a callback
# that queries get_result()/is_request_complete() for its own
# request must still find it. Releasing afterwards mutates the
# same object the dict holds.
self.completed_requests[request_id] = result self.completed_requests[request_id] = result
if callback: if callback:
try: try:
callback(result) callback(result)
except Exception as e: except Exception as e:
logger.error(f"Error in callback for request {request_id}: {e}") logger.error(f"Error in callback for request {request_id}: {e}")
self._release_payload(result)
logger.debug(f"Cache hit for {sport} {year} data") logger.debug(f"Cache hit for {sport} {year} data")
return request_id return request_id
@@ -333,8 +346,29 @@ class BackgroundDataService:
request.callback(result) request.callback(result)
except Exception as e: except Exception as e:
logger.error(f"Error in callback for request {request.id}: {e}") logger.error(f"Error in callback for request {request.id}: {e}")
# Delivered. Drop both references -- they point at the same
# object, so one survivor keeps the whole payload resident.
self._release_payload(result)
request.result = None
return result return result
@staticmethod
def _release_payload(result: FetchResult) -> None:
"""Drop a delivered payload, keeping the result's status and timings.
Only called once a callback has been handed the data. Consumers read
fetched data back from the cache under ``cache_key``; the copy carried
here was pinning a parsed season schedule -- 946 games for NCAA
football, roughly a tenth of total RAM on a 1GB Pi -- in memory until
the hourly sweep.
The cache-hit path matters most: it runs once per update interval per
sport, mints a fresh request_id each time, and a memory-tier miss
re-parses the payload from disk. Those were genuinely separate copies
accumulating toward the 500-entry cap, not shared references.
"""
result.data = None
def _make_request_with_retry(self, request: FetchRequest) -> requests.Response: def _make_request_with_retry(self, request: FetchRequest) -> requests.Response:
""" """
+4
View File
@@ -328,6 +328,10 @@ class ScrollHelper:
elapsed_time = current_time - (self.scroll_start_time or current_time) elapsed_time = current_time - (self.scroll_start_time or current_time)
# The image already includes display_width padding, so we only need total_scroll_width # The image already includes display_width padding, so we only need total_scroll_width
required_total_distance = self.total_scroll_width required_total_distance = self.total_scroll_width
# 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( self.logger.debug(
"Scroll progress: elapsed=%.2fs, target=%.2fs, total_scrolled=%.0f/%d px (%.1f%%)", "Scroll progress: elapsed=%.2fs, target=%.2fs, total_scrolled=%.0f/%d px (%.1f%%)",
elapsed_time, elapsed_time,
+84 -8
View File
@@ -181,6 +181,16 @@ class DisplayController:
self.plugin_modes = {} # mode -> plugin_instance mapping for plugin-first dispatch self.plugin_modes = {} # mode -> plugin_instance mapping for plugin-first dispatch
self.mode_to_plugin_id: Dict[str, str] = {} self.mode_to_plugin_id: Dict[str, str] = {}
self.plugin_display_modes: Dict[str, List[str]] = {} self.plugin_display_modes: Dict[str, List[str]] = {}
# plugin_display_modes is mutated only by _register_loaded_plugin /
# _unregister_plugin on the render thread, but the config-watcher
# thread reads it in _enabled_plugin_not_running. Both mutation sites
# run during reconcile (rare), so this lock never touches the per-frame
# path -- the hot-path reads are same-thread as the writes.
self._plugin_modes_lock = threading.Lock()
# Guards the consume-and-clear of _pending_plugin_reconcile. Only taken
# when a reconcile is actually pending or a config change arrives, both
# rare -- the per-frame path just reads the bool.
self._reconcile_flag_lock = threading.Lock()
# Per-plugin config-change callbacks, kept so we can unsubscribe a # Per-plugin config-change callbacks, kept so we can unsubscribe a
# plugin when it is disabled live. # plugin when it is disabled live.
self._plugin_config_callbacks: Dict[str, Callable] = {} self._plugin_config_callbacks: Dict[str, Callable] = {}
@@ -463,8 +473,10 @@ class DisplayController:
self._refresh_config_cache(new_config) self._refresh_config_cache(new_config)
# If a plugin was enabled/disabled, flag a reconcile for the main # If a plugin was enabled/disabled, flag a reconcile for the main
# loop to apply (loading/unloading off the watcher thread is unsafe). # loop to apply (loading/unloading off the watcher thread is unsafe).
if self._enabled_set_changed(old_config, new_config): if (self._enabled_set_changed(old_config, new_config)
self._pending_plugin_reconcile = True or self._enabled_plugin_not_running(new_config)):
with self._reconcile_flag_lock:
self._pending_plugin_reconcile = True
self.config_service.subscribe(_controller_config_change) self.config_service.subscribe(_controller_config_change)
@@ -1749,11 +1761,12 @@ class DisplayController:
# rebuilding available_modes happens here on the render thread so # rebuilding available_modes happens here on the render thread so
# it can't race with rendering. Deferred while on-demand is active # it can't race with rendering. Deferred while on-demand is active
# (the flag stays set) so we don't fight its temporary-enable. # (the flag stays set) so we don't fight its temporary-enable.
# The lock-free read is a fast path only; it can be a false
# negative (the watcher setting the flag just after it is read
# is seen next iteration), never a false positive that loses a
# request.
if self._pending_plugin_reconcile and not self.on_demand_active: if self._pending_plugin_reconcile and not self.on_demand_active:
# Only clear the flag on success -- a retryable failure self._service_pending_reconcile()
# (e.g. discovery) leaves it set so the request isn't lost.
if self._reconcile_enabled_plugins():
self._pending_plugin_reconcile = False
if not self.available_modes: if not self.available_modes:
# Nothing to render yet. Re-check _pending_plugin_reconcile # Nothing to render yet. Re-check _pending_plugin_reconcile
@@ -2813,7 +2826,8 @@ class DisplayController:
logger.debug("Using manifest display_modes for %s: %s", plugin_id, display_modes) logger.debug("Using manifest display_modes for %s: %s", plugin_id, display_modes)
if not (isinstance(display_modes, list) and display_modes): if not (isinstance(display_modes, list) and display_modes):
display_modes = [plugin_id] display_modes = [plugin_id]
self.plugin_display_modes[plugin_id] = list(display_modes) with self._plugin_modes_lock:
self.plugin_display_modes[plugin_id] = list(display_modes)
# Subscribe to config changes for per-plugin hot-reload. Bind plugin_id # Subscribe to config changes for per-plugin hot-reload. Bind plugin_id
# and instance as defaults so each plugin's callback targets its own # and instance as defaults so each plugin's callback targets its own
@@ -2847,7 +2861,8 @@ class DisplayController:
def _unregister_plugin(self, plugin_id: str) -> None: def _unregister_plugin(self, plugin_id: str) -> None:
"""Remove a plugin's modes, config subscription and instance, then """Remove a plugin's modes, config subscription and instance, then
unload it. Used by live disable hot-reload.""" unload it. Used by live disable hot-reload."""
modes = self.plugin_display_modes.pop(plugin_id, []) with self._plugin_modes_lock:
modes = self.plugin_display_modes.pop(plugin_id, [])
for mode in modes: for mode in modes:
if mode in self.available_modes: if mode in self.available_modes:
self.available_modes.remove(mode) self.available_modes.remove(mode)
@@ -2892,6 +2907,67 @@ class DisplayController:
} }
return enabled_map(old_config) != enabled_map(new_config) return enabled_map(old_config) != enabled_map(new_config)
def _service_pending_reconcile(self) -> None:
"""Consume a pending reconcile request and run it.
The request is consumed BEFORE reconciling, not cleared after. Clearing
after would drop any config change that lands while reconcile is
running: reconcile has already read its config by then, so the clear
erases a request it never served and the newest config never
reconciles -- the same "your save did nothing" failure this whole path
exists to prevent. Consuming first means such a request stays set and
is picked up on the next pass.
A retryable failure (e.g. discovery) re-arms the flag.
"""
with self._reconcile_flag_lock:
pending = self._pending_plugin_reconcile
self._pending_plugin_reconcile = False
if pending and not self._reconcile_enabled_plugins():
with self._reconcile_flag_lock:
self._pending_plugin_reconcile = True
def _enabled_plugin_not_running(self, new_config: Dict[str, Any]) -> bool:
"""True when a discovered plugin is enabled in config but not running.
``_enabled_set_changed`` compares only top-level ``enabled`` flags, which
misses the case that strands a plugin: one whose ``validate_config()``
returned False is absent from the running set, and the edit that fixes it
(enabling a league, filling in an API key) lives *nested* inside that
plugin's own section. No top-level flag changes, so no reconcile is
queued, and the save that should have fixed it appears to do nothing --
only toggling some unrelated plugin recovers it. hockey-scoreboard sat
enabled-but-absent on a live rig for four days this way.
Deliberately narrow: it fires only for ids the plugin manager has
actually discovered, so non-plugin sections that carry their own
``enabled`` flag (``schedule``, ``display``, ...) don't queue a reconcile
on every save. In the steady state -- everything enabled is loaded --
this is False and costs nothing. That matters because reconcile runs
``discover_plugins()`` on the render thread, where a needless
filesystem scan per config save would show up as a frame hitch.
Runs on the config-watcher thread, so both mappings it reads are
snapshotted under the lock that guards their writes.
"""
if self.plugin_manager is None:
return False
# Two snapshots, each taken under its own lock and never nested, so a
# half-written mapping is never observed and this can't deadlock
# against discovery (which holds the discovery lock while rebuilding).
try:
known = self.plugin_manager.discovered_plugin_ids()
except AttributeError:
# Older manager without the accessor: fall back to a plain read.
known = set(getattr(self.plugin_manager, 'plugin_manifests', ()) or ())
with self._plugin_modes_lock:
running = set(self.plugin_display_modes)
for key, value in new_config.items():
if (key in known and isinstance(value, dict)
and value.get('enabled', False) and key not in running):
return True
return False
def _reconcile_enabled_plugins(self) -> bool: def _reconcile_enabled_plugins(self) -> bool:
"""Load/unload plugins so the running set matches the enabled set in """Load/unload plugins so the running set matches the enabled set in
config. Runs on the main display thread (never the config-watcher config. Runs on the main display thread (never the config-watcher
+11
View File
@@ -631,6 +631,17 @@ class PluginManager:
return self.load_plugin(plugin_id) return self.load_plugin(plugin_id)
def discovered_plugin_ids(self) -> set:
"""Snapshot of the discovered plugin ids, taken under the discovery lock.
Callers on other threads (the config watcher) must not iterate
``plugin_manifests`` directly: discovery rebuilds it entry by entry, so
an unsynchronised reader can see a half-populated mapping or raise
"dictionary changed size during iteration".
"""
with self._discovery_lock:
return set(self.plugin_manifests)
def get_plugin(self, plugin_id: str) -> Optional[Any]: def get_plugin(self, plugin_id: str) -> Optional[Any]:
""" """
Get a loaded plugin instance by ID. Get a loaded plugin instance by ID.
+112 -33
View File
@@ -6,14 +6,40 @@ with state transitions and queries.
""" """
import threading import threading
import time
from collections import deque
from enum import Enum from enum import Enum
from typing import Optional, Dict, Any from typing import Optional, Dict, Any, Deque, List, Tuple
from datetime import datetime from datetime import datetime
import logging import logging
from src.logging_config import get_logger from src.logging_config import get_logger
# The history is diagnostic only -- nothing reads the entries themselves, just
# their count -- but it is appended to on the hot scheduling path: every update
# cycle records RUNNING on reserve and ENABLED on finish. Unbounded, that is
# 2,880 entries per plugin per day at the default 60s interval, which on a 1 GB
# Pi exhausts memory in weeks.
#
# Two limits, because a single entry count answers the wrong question. What a
# reader wants is "the last couple of hours", and how many transitions that is
# depends entirely on the plugin's update interval -- which on a real board
# spans 2s to 3600s. A flat 200 entries is 4.2 days for the slowest plugin and
# 3.3 minutes for the fastest, so the plugin churning hardest, the one worth
# looking at, keeps the least history.
#
# So: trim by AGE first, which makes the retained window comparable across
# plugins whatever their cadence...
STATE_HISTORY_MAX_AGE_SECONDS = 2 * 60 * 60
# ...and cap by COUNT second, purely as a memory ceiling for the fast pollers
# whose age window would otherwise run to thousands of entries. At ~230 bytes
# an entry this is ~0.5 MB per plugin worst case, and only plugins updating
# faster than roughly every 4s can reach it.
MAX_STATE_HISTORY_PER_PLUGIN = 2000
class PluginState(Enum): class PluginState(Enum):
"""Plugin state enumeration.""" """Plugin state enumeration."""
UNLOADED = "unloaded" # Plugin not loaded UNLOADED = "unloaded" # Plugin not loaded
@@ -37,11 +63,43 @@ class PluginStateManager:
self.logger = logger or get_logger(__name__) self.logger = logger or get_logger(__name__)
self._lock = threading.RLock() self._lock = threading.RLock()
self._states: Dict[str, PluginState] = {} self._states: Dict[str, PluginState] = {}
self._state_history: Dict[str, list] = {} # (monotonic timestamp, transition). The clock is monotonic so a DST
# shift or an NTP step cannot make entries look old and flush the
# history; the human-readable timestamp lives inside the transition.
self._state_history: Dict[str, Deque[Tuple[float, Dict[str, Any]]]] = {}
# Lifetime transition totals, kept separately so the count reported by
# get_state_info() stays truthful once the history above starts rolling.
self._state_transition_counts: Dict[str, int] = {}
self._error_info: Dict[str, Dict[str, Any]] = {} self._error_info: Dict[str, Dict[str, Any]] = {}
self._last_update: Dict[str, datetime] = {} self._last_update: Dict[str, datetime] = {}
self._last_display: Dict[str, datetime] = {} self._last_display: Dict[str, datetime] = {}
def _record_transition(
self,
plugin_id: str,
transition: Dict[str, Any]
) -> None:
"""Append a transition to the plugin's bounded history.
Callers must already hold ``_lock``. The deque discards its oldest
entry once it is full, so the history cannot grow without bound; the
lifetime total is tracked separately for get_state_info().
"""
history = self._state_history.get(plugin_id)
if history is None:
history = deque(maxlen=MAX_STATE_HISTORY_PER_PLUGIN)
self._state_history[plugin_id] = history
now = time.monotonic()
history.append((now, transition))
# Age out first; the deque's maxlen is the backstop for plugins that
# produce more than the ceiling within the window.
cutoff = now - STATE_HISTORY_MAX_AGE_SECONDS
while history and history[0][0] < cutoff:
history.popleft()
self._state_transition_counts[plugin_id] = (
self._state_transition_counts.get(plugin_id, 0) + 1
)
def set_state( def set_state(
self, self,
plugin_id: str, plugin_id: str,
@@ -60,16 +118,13 @@ class PluginStateManager:
old_state = self._states.get(plugin_id, PluginState.UNLOADED) old_state = self._states.get(plugin_id, PluginState.UNLOADED)
self._states[plugin_id] = state self._states[plugin_id] = state
if plugin_id not in self._state_history:
self._state_history[plugin_id] = []
transition = { transition = {
'timestamp': datetime.now(), 'timestamp': datetime.now(),
'from': old_state.value, 'from': old_state.value,
'to': state.value, 'to': state.value,
'error': str(error) if error else None 'error': str(error) if error else None
} }
self._state_history[plugin_id].append(transition) self._record_transition(plugin_id, transition)
# Store error info if transitioning to ERROR state # Store error info if transitioning to ERROR state
if state == PluginState.ERROR and error: if state == PluginState.ERROR and error:
@@ -126,17 +181,29 @@ class PluginStateManager:
state = self.get_state(plugin_id) state = self.get_state(plugin_id)
return state == PluginState.ENABLED return state == PluginState.ENABLED
def get_state_history(self, plugin_id: str) -> list: def get_state_history(self, plugin_id: str) -> List[Dict[str, Any]]:
""" """
Get state transition history for a plugin. Get state transition history for a plugin.
Retention is by age first -- transitions older than
STATE_HISTORY_MAX_AGE_SECONDS are dropped -- and by count second, at
MAX_STATE_HISTORY_PER_PLUGIN, which only binds for plugins updating
fast enough to exceed it inside that window.
Args: Args:
plugin_id: Plugin identifier plugin_id: Plugin identifier
Returns: Returns:
List of state transitions List of recent state transitions, oldest first. Both the list and
the transition dicts are copies, so callers cannot mutate the
manager's own history. The values inside a transition are all
immutable, so a shallow copy per entry is enough.
""" """
return self._state_history.get(plugin_id, []) with self._lock:
return [
dict(transition)
for _stamp, transition in self._state_history.get(plugin_id, ())
]
def set_error_info(self, plugin_id: str, error_info: Dict[str, Any]) -> None: def set_error_info(self, plugin_id: str, error_info: Dict[str, Any]) -> None:
""" """
@@ -179,9 +246,7 @@ class PluginStateManager:
old_state = self._states.get(plugin_id, PluginState.UNLOADED) old_state = self._states.get(plugin_id, PluginState.UNLOADED)
self._states[plugin_id] = state self._states[plugin_id] = state
if plugin_id not in self._state_history: self._record_transition(plugin_id, {
self._state_history[plugin_id] = []
self._state_history[plugin_id].append({
'timestamp': datetime.now(), 'timestamp': datetime.now(),
'from': old_state.value, 'from': old_state.value,
'to': state.value, 'to': state.value,
@@ -241,26 +306,40 @@ class PluginStateManager:
Returns: Returns:
Dictionary with state information Dictionary with state information
""" """
state = self.get_state(plugin_id) # One snapshot, one critical section. Each field was read under its own
info = { # lock, so an unload running concurrently could be observed half-done:
'state': state.value, # 'state' read before clear_state() removed it and
'is_loaded': self.is_loaded(plugin_id), # 'state_history_count' read after, giving a caller a plugin that is
'is_enabled': self.is_enabled(plugin_id), # ENABLED with zero transitions. _lock is an RLock, so the helpers
'is_running': self.is_running(plugin_id), # below can still take it.
'is_error': self.is_error(plugin_id), with self._lock:
'can_execute': self.can_execute(plugin_id), state = self.get_state(plugin_id)
'last_update': self.get_last_update(plugin_id), info = {
'last_display': self.get_last_display(plugin_id), 'state': state.value,
'error_info': self.get_error_info(plugin_id), 'is_loaded': self.is_loaded(plugin_id),
'state_history_count': len(self.get_state_history(plugin_id)) 'is_enabled': self.is_enabled(plugin_id),
} 'is_running': self.is_running(plugin_id),
'is_error': self.is_error(plugin_id),
'can_execute': self.can_execute(plugin_id),
'last_update': self.get_last_update(plugin_id),
'last_display': self.get_last_display(plugin_id),
'error_info': self.get_error_info(plugin_id),
'state_history_count': self._state_transition_counts.get(plugin_id, 0)
}
return info return info
def clear_state(self, plugin_id: str) -> None: def clear_state(self, plugin_id: str) -> None:
"""Clear all state information for a plugin.""" """Clear all state information for a plugin.
self._states.pop(plugin_id, None)
self._state_history.pop(plugin_id, None) Held under ``_lock`` so the five dicts are dropped as one unit: every
self._error_info.pop(plugin_id, None) other mutator takes the lock, and without it a concurrent set_state()
self._last_update.pop(plugin_id, None) could interleave and leave a plugin with history but no state.
self._last_display.pop(plugin_id, None) """
with self._lock:
self._states.pop(plugin_id, None)
self._state_history.pop(plugin_id, None)
self._state_transition_counts.pop(plugin_id, None)
self._error_info.pop(plugin_id, None)
self._last_update.pop(plugin_id, None)
self._last_display.pop(plugin_id, None)
+75 -11
View File
@@ -31,6 +31,18 @@ if TYPE_CHECKING:
logger = logging.getLogger(__name__) 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: def _percentile(ordered: List[float], fraction: float) -> float:
"""Nearest-rank percentile of an already-sorted list. """Nearest-rank percentile of an already-sorted list.
@@ -96,6 +108,11 @@ class VegasModeCoordinator:
self._is_active = False self._is_active = False
self._is_paused = False self._is_paused = False
self._should_stop = 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() self._state_lock = threading.Lock()
# Live priority tracking # Live priority tracking
@@ -248,6 +265,11 @@ class VegasModeCoordinator:
self._is_active = True self._is_active = True
self._should_stop = False self._should_stop = False
self._start_time = time.time() 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 # Line up the next group immediately, so the first extension is already
# warm rather than stalling the scroll to fetch it. # warm rather than stalling the scroll to fetch it.
@@ -395,8 +417,18 @@ class VegasModeCoordinator:
duration = self.render_pipeline.get_dynamic_duration() duration = self.render_pipeline.get_dynamic_duration()
start_time = time.time() start_time = time.time()
frame_count = 0 frame_count = 0
fps_log_interval = 5.0 # Log FPS every 5 seconds fps_log_interval = 5.0 # Sample FPS every 5 seconds
last_fps_log_time = start_time # 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 fps_frame_count = 0
# A mean hides stutter completely. At 120fps a five-second window is # A mean hides stutter completely. At 120fps a five-second window is
# ~600 frames, so a 200ms freeze -- plainly visible on a marquee -- # ~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) logger.info("Starting Vegas iteration for %.1fs", duration)
while True: 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 # Check for STATIC mode plugin that should pause scroll
static_plugin = self._check_static_plugin_trigger() static_plugin = self._check_static_plugin_trigger()
@@ -436,7 +474,7 @@ class VegasModeCoordinator:
# quarter of the budget spent not rendering. Subtracting the work # quarter of the budget spent not rendering. Subtracting the work
# already done keeps the pacing target while reclaiming that time, # already done keeps the pacing target while reclaiming that time,
# and yields the GIL either way so other threads still run. # 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)) time.sleep(max(0.0, frame_interval - frame_elapsed))
# Measured before the sleep: time spent working, not pacing. # Measured before the sleep: time spent working, not pacing.
@@ -448,16 +486,42 @@ class VegasModeCoordinator:
frame_count += 1 frame_count += 1
fps_frame_count += 1 fps_frame_count += 1
# Periodic FPS logging # Periodic FPS logging. Reported at INFO only when the frame rate
current_time = time.time() # 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: if current_time - last_fps_log_time >= fps_log_interval:
fps = fps_frame_count / (current_time - last_fps_log_time) fps = fps_frame_count / (current_time - last_fps_log_time)
p99 = _percentile(sorted(frame_times), 0.99) p99 = _percentile(sorted(frame_times), 0.99)
logger.info( target = self.vegas_config.target_fps
"Vegas FPS: %.1f (target: %d, frames: %d) p99 %.1fms worst %.1fms", degraded = target > 0 and fps < target * _FPS_HEALTHY_FRACTION
fps, self.vegas_config.target_fps, fps_frame_count, due = (current_time - self._fps_last_health_log
p99 * 1000.0, frame_worst * 1000.0 >= _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 last_fps_log_time = current_time
fps_frame_count = 0 fps_frame_count = 0
frame_worst = 0.0 frame_worst = 0.0
+79 -1
View File
@@ -5,7 +5,7 @@ Provides functions for identifying, masking, separating, and filtering
secret fields in plugin configurations based on JSON Schema x-secret markers. secret fields in plugin configurations based on JSON Schema x-secret markers.
""" """
from typing import Any, Dict, Set, Tuple from typing import Any, Dict, Optional, Set, Tuple
def find_secret_fields(properties: Dict[str, Any], prefix: str = '') -> Set[str]: def find_secret_fields(properties: Dict[str, Any], prefix: str = '') -> Set[str]:
@@ -202,11 +202,89 @@ def remove_empty_secrets(secrets: Dict[str, Any]) -> Dict[str, Any]:
nested = remove_empty_secrets(v) nested = remove_empty_secrets(v)
if nested: if nested:
result[k] = nested result[k] = nested
elif isinstance(v, list):
# Lists used to fall through to the scalar branch below and be
# kept verbatim, blanks and all. Because lists merge by
# *replacement*, saving any unrelated setting then wrote
# [{"token": ""}, ...] straight over the stored list and
# destroyed every credential in it.
pruned = _prune_secret_list(v)
if pruned is not None:
result[k] = pruned
elif v is not None and not (isinstance(v, str) and v.strip() == ''): elif v is not None and not (isinstance(v, str) and v.strip() == ''):
result[k] = v result[k] = v
return result return result
def _prune_secret_list(items: list) -> Optional[list]:
"""Strip blanks from inside a list of secrets, preserving every index.
The rest of the system treats a secrets list as *parallel* to the regular
one -- ``sec[i]`` holds the secret fields of item ``i``, and ``{}`` means
"item i has none" (see ConfigManager._strip_secrets_recursive). So an
emptied dict item stays ``{}``: putting ``None`` there makes that list stop
looking parallel, and the stripper then drops the whole key from the main
config, taking the non-secret fields with it.
A blank *scalar* becomes ``None``, meaning "no update at this index" --
:func:`merge_secrets` substitutes whatever is stored there. Returns
``None`` when nothing in the list carries a real value, so the caller drops
the key and leaves the stored list untouched.
"""
pruned: list = []
has_real_value = False
for item in items:
if isinstance(item, dict):
kept = remove_empty_secrets(item)
pruned.append(kept)
has_real_value = has_real_value or bool(kept)
elif isinstance(item, list):
sub = _prune_secret_list(item)
pruned.append(sub if sub is not None else [])
has_real_value = has_real_value or sub is not None
elif item is not None and not (isinstance(item, str) and item.strip() == ''):
pruned.append(item)
has_real_value = True
else:
pruned.append(None)
return pruned if has_real_value else None
def merge_secrets(stored: Any, incoming: Any) -> Any:
"""Merge submitted secrets over stored ones, element-wise inside lists.
``deep_merge`` replaces a list wholesale. For secrets that is destructive:
an incoming list that carries a real value for one entry and ``None`` for
the rest would drop the stored credentials of every other entry. Here a
list merges by index, and ``None`` means "keep what is stored".
Entries are matched by *position*, which is what the config form gives us
-- there is no schema-declared identity to key on, and it is the same
contract ConfigManager._strip_secrets_recursive already relies on. The
incoming list's length wins, so deleting an item deletes its secrets;
an item the client left blank keeps whatever is stored at that index.
"""
if isinstance(stored, dict) and isinstance(incoming, dict):
merged = dict(stored)
for key, value in incoming.items():
merged[key] = (merge_secrets(stored[key], value)
if key in stored else value)
return merged
if isinstance(stored, list) and isinstance(incoming, list):
# The incoming list sets the length -- the regular config's list is
# authoritative about how many items exist, and this one runs parallel
# to it. Removing an entry must therefore remove its secrets too.
merged_list = []
for index, item in enumerate(incoming):
stored_item = stored[index] if index < len(stored) else None
merged_list.append(stored_item if item is None
else merge_secrets(stored_item, item))
return merged_list
if incoming is None:
return stored
return incoming
def strip_masked_values(secrets: Dict[str, Any]) -> Dict[str, Any]: def strip_masked_values(secrets: Dict[str, Any]) -> Dict[str, Any]:
"""Remove values a client echoed back rather than changed. """Remove values a client echoed back rather than changed.
+85
View File
@@ -0,0 +1,85 @@
"""Non-finite JSON numbers must be rejected, not raise.
json.loads accepts Infinity/-Infinity/NaN by default (they are not valid JSON,
but Python's parser emits them) and Flask's get_json passes them straight
through. int(float('inf')) raises OverflowError, which is neither ValueError
nor TypeError -- so validation blocks that carefully caught those let it
through and Flask turned it into a 500.
The damage was not the status code. /config/dim-schedule answered with
CONFIG_SAVE_FAILED and suggested "Check file permissions on config directory"
and "Check available disk space" for what was actually an invalid number.
NaN already returned 400 (int(nan) raises ValueError), which is why this only
showed up for the infinities.
"""
import sys
from pathlib import Path
import pytest
sys.path.insert(0, str(Path(__file__).parent.parent))
from test._api_v3_test_helpers import api_v3_client, api_v3_module # noqa: F401,E402
#: (route, field) that returned 500 before OverflowError was caught. Both
#: infinity signs are exercised: int() raises OverflowError for either, but
#: only one of them was in the original report, and a guard that special-cased
#: the sign would pass a one-sided test.
NON_FINITE_ROUTES = [
('/api/v3/config/dim-schedule', 'dim_brightness'),
('/api/v3/errors/clear', 'max_age_hours'),
('/api/v3/config/main', 'multiplexing'),
('/api/v3/config/main', 'row_address_type'),
]
NON_FINITE_CASES = [
(route, '{"%s": %s}' % (field, literal))
for route, field in NON_FINITE_ROUTES
for literal in ('Infinity', '-Infinity')
]
@pytest.mark.parametrize("route,body", NON_FINITE_CASES)
def test_infinity_is_a_client_error_not_a_server_error(api_v3_client, route, body):
"""Exactly 400, not merely "some 4xx".
Accepting any 4xx would let a 404 pass, so renaming one of these routes
would leave the test green while testing nothing -- the failure mode this
whole file exists to catch.
"""
response = api_v3_client.post(route, data=body, content_type='application/json')
assert response.status_code == 400, (
f"{route} with {body} answered {response.status_code}; expected 400"
)
@pytest.mark.parametrize("route,body", [
('/api/v3/config/dim-schedule', '{"dim_brightness": NaN}'),
('/api/v3/errors/clear', '{"max_age_hours": NaN}'),
])
def test_nan_is_also_a_client_error(api_v3_client, route, body):
"""int(nan) raises ValueError so this path already worked -- pinned so a
refactor that narrows the except tuple cannot quietly break it."""
response = api_v3_client.post(route, data=body, content_type='application/json')
assert response.status_code == 400
def test_a_valid_number_is_accepted(api_v3_client, api_v3_module, monkeypatch):
"""Prove the widened except did not start swallowing ordinary input.
Asserting "not a 400" would not show that: the mocked save path fails for
any input, so the assertion would hold even if validation had rejected the
value. Give load_config a real dict and stub the atomic save, and the
endpoint reaches its success response -- which only happens if 30 passed
validation.
"""
api_v3_module.api_v3.config_manager.load_config.return_value = {}
monkeypatch.setattr(api_v3_module, '_save_config_atomic',
lambda *a, **k: (True, ''))
response = api_v3_client.post(
'/api/v3/config/dim-schedule',
data='{"dim_brightness": 30}',
content_type='application/json',
)
assert response.status_code == 200, response.get_data(as_text=True)[:200]
+187
View File
@@ -0,0 +1,187 @@
"""A delivered fetch payload must not stay resident on the stored result.
BackgroundDataService kept the fetched body on the FetchResult it filed in
`completed_requests`, which is swept only hourly and capped at 500 entries by
count. For status records that is free; for a season schedule it is not. NCAA
football's 2026 schedule is 946 games, and on a 1GB Pi 3B+ the parsed payload
measured ~90MB -- a tenth of the board's memory, pinned for an hour after the
consumer had already been handed it.
The cache-hit path was the worse of the two. It runs once per update interval
per sport, mints a fresh request_id each time, and hands back whatever the
cache returns -- so a memory-tier miss (the tier is capped at 150 entries)
re-parses the payload from disk into a genuinely new object. Those accumulate
as separate copies rather than shared references, which is the staircase seen
in the field: RSS stepping up ~90MB per sport as seasons loaded and never
coming back down.
Releasing is safe because the payload is written to the cache under the
request's cache_key before the result is built, and that is where consumers
read it from -- the callback is handed the object directly and the plugins use
it only in passing before reading the cache back.
Requests submitted *without* a callback keep their payload: polling
get_result() is then the only way to collect it, so releasing would break that
contract.
"""
import time
import pytest
from unittest.mock import MagicMock, Mock, patch
from src.background_data_service import BackgroundDataService
PAYLOAD = {"events": [{"id": f"g{i}"} for i in range(50)]}
@pytest.fixture
def cache():
m = MagicMock()
m.get.return_value = None
m.set.return_value = None
return m
@pytest.fixture
def service(cache):
svc = BackgroundDataService(cache, max_workers=2, request_timeout=5)
yield svc
svc.shutdown(wait=False)
def _wait(service, req_id, timeout=5):
"""Wait for the result to be FILED.
Enough for anything that is true by the time the worker stores the result:
its success flag, its error, the cache write that happened during the
fetch.
"""
deadline = time.time() + timeout
while not service.is_request_complete(req_id) and time.time() < deadline:
time.sleep(0.02)
def _wait_for_release(service, req_id, timeout=5):
"""Wait for the payload to be RELEASED, which is strictly later.
The worker files the result, then runs the callback, then releases. So
is_request_complete() goes true while the callback still has not run --
waiting on it alone leaves a window in which `seen` is empty and the
payload is still resident, and the assertions race the worker. It passes
in practice only because a one-line callback usually beats the 20ms poll.
Release happens after the callback returns, so a released payload also
means the callback has finished: one wait covers both.
"""
deadline = time.time() + timeout
while time.time() < deadline:
result = service.get_result(req_id)
if result is not None and result.data is None:
return
time.sleep(0.02)
raise AssertionError(
f"payload for {req_id} was never released (callback may not have run)")
def _resp():
r = Mock()
r.json.return_value = PAYLOAD
r.raise_for_status.return_value = None
return r
class TestFetchPath:
def test_callback_receives_the_payload_then_it_is_released(self, service, cache):
seen = {}
def callback(result):
# The consumer's one look at the data happens here.
seen['events'] = len(result.data['events'])
with patch.object(service.session, "get", return_value=_resp()):
req_id = service.submit_fetch_request(
sport="ncaa_fb", year=2026, url="https://example.com/s",
cache_key="ncaa_fb_2026", callback=callback, max_retries=0,
)
_wait_for_release(service, req_id)
assert seen['events'] == 50, "callback must still be handed the payload"
stored = service.get_result(req_id)
assert stored is not None
assert stored.success is True
assert stored.data is None, "payload must not stay on the stored result"
def test_nothing_is_lost_the_cache_holds_it(self, service, cache):
with patch.object(service.session, "get", return_value=_resp()):
req_id = service.submit_fetch_request(
sport="ncaa_fb", year=2026, url="https://example.com/s",
cache_key="ncaa_fb_2026", callback=lambda r: None, max_retries=0,
)
_wait(service, req_id)
cache.set.assert_called_once()
key, written = cache.set.call_args[0][:2]
assert key == "ncaa_fb_2026"
assert written == PAYLOAD, "the payload must be persisted before release"
def test_without_a_callback_the_payload_is_kept(self, service, cache):
# Polling get_result() is then the only delivery mechanism.
with patch.object(service.session, "get", return_value=_resp()):
req_id = service.submit_fetch_request(
sport="nfl", year=2026, url="https://example.com/s",
cache_key="nfl_2026", max_retries=0,
)
_wait(service, req_id)
assert service.get_result(req_id).data == PAYLOAD
def test_a_failed_fetch_still_records_its_error(self, service, cache):
with patch.object(service.session, "get", side_effect=Exception("boom")):
req_id = service.submit_fetch_request(
sport="nfl", year=2026, url="https://example.com/s",
cache_key="nfl_2026", callback=lambda r: None, max_retries=0,
)
_wait(service, req_id)
stored = service.get_result(req_id)
assert stored.success is False
assert stored.error is not None
class TestCacheHitPath:
def test_cache_hit_releases_after_the_callback(self, service, cache):
cache.get.return_value = PAYLOAD
seen = {}
req_id = service.submit_fetch_request(
sport="ncaa_fb", year=2026, url="https://example.com/s",
cache_key="ncaa_fb_2026",
callback=lambda r: seen.update(events=len(r.data['events'])),
)
assert seen['events'] == 50
assert service.get_result(req_id).data is None
def test_repeated_cache_hits_do_not_accumulate_payloads(self, service, cache):
# The staircase: one entry per update interval per sport, each one
# potentially a freshly parsed copy after a memory-tier miss.
cache.get.return_value = PAYLOAD
for _ in range(25):
service.submit_fetch_request(
sport="ncaa_fb", year=2026, url="https://example.com/s",
cache_key="ncaa_fb_2026", callback=lambda r: None,
)
retained = [r for r in service.completed_requests.values() if r.data is not None]
assert retained == [], f"{len(retained)} payloads still resident"
def test_cache_hit_without_a_callback_is_unchanged(self, service, cache):
cache.get.return_value = PAYLOAD
req_id = service.submit_fetch_request(
sport="nfl", year=2026, url="https://example.com/s",
cache_key="nfl_2026",
)
assert service.get_result(req_id).data == PAYLOAD
@@ -6,6 +6,7 @@ These tests cover the reconcile path that loads/unloads plugins and rebuilds
the dispatch maps on the main thread when the enabled set changes. the dispatch maps on the main thread when the enabled set changes.
""" """
import copy
from unittest.mock import MagicMock from unittest.mock import MagicMock
@@ -253,3 +254,182 @@ class TestEnabledSetChanged:
{"a": {"enabled": True, "duration": 30}}, {"a": {"enabled": True, "duration": 30}},
{"a": {"enabled": True, "duration": 45}}, {"a": {"enabled": True, "duration": 45}},
) is False ) is False
class TestEnabledPluginNotRunning:
"""A plugin that fails validate_config() is enabled but absent, and the
config edit that fixes it is nested inside the plugin's own section -- so
the top-level ``enabled`` comparison never sees it. These cover the second
gate that queues a reconcile in that case.
"""
def test_nested_edit_is_invisible_to_the_enabled_set_check(self, test_display_controller):
"""The original gate: proves why a second one is needed."""
controller = test_display_controller
old = {"hockey-scoreboard": {"enabled": True, "nhl": {"enabled": False}}}
new = {"hockey-scoreboard": {"enabled": True, "nhl": {"enabled": True}}}
# Enabling a league changes no top-level flag.
assert controller._enabled_set_changed(old, new) is False
def test_queues_reconcile_when_enabled_plugin_is_absent(self, test_display_controller):
controller = test_display_controller
controller.plugin_manager.plugin_manifests = {"hockey-scoreboard": {}}
controller.plugin_manager.discovered_plugin_ids.return_value = {"hockey-scoreboard"}
controller.plugin_display_modes = {} # failed to load
cfg = {"hockey-scoreboard": {"enabled": True, "nhl": {"enabled": True}}}
assert controller._enabled_plugin_not_running(cfg) is True
def test_quiet_when_every_enabled_plugin_is_running(self, test_display_controller):
controller = test_display_controller
controller.plugin_manager.plugin_manifests = {"hockey-scoreboard": {}}
controller.plugin_manager.discovered_plugin_ids.return_value = {"hockey-scoreboard"}
controller.plugin_display_modes = {"hockey-scoreboard": ["nhl"]}
cfg = {"hockey-scoreboard": {"enabled": True}}
assert controller._enabled_plugin_not_running(cfg) is False
def test_disabled_plugin_does_not_queue(self, test_display_controller):
controller = test_display_controller
controller.plugin_manager.plugin_manifests = {"hockey-scoreboard": {}}
controller.plugin_manager.discovered_plugin_ids.return_value = {"hockey-scoreboard"}
controller.plugin_display_modes = {}
cfg = {"hockey-scoreboard": {"enabled": False}}
assert controller._enabled_plugin_not_running(cfg) is False
def test_non_plugin_sections_do_not_queue(self, test_display_controller):
"""``schedule``/``display`` carry their own ``enabled`` and are never
in plugin_display_modes -- without the manifest check they would queue
a reconcile, and therefore a filesystem scan, on every config save."""
controller = test_display_controller
controller.plugin_manager.plugin_manifests = {"hockey-scoreboard": {}}
controller.plugin_manager.discovered_plugin_ids.return_value = {"hockey-scoreboard"}
controller.plugin_display_modes = {"hockey-scoreboard": ["nhl"]}
cfg = {
"hockey-scoreboard": {"enabled": True},
"schedule": {"enabled": True},
"display": {"enabled": True},
}
assert controller._enabled_plugin_not_running(cfg) is False
def test_non_dict_section_is_ignored(self, test_display_controller):
controller = test_display_controller
controller.plugin_manager.plugin_manifests = {"hockey-scoreboard": {}}
controller.plugin_manager.discovered_plugin_ids.return_value = {"hockey-scoreboard"}
controller.plugin_display_modes = {}
assert controller._enabled_plugin_not_running({"hockey-scoreboard": "nonsense"}) is False
def test_no_plugin_manager_is_quiet(self, test_display_controller):
controller = test_display_controller
controller.plugin_manager = None
assert controller._enabled_plugin_not_running({"x": {"enabled": True}}) is False
class TestReconcileQueuedThroughSubscriber:
"""End-to-end through the real config-change subscriber, not the helper.
Without the second gate this is the four-day-outage path: the plugin is
enabled, absent, and the save that enables its league sets no flag.
"""
@staticmethod
def _subscriber(controller):
subs = controller.config_service._subscribers['*']
for cb in subs:
if getattr(cb, '__name__', '') == '_controller_config_change':
return cb
raise AssertionError(f"controller subscriber not found among {subs}")
@staticmethod
def _configs(controller, plugin_section_old, plugin_section_new):
"""Build two full configs differing only inside the plugin section --
the subscriber refreshes its cache from these, so they must be real."""
base = copy.deepcopy(controller.config)
old = copy.deepcopy(base)
new = copy.deepcopy(base)
old["hockey-scoreboard"] = plugin_section_old
new["hockey-scoreboard"] = plugin_section_new
return old, new
def test_nested_edit_queues_reconcile_for_absent_plugin(self, test_display_controller):
controller = test_display_controller
controller.plugin_manager.plugin_manifests = {"hockey-scoreboard": {}}
controller.plugin_manager.discovered_plugin_ids.return_value = {"hockey-scoreboard"}
controller.plugin_display_modes = {} # validate_config() said False
controller._pending_plugin_reconcile = False
old, new = self._configs(
controller,
{"enabled": True, "nhl": {"enabled": False}},
{"enabled": True, "nhl": {"enabled": True}},
)
# The original gate is blind to this edit ...
assert controller._enabled_set_changed(old, new) is False
self._subscriber(controller)(old, new)
# ... but the reconcile is queued anyway.
assert controller._pending_plugin_reconcile is True
def test_steady_state_does_not_queue_reconcile(self, test_display_controller):
"""Everything enabled is running: an unrelated edit must not queue a
reconcile, or every config save drags a filesystem scan onto the
render thread."""
controller = test_display_controller
controller.plugin_manager.plugin_manifests = {"hockey-scoreboard": {}}
controller.plugin_manager.discovered_plugin_ids.return_value = {"hockey-scoreboard"}
controller.plugin_display_modes = {"hockey-scoreboard": ["nhl"]}
controller._pending_plugin_reconcile = False
old, new = self._configs(
controller,
{"enabled": True, "scroll_speed": 1},
{"enabled": True, "scroll_speed": 2},
)
self._subscriber(controller)(old, new)
assert controller._pending_plugin_reconcile is False
class TestPendingReconcileNotLost:
"""A config change arriving *during* reconcile must not be discarded.
The flag used to be cleared after a successful reconcile. Reconcile has
already read its config by then, so that clear erased a request it never
served and the newest config never reconciled -- the same "my save did
nothing" symptom this path exists to prevent.
"""
def test_request_arriving_during_reconcile_survives(self, test_display_controller):
controller = test_display_controller
controller._pending_plugin_reconcile = True
def reconcile_and_race():
# The watcher thread queues another change while we are mid-flight.
with controller._reconcile_flag_lock:
controller._pending_plugin_reconcile = True
return True
controller._reconcile_enabled_plugins = reconcile_and_race
controller._service_pending_reconcile()
assert controller._pending_plugin_reconcile is True, \
"a config change landing during reconcile was discarded"
def test_flag_cleared_on_a_quiet_success(self, test_display_controller):
controller = test_display_controller
controller._pending_plugin_reconcile = True
controller._reconcile_enabled_plugins = lambda: True
controller._service_pending_reconcile()
assert controller._pending_plugin_reconcile is False
def test_retryable_failure_rearms(self, test_display_controller):
controller = test_display_controller
controller._pending_plugin_reconcile = True
controller._reconcile_enabled_plugins = lambda: False
controller._service_pending_reconcile()
assert controller._pending_plugin_reconcile is True
def test_no_reconcile_when_nothing_pending(self, test_display_controller):
controller = test_display_controller
controller._pending_plugin_reconcile = False
calls = []
controller._reconcile_enabled_plugins = lambda: calls.append(1) or True
controller._service_pending_reconcile()
assert calls == []
+34 -2
View File
@@ -13,6 +13,7 @@ need root and mutate the system, so they are exercised manually instead.
""" """
import subprocess import subprocess
import tempfile
from pathlib import Path from pathlib import Path
import pytest import pytest
@@ -31,6 +32,16 @@ def run_lib(snippet: str, env: dict | None = None) -> subprocess.CompletedProces
) )
def _fstype_of(path: object) -> str:
"""Filesystem type backing ``path``, via the same tool the helper uses."""
result = subprocess.run(
["findmnt", "-no", "FSTYPE", "--target", str(path)],
capture_output=True, text=True,
env={"PATH": "/usr/bin:/bin:/usr/sbin:/sbin"},
)
return result.stdout.strip()
def call(fn: str, *args: object, env: dict | None = None) -> str: def call(fn: str, *args: object, env: dict | None = None) -> str:
joined = " ".join(str(a) for a in args) joined = " ".join(str(a) for a in args)
result = run_lib(f"{fn} {joined}", env=env) result = run_lib(f"{fn} {joined}", env=env)
@@ -195,8 +206,29 @@ class TestOomDetection:
class TestDiskBackedTmpdir: class TestDiskBackedTmpdir:
def test_returns_nothing_when_tmpdir_is_already_disk_backed(self, tmp_path): def test_returns_nothing_when_tmpdir_is_already_disk_backed(self, tmp_path):
# tmp_path is on the regular filesystem, so the default must be kept. # Do not assume tmp_path is disk-backed. Debian 13 -- the platform this
assert call("lm_disk_backed_tmpdir", env={"TMPDIR": str(tmp_path)}) == "" # helper exists for -- mounts /tmp as tmpfs, and pytest puts tmp_path
# under /tmp, so this asserted against a *memory*-backed directory and
# failed on the target platform while the helper behaved exactly as
# designed. Search for a directory whose backing store is really disk.
scratch = None
disk_backed = None
for candidate in (tmp_path, Path("/var/tmp"), LIB.parent):
if _fstype_of(candidate) not in ("tmpfs", "ramfs", ""):
if candidate is tmp_path:
disk_backed = candidate
else:
scratch = Path(tempfile.mkdtemp(dir=str(candidate)))
disk_backed = scratch
break
if disk_backed is None:
pytest.skip("no disk-backed directory available to test against")
try:
assert call("lm_disk_backed_tmpdir",
env={"TMPDIR": str(disk_backed)}) == ""
finally:
if scratch is not None:
scratch.rmdir()
def test_redirects_away_from_a_memory_backed_tmpdir(self): def test_redirects_away_from_a_memory_backed_tmpdir(self):
# Debian 13 mounts /tmp as tmpfs, which would otherwise hold the whole # Debian 13 mounts /tmp as tmpfs, which would otherwise hold the whole
+8 -2
View File
@@ -89,11 +89,17 @@ class TestContextualFormatter:
assert "hello" in out assert "hello" in out
def test_location_toggle(self): def test_location_toggle(self):
# Assert on the whole "module.func:lineno" token, not a bare ":42".
# The formatted line starts with an HH:MM:SS timestamp, so a bare
# ":{lineno}" also matches the clock whenever the minute or second
# happens to equal the line number -- about 3% of runs, which is a
# flaky failure with nothing wrong.
record = make_record() record = make_record()
location = f"{record.module}.{record.funcName}:{record.lineno}"
with_loc = ContextualFormatter(include_location=True).format(record) with_loc = ContextualFormatter(include_location=True).format(record)
without = ContextualFormatter(include_location=False).format(record) without = ContextualFormatter(include_location=False).format(record)
assert f":{record.lineno}" in with_loc assert location in with_loc
assert f":{record.lineno}" not in without assert location not in without
def test_record_not_mutated_no_double_prefix(self): def test_record_not_mutated_no_double_prefix(self):
# Regression: a record is formatted once PER HANDLER. The formatter # Regression: a record is formatted once PER HANDLER. The formatter
@@ -0,0 +1,63 @@
"""Tests for PluginManager.discovered_plugin_ids().
The config-watcher thread needs the set of discovered plugin ids while the
render thread may be rebuilding plugin_manifests. Iterating that dict directly
can observe a half-populated mapping or raise "dictionary changed size during
iteration", so the accessor snapshots it under the discovery lock.
"""
import tempfile
import threading
from pathlib import Path
import pytest
from src.plugin_system.plugin_manager import PluginManager
@pytest.fixture
def pm():
with tempfile.TemporaryDirectory() as tmp:
yield PluginManager(plugins_dir=str(Path(tmp) / "plugins"))
def test_returns_the_discovered_ids(pm):
pm.plugin_manifests = {"clock-simple": {}, "hockey-scoreboard": {}}
assert pm.discovered_plugin_ids() == {"clock-simple", "hockey-scoreboard"}
def test_empty_when_nothing_discovered(pm):
pm.plugin_manifests = {}
assert pm.discovered_plugin_ids() == set()
def test_is_a_snapshot_not_a_live_view(pm):
"""The caller iterates the result on another thread; it must not alias
the mapping discovery is still writing to."""
pm.plugin_manifests = {"clock-simple": {}}
snapshot = pm.discovered_plugin_ids()
pm.plugin_manifests["hockey-scoreboard"] = {}
assert snapshot == {"clock-simple"}
def test_takes_the_discovery_lock(pm):
"""Guards against the lock being dropped in a later refactor: with the
lock held by another thread the call must block rather than read."""
pm.plugin_manifests = {"clock-simple": {}}
finished = threading.Event()
def call():
pm.discovered_plugin_ids()
finished.set()
pm._discovery_lock.acquire()
try:
# RLock is reentrant per-thread, so use a *different* thread to prove
# the accessor actually waits on it.
t = threading.Thread(target=call, daemon=True)
t.start()
assert not finished.wait(timeout=0.3), "accessor did not take the discovery lock"
finally:
pm._discovery_lock.release()
t.join(timeout=2)
assert finished.is_set()
+166
View File
@@ -0,0 +1,166 @@
"""Plugin state history must not grow without bound.
`PluginStateManager` recorded every state transition in a per-plugin list and
never trimmed it. The only code that removed entries was `clear_state()`, called
solely from `PluginManager.unload_plugin()`, so a plugin that stays loaded --
i.e. normal operation -- never released a single entry.
The list is written on the hot scheduling path. Every update cycle appends
twice: `_reserve_for_update()` sets RUNNING and `_finish()` sets ENABLED back
again. At the default 60-second update interval that is 2,880 entries per
plugin per day, and nothing ever reads the entries -- `get_state_info()` only
takes their `len()`. It is pure dead weight.
Measured against the unpatched class, ten plugins on a 60s interval retain
864,010 transitions after thirty simulated days, for 231 MB of heap. On a 1 GB
Pi that is fatal on its own, and the failure is not a clean OOM: once
MemAvailable falls far enough, fork() starts returning ENOMEM, so sshd accepts
connections and closes them before its banner while the kernel still answers
pings. The board looks like a hardware fault and needs a power cycle.
These tests pin the cap, the retention order, and the one piece of behaviour the
cap must not change: `state_history_count` is surfaced through the web API, so
it has to keep reporting the lifetime total rather than plateauing at the cap.
"""
import os
import sys
import pytest
sys.path.insert(0, os.path.join(os.path.dirname(__file__), ".."))
from src.plugin_system.plugin_state import ( # noqa: E402
MAX_STATE_HISTORY_PER_PLUGIN,
PluginState,
PluginStateManager,
)
def _cycle_updates(manager, plugin_id, cycles):
"""Drive the real scheduling path: RUNNING on reserve, ENABLED on finish."""
for _ in range(cycles):
manager.set_state(plugin_id, PluginState.RUNNING)
manager.set_state(plugin_id, PluginState.ENABLED)
def test_state_history_is_capped():
"""A day of updates must not retain a day of transitions."""
manager = PluginStateManager()
manager.set_state("clock", PluginState.ENABLED)
# One simulated day at the default 60s update interval.
_cycle_updates(manager, "clock", 1440)
history = manager.get_state_history("clock")
assert len(history) <= MAX_STATE_HISTORY_PER_PLUGIN, (
f"history grew to {len(history)} entries; it is never trimmed"
)
def test_state_history_keeps_the_most_recent_transitions():
"""Trimming drops the oldest entries, not the newest."""
manager = PluginStateManager()
manager.set_state("clock", PluginState.ENABLED)
_cycle_updates(manager, "clock", MAX_STATE_HISTORY_PER_PLUGIN)
history = manager.get_state_history("clock")
# The scheduling cycle ends on ENABLED, so the newest entry is the
# RUNNING -> ENABLED half of the last cycle.
assert history[-1]["from"] == PluginState.RUNNING.value
assert history[-1]["to"] == PluginState.ENABLED.value
# And the very first ENABLED transition has aged out.
assert history[0]["from"] != PluginState.UNLOADED.value
def test_state_history_count_reports_lifetime_total():
"""The count exposed through the API must not plateau at the cap.
`get_state_info()['state_history_count']` is surfaced by the web UI. Capping
the retained list must not turn it into "entries we happen to still hold".
"""
manager = PluginStateManager()
manager.set_state("clock", PluginState.ENABLED)
total = 1
cycles = MAX_STATE_HISTORY_PER_PLUGIN * 2
_cycle_updates(manager, "clock", cycles)
total += cycles * 2
info = manager.get_state_info("clock")
assert info["state_history_count"] == total
assert len(manager.get_state_history("clock")) <= MAX_STATE_HISTORY_PER_PLUGIN
def test_error_transitions_are_capped_too():
"""set_state_with_error() appends to the same list and needs the same cap."""
manager = PluginStateManager()
manager.set_state("clock", PluginState.ENABLED)
for _ in range(MAX_STATE_HISTORY_PER_PLUGIN * 2):
manager.set_state_with_error(
"clock",
PluginState.ENABLED,
{"reason": "update timeout"},
error=RuntimeError("boom"),
)
assert len(manager.get_state_history("clock")) <= MAX_STATE_HISTORY_PER_PLUGIN
def test_history_is_isolated_per_plugin():
"""The cap is per plugin, not shared across the manager."""
manager = PluginStateManager()
for plugin_id in ("clock", "weather"):
manager.set_state(plugin_id, PluginState.ENABLED)
_cycle_updates(manager, plugin_id, 50)
assert len(manager.get_state_history("clock")) == 101
assert len(manager.get_state_history("weather")) == 101
def test_get_state_history_returns_a_copy():
"""Callers must not be able to mutate the manager's internal history."""
manager = PluginStateManager()
manager.set_state("clock", PluginState.ENABLED)
history = manager.get_state_history("clock")
history.clear()
assert len(manager.get_state_history("clock")) == 1
def test_get_state_history_entries_are_copies():
"""Copying the outer list is not enough -- the entries are handed out too.
A caller holding a returned transition must not be able to rewrite the
manager's record of what happened.
"""
manager = PluginStateManager()
manager.set_state("clock", PluginState.ENABLED)
entry = manager.get_state_history("clock")[0]
entry["to"] = "tampered"
entry["error"] = "injected"
stored = manager.get_state_history("clock")[0]
assert stored["to"] == PluginState.ENABLED.value
assert stored["error"] is None
def test_clear_state_drops_history():
"""Unloading a plugin still releases everything it accumulated."""
manager = PluginStateManager()
manager.set_state("clock", PluginState.ENABLED)
_cycle_updates(manager, "clock", 10)
manager.clear_state("clock")
assert manager.get_state_history("clock") == []
assert manager.get_state_info("clock")["state_history_count"] == 0
if __name__ == "__main__":
sys.exit(pytest.main([__file__, "-v"]))
+209
View File
@@ -0,0 +1,209 @@
"""Retention is bounded by age first and by count second.
The cap added in the parent change is a flat entry count, and an entry count
answers the wrong question. What a reader wants from this history is "the last
couple of hours"; how many transitions that is depends entirely on the
plugin's update interval, which on a real board spans 2s to 3600s. A flat 200
entries is 4.2 days of history for the slowest plugin and 3.3 minutes for the
fastest -- so the plugin churning hardest, the one actually worth looking at,
keeps the least.
Trimming by age makes the retained window comparable whatever the cadence, and
the count then serves only as a memory ceiling for pollers fast enough to
produce thousands of transitions inside that window.
"""
import time
import pytest
from src.plugin_system.plugin_state import (
PluginState,
PluginStateManager,
MAX_STATE_HISTORY_PER_PLUGIN,
STATE_HISTORY_MAX_AGE_SECONDS,
)
class FakeClock:
"""A monotonic clock the test drives, so no test has to sleep."""
def __init__(self):
self.t = 1000.0
def __call__(self):
return self.t
def advance(self, seconds):
self.t += seconds
@pytest.fixture
def clock(monkeypatch):
c = FakeClock()
monkeypatch.setattr("src.plugin_system.plugin_state.time.monotonic", c)
return c
def _cycle(manager, plugin_id, clock, interval, cycles):
"""One update cycle: RUNNING on reserve, ENABLED on finish."""
for _ in range(cycles):
manager.set_state(plugin_id, PluginState.RUNNING)
manager.set_state(plugin_id, PluginState.ENABLED)
clock.advance(interval)
def test_transitions_older_than_the_window_are_dropped(clock):
m = PluginStateManager()
_cycle(m, "clock", clock, interval=60, cycles=10)
assert len(m.get_state_history("clock")) == 20
# Nothing happens for longer than the window, then one more cycle.
clock.advance(STATE_HISTORY_MAX_AGE_SECONDS + 1)
_cycle(m, "clock", clock, interval=60, cycles=1)
assert len(m.get_state_history("clock")) == 2, (
"only the transitions inside the window should survive")
def test_every_plugin_keeps_the_same_WINDOW_not_the_same_COUNT(clock):
"""The point of the age policy, stated as the property that distinguishes it.
Run both plugins for three times the retention window. Under a flat count
cap the slow one would still be holding transitions from hours before the
window, because it never produces enough entries to evict them. Under the
age policy each plugin retains its own last two hours and no more --
different entry counts, same span of time.
"""
window = STATE_HISTORY_MAX_AGE_SECONDS
m = PluginStateManager()
_cycle(m, "slow", clock, interval=60, cycles=(3 * window) // 60)
slow = len(m.get_state_history("slow"))
# Assert the property directly rather than a derived count. The guarantee
# is about the SPAN of retained history, not its age against the current
# clock: trimming happens on append, so a plugin that has gone quiet keeps
# its last window until it writes again. That is intentional -- it is
# bounded either way, and a lazy trim costs nothing on the hot path.
stamps = [stamp for stamp, _ in m._state_history["slow"]]
assert stamps[-1] - stamps[0] <= window, (
f"retained history spans {stamps[-1] - stamps[0]:.0f}s, "
f"window is {window}s")
assert slow < 2 * ((3 * window) // 60), (
f"slow plugin kept {slow} entries -- three windows' worth was retained")
clock.t = 1000.0
_cycle(m, "fast", clock, interval=2, cycles=(3 * window) // 2)
fast = len(m.get_state_history("fast"))
# Different counts, and the fast poller keeps more of them -- under a flat
# count cap these would be equal and the fast one would cover minutes.
assert fast > slow, f"fast={fast} slow={slow}"
def test_the_count_ceiling_still_bounds_a_fast_poller(clock):
"""Age alone would let a 2s plugin hold 7,200 entries."""
m = PluginStateManager()
_cycle(m, "flights", clock, interval=2, cycles=STATE_HISTORY_MAX_AGE_SECONDS)
assert len(m.get_state_history("flights")) <= MAX_STATE_HISTORY_PER_PLUGIN
def test_a_burst_inside_the_window_is_capped_not_kept(clock):
"""Transitions with no time between them still cannot grow without bound."""
m = PluginStateManager()
for _ in range(MAX_STATE_HISTORY_PER_PLUGIN * 3):
m.set_state("flapping", PluginState.RUNNING) # clock never advances
assert len(m.get_state_history("flapping")) <= MAX_STATE_HISTORY_PER_PLUGIN
def test_ageing_out_does_not_disturb_the_lifetime_count(clock):
m = PluginStateManager()
_cycle(m, "clock", clock, interval=60, cycles=10)
clock.advance(STATE_HISTORY_MAX_AGE_SECONDS + 1)
_cycle(m, "clock", clock, interval=60, cycles=1)
assert len(m.get_state_history("clock")) == 2
assert m.get_state_info("clock")["state_history_count"] == 22, (
"the lifetime total must survive trimming, it is the flap signal")
def test_the_surviving_entries_are_the_recent_ones(clock):
m = PluginStateManager()
_cycle(m, "clock", clock, interval=60, cycles=5)
clock.advance(STATE_HISTORY_MAX_AGE_SECONDS + 1)
m.set_state("clock", PluginState.ERROR)
history = m.get_state_history("clock")
assert [h["to"] for h in history] == ["error"]
def test_a_monotonic_clock_is_used_not_the_wall_clock(clock):
"""A DST shift or NTP step must not flush the history.
The trim reads time.monotonic(); the human-readable datetime inside each
transition is for display only.
"""
m = PluginStateManager()
_cycle(m, "clock", clock, interval=60, cycles=3)
before = len(m.get_state_history("clock"))
import datetime as real_datetime
class ShiftedDatetime(real_datetime.datetime):
@classmethod
def now(cls, tz=None):
return real_datetime.datetime(1999, 1, 1) # clock jumps backwards
import src.plugin_system.plugin_state as ps
original = ps.datetime
ps.datetime = ShiftedDatetime
try:
m.set_state("clock", PluginState.ENABLED)
finally:
ps.datetime = original
assert len(m.get_state_history("clock")) == before + 1, (
"a wall-clock jump must not trim anything")
def test_get_state_info_is_a_consistent_snapshot():
"""An unload running concurrently must not be observed half-done.
Each field used to be read under its own lock, so clear_state() could
interleave: 'state' read before the removal, 'state_history_count' after,
handing a caller a plugin that is ENABLED with zero transitions. The whole
payload is now built in one critical section.
"""
import threading
m = PluginStateManager()
for _ in range(50):
m.set_state("clock", PluginState.RUNNING)
m.set_state("clock", PluginState.ENABLED)
inconsistent = []
stop = threading.Event()
def reader():
while not stop.is_set():
info = m.get_state_info("clock")
# Either fully present or fully cleared -- never a live state with
# a wiped count.
if info["state"] != PluginState.UNLOADED.value and \
info["state_history_count"] == 0:
inconsistent.append(info)
return
def clearer():
for _ in range(200):
for _ in range(20):
m.set_state("clock", PluginState.ENABLED)
m.clear_state("clock")
t = threading.Thread(target=reader, daemon=True)
t.start()
clearer()
stop.set()
t.join(timeout=5)
assert not inconsistent, f"observed a torn snapshot: {inconsistent[:1]}"
@@ -0,0 +1,92 @@
"""/api/v3/system/status must report MemAvailable, not just used/total.
"Memory used %" cannot tell a healthy board from one about to fail. Page cache
counts as used and is reclaimable on demand, so a Pi can read 70% used and be
perfectly fine, or read the same and be minutes from trouble. MemAvailable is
the kernel's own estimate of what a new allocation can actually obtain, and it
is the number that tracked the failure on a 1GB Pi 3B+: healthy running sat at
500MB+, the crash happened at 73MB, and by then fork() was failing -- sshd
could not spawn a session and systemd could not respawn the display, while the
kernel carried on answering pings.
psutil.virtual_memory().available is MemAvailable on Linux. total - used is not
a substitute: they diverge exactly when unreclaimable memory (shmem, tmpfs) is
in play, which is when the distinction matters.
"""
import json
import sys
from pathlib import Path
from unittest.mock import MagicMock, patch
import pytest
from flask import Flask
sys.path.insert(0, str(Path(__file__).parent.parent))
MB = 1024 * 1024
@pytest.fixture
def client():
pytest.importorskip("psutil")
app = Flask(__name__)
app.config["TESTING"] = True
from web_interface.blueprints.api_v3 import api_v3
for attr in ("config_manager", "plugin_manager", "cache_manager"):
setattr(api_v3, attr, MagicMock())
if "api_v3" not in app.blueprints:
app.register_blueprint(api_v3, url_prefix="/api/v3")
return app.test_client()
def _memory(total_mb, used_mb, available_mb):
m = MagicMock()
m.total = total_mb * MB
m.used = used_mb * MB
m.available = available_mb * MB
m.percent = round(used_mb / total_mb * 100, 1)
return m
def _get_status(client, memory):
# The endpoint caches for 10s; bypass so each case is measured fresh.
with patch("web_interface.cache.get_cached", return_value=None), \
patch("psutil.virtual_memory", return_value=memory), \
patch("psutil.cpu_percent", return_value=5.0), \
patch("psutil.boot_time", return_value=0.0):
resp = client.get("/api/v3/system/status")
assert resp.status_code == 200, resp.data
return json.loads(resp.data)["data"]
def test_available_memory_is_reported(client):
data = _get_status(client, _memory(total_mb=905, used_mb=620, available_mb=284))
assert "memory_available_mb" in data
assert data["memory_available_mb"] == pytest.approx(284, abs=0.5)
def test_available_is_not_total_minus_used(client):
# The case the readout exists for: 600MB is "not used", but only 300MB can
# actually be allocated. Reporting used% alone would call this healthy.
data = _get_status(client, _memory(total_mb=1000, used_mb=400, available_mb=300))
derived = data["memory_total_mb"] - data["memory_used_mb"]
assert derived == pytest.approx(600, abs=1)
assert data["memory_available_mb"] == pytest.approx(300, abs=0.5)
assert data["memory_available_mb"] != pytest.approx(derived, abs=1), \
"available must come from MemAvailable, not be derived from used"
def test_existing_memory_fields_are_unchanged(client):
data = _get_status(client, _memory(total_mb=905, used_mb=620, available_mb=284))
assert data["memory_total_mb"] == pytest.approx(905, abs=0.5)
assert data["memory_used_mb"] == pytest.approx(620, abs=0.5)
assert "memory_used_percent" in data
def test_a_nearly_exhausted_board_reports_a_small_number(client):
# 73MB available is what the board actually read when it stopped being able
# to fork. The readout has to surface that rather than round it away.
data = _get_status(client, _memory(total_mb=905, used_mb=800, available_mb=73))
assert data["memory_available_mb"] == pytest.approx(73, abs=0.5)
+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")
@@ -229,6 +229,44 @@ class TestSavePluginConfig:
"REAL-KEY-0123456789", "an unrelated edit destroyed the API key" "REAL-KEY-0123456789", "an unrelated edit destroyed the API key"
assert env.fresh_load()[PLUGIN_ID]["city"] == "Dallas" assert env.fresh_load()[PLUGIN_ID]["city"] == "Dallas"
def test_an_unrelated_edit_does_not_erase_array_item_secrets(self, env):
"""The scalar api_key case above, but for a list of credentials.
remove_empty_secrets recursed into dicts only, so a list went into
deep_merge untouched -- and lists merge by *replacement*. Saving any
unrelated field posted [{"token": ""}, ...] straight over the stored
array and destroyed every token in it at once.
"""
assert self._save(env, {"accounts": [
{"name": "a", "token": "REAL-A"},
{"name": "b", "token": "REAL-B"},
], "city": "Austin"}).status_code == 200
# the user changes the city; both masked tokens ride along blank
assert self._save(env, {"accounts": [
{"name": "a", "token": ""},
{"name": "b", "token": ""},
], "city": "Dallas"}).status_code == 200
merged = env.fresh_load()[PLUGIN_ID]
assert [a.get("token") for a in merged["accounts"]] == \
["REAL-A", "REAL-B"], "an unrelated edit destroyed the array secrets"
assert [a["name"] for a in merged["accounts"]] == ["a", "b"]
assert merged["city"] == "Dallas"
def test_one_array_secret_can_be_changed_without_losing_the_rest(self, env):
assert self._save(env, {"accounts": [
{"name": "a", "token": "REAL-A"},
{"name": "b", "token": "REAL-B"},
]}).status_code == 200
assert self._save(env, {"accounts": [
{"name": "a", "token": ""},
{"name": "b", "token": "NEW-B"},
]}).status_code == 200
merged = env.fresh_load()[PLUGIN_ID]
assert [a.get("token") for a in merged["accounts"]] == ["REAL-A", "NEW-B"]
def test_a_secret_can_still_be_changed(self, env): def test_a_secret_can_still_be_changed(self, env):
"""Dropping blanks must not stop a real new value from being saved.""" """Dropping blanks must not stop a real new value from being saved."""
self._save(env, {"api_key": "first-key"}) self._save(env, {"api_key": "first-key"})
@@ -0,0 +1,45 @@
"""The validation logging ran before separate_secrets, so it logged credentials.
api_v3's plugin-config save logged `Full config: {plugin_config}` at INFO and
`Config that failed: {plugin_config}` at ERROR. Both run *before*
separate_secrets(), so plugin_config still held the values the user just typed
into the form -- API keys and tokens went to the journal in clear text.
"""
import re
from pathlib import Path
import pytest
SOURCE = (Path(__file__).resolve().parents[2]
/ "web_interface" / "blueprints" / "api_v3.py")
#: Objects that still hold submitted secret values at the point these log
#: calls run. Interpolating one whole into a log message leaks credentials.
UNREDACTED = ("plugin_config", "secrets_config", "current_secrets")
def _logging_lines():
for number, line in enumerate(SOURCE.read_text(encoding="utf-8").splitlines(), 1):
stripped = line.strip()
if stripped.startswith("#"):
continue
if re.match(r"logger\.(debug|info|warning|error|critical|exception)\(", stripped):
yield number, stripped
@pytest.mark.parametrize("name", UNREDACTED)
def test_no_log_call_interpolates_a_whole_secret_bearing_object(name):
# {name} or {name['k']} leaks; {list(name.keys())} and {len(name)} do not.
bare = re.compile(r"\{" + re.escape(name) + r"(\[[^\]]*\])*\}")
offenders = [f"{n}: {text}" for n, text in _logging_lines() if bare.search(text)]
assert not offenders, (
f"{name} still holds submitted secrets where these log calls run:\n "
+ "\n ".join(offenders))
def test_the_guard_would_notice_a_reintroduced_leak():
"""Pin the detector itself, so a rewrite cannot silently stop matching."""
bare = re.compile(r"\{" + re.escape("plugin_config") + r"(\[[^\]]*\])*\}")
assert bare.search('logger.info(f"Full config: {plugin_config}")')
assert bare.search("logger.error(f\"{plugin_config['api_key']}\")")
assert not bare.search('logger.info(f"{list(plugin_config.keys())}")')
+65
View File
@@ -17,6 +17,7 @@ from src.web_interface.secret_helpers import (
separate_secrets, separate_secrets,
mask_secret_fields, mask_secret_fields,
mask_all_secret_values, mask_all_secret_values,
merge_secrets,
remove_empty_secrets, remove_empty_secrets,
) )
@@ -239,3 +240,67 @@ class TestRemoveEmptySecrets:
def test_keeps_falsey_non_string_values(self): def test_keeps_falsey_non_string_values(self):
# 0 and False are neither None nor blank strings — they are kept. # 0 and False are neither None nor blank strings — they are kept.
assert remove_empty_secrets({"a": 0, "b": False}) == {"a": 0, "b": False} assert remove_empty_secrets({"a": 0, "b": False}) == {"a": 0, "b": False}
class TestArrayItemSecrets:
"""Lists merge by replacement, so a blanked array wipes stored credentials.
remove_empty_secrets recursed into dicts but let a list through untouched,
so [{"token": ""}] went straight into deep_merge and overwrote the stored
list. Saving any unrelated setting destroyed every token in the array.
"""
STORED = {"accounts": [{"name": "a", "token": "REAL-A"},
{"name": "b", "token": "REAL-B"}]}
def test_an_unrelated_save_keeps_every_stored_token(self):
posted = {"accounts": [{"name": "a", "token": ""},
{"name": "b", "token": ""}]}
merged = merge_secrets(self.STORED, remove_empty_secrets(posted))
assert [a["token"] for a in merged["accounts"]] == ["REAL-A", "REAL-B"]
def test_editing_one_entry_leaves_the_others_alone(self):
posted = {"accounts": [{"name": "a", "token": ""},
{"name": "b", "token": "NEW-B"}]}
merged = merge_secrets(self.STORED, remove_empty_secrets(posted))
assert [a["token"] for a in merged["accounts"]] == ["REAL-A", "NEW-B"]
def test_a_new_entry_is_appended(self):
posted = {"accounts": [{"name": "a", "token": ""},
{"name": "b", "token": ""},
{"name": "c", "token": "NEW-C"}]}
merged = merge_secrets(self.STORED, remove_empty_secrets(posted))
assert [a["token"] for a in merged["accounts"]] == \
["REAL-A", "REAL-B", "NEW-C"]
def test_a_list_of_bare_strings_merges_by_index(self):
merged = merge_secrets({"keys": ["K1", "K2", "K3"]},
remove_empty_secrets({"keys": ["", "K2-NEW", ""]}))
assert merged["keys"] == ["K1", "K2-NEW", "K3"]
def test_an_all_blank_list_is_dropped_entirely(self):
posted = {"accounts": [{"token": ""}, {"token": ""}]}
assert "accounts" not in remove_empty_secrets(posted)
def test_plain_dict_secrets_are_unaffected(self):
merged = merge_secrets({"api_key": "OLD", "other": "keep"},
remove_empty_secrets({"api_key": "", "other": "changed"}))
assert merged == {"api_key": "OLD", "other": "changed"}
def test_a_removed_entry_takes_its_secret_with_it(self):
"""The regular config's list is authoritative about how many items
exist, and the secrets list runs parallel to it -- see
ConfigManager._strip_secrets_recursive. So a shorter incoming list
must shorten the stored secrets too, or the two fall out of step."""
posted = {"accounts": [{"name": "a", "token": "NEW-A"}]}
merged = merge_secrets(self.STORED, remove_empty_secrets(posted))
assert [a["token"] for a in merged["accounts"]] == ["NEW-A"]
def test_an_emptied_item_stays_a_dict_not_none(self):
"""None there stops the list looking parallel, and
_strip_secrets_recursive then drops the whole key from the main
config -- deleting the item's non-secret fields as well."""
pruned = remove_empty_secrets(
{"accounts": [{"token": "real"}, {"token": ""}]})
assert pruned["accounts"] == [{"token": "real"}, {}]
assert None not in pruned["accounts"]
+46 -32
View File
@@ -22,7 +22,8 @@ logger = logging.getLogger(__name__)
from src.web_interface.api_helpers import success_response, error_response, validate_request_json 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.errors import ErrorCode
from src.web_interface.secret_helpers import (find_secret_fields, mask_all_secret_values, from src.web_interface.secret_helpers import (find_secret_fields, mask_all_secret_values,
remove_empty_secrets, separate_secrets, merge_secrets, remove_empty_secrets,
separate_secrets,
strip_masked_values) strip_masked_values)
from src.web_interface.error_handler import describe_exception, redact_text from src.web_interface.error_handler import describe_exception, redact_text
from src.plugin_system.operation_types import OperationType from src.plugin_system.operation_types import OperationType
@@ -597,7 +598,7 @@ def save_dim_schedule_config():
dim_brightness = 30 dim_brightness = 30
else: else:
dim_brightness = int(dim_brightness_raw) dim_brightness = int(dim_brightness_raw)
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
return error_response( return error_response(
ErrorCode.VALIDATION_ERROR, ErrorCode.VALIDATION_ERROR,
"dim_brightness must be an integer between 0 and 100", "dim_brightness must be an integer between 0 and 100",
@@ -797,7 +798,7 @@ def save_main_config():
}), 400 }), 400
try: try:
target_fps = int(raw_target_fps) target_fps = int(raw_target_fps)
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
return jsonify({ return jsonify({
'status': 'error', 'status': 'error',
'message': "Invalid value for target_fps: must be an integer" 'message': "Invalid value for target_fps: must be an integer"
@@ -867,7 +868,7 @@ def save_main_config():
mux_val = int(data['multiplexing']) mux_val = int(data['multiplexing'])
if mux_val < 0 or mux_val > 22: if mux_val < 0 or mux_val > 22:
return jsonify({'status': 'error', 'message': f"Invalid multiplexing value '{data['multiplexing']}'. Must be an integer from 0 to 22."}), 400 return jsonify({'status': 'error', 'message': f"Invalid multiplexing value '{data['multiplexing']}'. Must be an integer from 0 to 22."}), 400
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
return jsonify({'status': 'error', 'message': f"Invalid multiplexing value '{data['multiplexing']}'. Must be an integer from 0 to 22."}), 400 return jsonify({'status': 'error', 'message': f"Invalid multiplexing value '{data['multiplexing']}'. Must be an integer from 0 to 22."}), 400
# Validate pixel_mapper_config (free-form mapper string, e.g. "U-mapper;Rotate:90") # Validate pixel_mapper_config (free-form mapper string, e.g. "U-mapper;Rotate:90")
@@ -885,7 +886,7 @@ def save_main_config():
rat_val = int(data['row_address_type']) rat_val = int(data['row_address_type'])
if rat_val < 0 or rat_val > 4: if rat_val < 0 or rat_val > 4:
return jsonify({'status': 'error', 'message': f"Invalid row_address_type '{data['row_address_type']}'. Must be an integer from 0 to 4."}), 400 return jsonify({'status': 'error', 'message': f"Invalid row_address_type '{data['row_address_type']}'. Must be an integer from 0 to 4."}), 400
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
return jsonify({'status': 'error', 'message': f"Invalid row_address_type '{data['row_address_type']}'. Must be an integer from 0 to 4."}), 400 return jsonify({'status': 'error', 'message': f"Invalid row_address_type '{data['row_address_type']}'. Must be an integer from 0 to 4."}), 400
# Handle hardware settings # Handle hardware settings
@@ -910,7 +911,7 @@ def save_main_config():
if rp1_val not in (0, 1): if rp1_val not in (0, 1):
return jsonify({'status': 'error', 'message': "rp1_rio must be 0 (PIO) or 1 (RIO)"}), 400 return jsonify({'status': 'error', 'message': "rp1_rio must be 0 (PIO) or 1 (RIO)"}), 400
current_config['display']['runtime']['rp1_rio'] = rp1_val current_config['display']['runtime']['rp1_rio'] = rp1_val
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
return jsonify({'status': 'error', 'message': "rp1_rio must be 0 or 1"}), 400 return jsonify({'status': 'error', 'message': "rp1_rio must be 0 or 1"}), 400
# Handle checkboxes - coerce to bool to ensure proper JSON types # Handle checkboxes - coerce to bool to ensure proper JSON types
@@ -963,7 +964,7 @@ def save_main_config():
copies = None copies = None
try: try:
copies = int(data['double_sided_copies']) copies = int(data['double_sided_copies'])
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
if enabled: if enabled:
return jsonify({'status': 'error', 'message': "Double-sided copies must be an integer"}), 400 return jsonify({'status': 'error', 'message': "Double-sided copies must be an integer"}), 400
if copies is not None and not (2 <= copies <= 8): if copies is not None and not (2 <= copies <= 8):
@@ -1036,7 +1037,7 @@ def save_main_config():
if data.get('vegas_extend_threshold_screens') not in ('', None): if data.get('vegas_extend_threshold_screens') not in ('', None):
try: try:
screens = float(data['vegas_extend_threshold_screens']) screens = float(data['vegas_extend_threshold_screens'])
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
return jsonify({ return jsonify({
'status': 'error', 'status': 'error',
'message': "Invalid value for vegas_extend_threshold_screens: " 'message': "Invalid value for vegas_extend_threshold_screens: "
@@ -1053,7 +1054,7 @@ def save_main_config():
if data.get('vegas_max_plugin_width_ratio') not in ('', None): if data.get('vegas_max_plugin_width_ratio') not in ('', None):
try: try:
ratio = float(data['vegas_max_plugin_width_ratio']) ratio = float(data['vegas_max_plugin_width_ratio'])
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
return jsonify({ return jsonify({
'status': 'error', 'status': 'error',
'message': "Invalid value for vegas_max_plugin_width_ratio: " 'message': "Invalid value for vegas_max_plugin_width_ratio: "
@@ -1101,7 +1102,7 @@ def save_main_config():
continue continue
try: try:
int_value = int(raw_value) int_value = int(raw_value)
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
return jsonify({ return jsonify({
'status': 'error', 'status': 'error',
'message': f"Invalid value for {field_name}: must be an integer" 'message': f"Invalid value for {field_name}: must be an integer"
@@ -1153,7 +1154,7 @@ def save_main_config():
if not (1024 <= port_val <= 65535): if not (1024 <= port_val <= 65535):
return jsonify({'status': 'error', 'message': "sync_port must be between 1024 and 65535"}), 400 return jsonify({'status': 'error', 'message': "sync_port must be between 1024 and 65535"}), 400
current_config['sync']['port'] = port_val current_config['sync']['port'] = port_val
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
return jsonify({'status': 'error', 'message': "sync_port must be an integer"}), 400 return jsonify({'status': 'error', 'message': "sync_port must be an integer"}), 400
if "sync_follower_position" in data: if "sync_follower_position" in data:
@@ -1197,7 +1198,7 @@ def save_main_config():
raw_value = data.pop(field) raw_value = data.pop(field)
try: try:
int_value = int(raw_value) int_value = int(raw_value)
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
return jsonify({'status': 'error', return jsonify({'status': 'error',
'message': f"Invalid duration for {field}: must be an integer"}), 400 'message': f"Invalid duration for {field}: must be an integer"}), 400
current_config['display']['display_durations'][field] = int_value current_config['display']['display_durations'][field] = int_value
@@ -1220,7 +1221,7 @@ def save_main_config():
continue continue
try: try:
int_value = int(raw_value) int_value = int(raw_value)
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
return jsonify({'status': 'error', return jsonify({'status': 'error',
'message': f"Invalid duration for mode '{mode_key}': must be an integer"}), 400 'message': f"Invalid duration for mode '{mode_key}': must be an integer"}), 400
current_config['display']['display_durations'][mode_key] = int_value current_config['display']['display_durations'][mode_key] = int_value
@@ -1296,7 +1297,10 @@ def save_main_config():
if secrets_config: if secrets_config:
if plugin_id not in current_secrets: if plugin_id not in current_secrets:
current_secrets[plugin_id] = {} current_secrets[plugin_id] = {}
current_secrets[plugin_id] = deep_merge(current_secrets[plugin_id], secrets_config) # Lists merge by replacement, so deep_merge here wrote a
# blanked array straight over the stored credentials.
current_secrets[plugin_id] = merge_secrets(
current_secrets[plugin_id], secrets_config)
# Save secrets file # Save secrets file
api_v3.config_manager.save_raw_file_content('secrets', current_secrets) api_v3.config_manager.save_raw_file_content('secrets', current_secrets)
@@ -1559,6 +1563,11 @@ def get_system_status():
'memory_used_percent': round(memory_percent, 1), 'memory_used_percent': round(memory_percent, 1),
'memory_total_mb': round(memory.total / (1024 * 1024), 1), 'memory_total_mb': round(memory.total / (1024 * 1024), 1),
'memory_used_mb': round(memory.used / (1024 * 1024), 1), 'memory_used_mb': round(memory.used / (1024 * 1024), 1),
# MemAvailable, not total-minus-used: it accounts for reclaimable
# page cache, so it is what actually predicts memory trouble. A
# board can read 70% "used" and be fine, or read the same and be
# about to fail fork(), and only this number tells them apart.
'memory_available_mb': round(memory.available / (1024 * 1024), 1),
'cpu_temp': round(cpu_temp, 1) if cpu_temp is not None else None, 'cpu_temp': round(cpu_temp, 1) if cpu_temp is not None else None,
'disk_used_percent': round(disk_percent, 1), 'disk_used_percent': round(disk_percent, 1),
'disk_total_gb': round(disk.total / (1024 * 1024 * 1024), 1), 'disk_total_gb': round(disk.total / (1024 * 1024 * 1024), 1),
@@ -5118,7 +5127,7 @@ def save_plugin_config():
converted_array.append(int(v)) converted_array.append(int(v))
else: else:
converted_array.append(float(v)) converted_array.append(float(v))
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
converted_array.append(v) converted_array.append(v)
else: else:
converted_array.append(v) converted_array.append(v)
@@ -5143,7 +5152,7 @@ def save_plugin_config():
converted_array.append(int(v)) converted_array.append(int(v))
else: else:
converted_array.append(float(v)) converted_array.append(float(v))
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
converted_array.append(v) converted_array.append(v)
else: else:
converted_array.append(v) converted_array.append(v)
@@ -5180,7 +5189,7 @@ def save_plugin_config():
converted_array.append(int(v)) converted_array.append(int(v))
else: else:
converted_array.append(float(v)) converted_array.append(float(v))
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
converted_array.append(v) converted_array.append(v)
else: else:
converted_array.append(v) converted_array.append(v)
@@ -5204,7 +5213,7 @@ def save_plugin_config():
converted_array.append(int(v)) converted_array.append(int(v))
else: else:
converted_array.append(float(v)) converted_array.append(float(v))
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
converted_array.append(v) converted_array.append(v)
else: else:
converted_array.append(v) converted_array.append(v)
@@ -5371,7 +5380,7 @@ def save_plugin_config():
if isinstance(v, str): if isinstance(v, str):
try: try:
converted.append(int(v) if item_type == 'integer' else float(v)) converted.append(int(v) if item_type == 'integer' else float(v))
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
converted.append(v) converted.append(v)
else: else:
converted.append(v) converted.append(v)
@@ -5496,7 +5505,7 @@ def save_plugin_config():
try: try:
normalized[key] = int(value_stripped) normalized[key] = int(value_stripped)
continue continue
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
pass pass
elif isinstance(value, (int, float)): elif isinstance(value, (int, float)):
normalized[key] = int(value) normalized[key] = int(value)
@@ -5514,7 +5523,7 @@ def save_plugin_config():
try: try:
normalized[key] = float(value_stripped) normalized[key] = float(value_stripped)
continue continue
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
pass pass
elif isinstance(value, (int, float)): elif isinstance(value, (int, float)):
normalized[key] = float(value) normalized[key] = float(value)
@@ -5569,7 +5578,7 @@ def save_plugin_config():
try: try:
normalized_array.append(int(v)) normalized_array.append(int(v))
continue continue
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
pass pass
elif isinstance(v, (int, float)): elif isinstance(v, (int, float)):
normalized_array.append(int(v)) normalized_array.append(int(v))
@@ -5579,7 +5588,7 @@ def save_plugin_config():
try: try:
normalized_array.append(float(v)) normalized_array.append(float(v))
continue continue
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
pass pass
elif isinstance(v, (int, float)): elif isinstance(v, (int, float)):
normalized_array.append(float(v)) normalized_array.append(float(v))
@@ -5595,7 +5604,7 @@ def save_plugin_config():
if isinstance(v, str): if isinstance(v, str):
try: try:
normalized_array.append(int(v)) normalized_array.append(int(v))
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
normalized_array.append(v) normalized_array.append(v)
elif isinstance(v, (int, float)): elif isinstance(v, (int, float)):
normalized_array.append(int(v)) normalized_array.append(int(v))
@@ -5609,7 +5618,7 @@ def save_plugin_config():
if isinstance(v, str): if isinstance(v, str):
try: try:
normalized_array.append(float(v)) normalized_array.append(float(v))
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
normalized_array.append(v) normalized_array.append(v)
else: else:
normalized_array.append(v) normalized_array.append(v)
@@ -5632,7 +5641,7 @@ def save_plugin_config():
if isinstance(value, str): if isinstance(value, str):
try: try:
normalized[key] = int(value) normalized[key] = int(value)
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
normalized[key] = value normalized[key] = value
else: else:
normalized[key] = value normalized[key] = value
@@ -5641,7 +5650,7 @@ def save_plugin_config():
if isinstance(value, str): if isinstance(value, str):
try: try:
normalized[key] = float(value) normalized[key] = float(value)
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
normalized[key] = value normalized[key] = value
else: else:
normalized[key] = value normalized[key] = value
@@ -5675,8 +5684,10 @@ def save_plugin_config():
if schema: if schema:
# Log what we're validating for debugging # Log what we're validating for debugging
logger.info(f"Validating config for {plugin_id}") logger.info(f"Validating config for {plugin_id}")
# Only the shape. plugin_config still holds the submitted secret
# values at this point -- separate_secrets does not run until
# below -- so logging it wrote live credentials to the journal.
logger.info(f"Config keys being validated: {list(plugin_config.keys())}") logger.info(f"Config keys being validated: {list(plugin_config.keys())}")
logger.info(f"Full config: {plugin_config}")
# Get enhanced schema keys (including injected core properties) # Get enhanced schema keys (including injected core properties)
# We need to create an enhanced schema to get the actual allowed keys # We need to create an enhanced schema to get the actual allowed keys
@@ -5699,7 +5710,8 @@ def save_plugin_config():
# Log validation errors for debugging # Log validation errors for debugging
logger.error(f"Config validation failed for {plugin_id}") logger.error(f"Config validation failed for {plugin_id}")
logger.error(f"Validation errors: {validation_errors}") logger.error(f"Validation errors: {validation_errors}")
logger.error(f"Config that failed: {plugin_config}") # Keys only, for the same reason as above.
logger.error(f"Config keys that failed: {list(plugin_config.keys())}")
logger.error(f"Schema properties: {list(enhanced_schema.get('properties', {}).keys())}") logger.error(f"Schema properties: {list(enhanced_schema.get('properties', {}).keys())}")
# Also print to console for immediate visibility # Also print to console for immediate visibility
@@ -5750,7 +5762,9 @@ def save_plugin_config():
if secrets_config: if secrets_config:
if plugin_id not in current_secrets: if plugin_id not in current_secrets:
current_secrets[plugin_id] = {} current_secrets[plugin_id] = {}
current_secrets[plugin_id] = deep_merge(current_secrets[plugin_id], secrets_config) # See above -- secrets lists must merge element-wise.
current_secrets[plugin_id] = merge_secrets(
current_secrets[plugin_id], secrets_config)
# Save secrets file # Save secrets file
try: try:
api_v3.config_manager.save_raw_file_content('secrets', current_secrets) api_v3.config_manager.save_raw_file_content('secrets', current_secrets)
@@ -6779,7 +6793,7 @@ def get_font_preview() -> tuple[Response, int] | Response:
# Safe integer parsing for size # Safe integer parsing for size
try: try:
size = int(request.args.get('size', 12)) size = int(request.args.get('size', 12))
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
return jsonify({'status': 'error', 'message': 'Invalid font size'}), 400 return jsonify({'status': 'error', 'message': 'Invalid font size'}), 400
if not font_filename: if not font_filename:
@@ -8360,7 +8374,7 @@ def clear_old_errors():
context={'provided_value': raw_max_age}, context={'provided_value': raw_max_age},
status_code=400 status_code=400
) )
except (ValueError, TypeError): except (ValueError, TypeError, OverflowError):
return error_response( return error_response(
error_code=ErrorCode.INVALID_INPUT, error_code=ErrorCode.INVALID_INPUT,
message="max_age_hours must be a valid integer", message="max_age_hours must be a valid integer",
+11 -1
View File
@@ -126,7 +126,17 @@ window.showRestartPending = function(message) {
} catch { /* private browsing */ } } catch { /* private browsing */ }
const banner = document.getElementById('restart-pending-banner'); const banner = document.getElementById('restart-pending-banner');
const text = document.getElementById('restart-pending-text'); const text = document.getElementById('restart-pending-text');
if (text && message) text.textContent = message; if (text) {
// Without the else-branch a config save inherited whatever wording the
// previous update left in the DOM: showRestartPending() clears the
// stored text but used to leave the element itself alone. The default
// is read back from the server-rendered copy rather than duplicated
// here, so the template stays the one place that owns the string.
if (text.dataset.defaultText === undefined) {
text.dataset.defaultText = text.textContent.trim();
}
text.textContent = message || text.dataset.defaultText;
}
if (banner) banner.style.display = 'block'; if (banner) banner.style.display = 'block';
}; };
@@ -687,12 +687,35 @@
const mUsedGb = d.memory_used_mb != null ? (d.memory_used_mb / 1024).toFixed(1) : null; const mUsedGb = d.memory_used_mb != null ? (d.memory_used_mb / 1024).toFixed(1) : null;
const mTotGb = d.memory_total_mb != null ? (d.memory_total_mb / 1024).toFixed(1) : null; const mTotGb = d.memory_total_mb != null ? (d.memory_total_mb / 1024).toFixed(1) : null;
const temp = d.cpu_temp != null ? d.cpu_temp + '°C' : 'N/A'; const temp = d.cpu_temp != null ? d.cpu_temp + '°C' : 'N/A';
// Available memory is the number that predicts trouble. When it
// runs out the board does not fail cleanly: fork() starts
// returning ENOMEM, so sshd cannot spawn a session and systemd
// cannot respawn the display, while the kernel keeps answering
// pings. Thresholds are drawn from that failure -- it was
// measured at 73MB free, and healthy running sits well above.
// Round ONCE, then colour and label off the same number.
// The API sends one decimal place, so classifying the raw
// value and displaying the rounded one disagreed at the
// boundaries: 149.6 rendered as "150 MB" in red, and 299.6 as
// "300 MB" in amber, both contradicting the threshold the
// colour claims to apply. Which side of the line a spare
// 0.4MB falls on does not matter; the tile agreeing with
// itself does.
const availMb = d.memory_available_mb == null
? null : Math.round(d.memory_available_mb);
const availColor = availMb == null ? 'text-gray-400'
: availMb < 150 ? 'text-red-600'
: availMb < 300 ? 'text-amber-500'
: 'text-green-600';
panel.innerHTML = panel.innerHTML =
diagTile('fa-microchip', 'text-blue-600', 'CPU Usage', diagTile('fa-microchip', 'text-blue-600', 'CPU Usage',
(d.cpu_percent != null ? d.cpu_percent : '--') + '%', null) + (d.cpu_percent != null ? d.cpu_percent : '--') + '%', null) +
diagTile('fa-memory', 'text-green-600', 'Memory', diagTile('fa-memory', 'text-green-600', 'Memory',
(d.memory_used_percent != null ? d.memory_used_percent : '--') + '%', (d.memory_used_percent != null ? d.memory_used_percent : '--') + '%',
(mUsedGb && mTotGb) ? `${mUsedGb} / ${mTotGb} GB` : null) + (mUsedGb && mTotGb) ? `${mUsedGb} / ${mTotGb} GB` : null) +
diagTile('fa-memory', availColor, 'Available Memory',
availMb != null ? `${availMb} MB` : '--',
mTotGb ? `of ${mTotGb} GB total` : null) +
diagTile('fa-thermometer-half', 'text-red-600', 'CPU Temp', temp, null) + diagTile('fa-thermometer-half', 'text-red-600', 'CPU Temp', temp, null) +
diagTile('fa-hdd', 'text-indigo-600', 'Disk', diagTile('fa-hdd', 'text-indigo-600', 'Disk',
(d.disk_used_percent != null ? d.disk_used_percent : '--') + '%', (d.disk_used_percent != null ? d.disk_used_percent : '--') + '%',