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>
This commit is contained in:
Chuck
2026-08-07 16:17:11 -04:00
committed by GitHub
co-authored by Claude Fable 5
parent fc25a70d75
commit ee59caa577
28 changed files with 3875 additions and 292 deletions
+274
View File
@@ -0,0 +1,274 @@
"""
Tests for src/logging_config.py — the formatters, adapter, and setup used
by every logger in the system (BasePlugin uses get_logger, not stdlib
logging.getLogger).
Includes regression guards for two fixed bugs: ContextualFormatter used to
mutate record.msg in place (double-prefixing with two handlers), and
log_error hardcoded exc_info=True so passing it explicitly raised
TypeError.
"""
import json
import logging
import sys
import pytest
from src.logging_config import (
ContextualFormatter,
PluginLoggerAdapter,
StructuredFormatter,
get_logger,
log_debug,
log_error,
log_info,
log_warning,
log_with_context,
setup_logging,
)
def make_record(msg="hello", level=logging.INFO, **extra):
record = logging.LogRecord(
name="test.logger", level=level, pathname=__file__, lineno=42,
msg=msg, args=(), exc_info=None)
for key, value in extra.items():
setattr(record, key, value)
return record
class TestStructuredFormatter:
def test_emits_valid_json_with_base_keys(self):
out = json.loads(StructuredFormatter().format(make_record()))
assert set(out) == {
"timestamp", "level", "logger", "message",
"module", "function", "line",
}
assert out["level"] == "INFO"
assert out["message"] == "hello"
assert out["logger"] == "test.logger"
def test_optional_keys_only_when_present(self):
record = make_record(context={"k": "v"}, plugin_id="clock",
operation_id="op-1")
out = json.loads(StructuredFormatter().format(record))
assert out["context"] == {"k": "v"}
assert out["plugin_id"] == "clock"
assert out["operation_id"] == "op-1"
def test_exception_key_when_exc_info_present(self):
try:
raise ValueError("kaboom")
except ValueError:
record = logging.LogRecord(
name="t", level=logging.ERROR, pathname=__file__, lineno=1,
msg="failed", args=(), exc_info=sys.exc_info())
out = json.loads(StructuredFormatter().format(record))
assert "kaboom" in out["exception"]
def test_percent_args_formatted_into_message(self):
record = logging.LogRecord(
name="t", level=logging.INFO, pathname=__file__, lineno=1,
msg="count=%d", args=(7,), exc_info=None)
out = json.loads(StructuredFormatter().format(record))
assert out["message"] == "count=7"
class TestContextualFormatter:
def test_context_prefix_prepended(self):
record = make_record(plugin_id="clock", operation_id="op-1",
context={"k": "v"})
out = ContextualFormatter().format(record)
assert "[Plugin: clock] [Op: op-1] [k: v] hello" in out
def test_include_context_false_leaves_message_bare(self):
record = make_record(plugin_id="clock")
out = ContextualFormatter(include_context=False).format(record)
assert "[Plugin:" not in out
assert "hello" in out
def test_location_toggle(self):
record = make_record()
with_loc = ContextualFormatter(include_location=True).format(record)
without = ContextualFormatter(include_location=False).format(record)
assert f":{record.lineno}" in with_loc
assert f":{record.lineno}" not in without
def test_record_not_mutated_no_double_prefix(self):
# Regression: a record is formatted once PER HANDLER. The formatter
# must not mutate record.msg, or the second handler's format call
# prepends the prefix again.
record = make_record(plugin_id="clock")
formatter = ContextualFormatter()
first = formatter.format(record)
second = formatter.format(record)
assert record.msg == "hello" # untouched
assert first.count("[Plugin: clock]") == 1
assert second.count("[Plugin: clock]") == 1
def test_percent_args_still_format_after_copy(self):
record = logging.LogRecord(
name="t", level=logging.INFO, pathname=__file__, lineno=1,
msg="count=%d", args=(7,), exc_info=None)
record.plugin_id = "clock"
out = ContextualFormatter().format(record)
assert "[Plugin: clock] count=7" in out
def test_exception_renders_through_two_handlers(self):
try:
raise ValueError("kaboom")
except ValueError:
record = logging.LogRecord(
name="t", level=logging.ERROR, pathname=__file__, lineno=1,
msg="failed", args=(), exc_info=sys.exc_info())
record.plugin_id = "clock"
formatter = ContextualFormatter()
assert "kaboom" in formatter.format(record)
assert "kaboom" in formatter.format(record) # second handler's pass
class TestPluginLoggerAdapter:
def _capture(self, adapter):
records = []
handler = logging.Handler()
handler.emit = records.append
adapter.logger.addHandler(handler)
adapter.logger.setLevel(logging.DEBUG)
return records
def test_stamps_plugin_id_on_every_record(self):
adapter = get_logger("test.adapter1", plugin_id="clock")
records = self._capture(adapter)
adapter.info("x")
assert records[0].plugin_id == "clock"
def test_explicit_extra_plugin_id_wins(self):
adapter = get_logger("test.adapter2", plugin_id="clock")
records = self._capture(adapter)
adapter.info("x", extra={"plugin_id": "other"})
assert records[0].plugin_id == "other"
def test_unrelated_extra_keys_preserved(self):
adapter = get_logger("test.adapter3", plugin_id="clock")
records = self._capture(adapter)
adapter.info("x", extra={"custom": 1})
assert records[0].plugin_id == "clock"
assert records[0].custom == 1
class TestGetLogger:
def test_plain_logger_without_plugin_id(self):
logger = get_logger("test.plain")
assert isinstance(logger, logging.Logger)
assert logger.name == "test.plain"
def test_adapter_with_plugin_id(self):
adapter = get_logger("test.wrapped", plugin_id="clock")
assert isinstance(adapter, PluginLoggerAdapter)
assert adapter.logger.name == "test.wrapped"
class TestSetupLogging:
# conftest's autouse reset_logging restores root handlers after each test.
def test_installs_single_stdout_handler(self):
setup_logging()
root = logging.getLogger()
assert len(root.handlers) == 1
assert isinstance(root.handlers[0], logging.StreamHandler)
def test_repeat_calls_do_not_accumulate_handlers(self):
setup_logging()
setup_logging()
assert len(logging.getLogger().handlers) == 1
def test_json_format_selects_structured_formatter(self):
setup_logging(format_type="json")
assert isinstance(
logging.getLogger().handlers[0].formatter, StructuredFormatter)
def test_readable_format_selects_contextual_formatter(self):
setup_logging(format_type="readable")
assert isinstance(
logging.getLogger().handlers[0].formatter, ContextualFormatter)
def test_log_file_adds_file_handler(self, tmp_path):
log_file = tmp_path / "test.log"
setup_logging(log_file=str(log_file))
root = logging.getLogger()
file_handlers = [h for h in root.handlers
if isinstance(h, logging.FileHandler)]
assert len(file_handlers) == 1
for h in file_handlers:
h.close()
def test_unwritable_log_file_warns_and_keeps_console(self, tmp_path, capsys):
bad_path = tmp_path / "no-such-dir" / "test.log"
setup_logging(log_file=str(bad_path)) # must not raise
assert len(logging.getLogger().handlers) == 1 # console only
assert "Could not set up file logging" in capsys.readouterr().err
def test_debug_env_true_enables_debug(self, monkeypatch):
monkeypatch.setenv("LEDMATRIX_DEBUG", "TRUE")
setup_logging()
assert logging.getLogger().level == logging.DEBUG
def test_debug_env_other_values_stay_info(self, monkeypatch):
# Pinned: only the literal (case-insensitive) "true" enables debug;
# "1" does not.
monkeypatch.setenv("LEDMATRIX_DEBUG", "1")
setup_logging()
assert logging.getLogger().level == logging.INFO
def test_explicit_level_wins_over_env(self, monkeypatch):
monkeypatch.setenv("LEDMATRIX_DEBUG", "true")
setup_logging(level=logging.WARNING)
assert logging.getLogger().level == logging.WARNING
class TestLogWithContext:
def _capture(self, name):
logger = logging.getLogger(name)
records = []
handler = logging.Handler()
handler.emit = records.append
logger.addHandler(handler)
logger.setLevel(logging.DEBUG)
return logger, records
def test_context_attrs_stamped(self):
logger, records = self._capture("test.lwc1")
log_with_context(logger, logging.INFO, "msg",
context={"k": "v"}, plugin_id="clock",
operation_id="op-1")
record = records[0]
assert record.context == {"k": "v"}
assert record.plugin_id == "clock"
assert record.operation_id == "op-1"
def test_wrappers_use_their_levels(self):
logger, records = self._capture("test.lwc2")
log_debug(logger, "d")
log_info(logger, "i")
log_warning(logger, "w")
assert [r.levelno for r in records] == [
logging.DEBUG, logging.INFO, logging.WARNING]
def test_log_error_defaults_exc_info_true(self):
logger, records = self._capture("test.lwc3")
try:
raise ValueError("kaboom")
except ValueError:
log_error(logger, "failed")
assert records[0].levelno == logging.ERROR
assert records[0].exc_info is not None
def test_log_error_accepts_explicit_exc_info(self):
# Regression: the old hardcoded exc_info=True raised
# "got multiple values for keyword argument 'exc_info'".
logger, records = self._capture("test.lwc4")
log_error(logger, "failed", exc_info=False)
# Falsy exc_info is stored verbatim on the record; the contract is
# simply "no traceback attached".
assert not records[0].exc_info