"""Logging: eine Zeile je Ereignis, als JSON (Betrieb) oder Text (Entwicklung). Jede Zeile trägt den Kontext, in dem sie entsteht: request_id, user_id, workspace_id, run_id und worker_id. Gesetzt wird er über contextvars (Middleware im Web, Run im Worker), damit Aufrufer nichts durchreichen müssen. Nie geloggt werden Inhalte (Prompts, Antworten, Abfrageergebnisse) und Geheimnisse; als zweite Sicherung maskiert ein Filter typische Muster (Bearer-Token, API-Keys, Passwörter). """ import json import logging import re import sys from collections.abc import Iterator, Mapping from contextlib import contextmanager from contextvars import ContextVar from datetime import UTC, datetime from types import MappingProxyType from typing import Any CONTEXT_FIELDS = ("request_id", "user_id", "workspace_id", "run_id", "worker_id") # Unveränderlich: Änderungen setzen immer ein neues Dict, der Standard wird nie geteilt beschrieben _context: ContextVar[Mapping[str, Any]] = ContextVar("aiw_log_context", default=MappingProxyType({})) # Felder des LogRecord, die nicht als Zusatzangaben ausgegeben werden _STANDARD = set(vars(logging.LogRecord("", 0, "", 0, "", None, None))) | {"message", "asctime", "taskName", "color_message"} SECRETS = [ (re.compile(r"(?i)(bearer\s+)[A-Za-z0-9._~+/=-]{6,}"), r"\1***"), (re.compile(r"\b(sk|pk|rk)-[A-Za-z0-9_-]{8,}"), r"\1-***"), (re.compile(r"(?i)\b(password|passwort|secret|token|api_key|apikey)(\s*[=:]\s*)([^\s,;&\"']+)"), r"\1\2***"), (re.compile(r"(?i)(://[^:/@\s]+:)[^@\s]+@"), r"\1***@"), ] def redact(text: str) -> str: for pattern, replacement in SECRETS: text = pattern.sub(replacement, text) return text def bind(**values: Any) -> None: """Kontext für alle folgenden Zeilen dieses Requests bzw. Runs ergänzen.""" _context.set({**_context.get(), **{k: v for k, v in values.items() if v is not None}}) @contextmanager def scope(**values: Any) -> Iterator[None]: """Kontext nur für einen Abschnitt, danach wieder der vorherige.""" token = _context.set({**_context.get(), **{k: v for k, v in values.items() if v is not None}}) try: yield finally: _context.reset(token) def current() -> dict[str, Any]: return dict(_context.get()) def clear() -> None: _context.set({}) class ContextFilter(logging.Filter): def filter(self, record: logging.LogRecord) -> bool: for key, value in _context.get().items(): if not hasattr(record, key): setattr(record, key, value) return True _factory = logging.getLogRecordFactory() def _record(*args: Any, **kwargs: Any) -> logging.LogRecord: """Kontext beim Erzeugen anhängen: dann tragen ihn alle Handler, auch fremde.""" record = _factory(*args, **kwargs) record.__dict__.update(_context.get()) return record if not getattr(_factory, "aiw", False): _record.aiw = True # type: ignore[attr-defined] logging.setLogRecordFactory(_record) def extras(record: logging.LogRecord) -> dict[str, Any]: return {k: v for k, v in vars(record).items() if k not in _STANDARD and not k.startswith("_")} class JsonFormatter(logging.Formatter): def format(self, record: logging.LogRecord) -> str: entry: dict[str, Any] = { "time": datetime.fromtimestamp(record.created, UTC).isoformat(timespec="milliseconds"), "level": record.levelname.lower(), "logger": record.name, "message": redact(record.getMessage()), } for key, value in extras(record).items(): entry[key] = redact(value) if isinstance(value, str) else value if record.exc_info: entry["exception"] = redact(self.formatException(record.exc_info)) return json.dumps(entry, ensure_ascii=False, default=str) class TextFormatter(logging.Formatter): def __init__(self) -> None: super().__init__("%(asctime)s %(levelname)s %(name)s: %(message)s") def format(self, record: logging.LogRecord) -> str: text = redact(super().format(record)) fields = extras(record) if fields: text += " " + " ".join(f"{k}={fields[k]}" for k in sorted(fields)) return text def setup(level: str = "INFO", fmt: str = "text") -> None: handler = logging.StreamHandler(sys.stdout) handler.setFormatter(JsonFormatter() if fmt == "json" else TextFormatter()) handler.addFilter(ContextFilter()) root = logging.getLogger() root.handlers[:] = [handler] root.setLevel(level.upper()) # Eigene Zugriffszeile statt der von uvicorn; Fehler von uvicorn laufen über root logging.getLogger("uvicorn.access").disabled = True for name in ("uvicorn", "uvicorn.error"): logging.getLogger(name).handlers[:] = [] logging.getLogger(name).propagate = True # httpx loggt jede Anfrage mit voller URL auf INFO logging.getLogger("httpx").setLevel(logging.WARNING)