"""Observability plumbing — logging format, request IDs, request log.

- ``setup_logging()``: human-readable text by default, JSON lines when
  ``PROCUREMENT_LOG_FORMAT=json`` (what Promtail/Loki prefers).
- ``request_context`` middleware: assigns an X-Request-ID to every request
  (honours one sent by the edge), echoes it in the response, and logs one
  structured line per request (method, path, status, duration, request id)
  — this is what makes access logs useful in Loki.
"""
import contextvars
import json
import logging
import time
import uuid

from starlette.middleware.base import BaseHTTPMiddleware
from starlette.requests import Request
from starlette.responses import Response

request_id_var: contextvars.ContextVar[str] = contextvars.ContextVar("request_id", default="-")

_SKIP_ACCESS_LOG = {"/health", "/health/ready", "/metrics"}


class JsonFormatter(logging.Formatter):
    """Minimal JSON-lines formatter for Loki/Promtail ingestion."""

    def format(self, record: logging.LogRecord) -> str:
        payload = {
            "ts": self.formatTime(record, "%Y-%m-%dT%H:%M:%S%z"),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
            "request_id": request_id_var.get(),
        }
        if record.exc_info:
            payload["exception"] = self.formatException(record.exc_info)
        for key in ("http_method", "http_path", "http_status", "duration_ms"):
            value = getattr(record, key, None)
            if value is not None:
                payload[key] = value
        return json.dumps(payload, ensure_ascii=False)


def setup_logging(log_format: str = "text", level: int = logging.INFO) -> None:
    formatter = JsonFormatter() if log_format.lower() == "json" else logging.Formatter(
        "%(asctime)s %(levelname)s %(name)s — %(message)s"
    )
    root = logging.getLogger()
    for handler in root.handlers[:]:
        root.removeHandler(handler)
    handler = logging.StreamHandler()
    handler.setFormatter(formatter)
    root.addHandler(handler)
    root.setLevel(level)


class RequestContextMiddleware(BaseHTTPMiddleware):
    """X-Request-ID + one access-log line per request."""

    async def dispatch(self, request: Request, call_next) -> Response:
        rid = request.headers.get("x-request-id") or uuid.uuid4().hex
        token = request_id_var.set(rid)
        started = time.perf_counter()
        try:
            response = await call_next(request)
        except Exception:
            duration_ms = round((time.perf_counter() - started) * 1000, 1)
            logging.getLogger("procurement.access").exception(
                "unhandled exception",
                extra={"http_method": request.method, "http_path": request.url.path,
                       "http_status": 500, "duration_ms": duration_ms},
            )
            request_id_var.reset(token)
            raise
        duration_ms = round((time.perf_counter() - started) * 1000, 1)
        response.headers["X-Request-ID"] = rid
        request_id_var.reset(token)
        if request.url.path not in _SKIP_ACCESS_LOG:
            logging.getLogger("procurement.access").info(
                "%s %s -> %s",
                request.method, request.url.path, response.status_code,
                extra={"http_method": request.method, "http_path": request.url.path,
                       "http_status": response.status_code, "duration_ms": duration_ms},
            )
        return response