backend/logger.py

"""Per-job file logger. Writes structured logs to data/logs/<secret_key>.log"""
from __future__ import annotations

import logging
import os
import sys
import traceback
from datetime import datetime, timezone
from pathlib import Path

# Use uvicorn's own logger so output is guaranteed to reach the terminal
_term = logging.getLogger("uvicorn")

from backend.config import settings


def _logs_dir() -> Path:
    base = Path(__file__).parent.parent
    p = base / settings.logs_dir
    p.mkdir(parents=True, exist_ok=True)
    return p


class JobLogger:
    """
    Writes timestamped log lines to both:
      - data/logs/<secret_key>.log  (persistent, one file per job)
      - stdout (so uvicorn terminal shows progress in real time)

    Usage:
        log = JobLogger(secret_key)
        log.info("Step 1 — PDF → Markdown")
        log.success("Review complete", overall_assessment=3.5)
        log.error("LLM call failed", exc=e)
    """

    def __init__(self, secret_key: str):
        self._key = secret_key
        self._short = secret_key[-8:]
        self._path = _logs_dir() / f"{secret_key}.log"

    # ── Public API ─────────────────────────────────────────────────────────────

    def info(self, msg: str, **kv):
        self._write("INFO ", msg, kv)

    def success(self, msg: str, **kv):
        self._write("OK   ", msg, kv)

    def warning(self, msg: str, **kv):
        self._write("WARN ", msg, kv)

    def error(self, msg: str, exc: BaseException | None = None, **kv):
        self._write("ERROR", msg, kv)
        if exc is not None:
            tb = traceback.format_exc()
            self._raw(tb)

    def separator(self, label: str = ""):
        line = f"{'─' * 60}"
        if label:
            line = f"{'─' * 4} {label} {'─' * max(0, 55 - len(label))}"
        self._raw(line)
        self._raw_term(line)

    def llm_prompt(self, step: str, prompt: str):
        """Log the full LLM prompt for a pipeline step (for quality review)."""
        self.separator(f"PROMPT — {step}")
        self._raw(prompt.strip())
        self.separator()

    def llm_response(self, step: str, response: str):
        """Log the full LLM response for a pipeline step."""
        self.separator(f"RESPONSE — {step}")
        self._raw(response.strip())
        self.separator()

    # ── Internal ───────────────────────────────────────────────────────────────

    def _write(self, level: str, msg: str, kv: dict):
        ts = datetime.now(timezone.utc).strftime("%H:%M:%S")
        kv_str = "  " + "  ".join(f"{k}={v!r}" for k, v in kv.items()) if kv else ""
        line = f"[{ts}] {level} {msg}{kv_str}"
        self._raw(line)
        # Route through uvicorn's logger so output is guaranteed to reach
        # the terminal regardless of subprocess/buffering on Windows.
        line = f"[{self._short}] {level.strip()} {msg}{kv_str}"
        try:
            _term.info(line)
        except Exception:
            pass

    def _raw(self, text: str):
        with self._path.open("a", encoding="utf-8") as f:
            f.write(text + "\n")

    def _raw_term(self, text: str):
        try:
            _term.info(text)
        except Exception:
            pass