111 lines
3.6 KiB
Python
111 lines
3.6 KiB
Python
"""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",
|
|
"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
|