"""JSON logs, request ids and an access log (lesson 21)."""
import contextvars
import json
import logging
import re
import sys
import time
import uuid

request_id: contextvars.ContextVar[str] = contextvars.ContextVar("request_id", default="-")
access_log = logging.getLogger("orders.access")
_SAFE_ID = re.compile(r"[A-Za-z0-9-]{8,64}")


class JsonFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> str:
        entry = {"ts": self.formatTime(record, "%Y-%m-%dT%H:%M:%S"), "level": record.levelname,
                 "logger": record.name, "msg": record.getMessage(), "request_id": request_id.get()}
        entry.update(getattr(record, "fields", {}))
        if record.exc_info:
            entry["error"] = repr(record.exc_info[1])
        return json.dumps(entry, default=str)


def configure_logging(level: str = "INFO") -> None:
    handler = logging.StreamHandler(sys.stdout)
    handler.setFormatter(JsonFormatter())
    logging.basicConfig(level=level, handlers=[handler], force=True)
    for name in ("uvicorn", "uvicorn.error"):                  # uvicorn's own logs become JSON too
        logging.getLogger(name).handlers.clear()
        logging.getLogger(name).propagate = True
    logging.getLogger("uvicorn.access").disabled = True         # replaced by orders.access below
    logging.getLogger("httpx").setLevel(logging.WARNING)


class RequestContextMiddleware:
    """Pure ASGI: request id in, request id out, one access-log line per request."""

    def __init__(self, app) -> None:
        self.app = app

    async def __call__(self, scope, receive, send) -> None:
        if scope["type"] != "http":
            return await self.app(scope, receive, send)
        incoming = dict(scope["headers"]).get(b"x-request-id", b"").decode("latin-1")
        rid = incoming if _SAFE_ID.fullmatch(incoming) else uuid.uuid4().hex[:16]
        token = request_id.set(rid)
        status, start = 500, time.perf_counter()

        async def send_with_id(message) -> None:
            nonlocal status
            if message["type"] == "http.response.start":
                status = message["status"]
                message["headers"] = [*message.get("headers", []), (b"x-request-id", rid.encode())]
            await send(message)

        try:
            await self.app(scope, receive, send_with_id)
        finally:
            principal = scope.get("state", {}).get("principal")
            access_log.info("request", extra={"fields": {
                "method": scope["method"],
                "route": getattr(scope.get("route"), "path", "unmatched"),
                "status": status,
                "user_id": getattr(principal, "id", None),
                "duration_ms": round((time.perf_counter() - start) * 1000, 1)}})
            request_id.reset(token)