|
| 1 | +"""Runtime logging utilities for wave synthesis/scoring observability.""" |
| 2 | + |
| 3 | +from __future__ import annotations |
| 4 | + |
| 5 | +import atexit |
| 6 | +import json |
| 7 | +import logging |
| 8 | +from dataclasses import dataclass |
| 9 | +from datetime import UTC, datetime |
| 10 | +from logging.handlers import QueueHandler, QueueListener, RotatingFileHandler |
| 11 | +from queue import SimpleQueue |
| 12 | +from collections.abc import Callable |
| 13 | +from typing import Any |
| 14 | + |
| 15 | +_VALID_FORMATS = {"text", "json"} |
| 16 | + |
| 17 | + |
| 18 | +@dataclass(slots=True) |
| 19 | +class RuntimeLoggingConfig: |
| 20 | + """Configuration for runtime logging sinks and formatting.""" |
| 21 | + |
| 22 | + enabled: bool = False |
| 23 | + level: str = "INFO" |
| 24 | + file_path: str | None = None |
| 25 | + format: str = "text" |
| 26 | + max_bytes: int = 0 |
| 27 | + backup_count: int = 3 |
| 28 | + console: bool = False |
| 29 | + logger_name: str = "vxsort.runtime" |
| 30 | + |
| 31 | + |
| 32 | +def parse_log_level(level: str | int) -> int: |
| 33 | + """Return numeric logging level from string/int input.""" |
| 34 | + if isinstance(level, int): |
| 35 | + return level |
| 36 | + |
| 37 | + normalized = level.strip().upper() |
| 38 | + mapping = { |
| 39 | + "CRITICAL": logging.CRITICAL, |
| 40 | + "ERROR": logging.ERROR, |
| 41 | + "WARNING": logging.WARNING, |
| 42 | + "WARN": logging.WARNING, |
| 43 | + "INFO": logging.INFO, |
| 44 | + "DEBUG": logging.DEBUG, |
| 45 | + } |
| 46 | + if normalized not in mapping: |
| 47 | + msg = f"Unknown log level: {level!r}" |
| 48 | + raise ValueError(msg) |
| 49 | + return mapping[normalized] |
| 50 | + |
| 51 | + |
| 52 | +class EventTextFormatter(logging.Formatter): |
| 53 | + """Text formatter that prints event + key/value fields.""" |
| 54 | + |
| 55 | + def format(self, record: logging.LogRecord) -> str: # noqa: D401 |
| 56 | + ts = datetime.fromtimestamp(record.created, tz=UTC).isoformat() |
| 57 | + event = getattr(record, "event_name", record.getMessage()) |
| 58 | + fields = getattr(record, "event_fields", {}) |
| 59 | + if fields: |
| 60 | + rendered_fields = " ".join( |
| 61 | + f"{key}={value!r}" for key, value in fields.items() |
| 62 | + ) |
| 63 | + return f"{ts} [{record.levelname}] {event} | {rendered_fields}" |
| 64 | + return f"{ts} [{record.levelname}] {event}" |
| 65 | + |
| 66 | + |
| 67 | +class EventJsonFormatter(logging.Formatter): |
| 68 | + """JSONL formatter for high-volume machine-readable logs.""" |
| 69 | + |
| 70 | + def format(self, record: logging.LogRecord) -> str: # noqa: D401 |
| 71 | + payload: dict[str, Any] = { |
| 72 | + "ts": datetime.fromtimestamp(record.created, tz=UTC).isoformat(), |
| 73 | + "level": record.levelname, |
| 74 | + "logger": record.name, |
| 75 | + "event": getattr(record, "event_name", record.getMessage()), |
| 76 | + } |
| 77 | + payload.update(getattr(record, "event_fields", {})) |
| 78 | + |
| 79 | + if record.exc_info: |
| 80 | + payload["exception"] = self.formatException(record.exc_info) |
| 81 | + |
| 82 | + return json.dumps(payload, default=str) |
| 83 | + |
| 84 | + |
| 85 | +def _make_formatter(fmt: str) -> logging.Formatter: |
| 86 | + if fmt not in _VALID_FORMATS: |
| 87 | + msg = f"Unsupported log format: {fmt!r}. Expected one of {_VALID_FORMATS}" |
| 88 | + raise ValueError(msg) |
| 89 | + if fmt == "json": |
| 90 | + return EventJsonFormatter() |
| 91 | + return EventTextFormatter() |
| 92 | + |
| 93 | + |
| 94 | +def configure_runtime_logging( |
| 95 | + config: RuntimeLoggingConfig, |
| 96 | +) -> tuple[logging.Logger, Callable[[], None]]: |
| 97 | + """Configure queue-backed runtime logging and return (logger, shutdown).""" |
| 98 | + logger = logging.getLogger(config.logger_name) |
| 99 | + |
| 100 | + for handler in list(logger.handlers): |
| 101 | + logger.removeHandler(handler) |
| 102 | + |
| 103 | + if not config.enabled: |
| 104 | + logger.setLevel(logging.NOTSET) |
| 105 | + logger.propagate = True |
| 106 | + |
| 107 | + def _noop_shutdown() -> None: |
| 108 | + return |
| 109 | + |
| 110 | + return logger, _noop_shutdown |
| 111 | + |
| 112 | + level = parse_log_level(config.level) |
| 113 | + formatter = _make_formatter(config.format) |
| 114 | + |
| 115 | + target_handlers: list[logging.Handler] = [] |
| 116 | + |
| 117 | + if config.file_path: |
| 118 | + if config.max_bytes and config.max_bytes > 0: |
| 119 | + file_handler: logging.Handler = RotatingFileHandler( |
| 120 | + config.file_path, |
| 121 | + maxBytes=config.max_bytes, |
| 122 | + backupCount=config.backup_count, |
| 123 | + encoding="utf-8", |
| 124 | + ) |
| 125 | + else: |
| 126 | + file_handler = logging.FileHandler(config.file_path, encoding="utf-8") |
| 127 | + file_handler.setLevel(level) |
| 128 | + file_handler.setFormatter(formatter) |
| 129 | + target_handlers.append(file_handler) |
| 130 | + |
| 131 | + if config.console: |
| 132 | + console_handler = logging.StreamHandler() |
| 133 | + console_handler.setLevel(level) |
| 134 | + console_handler.setFormatter(formatter) |
| 135 | + target_handlers.append(console_handler) |
| 136 | + |
| 137 | + if not target_handlers: |
| 138 | + logger.setLevel(logging.NOTSET) |
| 139 | + logger.propagate = True |
| 140 | + |
| 141 | + def _noop_shutdown() -> None: |
| 142 | + return |
| 143 | + |
| 144 | + return logger, _noop_shutdown |
| 145 | + |
| 146 | + queue_obj: SimpleQueue[Any] = SimpleQueue() |
| 147 | + queue_handler = QueueHandler(queue_obj) |
| 148 | + queue_handler.setLevel(level) |
| 149 | + logger.addHandler(queue_handler) |
| 150 | + logger.setLevel(level) |
| 151 | + logger.propagate = False |
| 152 | + |
| 153 | + listener = QueueListener(queue_obj, *target_handlers, respect_handler_level=True) |
| 154 | + listener.start() |
| 155 | + |
| 156 | + def _shutdown() -> None: |
| 157 | + try: |
| 158 | + listener.stop() |
| 159 | + except Exception: |
| 160 | + pass |
| 161 | + for handler in target_handlers: |
| 162 | + try: |
| 163 | + handler.flush() |
| 164 | + except Exception: |
| 165 | + pass |
| 166 | + try: |
| 167 | + handler.close() |
| 168 | + except Exception: |
| 169 | + pass |
| 170 | + for handler in list(logger.handlers): |
| 171 | + logger.removeHandler(handler) |
| 172 | + logger.setLevel(logging.NOTSET) |
| 173 | + logger.propagate = True |
| 174 | + |
| 175 | + atexit.register(_shutdown) |
| 176 | + return logger, _shutdown |
| 177 | + |
| 178 | + |
| 179 | +def log_event( |
| 180 | + logger: logging.Logger, |
| 181 | + level: int | str, |
| 182 | + event: str, |
| 183 | + **fields: Any, |
| 184 | +) -> None: |
| 185 | + """Emit one structured runtime event.""" |
| 186 | + level_no = parse_log_level(level) if isinstance(level, str) else level |
| 187 | + if not logger.isEnabledFor(level_no): |
| 188 | + return |
| 189 | + |
| 190 | + logger.log( |
| 191 | + level_no, |
| 192 | + event, |
| 193 | + extra={"event_name": event, "event_fields": fields}, |
| 194 | + ) |
0 commit comments