"""Structured, PII-safe logging. Two rules drive this module: * Only keys in :data:`SAFE_EXTRA_KEYS` are ever emitted. Resume text, job-description text, prompts, and full model responses have no route into a log line. * Exceptions are logged as a type plus a frame summary (``file:line:func``), never as a formatted message. Provider error messages can echo request content, so the message itself is dropped. """ from __future__ import annotations import json import logging import sys import traceback from contextvars import ContextVar from datetime import UTC, datetime from typing import Any request_id_var: ContextVar[str] = ContextVar("request_id", default="-") SAFE_EXTRA_KEYS: frozenset[str] = frozenset( { "candidate_id", # Deliberately not "filename": that is a reserved LogRecord attribute holding # the *source file* of the log call. Passing it via ``extra`` raises KeyError, # and reading it back would emit the wrong value entirely. "file_name", "status", "error_code", "duration_ms", "dropped_keywords", "model", "stop_reason", "input_tokens", "output_tokens", "cached_tokens", "reasoning_tokens", "provider_request_id", "page_count", "extracted_chars", "truncated", "total", "succeeded", "failed", "concurrency", "http_status", "path", } ) _MAX_FRAMES = 5 def _frame_summary(exc: BaseException) -> list[str]: """Location-only traceback. Deliberately excludes the exception message.""" frames = traceback.extract_tb(exc.__traceback__)[-_MAX_FRAMES:] return [f"{frame.filename}:{frame.lineno}:{frame.name}" for frame in frames] class JsonFormatter(logging.Formatter): def format(self, record: logging.LogRecord) -> str: payload: dict[str, Any] = { "ts": datetime.now(UTC).isoformat(timespec="milliseconds"), "level": record.levelname, "logger": record.name, "event": record.getMessage(), "request_id": request_id_var.get(), } for key, value in record.__dict__.items(): if key in SAFE_EXTRA_KEYS: payload[key] = value if record.exc_info is not None: exc = record.exc_info[1] if exc is not None: payload["exc_type"] = type(exc).__name__ payload["exc_frames"] = _frame_summary(exc) return json.dumps(payload, default=str) class SafeTextFormatter(logging.Formatter): """Human-readable fallback. Same redaction rules as :class:`JsonFormatter`.""" def format(self, record: logging.LogRecord) -> str: extras = " ".join( f"{key}={value}" for key, value in record.__dict__.items() if key in SAFE_EXTRA_KEYS ) base = f"{record.levelname:<8} {request_id_var.get()} {record.name} {record.getMessage()}" if extras: base = f"{base} | {extras}" if record.exc_info is not None: exc = record.exc_info[1] if exc is not None: base = f"{base} | exc_type={type(exc).__name__}" return base def configure_logging(*, level: str = "INFO", fmt: str = "json") -> None: handler = logging.StreamHandler(stream=sys.stdout) handler.setFormatter(JsonFormatter() if fmt == "json" else SafeTextFormatter()) root = logging.getLogger() for existing in list(root.handlers): root.removeHandler(existing) root.addHandler(handler) root.setLevel(level.upper()) # Uvicorn's access log echoes the full request line; the app logs requests itself. logging.getLogger("uvicorn.access").disabled = True