mirror of
https://github.com/ChuckBuilds/LEDMatrix.git
synced 2026-08-20 09:59:09 +00:00
Compare commits
1
Commits
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
fc6104f229 |
+1
-54
@@ -130,12 +130,7 @@ def setup_logging(
|
||||
# Console handler (always add)
|
||||
console_handler = logging.StreamHandler(sys.stdout)
|
||||
console_handler.setLevel(level)
|
||||
# Under systemd, tag each line so the journal records the real severity
|
||||
# rather than filing everything as informational. The file handler below
|
||||
# keeps the plain formatter: the prefix is meaningful to journald and noise
|
||||
# anywhere else.
|
||||
console_handler.setFormatter(
|
||||
JournalPriorityFormatter(formatter) if _under_systemd() else formatter)
|
||||
console_handler.setFormatter(formatter)
|
||||
root_logger.addHandler(console_handler)
|
||||
|
||||
# File handler (if specified)
|
||||
@@ -150,54 +145,6 @@ def setup_logging(
|
||||
sys.stderr.write(f"Warning: Could not set up file logging to {log_file}: {e}\n")
|
||||
|
||||
|
||||
#: syslog priorities, which is what systemd parses from a "<N>" prefix on
|
||||
#: stdout. Mapped from Python's levels.
|
||||
_SYSLOG_PRIORITY = {
|
||||
logging.CRITICAL: 2, # LOG_CRIT
|
||||
logging.ERROR: 3, # LOG_ERR
|
||||
logging.WARNING: 4, # LOG_WARNING
|
||||
logging.INFO: 6, # LOG_INFO
|
||||
logging.DEBUG: 7, # LOG_DEBUG
|
||||
}
|
||||
|
||||
|
||||
class JournalPriorityFormatter(logging.Formatter):
|
||||
"""Wraps a formatter, prefixing each line with its syslog priority.
|
||||
|
||||
Under systemd everything this process writes to stdout lands in the journal
|
||||
as PRIORITY=6, whatever the Python level was. Measured on a live rig: 55
|
||||
ERROR lines and 13 WARNING lines in a day, every one of them recorded as
|
||||
informational, so `journalctl -p err -u ledmatrix` returned nothing at all
|
||||
while errors were being logged. Anyone triaging has to grep the message
|
||||
text instead, which is both slower and wrong -- a search for "oom" matches
|
||||
the radar logging "zoom=9".
|
||||
|
||||
systemd reads a leading "<N>" on each line and uses it as the priority
|
||||
(sd-daemon(3)), so this needs no extra dependency. Multi-line records get
|
||||
the prefix on every line, since the journal splits them and an unprefixed
|
||||
continuation would fall back to the default.
|
||||
"""
|
||||
|
||||
def __init__(self, inner: logging.Formatter):
|
||||
super().__init__()
|
||||
self._inner = inner
|
||||
|
||||
def format(self, record: logging.LogRecord) -> str:
|
||||
text = self._inner.format(record)
|
||||
prefix = f"<{_SYSLOG_PRIORITY.get(record.levelno, 6)}>"
|
||||
return "\n".join(prefix + line for line in text.split("\n"))
|
||||
|
||||
|
||||
def _under_systemd() -> bool:
|
||||
"""True when stdout is the journal.
|
||||
|
||||
systemd sets JOURNAL_STREAM for services whose output it captures. Without
|
||||
this check the "<N>" prefixes would show up as literal noise when the
|
||||
program is run from a terminal, in the emulator, or in tests.
|
||||
"""
|
||||
return bool(os.environ.get("JOURNAL_STREAM"))
|
||||
|
||||
|
||||
class PluginLoggerAdapter(logging.LoggerAdapter):
|
||||
"""LoggerAdapter that stamps every record with its plugin_id.
|
||||
|
||||
|
||||
@@ -0,0 +1,143 @@
|
||||
"""GET /config/main must not hand out credentials.
|
||||
|
||||
The endpoint returned the raw config to anyone who could reach the port, and
|
||||
this web interface has no authentication of any kind. Measured against a live
|
||||
rig, an unauthenticated request returned:
|
||||
|
||||
github.api_token 40 chars
|
||||
incoming-packages.ha_token 183 chars
|
||||
jellyfin-now-playing.api_key 32 chars
|
||||
ledmatrix-weather.api_key 32 chars
|
||||
on-air.mqtt_password 8 chars
|
||||
youtube.api_key 20 chars
|
||||
youtube-stats.api_key 39 chars
|
||||
|
||||
A GitHub token and a Home Assistant long-lived token among them.
|
||||
|
||||
The x-secret masking the plugin config endpoints use does not apply here: this
|
||||
endpoint never consults a schema, and core keys such as github.api_token have
|
||||
no schema to carry the marker. Several of those fields *are* tagged x-secret in
|
||||
their plugin's schema and were still returned in full, which is what makes the
|
||||
schema route the wrong one to rely on for this endpoint.
|
||||
|
||||
Matching on field name is blunt. For a whole-config dump it is the right
|
||||
default: anything named like a credential should not leave the process, and a
|
||||
new plugin that adds a differently-shaped secret is covered without anyone
|
||||
remembering to tag it.
|
||||
"""
|
||||
import pytest
|
||||
|
||||
from web_interface.blueprints.api_v3 import (
|
||||
_looks_like_a_credential,
|
||||
_redact_credentials,
|
||||
)
|
||||
|
||||
|
||||
@pytest.mark.parametrize("name", [
|
||||
"password", "mqtt_password", "opensky_password", "passwd",
|
||||
"api_key", "apikey", "API_KEY", "flightaware_api_key",
|
||||
"token", "ha_token", "api_token", "access_token",
|
||||
"secret", "client_secret", "spotify_client_secret",
|
||||
"access_key", "private_key",
|
||||
])
|
||||
def test_credential_names_are_recognised(name):
|
||||
assert _looks_like_a_credential(name)
|
||||
|
||||
|
||||
@pytest.mark.parametrize("name", [
|
||||
"timezone", "city", "brightness", "enabled", "update_interval",
|
||||
"favorite_teams", "display_duration", "keyword",
|
||||
])
|
||||
def test_ordinary_names_are_left_alone(name):
|
||||
assert not _looks_like_a_credential(name)
|
||||
|
||||
|
||||
def test_the_measured_leak_is_closed():
|
||||
"""The exact shape taken off the rig."""
|
||||
config = {
|
||||
"github": {"api_token": "ghp_" + "x" * 36},
|
||||
"incoming-packages": {"ha_token": "y" * 183, "enabled": True},
|
||||
"jellyfin-now-playing": {"api_key": "z" * 32},
|
||||
"on-air": {"mqtt_password": "hunter22"},
|
||||
"youtube": {"api_key": "k" * 20},
|
||||
"timezone": "America/New_York",
|
||||
}
|
||||
out = _redact_credentials(config)
|
||||
assert out["github"]["api_token"] == ""
|
||||
assert out["incoming-packages"]["ha_token"] == ""
|
||||
assert out["jellyfin-now-playing"]["api_key"] == ""
|
||||
assert out["on-air"]["mqtt_password"] == ""
|
||||
assert out["youtube"]["api_key"] == ""
|
||||
# Everything else survives, or the config editor breaks.
|
||||
assert out["timezone"] == "America/New_York"
|
||||
assert out["incoming-packages"]["enabled"] is True
|
||||
|
||||
|
||||
def test_nested_and_listed_credentials_are_reached():
|
||||
config = {"a": {"b": {"c": {"password": "p"}}},
|
||||
"feeds": [{"name": "x", "api_key": "k"}, {"name": "y"}]}
|
||||
out = _redact_credentials(config)
|
||||
assert out["a"]["b"]["c"]["password"] == ""
|
||||
assert out["feeds"][0]["api_key"] == ""
|
||||
assert out["feeds"][0]["name"] == "x"
|
||||
|
||||
|
||||
def test_the_original_is_not_mutated():
|
||||
"""The caller holds the live config; redaction must not edit it in place."""
|
||||
config = {"github": {"api_token": "keepme"}}
|
||||
_redact_credentials(config)
|
||||
assert config["github"]["api_token"] == "keepme"
|
||||
|
||||
|
||||
def test_a_credential_shaped_container_is_still_walked():
|
||||
"""`secrets: {...}` is a section name, not a value to blank."""
|
||||
config = {"secrets": {"api_key": "k", "note": "keep"}}
|
||||
out = _redact_credentials(config)
|
||||
assert out["secrets"]["api_key"] == ""
|
||||
assert out["secrets"]["note"] == "keep"
|
||||
|
||||
|
||||
def test_non_dict_input_passes_through():
|
||||
assert _redact_credentials("plain") == "plain"
|
||||
assert _redact_credentials(7) == 7
|
||||
assert _redact_credentials(None) is None
|
||||
|
||||
|
||||
def test_the_endpoint_itself_redacts():
|
||||
"""Through the view function, not the helper.
|
||||
|
||||
The helper tests above all passed with the route still returning
|
||||
`config` -- reverting the one line that calls the redactor changed
|
||||
nothing, because nothing exercised the route. A property asserted on a
|
||||
helper is not a property asserted on the endpoint, and it is the endpoint
|
||||
that is exposed to the network.
|
||||
"""
|
||||
import json as _json
|
||||
from unittest.mock import MagicMock
|
||||
|
||||
import flask
|
||||
|
||||
from web_interface.blueprints import api_v3 as mod
|
||||
|
||||
raw = {"github": {"api_token": "ghp_secret_value"},
|
||||
"timezone": "America/New_York"}
|
||||
|
||||
manager = MagicMock()
|
||||
manager.load_config.return_value = raw
|
||||
previous = getattr(mod.api_v3, "config_manager", None)
|
||||
mod.api_v3.config_manager = manager
|
||||
|
||||
app = flask.Flask(__name__)
|
||||
try:
|
||||
with app.test_request_context("/config/main"):
|
||||
response = mod.get_main_config()
|
||||
payload = response.get_json() if hasattr(response, "get_json") else _json.loads(response[0].data)
|
||||
finally:
|
||||
mod.api_v3.config_manager = previous
|
||||
|
||||
data = payload["data"]
|
||||
assert data["github"]["api_token"] == "", (
|
||||
"the endpoint returned the token; the redactor is not wired in")
|
||||
assert data["timezone"] == "America/New_York"
|
||||
# And the config the manager handed over is untouched.
|
||||
assert raw["github"]["api_token"] == "ghp_secret_value"
|
||||
@@ -1,101 +0,0 @@
|
||||
"""Log lines must reach the journal with their real severity.
|
||||
|
||||
Everything this process writes to stdout lands in the journal as PRIORITY=6,
|
||||
whatever the Python level was, because journald has no other signal. Measured
|
||||
on a live rig over 24 hours: 55 lines containing " - ERROR - " and 13
|
||||
containing " - WARNING - ", every one of them recorded as informational. So
|
||||
|
||||
journalctl -p err -u ledmatrix
|
||||
|
||||
returned nothing while errors were being logged, and anyone triaging has to
|
||||
grep the message text instead. That is slower and it is wrong: a search for
|
||||
"oom" also matches the radar logging "zoom=9", which is exactly the false
|
||||
positive it produced during this audit.
|
||||
|
||||
systemd reads a leading "<N>" on each stdout line and uses it as the priority
|
||||
(sd-daemon(3)), so this needs no extra dependency -- and it must only be
|
||||
applied when systemd is actually reading, or the prefixes become literal noise
|
||||
in a terminal, the emulator, and test output.
|
||||
"""
|
||||
import logging
|
||||
import os
|
||||
from unittest.mock import patch
|
||||
|
||||
import pytest
|
||||
|
||||
from src.logging_config import JournalPriorityFormatter, _SYSLOG_PRIORITY, _under_systemd
|
||||
|
||||
|
||||
class _Plain(logging.Formatter):
|
||||
def format(self, record):
|
||||
return record.getMessage()
|
||||
|
||||
|
||||
def _record(level, msg="hello"):
|
||||
return logging.LogRecord("t", level, "f.py", 1, msg, None, None)
|
||||
|
||||
|
||||
@pytest.mark.parametrize("level,expected", [
|
||||
(logging.CRITICAL, 2),
|
||||
(logging.ERROR, 3),
|
||||
(logging.WARNING, 4),
|
||||
(logging.INFO, 6),
|
||||
(logging.DEBUG, 7),
|
||||
])
|
||||
def test_each_level_maps_to_its_syslog_priority(level, expected):
|
||||
out = JournalPriorityFormatter(_Plain()).format(_record(level))
|
||||
assert out.startswith(f"<{expected}>"), out
|
||||
assert _SYSLOG_PRIORITY[level] == expected
|
||||
|
||||
|
||||
def test_error_and_info_are_distinguishable():
|
||||
"""The whole point: journalctl -p err must be able to tell them apart."""
|
||||
fmt = JournalPriorityFormatter(_Plain())
|
||||
assert fmt.format(_record(logging.ERROR))[:3] != fmt.format(_record(logging.INFO))[:3]
|
||||
|
||||
|
||||
def test_every_line_of_a_multiline_record_is_tagged():
|
||||
"""The journal splits them, and an untagged continuation loses its level.
|
||||
|
||||
A traceback is the case that matters -- it is the most important thing in
|
||||
the log and the longest.
|
||||
"""
|
||||
out = JournalPriorityFormatter(_Plain()).format(
|
||||
_record(logging.ERROR, "Traceback:\nline one\nline two"))
|
||||
lines = out.split("\n")
|
||||
assert len(lines) == 3
|
||||
assert all(line.startswith("<3>") for line in lines), lines
|
||||
|
||||
|
||||
def test_the_message_survives_intact():
|
||||
out = JournalPriorityFormatter(_Plain()).format(_record(logging.WARNING, "disk full"))
|
||||
assert out == "<4>disk full"
|
||||
|
||||
|
||||
def test_an_unknown_level_falls_back_to_info():
|
||||
out = JournalPriorityFormatter(_Plain()).format(_record(25))
|
||||
assert out.startswith("<6>")
|
||||
|
||||
|
||||
def test_prefixing_is_off_outside_systemd():
|
||||
"""Otherwise a terminal run, the emulator and pytest all show `<6>`."""
|
||||
with patch.dict(os.environ, {}, clear=True):
|
||||
assert not _under_systemd()
|
||||
with patch.dict(os.environ, {"JOURNAL_STREAM": "8:12345"}):
|
||||
assert _under_systemd()
|
||||
|
||||
|
||||
def test_setup_uses_the_wrapper_only_under_systemd():
|
||||
from src.logging_config import setup_logging
|
||||
|
||||
for env, expect_wrapped in (({}, False), ({"JOURNAL_STREAM": "8:1"}, True)):
|
||||
with patch.dict(os.environ, env, clear=True):
|
||||
setup_logging()
|
||||
handlers = [h for h in logging.getLogger().handlers
|
||||
if isinstance(h, logging.StreamHandler)]
|
||||
assert handlers, "no stream handler installed"
|
||||
wrapped = any(isinstance(h.formatter, JournalPriorityFormatter)
|
||||
for h in handlers)
|
||||
assert wrapped is expect_wrapped, (
|
||||
f"JOURNAL_STREAM={env}: wrapped={wrapped}, expected {expect_wrapped}")
|
||||
logging.getLogger().handlers.clear()
|
||||
@@ -262,15 +262,54 @@ def _stop_display_service():
|
||||
result['status'] = status
|
||||
return result
|
||||
|
||||
#: Field names whose value is a credential. Matched by name because this
|
||||
#: endpoint returns the whole config, core keys included, and core config has
|
||||
#: no schema to carry x-secret markers.
|
||||
_CREDENTIAL_NAME_PARTS = ("password", "passwd", "secret", "token", "api_key",
|
||||
"apikey", "access_key", "private_key", "client_secret")
|
||||
|
||||
|
||||
def _looks_like_a_credential(name: str) -> bool:
|
||||
lowered = name.lower()
|
||||
return any(part in lowered for part in _CREDENTIAL_NAME_PARTS)
|
||||
|
||||
|
||||
def _redact_credentials(value):
|
||||
"""A copy of `value` with credential-named fields blanked.
|
||||
|
||||
/config/main returned the raw config to anyone who could reach the port,
|
||||
and this interface has no authentication. On one rig that meant a 40-char
|
||||
GitHub token, a 183-char Home Assistant token and five API keys were
|
||||
readable by anything on the LAN.
|
||||
|
||||
The x-secret masking used by the plugin config endpoints does not help
|
||||
here: this endpoint never consults a schema, and core keys such as
|
||||
github.api_token have no schema to mark. Matching on the field name is
|
||||
blunt, but for a whole-config dump the right default is that anything
|
||||
named like a credential does not leave the process.
|
||||
|
||||
Blanked rather than removed, and safe to blank: POST /config/main merges
|
||||
into the loaded config and only writes the keys it was given, so a client
|
||||
that round-trips this response cannot erase a secret it never saw.
|
||||
"""
|
||||
if isinstance(value, dict):
|
||||
return {k: ("" if _looks_like_a_credential(k) and not isinstance(v, (dict, list))
|
||||
else _redact_credentials(v))
|
||||
for k, v in value.items()}
|
||||
if isinstance(value, list):
|
||||
return [_redact_credentials(item) for item in value]
|
||||
return value
|
||||
|
||||
|
||||
@api_v3.route('/config/main', methods=['GET'])
|
||||
def get_main_config():
|
||||
"""Get main configuration"""
|
||||
"""Get main configuration, with credentials redacted."""
|
||||
try:
|
||||
if not api_v3.config_manager:
|
||||
return jsonify({'status': 'error', 'message': 'Config manager not initialized'}), 500
|
||||
|
||||
config = api_v3.config_manager.load_config()
|
||||
return jsonify({'status': 'success', 'data': config})
|
||||
return jsonify({'status': 'success', 'data': _redact_credentials(config)})
|
||||
except Exception as e:
|
||||
logger.error('Unhandled exception', exc_info=True)
|
||||
return jsonify({'status': 'error', 'message': 'An error occurred; see logs for details', 'details': describe_exception(e)}), 500
|
||||
|
||||
Reference in New Issue
Block a user