2 Commits

Include renames

Author	SHA1	Message	Date
ChuckandClaude Opus 5	863e4a1ecd	consolidate(perf): cut SD writes, log volume, and metrics churn (#486) ... * fix(plugins): one bad metrics cache entry should not stop every plugin Caught live on a rig: every plugin failing, once each, continuously. ERROR - src.plugin_system.plugin_manager - plugin geochron operation failed: ResourceMetrics.__init__() got an unexpected keyword argument 'consecutive_failures' ERROR - ... plugin text-display operation failed: ... ERROR - ... plugin news operation failed: ... ERROR - ... plugin odds-ticker operation failed: ... with /api/v3/health reporting plugin_system: not_initialized while the display process itself kept running and updating the panel. `consecutive_failures` is a plugin_health field, not a metrics one. get_metrics() does ResourceMetrics(**cached), which raises TypeError on a single unrecognised key, and that exception escapes into plugin_manager and is reported per plugin. One malformed cache entry takes the whole plugin system down. How a health-shaped record came to sit under a plugin_metrics key on that machine is not established, and I could not finish the diagnosis: the rig went back into its EIO failure mode partway through -- SSH resetting pre-banner, systemctl unexecutable -- while the web API kept answering from RAM. Checked before that: the cache files on disk are correctly shaped and separate, and CacheManager.get() returns the right record for each key, so it is not a live key collision. A restored backup mixing two machines' caches is the likeliest explanation, and that rig had one restored onto it. Either way the loader should not be brittle enough for the answer to matter. plugin_health already repairs its records field by field rather than trusting what is on disk; this does the same. Known fields are kept, unknown ones are dropped and named once in the log so a genuine schema change stays visible rather than being silently discarded, and a non-mapping entry no longer raises. Keeping the known fields matters: discarding the record wholesale would throw away real call counts and timings because of an unrelated stray key. Mutation-checked: restoring ResourceMetrics(**cached) fails 6 checks, dropping the whole record fails the field-preservation check, and dropping unknown fields silently fails the logging check. 28 tests pass across the resource monitor and plugin health suites. * perf(health): stop rewriting a health record on every healthy cycle Every successful plugin update called record_success(), which persisted the record unconditionally. In steady state the only fields that had changed were total_successes and last_success_time -- a counter and a timestamp that health_monitor surfaces for display and that nothing reads back after a restart. Nothing alerts on the age of last_successful_update; it is carried in the metrics dataclass and shown. Measured on a rig running 24 plugins, all steady-state (0 consecutive failures, circuit closed): a five-minute sample caught 22 health-file rewrites, about 4.4 a minute or 6,300 a day. Each write is ~400 bytes through cache_manager.set(), which writes a file per call, so each one costs a filesystem block plus an ext4 journal write. That lands on an SD card, where the unit of cost is an erase-block cycle rather than the bytes involved, and where wear is what eventually kills the card. Two cards have already failed on the other rig with the same signature -- unreadable block device, EIO on exec, sshd unable to read its host keys. The circuit breaker still has to survive a restart, so the write is kept for exactly the fields it is rebuilt from: consecutive_failures, circuit_state, circuit_opened_time, half_open_start_time. A failure, a circuit opening and a recovery are all still written the moment they happen. In-memory state is updated every time either way, so the health API and web UI show what they always did. Tested: 100 healthy cycles now perform zero writes after the first, the counters remain accurate in memory, and a failure, a recovery and a half-open-to-closed transition each still reach disk. One test kills and rebuilds the tracker from the cache to prove the breaker's state genuinely survives what is no longer written. Mutation-checked both ways: persisting unconditionally again fails the steady-state test, and widening _DURABLE_FIELDS to include last_success_time fails it too. The 46 existing health tests pass. (cherry picked from commit 14abea2d24) (cherry picked from commit 0f77bd2345) * perf(vegas): trace the content path at DEBUG instead of INFO plugin_adapter narrates every step of acquiring content from every plugin -- "Has get_vegas_content", "Native: calling get_vegas_content()", "Native content returned None", "Has scroll_helper", per-item sizes -- once per plugin per cycle, all at INFO. Measured on a live rig: 13,408 log lines an hour, of which 13,366 were INFO and 35 were WARNING. Roughly 223 lines a minute of string formatting on a Pi that is also driving the panel, written through journald to the SD card, with the 35 lines that actually indicate a problem buried among them. Top repeated messages in that hour: 717 Scroll progress: elapsed=... total_scrolled=.../... px 399 [plugin] --> INCLUDED in Vegas scroll 323 [plugin] content_type=static, display_mode=fixed 195 [plugin] Has get_vegas_content: True 195 [plugin] Native: calling get_vegas_content() 168 [plugin] Native: get_vegas_content() returned None 168 [plugin] Native content returned None <- the same fact, twice 54 logger.info calls in plugin_adapter become logger.debug, along with the per-frame scroll-progress line in scroll_helper. Together those are 3,174 of the 13,408 lines an hour, a 23% cut, and the ~3,600 odds-manager lines are addressed separately by ledmatrix-plugins#300. Nothing is lost: the 19 warning/error/exception calls in the module are untouched, so real failures still surface at their own level. This is a logging-level change only -- no control flow, no behaviour. One INFO call is deliberate and stays. The padding-strip message picks its level at runtime (`logger.warning if (left and right) else logger.info`) and test_vegas_plugin_adapter.py pins that choice; it survives because it is not a direct logger.info call site. That test still passes. Mutation-checked both ways: reintroducing a single INFO trace fails the guard, and demoting the warning/error calls along with the trace fails a second guard written for exactly that mistake. 537 vegas and scroll tests pass. (cherry picked from commit e496d95dfe) (cherry picked from commit 8d1e43c15a) * fix(logging): give the journal the real severity of each line Everything this process writes to stdout reaches the journal as PRIORITY=6, whatever the Python level was, because journald has nothing else to go on. Measured on a live rig over 24 hours: lines containing " - ERROR - " 55 lines containing " - WARNING - " 13 journald PRIORITY recorded 6, for every one of them So `journalctl -p err -u ledmatrix` returns nothing while errors are being logged, and `-p warning` likewise. Triage falls back to grepping message text, which is slower and unreliable: during this audit a search for "oom" matched the radar logging "zoom=9" twenty-four times and briefly looked like the OOM killer had been firing. systemd reads a leading "<N>" on each stdout line and takes it as the priority (sd-daemon(3)), so a formatter that prefixes one costs no dependency. Every line of a multi-line record is tagged, not just the first -- the journal splits them, and an untagged continuation reverts to the default, which would leave the body of a traceback filed as informational while its first line was an error. Applied only when JOURNAL_STREAM is set, which systemd sets for services whose output it captures. Run from a terminal, in the emulator or under pytest the prefixes would be literal noise, and the file handler keeps the plain formatter for the same reason. Mutation-checked three ways: prefixing unconditionally fails the outside-systemd test, prefixing only the first line fails the multi-line test, and mapping ERROR to 6 fails the level mapping. 39 tests pass across the logging suites. (cherry picked from commit 780fca6365) * fix(logging): let callers see through the journald formatter wrapper CI caught what local testing could not: two existing tests in test_logging_config.py assert that setup_logging() selected a StructuredFormatter or a ContextualFormatter, by checking the console handler's formatter directly. Wrapping that formatter to tag each line with its syslog priority makes those assertions false. They passed locally and failed on the runner because the wrapper is applied only when JOURNAL_STREAM is set -- absent in a terminal, present in CI. An environment-dependent break, which is the kind that gets shipped. The wrapper now exposes the formatter it delegates to, and those two tests look through it. They are about which formatter format_type selects, and that behaviour is unchanged; only the object they have to reach for moved. Verified both ways this time: 39 tests pass with JOURNAL_STREAM set and with it unset. * perf(plugins): stop rewriting a plugin's metrics file on every call Plugin metrics were persisted to the cache inside monitor_call, so every call by every plugin rewrote a small JSON file. Measured on a running rig: one plugin's plugin_metrics file changed nine times a minute, with fourteen such files active. Each is around 350 bytes, which on ext4 costs a 4KB block plus a journal entry, so the cost is dominated by the write itself rather than the payload. Cache writes accounted for essentially all of that device's 2.4 MB/min of SD traffic, on a card that wears out and has already failed twice on the other rig. Metrics cannot be de-duplicated the way health state can, because call_count changes on every call and the timings usually do too. So they are rate-limited instead: at most one write per plugin per 30 seconds. The in-memory copy stays authoritative and exact -- a plugin's call_count is still precise the instant after it runs. Only the cross-process snapshot the web UI reads is delayed, and telemetry up to half a minute old is still a fair description of a long-running plugin. reset_metrics clears the throttle timestamp, so a reset is not left showing a deleted key for the rest of the interval. Extrapolating the sampled rate, this takes metric writes from roughly 126 a minute to 28. Health persistence, the other half of the churn, is handled separately in #475. Verified by reverting the throttle: the churn test then reports 50 writes for 50 calls. 88 tests pass across resource monitor, plugin system and web API. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW * fix: use a monotonic clock and only mark metrics persisted once written Two review findings on the throttle, both right. The interval compared wall-clock timestamps. These devices have no RTC, so the clock jumps by however far off boot-time was the moment NTP first syncs -- a forward jump would allow an early write, a backward one would stall the snapshot well past the interval. time.monotonic() is not subject to either. The timestamp was also recorded before cache_manager.set(). A set() that raised would buy the next interval's silence without leaving a snapshot behind, which is the one case where skipping the write is least affordable. Recorded after the write lands instead, so a failure is retried on the next call. Verified by restoring the original ordering: the new test then reports one write where two are expected. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW * Address all six review findings on the perf consolidation CodeRabbit reported six; this is all six, checked against its own "Actionable comments posted: 6" rather than against what I happened to scroll past. Three are real defects in the code: 1. _under_systemd() trusted the presence of JOURNAL_STREAM. systemd publishes JOURNAL_STREAM as "dev:ino", and every child process inherits it -- including one whose stdout has been redirected to a pipe or a file. The variable outlives the descriptor it describes, so a subprocess would decide it was talking to the journal and emit the "<N>" priority prefixes as literal noise into that captured output. That is exactly the noise the function exists to prevent. It now parses the pair and fstats stdout, per systemd's own guidance, and returns False for missing, malformed, mismatched, or unusable descriptors. 2. Cached metrics were not type-checked. A dataclass does not enforce its annotations, so ResourceMetrics(call_count="not a number") builds happily and only fails later, deep inside monitor_call: TypeError: can only concatenate str (not "int") to str Values are now coerced to their declared type at load, where there is still a cache key to name in the warning, and a value that cannot be coerced starts the plugin fresh instead of arming a delayed failure. A numeric string is accepted rather than discarded -- a JSON round-trip can widen an int, and that is recoverable. 3. The first metrics snapshot was skipped for the first 30s of uptime. _persist_metrics used 0.0 as the "never written" default. monotonic() is time since boot on Linux and systemd starts this service at boot, so `now - 0.0 < 30` was true for the first half-minute of every run: the throttle swallowed the very first write, the one that matters most after a restart. The sentinel is now None and the interval is only applied when a previous write exists. Three are tests that could pass without testing anything: 4. test_health_write_churn's fake cache stored by reference, so the tracker kept mutating the object already in the store -- a record could look persisted when no write had happened, which is precisely what test_durable_state_survives_a_restart exists to detect. Both directions now deep-copy, like a cache that serialises to a file. Verified: disabling the one real cache write now fails three tests. 5. test_values_of_the_wrong_type_do_not_raise asserted only that a dataclass had been constructed, which was true with the bad value still in it. It now asserts the loaded metrics are usable -- the field is numeric, and arithmetic on it does not raise -- across four kinds of bad value. 6. test_vegas_log_volume counted "logger.error(" in the source text, which also matches comments, docstrings and string literals -- including that module's own docstring, which names those levels. A real error call could be demoted with the tally unmoved. It now walks the AST, reusing the helper already in the file. Verified: demoting all 18 warning/error/exception calls now fails the test. Verified: every fix mutation-checked by reverting it and confirming the matching test fails. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01STMbQE4YctTacQXfbYqKuW --------- Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-21 15:50:55 -04:00
ChuckandClaude Fable 5	ee59caa577	Follow-ups from #441: secret-helper migration, ten more bug fixes, and coverage for every remaining untested module (#444) ... * refactor(web): use canonical secret helpers in api_v3; make ConfigManager secret strip/merge array-aware api_v3.py carried three inline nested copies of find_secret_fields/ separate_secrets (main-config save, plugin-config save, plugin-config reset). They drifted from each other (one lacked isinstance guards) and none supported the canonical module's array-item secrets (accounts[].token). All three endpoints now import from src/web_interface/secret_helpers. Adopting the canonical behavior makes array-item secrets reachable, and their parallel-placeholder shape ([{'token': ...}, {}] alongside the regular list) was not survivable by ConfigManager's round-trip: _strip_secrets_recursive dropped the whole key (losing the regular fields from config.json) and _deep_merge replaced the regular list wholesale on load. Both are now array-aware: - strip removes the secret fields from each item and ALWAYS keeps the list so indices survive for merge-on-load; whole-key secrets (scalar lists, shape mismatches) still drop the key entirely — never leak. - merge folds each secrets item into the config item at the same index, skipping {} placeholders. The regular list's length is authoritative in both directions: a user deleting an array item never has it resurrected from a stale secrets entry (extras warn and are ignored). api_v3's own deep_merge intentionally still replaces lists wholesale — form posts carry complete arrays and index-merging would resurrect deleted items; a comment now documents that. Tests: the parity guard flips from 'exactly 3 inline copies' to 'zero, and the canonical import must exist'; TestArraySecretStripAndMerge covers the new strip/merge semantics incl. length-mismatch contracts; new test_api_v3_secret_roundtrip.py drives all three endpoints through a Flask client with a REAL ConfigManager+SchemaManager over tmp_path, proving secrets land in config_secrets.json, config.json stays clean, and a fresh load merges them back into the right array items. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01NohXi78cwsAKtN1sCfxjUh * fix: repair broken helper paths across display, cache, odds, logging, resolver, repos, config, validator Nine fixes for bugs surfaced while writing coverage for previously untested modules (plus the bool-duration quirk pinned in PR #441): - base_plugin.get_display_duration: exclude bools from both numeric branches — display_duration=True no longer reads as a 1-second slot; it falls through to config, then the 15.0 default. - display_helper: draw_error_message/draw_no_data_message called _draw_centered_text with the wrong arguments and crashed with AttributeError — both now delegate to draw_centered_text. draw_scorebug_layout drew status and clock at the same y, overprinting each other — they now share one combined top line. draw_ticker_layout drew its text starting at x=display_width (fully off-canvas), returning a blank frame every time — now draws at x=0; scroll_speed stays accepted-but-unused and is documented as such. - api_helper.clear_cache guarded on a nonexistent CacheManager.clear() method, silently never clearing anything; it now uses the real surface (clear_cache/delete/list_cache_files) and no-ops safely otherwise. - base_odds_manager._extract_espn_data raised AttributeError when ESPN sent explicit JSON nulls ("homeTeamOdds": null) — every level now null-safes with 'or {}'. format_odds_summary gated on is_odds_available, which deliberately ignores money lines, so ML-only odds formatted as "No odds available" — it now gates only on empty/no_odds data and formats money lines. - logging_config.ContextualFormatter mutated record.msg in place, so a second handler prepended the context prefix twice; it now formats a copy. log_error hardcoded exc_info=True and raised TypeError when the caller passed exc_info — now kwargs.setdefault. - dynamic_team_resolver wrote its "shared" class cache through self, creating instance shadows — the cache was per-instance and every scoreboard refetched rankings. Writes now go through the class. - saved_repositories cleaned URLs with an unanchored .replace('.git','') that mangled URLs merely containing '.git' (my.github.io -> myhub.io); now strips only a trailing suffix. add/remove also roll back the in-memory list when the save fails, so memory always matches disk. - config_helper.merge_configs shallow-copied the base, aliasing every un-overridden nested dict into the result — now deep-copies. - startup_validator.validate_all accumulated errors/warnings across calls — now resets both lists per run. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01NohXi78cwsAKtN1sCfxjUh * test: cover the previously untested modules Nine new suites plus an extension, asserting the Phase-1b fixed behavior and pinning the quirks deliberately left alone: - test_logging_config.py: formatters (JSON shape, no record mutation, single prefix through two handlers), PluginLoggerAdapter precedence, setup_logging handler hygiene and LEDMATRIX_DEBUG, log_error exc_info. - test_startup_validator.py: exact messages, error-vs-warning split, accessor split (load_config vs get_config), cache-dir branches with os.access monkeypatched (root can write anything in CI), idempotence, raise_on_errors classification precedence. - test_config_helper.py (full): load/save round trips, dot-notation get/set incl. silent-failure contract, post-fix no-aliasing merge, schema validation branches, the '{id}_config' key pin, default-enabled pin. - test_saved_repositories.py: three load shapes, bare-list rewrite pin, trailing-only .git strip (my.github.io regression), save-failure rollback, type-classification case-sensitivity pin. - test_api_helper.py: rate-limit math, cache-hit short circuit, ESPN URL/key formats, exact User-Agent guard, retry adapter, post-fix clear_cache against the real CacheManager surface, ttl-dropped pin. - test_base_odds_manager.py: cache-key/URL construction, no_odds sentinel round trip, stale-cache fallback, null-safe extraction, ML-only formatting, is_odds_available truth table (ML-blind by contract), config key/attr mismatch pin. - test_dynamic_team_resolver.py: expansion/dedup/slicing, dropped unknown-dynamic names (TOP_ substring hazard pinned), genuinely shared class cache (second instance: zero HTTP), TTL expiry, failure degradation without raising. - test_display_helper.py (full): the fixed error/no-data renders, combined scorebug top line, non-blank ticker with scroll_speed no-op pin, composite upconversion, logo bleed positions, square orientation pin. - test_skin_runtime_cache.py: discovery-cache hit/invalidation semantics (manifest mtime, .py edits pinned as non-invalidating), sys.modules namespacing contract incl. bare-name restore and stdlib shadowing, entry-module execute-once, API minor-version tolerance, skin_matches_target table. - test_sports_capabilities.py (extended): _draw_celebration_layout executed for real (flash window, matrix-dims fallback, highlight alternation, logo-failure isolation), _should_celebrate_for direct, strict duration boundary, score_to_int edges, both-teams-score precedence, expired-coalesce refire, disabled-win baseline preservation, id-less prune. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01NohXi78cwsAKtN1sCfxjUh * test: real schedule/dim coverage for DisplayController; fix two vacuous schedule tests New test_display_controller_schedule.py drives _check_schedule and _check_dim_schedule on a bare controller stub: same-day and midnight-crossing windows with inclusive boundaries, global vs per-day vs legacy-inferred modes (and dim's global-only default — no legacy inference), per-day disabled days, invalid %H:%M fallbacks, unknown timezone -> UTC, dim_brightness default 30, inactive-display short circuit, and the _was_display_active/_was_dimmed transition flags. test_display_controller.py's test_schedule_disabled and test_active_hours patched config_service.get_config — which _check_schedule never reads — so both asserted the init-default value and could not fail. Rewritten on the test_inactive_hours pattern (inject controller.config['schedule'], reset the minute gate, flip the flag to the opposite state first so the assertion has teeth). Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01NohXi78cwsAKtN1sCfxjUh * ci: raise coverage floor to 48% Measured 50% with the new suites in place (was 47% baseline when the gate was introduced at 45); floor stays two points under measured. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01NohXi78cwsAKtN1sCfxjUh * fix: address CodeQL alert and review findings - config_manager: the "secrets list longer than config list" warning now interpolates only config-side data (no key name or secrets-derived values), resolving the CodeQL clear-text-logging alert. - base_plugin: validate_config rejects bool display_duration, matching get_display_duration (bool is an int subclass and would otherwise pass as a positive number). - config_helper: merge_configs deep-copies override values in the non-recursive branch so mutating the merged result cannot reach back into override_config. - saved_repositories: saves are atomic (temp file + fsync + os.replace), so a failed write can no longer truncate saved_repositories.json. - tests: regression cases for each fix, plus a pin that whole-item array secrets (key[] + key[].field both marked) strip to empty {} skeletons — no secret values can reach config.json. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01NohXi78cwsAKtN1sCfxjUh --------- Co-authored-by: Claude <noreply@anthropic.com>	2026-08-07 16:17:11 -04:00