Files
siftlode/backend/tests/test_logger_names.py
T
peter 54d19cc386 fix(logs): deep-review round 1 — say each failure once, and scrub it everywhere
- yt-dlp's text is scrubbed wherever it is logged, not only in the adapter:
  `formats.log_safe` takes out the URL, the `[extractor] <id>:` prefix and
  file paths, and the job-failed, refused, edit-failed and backfill lines use
  it. Done lines log the asset id, not the title-built path. The PII contract
  now bans `rel`/`rel_path`/`title`.
- A traceback goes with a download/edit failure only when it is our own code
  failing; for yt-dlp's DownloadError, our RuntimeErrors and OSErrors its foot
  is the unscrubbed message.
- yt-dlp's `error` maps to WARNING: it fires on attempts the fallback client
  set recovers from; the job's verdict is `download.job.failed`.
- The sink groups a bare `%s` pass-through by its text (numbers folded), and
  a process's last batch closes the repeat window, so a short-lived download
  child still reports what it dropped.
- Worker-side failures (stall, wall-clock, no asset, cached asset error) log
  `download.job.failed` with a cause; they left no line at all before. The
  crash, supervisor-error and non-zero-exit lines carry the code too.
- An edit failure is one coded line in `_fail_edit`, for every path.
- `logs.get_logger("__main__")` resolves to the `-m` module, so the worker
  and the download child keep their names.
- TRACE lines carrying user content are gated on `logs.consented_trace()`,
  not on the process level; a contract test pins it.
- The OAuth token refresh goes through `_upstream_failure`; transport errors
  carry reason `transport`. Subscribe recognises a duplicate by reason code
  only (the prose fallback was dead).
- Once-only guards for a stale sysconfig override and a refusing HLS session
  directory; item_detail splits Plex failures from our own parse bugs.
- The playlist breaker line names the playlist and the action; comments that
  were false (runner noqa, `_merge_vtt`, sink grouping) are corrected.
2026-09-18 03:16:15 +02:00

122 lines
4.9 KiB
Python

"""E22.5 S2 — every module's logger is named after the module.
The names used to be literals, and 25 of them covered 34 modules: `plex/client.py`, `plex/stream.py`,
`plex/subtitles.py`, `plex/sync.py` and two route modules all called themselves `siftlode.plex`, and
`downloads/pipeline.py` called itself `siftlode.worker`. A level pinned per logger could not separate
them, and neither can E22.6's console filter — the `logger` field is in every stored row precisely so
it can be filtered on.
So the name is derived, not written: `logs.get_logger(__name__)`. These cases pin the derivation and
the rule, because the rule is only worth having if a hand-rolled name fails the gate.
"""
import ast
import logging
import pathlib
import sys
import types
import pytest
from app import logs
APP = pathlib.Path(logs.__file__).resolve().parent
_ESCAPE = "logger-name-ok"
@pytest.mark.parametrize(
("module", "expected"),
[
("app.plex.sync", "siftlode.plex.sync"),
("app.plex.stream", "siftlode.plex.stream"),
("app.routes.channels", "siftlode.routes.channels"),
("app.worker", "siftlode.worker"),
# A script that is not a module of ours (pytest itself, here): it lands on the root of our
# tree rather than inventing `siftlode.__main__`, which nothing would think to filter on.
("__main__", "siftlode"),
],
)
def test_the_name_follows_the_module(module, expected):
assert logs.get_logger(module).name == expected
@pytest.mark.parametrize(
("spec_name", "expected"),
[
# How the worker and the download child actually run: `python -m app.worker`, and the
# worker's own `[sys.executable, "-m", "app.downloads.runner", ...]`. `__name__` is
# `__main__` in both, and taken at its word both processes logged as the bare root.
("app.worker", "siftlode.worker"),
("app.downloads.runner", "siftlode.downloads.runner"),
],
)
def test_a_module_run_with_dash_m_keeps_its_own_name(monkeypatch, spec_name, expected):
main = types.ModuleType("__main__")
main.__spec__ = types.SimpleNamespace(name=spec_name)
monkeypatch.setitem(sys.modules, "__main__", main)
assert logs.get_logger("__main__").name == expected
def test_a_plain_script_has_no_spec_and_stays_the_root(monkeypatch):
main = types.ModuleType("__main__")
main.__spec__ = None
monkeypatch.setitem(sys.modules, "__main__", main)
assert logs.get_logger("__main__").name == "siftlode"
def test_every_derived_logger_stays_under_the_one_tree():
"""`configure_logging` hangs the level and the handler off the root, and the tests attach their
sink to `siftlode` — a name outside that tree would be invisible to both."""
for module in ("app.main", "app.plex.sync", "app.routes.plex.people", "app"):
assert logs.get_logger(module).name.startswith("siftlode")
def test_the_module_logger_is_reachable_by_its_derived_name():
"""Not a new logger object per call: the stdlib registry is keyed by name, and an operator
pinning `siftlode.plex.sync` has to reach the same instance the module logs through."""
from app.plex import sync
assert sync.log is logging.getLogger("siftlode.plex.sync")
def test_no_module_hand_rolls_a_logger_name():
offenders = []
for path in sorted(APP.rglob("*.py")):
src = path.read_text(encoding="utf-8")
lines = src.splitlines()
for node in ast.walk(ast.parse(src)):
if not isinstance(node, ast.Call):
continue
func = node.func
called = (
func.attr
if isinstance(func, ast.Attribute)
else func.id
if isinstance(func, ast.Name)
else ""
)
if called == "get_logger":
# The derivation itself is only as good as its argument: a literal here does not
# name a module, it collapses to the root and pools modules together again.
arg = node.args[0] if len(node.args) == 1 else None
if isinstance(arg, ast.Name) and arg.id == "__name__" and not node.keywords:
continue
elif called == "getLogger":
# A no-argument `logging.getLogger()` is the ROOT logger — level plumbing, not a
# module's own logger, and nothing to name. A `name=` keyword is still a name.
if not node.args and not node.keywords:
continue
else:
continue
start = max(0, node.lineno - 2) # the call's lines, plus the one above it
span = " ".join(lines[start : (node.end_lineno or node.lineno)])
if _ESCAPE in span:
continue
offenders.append(f"{path.relative_to(APP)}:{node.lineno}")
assert offenders == [], (
"a module names its own logger; use `logs.get_logger(__name__)`, or say why the name is "
f"not the module's with `# {_ESCAPE}: <why>` — {offenders}"
)