siftlode/backend/tests/test_logger_names.py

"""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 the console's 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}"
    )