diff --git a/src/psd/__init__.py b/src/psd/__init__.py index 429e441..31efab3 100644 --- a/src/psd/__init__.py +++ b/src/psd/__init__.py @@ -8,6 +8,7 @@ from .config import PSDConfig from .feature_flags import FLAGS, FeatureFlags, disable, enable from .graph import GraphConfig, find_optimal_path +from .log_analyzer import LogStats, analyze_log, summarize_logs from .logging_utils import setup_logging setup_logging() @@ -35,5 +36,8 @@ "disable", "PSDTorch", "PSDTensorFlow", + "LogStats", + "analyze_log", + "summarize_logs", "__version__", ] diff --git a/src/psd/graph.py b/src/psd/graph.py index 1f607d5..a032804 100644 --- a/src/psd/graph.py +++ b/src/psd/graph.py @@ -227,7 +227,11 @@ def find_optimal_path( return path finally: duration = perf_counter() - start_time - logger.info("find_optimal_path executed in %.6f seconds", duration) + logger.info( + "find_optimal_path executed in %.6f seconds", + duration, + extra={"duration": duration}, + ) __all__ = ["find_optimal_path", "GraphConfig"] diff --git a/src/psd/log_analyzer.py b/src/psd/log_analyzer.py new file mode 100644 index 0000000..a5a7266 --- /dev/null +++ b/src/psd/log_analyzer.py @@ -0,0 +1,61 @@ +from __future__ import annotations + +import json +from dataclasses import dataclass +from pathlib import Path + + +@dataclass +class LogStats: + """Summary statistics for a log file.""" + + error_count: int + avg_latency: float + latency_count: int + + +def analyze_log(path: str | Path) -> LogStats: + """Summarise errors and latency metrics in a structured log file. + + Parameters + ---------- + path: + Path to a log file containing one JSON object per line. + """ + + p = Path(path) + errors = 0 + latencies: list[float] = [] + if not p.is_file(): + return LogStats(0, 0.0, 0) + with p.open() as fh: + for line in fh: + try: + record = json.loads(line) + except json.JSONDecodeError: + continue + if record.get("level") == "ERROR": + errors += 1 + if "duration" in record: + try: + latencies.append(float(record["duration"])) + except (TypeError, ValueError): + continue + avg = sum(latencies) / len(latencies) if latencies else 0.0 + return LogStats(errors, avg, len(latencies)) + + +def summarize_logs(directory: str | Path = "logs") -> dict[str, LogStats]: + """Summarise all log files in ``directory``. + + Returns a mapping of filename to :class:`LogStats`. + """ + + dir_path = Path(directory) + summaries: dict[str, LogStats] = {} + for file in dir_path.glob("*.log*"): + summaries[file.name] = analyze_log(file) + return summaries + + +__all__ = ["LogStats", "analyze_log", "summarize_logs"] diff --git a/src/psd/logging_utils.py b/src/psd/logging_utils.py index 6f4a85c..2038bdd 100644 --- a/src/psd/logging_utils.py +++ b/src/psd/logging_utils.py @@ -3,6 +3,7 @@ import json import logging import logging.config +from logging.handlers import RotatingFileHandler from pathlib import Path @@ -16,16 +17,70 @@ def format(self, record: logging.LogRecord) -> str: # pragma: no cover - trivia "name": record.name, "message": record.getMessage(), } + # Include extra attributes added via the ``extra`` argument + reserved = { + "name", + "msg", + "args", + "levelname", + "levelno", + "pathname", + "filename", + "module", + "exc_info", + "exc_text", + "stack_info", + "lineno", + "funcName", + "created", + "msecs", + "relativeCreated", + "thread", + "threadName", + "processName", + "process", + "message", + } + for key, value in record.__dict__.items(): + if key in reserved or key.startswith("_"): + continue + try: + json.dumps(value) + data[key] = value + except TypeError: # pragma: no cover - non-serialisable extras + data[key] = str(value) if record.exc_info: data["exc_info"] = self.formatException(record.exc_info) return json.dumps(data) def setup_logging(config_path: str | Path | None = None) -> None: - """Load logging configuration from ``logging.ini`` if present.""" + """Initialise structured logging with optional configuration file. + + If ``config_path`` (or ``logging.ini``) is present, it will be loaded via + :func:`logging.config.fileConfig`. Otherwise a sensible default + configuration with a rotating JSON log file and console output is + installed. + """ path = Path(config_path or "logging.ini") - if not path.is_file(): + if path.is_file(): + Path("logs").mkdir(exist_ok=True) + logging.config.fileConfig(path, disable_existing_loggers=False) + return + + root = logging.getLogger() + if root.handlers: # pragma: no cover - defensive programming return + root.setLevel(logging.INFO) Path("logs").mkdir(exist_ok=True) - logging.config.fileConfig(path, disable_existing_loggers=False) + + formatter = JsonFormatter() + + file_handler = RotatingFileHandler("logs/psd.log", maxBytes=1_048_576, backupCount=3) + file_handler.setFormatter(formatter) + root.addHandler(file_handler) + + console = logging.StreamHandler() + console.setFormatter(formatter) + root.addHandler(console) diff --git a/tests/test_log_analyzer.py b/tests/test_log_analyzer.py new file mode 100644 index 0000000..4cff292 --- /dev/null +++ b/tests/test_log_analyzer.py @@ -0,0 +1,22 @@ +from __future__ import annotations + +import json +from pathlib import Path + +import pytest + +from psd.log_analyzer import analyze_log + + +def test_analyze_log(tmp_path: Path) -> None: + log_file = tmp_path / "psd.log" + records = [ + {"time": "0", "level": "INFO", "name": "t", "message": "ok", "duration": 0.1}, + {"time": "1", "level": "ERROR", "name": "t", "message": "fail"}, + {"time": "2", "level": "INFO", "name": "t", "message": "ok", "duration": 0.3}, + ] + log_file.write_text("\n".join(json.dumps(r) for r in records)) + stats = analyze_log(log_file) + assert stats.error_count == 1 + assert stats.latency_count == 2 + assert stats.avg_latency == pytest.approx(0.2)