"""What a log line may NOT carry.

`logs.redact_text` is a safety net over addresses and credential params, and it was doing the whole
job: every one of these call sites was putting user content into a line and relying on the net to
catch it. Two things were wrong with that. What the net does NOT cover went in whole — a search
term, a source URL, an upstream body that quotes the request back — and what it DOES cover came out
as `[email]`, so the line's one variable was a constant and the line said nothing.

The cases below pin the call sites. The last one pins the family: no future log call may pass the
same kind of value without saying, on the line, why it is safe.
"""

import ast
import json
import logging
import pathlib

import httpx
import pytest

from app import logs
from app.youtube.client import YouTubeError, _upstream_failure

TERM = "the exact thing they typed"


class _Sink(logging.Handler):
    """The stdout handler's own filter and formatter, so a case sees the bytes a deployment writes
    — not the record before redaction ran."""

    def __init__(self):
        super().__init__(level=logging.NOTSET)
        self.lines: list[str] = []
        self.setFormatter(logs.JsonFormatter())
        self.addFilter(logs.ContextFilter())

    def emit(self, record):
        self.lines.append(self.format(record))

    def objects(self) -> list[dict]:
        return [json.loads(line) for line in self.lines]

    def at(self, level: str) -> list[dict]:
        return [o for o in self.objects() if o["level"] == level]


@pytest.fixture
def sink():
    logger = logging.getLogger("siftlode")
    handler = _Sink()
    previous = logger.level
    logger.addHandler(handler)
    logger.setLevel(logs.TRACE)
    try:
        yield handler
    finally:
        logger.removeHandler(handler)
        logger.setLevel(previous)


def _youtube_403(term: str) -> httpx.Response:
    """A real-shaped Data API error. `message` is prose, and prose from an upstream quotes the
    request back — which is how a search term ends up in our log through someone else's words."""
    return httpx.Response(
        403,
        json={
            "error": {
                "code": 403,
                "message": f"The request for '{term}' cannot be completed: quota exceeded.",
                "errors": [{"reason": "quotaExceeded", "domain": "youtube.quota"}],
            }
        },
        request=httpx.Request("GET", "https://www.googleapis.com/youtube/v3/search"),
    )


def test_an_upstream_failure_logs_the_reason_code_and_not_the_body(sink):
    err = _upstream_failure("GET", "search", _youtube_403(TERM))

    (line,) = sink.at("WARNING")
    assert line["attrs"]["reason"] == "quotaExceeded"
    assert line["attrs"]["status"] == 403
    assert TERM not in json.dumps(line)
    # The error is raised to callers that put it in a log line of their own (routes/channels.py)
    # and in a 422 answered to the user, so the body must not travel in it either.
    assert TERM not in str(err)
    assert err.reason == "quotaExceeded"


@pytest.fixture
def consented():
    """The request scope of a user who turned Teljes (TRACE) on for themselves."""
    scope = logs._RequestScope()
    scope.user_id, scope.level = 7, logs.TRACE
    token = logs._scope.set(scope)
    try:
        yield
    finally:
        logs._scope.reset(token)


def test_the_body_is_kept_for_the_one_user_who_consented_to_it(sink, consented):
    _upstream_failure("GET", "search", _youtube_403(TERM))

    # The diagnostic is not lost, it is gated — on the consent the privacy policy describes.
    (trace,) = sink.at("TRACE")
    assert TERM in trace["attrs"]["body"]


def test_a_process_running_at_trace_is_not_anyones_consent(sink):
    """`sink` runs the whole tree at TRACE — what an admin setting `log_level` to TRACE does. That
    buys more detail, not every user's search terms quoted back (`logs._traced`)."""
    _upstream_failure("GET", "search", _youtube_403(TERM))

    assert sink.at("TRACE") == []
    assert TERM not in json.dumps(sink.objects())


def test_a_scope_with_no_elevation_is_not_consent():
    scope = logs._RequestScope()
    scope.user_id = 7
    token = logs._scope.set(scope)
    try:
        assert not logs.consented_trace()
    finally:
        logs._scope.reset(token)
    assert not logs.consented_trace()  # a scheduler thread: no request at all


def test_a_refused_token_refresh_names_the_oauth_reason_and_not_its_prose(sink, monkeypatch):
    """The token endpoint's error is `{"error": "<code>", "error_description": <prose>}` — not the
    Data API's shape. The refresh goes through the same door, so it gets the same treatment."""
    from types import SimpleNamespace

    from app.youtube import client as yt

    resp = httpx.Response(
        400,
        json={"error": "invalid_grant", "error_description": "Token has been expired or revoked."},
        request=httpx.Request("POST", "https://oauth2.googleapis.com/token"),
    )
    client = yt.YouTubeClient.__new__(yt.YouTubeClient)  # no HTTP client: `_send` is the stub
    client.db = SimpleNamespace(add=lambda obj: None, commit=lambda: None)
    client.user = SimpleNamespace(
        id=1, token=SimpleNamespace(access_token=None, expiry=None, refresh_token_enc=b"x")
    )
    monkeypatch.setattr(yt, "decrypt_optional", lambda value: None)
    monkeypatch.setattr(yt, "decrypt", lambda value: "a-refresh-token")
    monkeypatch.setattr(yt.sysconfig, "get_str", lambda db, key: "")
    monkeypatch.setattr(client, "_send", lambda *a, **k: resp)

    with pytest.raises(YouTubeError) as caught:
        client._access_token()
    err = caught.value

    (line,) = sink.at("WARNING")
    assert line["attrs"]["reason"] == "invalid_grant"
    assert err.reason == "invalid_grant"
    assert "revoked" not in str(err) and "revoked" not in json.dumps(line)


def test_an_unparseable_body_still_names_the_status(sink):
    """A proxy answering HTML has no `reason` to take — the line must still be worth reading, and
    must still not fall back to printing the body."""
    resp = httpx.Response(
        502,
        text="<html><body>Bad Gateway</body></html>",
        request=httpx.Request("GET", "https://www.googleapis.com/youtube/v3/search"),
    )
    err = _upstream_failure("GET", "search", resp)

    (line,) = sink.at("WARNING")
    assert line["attrs"] == {
        "method": "GET",
        "path": "search",
        "status": 502,
        "reason": "<unparseable>",
    }
    assert "Bad Gateway" not in str(err)
    assert isinstance(err, YouTubeError)


def test_a_sign_in_names_the_account_by_id_and_not_by_address(client, make_user, sink):
    make_user(email="signing.in@example.com", password="correct horse battery")

    r = client.post(
        "/auth/password-login",
        json={"email": "signing.in@example.com", "password": "correct horse battery"},
    )
    assert r.status_code == 200

    (line,) = [o for o in sink.at("INFO") if o.get("event") == "auth.login.ok"]
    assert line["attrs"]["method"] == "password"
    assert isinstance(line["attrs"]["uid"], int)
    # Not `[email]` either: the redacted form is what made the old line useless.
    assert "signing.in" not in json.dumps(line)
    assert logs.REDACTED_EMAIL not in json.dumps(line)


# --- the family ------------------------------------------------------------------------------
# Names that hold something a person typed or a place they went. A log call may still pass one —
# `main.py` logs the instance's OWN setup URL — but it has to say so on the line, which is the
# difference between a decision and an oversight.
_BANNED_NAMES = frozenset(
    {
        "term",
        "q",
        "query",
        "search_term",
        "email",
        "emails",
        "recipients",
        "recipient",
        "url",
        "webpage_url",
        "source_url",
        "source_webpage_url",
        "password",
        # A download's path is built from its channel and its title (`storage.rel_path`), so it
        # names what someone downloaded exactly as the URL does. Log the asset id.
        "rel",
        "rel_path",
        "title",
    }
)
_BANNED_ATTRS = frozenset(
    {"text", "content", "email", "url", "query", "rel_path", "title", "display_name"}
)
_ESCAPE = "log-pii-ok"
_LOG_METHODS = frozenset(
    {"debug", "info", "warning", "warn", "error", "exception", "critical", "log"}
)


def _is_log_call(node: ast.AST) -> bool:
    if not isinstance(node, ast.Call) or not isinstance(node.func, ast.Attribute):
        return False
    if node.func.attr not in _LOG_METHODS:
        return False
    base, name = node.func.value, ""
    while isinstance(base, ast.Attribute):
        name = f"{base.attr}.{name}"
        base = base.value
    if isinstance(base, ast.Name):
        name = f"{base.id}.{name}"
    return "log" in name.lower()


def _offending(node: ast.Call) -> set[str]:
    found: set[str] = set()
    for sub in ast.walk(node):
        if isinstance(sub, ast.Name) and sub.id in _BANNED_NAMES:
            found.add(sub.id)
        elif isinstance(sub, ast.Attribute) and sub.attr in _BANNED_ATTRS:
            found.add(f".{sub.attr}")
    return found


def test_no_log_call_passes_what_a_person_typed():
    root = pathlib.Path(__file__).resolve().parents[1] / "app"
    offenders = []
    for path in sorted(root.rglob("*.py")):
        src = path.read_text(encoding="utf-8")
        lines = src.splitlines()
        for node in ast.walk(ast.parse(src)):
            if not _is_log_call(node):
                continue
            names = _offending(node)
            if not names:
                continue
            # The call's own lines plus the one directly above it — a marker belongs either
            # on the argument or on the comment line introducing the call, and nowhere
            # further, or one call's justification would excuse its neighbour.
            start = max(0, node.lineno - 2)
            span = " ".join(lines[start : (node.end_lineno or node.lineno)])
            if _ESCAPE in span:
                continue
            offenders.append(f"{path.relative_to(root)}:{node.lineno} {sorted(names)}")
    assert offenders == [], (
        "a log call carries user-typed content; log an id or a reason code instead, or mark "
        f"the argument (or the line directly above the call) `# {_ESCAPE}: <why it is "
        f"safe>` — {offenders}"
    )


_AT_LEAST_DEBUG = {"DEBUG", "INFO", "WARNING", "WARN", "ERROR", "CRITICAL", "FATAL"}


def _may_run_at_trace(call: ast.Call) -> bool:
    """A `log.log(level, …)` whose level is not provably DEBUG or above: `logs.TRACE`, a bare
    `TRACE`, a literal 5 — or a variable, which could be any of them."""
    if call.func.attr != "log" or not call.args:
        return False
    level = call.args[0]
    if isinstance(level, ast.Attribute | ast.Name):
        return (level.attr if isinstance(level, ast.Attribute) else level.id) not in _AT_LEAST_DEBUG
    if isinstance(level, ast.Constant) and isinstance(level.value, int):
        return level.value < logging.DEBUG
    return True


def _is_consent_check(test: ast.expr) -> bool:
    """Exactly `…consented_trace()`: not `not …`, not `x or …` — each of those runs the body when
    there is no consent."""
    return (
        isinstance(test, ast.Call)
        and isinstance(test.func, ast.Attribute | ast.Name)
        and (test.func.attr if isinstance(test.func, ast.Attribute) else test.func.id)
        == "consented_trace"
    )


def _guarded_by_consent(node: ast.AST, parents: dict[ast.AST, ast.AST]) -> bool:
    """The node runs only inside the BODY of an `if <consented_trace()>:` — not its `else`."""
    while node in parents:
        parent = parents[node]
        if isinstance(parent, ast.If) and _is_consent_check(parent.test) and node in parent.body:
            return True
        node = parent
    return False


def _parents(tree: ast.AST) -> dict[ast.AST, ast.AST]:
    return {child: node for node in ast.walk(tree) for child in ast.iter_child_nodes(node)}


_GATE_SHAPES = {
    "the body of the check": ("if logs.consented_trace():\n    log.log(logs.TRACE, 'x')", True),
    "its else": (
        "if logs.consented_trace():\n    pass\nelse:\n    log.log(logs.TRACE, 'x')",
        False,
    ),
    "a negated check": ("if not logs.consented_trace():\n    log.log(logs.TRACE, 'x')", False),
    "an or": ("if debug or logs.consented_trace():\n    log.log(logs.TRACE, 'x')", False),
    "a nested block in the body": (
        "if logs.consented_trace():\n    for t in ts:\n        log.log(logs.TRACE, 'x')",
        True,
    ),
}


@pytest.mark.parametrize("shape", list(_GATE_SHAPES))
def test_the_consent_gate_is_the_body_of_the_check_and_nothing_else(shape):
    src, gated = _GATE_SHAPES[shape]
    tree = ast.parse(src)
    (call,) = [n for n in ast.walk(tree) if isinstance(n, ast.Call) and _is_log_call(n)]
    assert _guarded_by_consent(call, _parents(tree)) is gated


@pytest.mark.parametrize(
    ("level", "trace"),
    [
        ("logs.TRACE", True),
        ("TRACE", True),
        ("5", True),
        ("level", True),
        ("levels[scope]", True),
        ("logging.DEBUG", False),
        ("logging.WARNING", False),
        ("20", False),
    ],
)
def test_a_level_that_may_be_trace_is_treated_as_trace(level, trace):
    (call,) = [n for n in ast.walk(ast.parse(f"log.log({level}, 'x')")) if isinstance(n, ast.Call)]
    assert _may_run_at_trace(call) is trace


def test_every_escaped_trace_line_is_gated_on_the_users_own_consent():
    """`log-pii-ok` on a TRACE line means "this is what the user's Teljes consent is for". The TRACE
    level alone does not hold that promise: an admin can run the whole process at TRACE, and a
    scheduler thread has no user at all. So the line must sit under `logs.consented_trace()`."""
    root = pathlib.Path(__file__).resolve().parents[1] / "app"
    offenders = []
    for path in sorted(root.rglob("*.py")):
        src = path.read_text(encoding="utf-8")
        lines = src.splitlines()
        tree = ast.parse(src)
        parents = _parents(tree)
        for node in ast.walk(tree):
            if not _is_log_call(node) or not _offending(node):
                continue
            span = " ".join(lines[max(0, node.lineno - 2) : (node.end_lineno or node.lineno)])
            if (
                _may_run_at_trace(node)
                and _ESCAPE in span
                and not _guarded_by_consent(node, parents)
            ):
                offenders.append(f"{path.relative_to(root)}:{node.lineno}")
    assert offenders == [], (
        f"a TRACE line with user content is not under consented_trace(): {offenders}"
    )


def test_a_database_error_does_not_carry_the_values_it_was_given(db):
    """DB lane. A failed write's message is logged and stored as the job's error text; with its
    bound parameters in it, that is the title or the file path the row was about."""
    from sqlalchemy import exc as sa_exc
    from sqlalchemy import text

    # Postgres's own text for this one names no value ("value too long for type character
    # varying(3)"), so what is left to leak is SQLAlchemy's `[parameters: …]` suffix.
    db.execute(text("CREATE TEMP TABLE pii_probe (x varchar(3))"))
    with pytest.raises(sa_exc.DBAPIError) as caught:
        db.execute(text("INSERT INTO pii_probe VALUES (:v)"), {"v": "A_Private_Title"})
    db.rollback()
    assert "value too long" in str(caught.value)
    assert "A_Private_Title" not in str(caught.value)