mirror of
https://github.com/ChuckBuilds/LEDMatrix.git
synced 2026-08-20 09:59:09 +00:00
ChuckBuilds
5b64dbe847
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)
64 lines
2.5 KiB
Python
64 lines
2.5 KiB
Python
"""The Vegas content path must trace at DEBUG, not INFO.
|
|
|
|
plugin_adapter narrates every step of acquiring content from every plugin --
|
|
"Has get_vegas_content", "Native: calling get_vegas_content()", "Native content
|
|
returned None", "Has scroll_helper", the per-item sizes -- and it does that for
|
|
each plugin on each cycle.
|
|
|
|
Measured on a live rig: 13,408 log lines an hour, of which 13,366 were INFO and
|
|
35 were WARNING. plugin_adapter alone produced 2,457 of them. That is ~223
|
|
lines a minute of string formatting on a Pi that is also driving the panel, all
|
|
of it written through journald to the SD card, and it buries the 35 lines that
|
|
actually indicate a problem.
|
|
|
|
Nothing is lost by moving it to DEBUG: the 19 warning/error/exception calls in
|
|
the module are untouched, so real failures still surface at their own level.
|
|
|
|
One INFO call is deliberate and stays -- the padding-strip message chooses its
|
|
level at runtime (`logger.warning if (left and right) else logger.info`) and
|
|
test_vegas_plugin_adapter.py pins it.
|
|
"""
|
|
import ast
|
|
from pathlib import Path
|
|
|
|
import pytest
|
|
|
|
ADAPTER = (Path(__file__).resolve().parent.parent / "src" / "vegas_mode"
|
|
/ "plugin_adapter.py")
|
|
|
|
|
|
def _info_calls(path):
|
|
"""Direct logger.info(...) call sites in a module."""
|
|
tree = ast.parse(path.read_text(encoding="utf-8"))
|
|
found = []
|
|
for node in ast.walk(tree):
|
|
if (isinstance(node, ast.Call)
|
|
and isinstance(node.func, ast.Attribute)
|
|
and node.func.attr == "info"
|
|
and getattr(node.func.value, "id", None) == "logger"):
|
|
found.append(node.lineno)
|
|
return found
|
|
|
|
|
|
def test_the_content_path_does_not_trace_at_info():
|
|
calls = _info_calls(ADAPTER)
|
|
assert not calls, (
|
|
"plugin_adapter should trace at DEBUG; found logger.info at lines "
|
|
f"{calls}. This path runs per plugin per cycle and its output goes to "
|
|
"the SD card via journald."
|
|
)
|
|
|
|
|
|
def test_real_failures_still_have_a_level_of_their_own():
|
|
"""Demoting the trace must not have swept up the error reporting."""
|
|
source = ADAPTER.read_text(encoding="utf-8")
|
|
loud = sum(source.count(f"logger.{level}(")
|
|
for level in ("warning", "error", "exception"))
|
|
assert loud >= 15, f"only {loud} warning/error/exception calls remain"
|
|
|
|
|
|
def test_the_deliberate_runtime_chosen_level_survives():
|
|
"""The padding-strip message picks its level at runtime; leave it alone."""
|
|
source = ADAPTER.read_text(encoding="utf-8")
|
|
assert "logger.warning if (left and right) else logger.info" in source
|