From 541b59b4e387dcc9e6a7b42a5394a9ec49929e7c Mon Sep 17 00:00:00 2001 From: Robert Helewka Date: Tue, 5 May 2026 14:32:27 -0400 Subject: [PATCH] log: add RotatingFileHandler so DEBUG output survives Rich's console takeover MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit fast-agent's progress_display installs a Rich Live renderer on stdout/stderr; plain StreamHandler records get swallowed mid-render, making the bearer- forwarding DEBUG logs invisible on the console. Route every pallas.* record to two sinks: 1. ~/.local/state/pallas/pallas.log (rotating, 10MiB x5) — durable capture regardless of who owns the TTY. Overridable via PALLAS_LOG_FILE. 2. sys.__stderr__ — the original stderr FD captured before Rich could grab it, so records still reach the TTY / journal when DEBUG is on. Avoids /tmp deliberately: systemd PrivateTmp=yes made /tmp/pallas-bearer.log invisible during the original debug saga. --- pallas/log.py | 73 ++++++++++++++++++++++++++++++++++++++++++++++++--- 1 file changed, 69 insertions(+), 4 deletions(-) diff --git a/pallas/log.py b/pallas/log.py index f3589e8..a52151d 100644 --- a/pallas/log.py +++ b/pallas/log.py @@ -17,8 +17,10 @@ Level conventions (Ouranos Lab — Python services use UPPERCASE): import json import logging +import logging.handlers import os import re +import sys from datetime import datetime, timezone from pathlib import Path @@ -92,6 +94,28 @@ def _level_from_fastagent_config() -> str | None: return str(level) if level else None +def _resolve_log_file() -> Path: + """Return the path Pallas will append JSON log records to. + + Order of precedence: + + 1. ``PALLAS_LOG_FILE`` — explicit override (absolute path recommended). + 2. ``$XDG_STATE_HOME/pallas/pallas.log`` if ``XDG_STATE_HOME`` is set. + 3. ``~/.local/state/pallas/pallas.log`` — XDG default. + + The parent directory is created lazily (``mkdir -p``) so a fresh host + doesn't need any prep work. We avoid ``/tmp`` because systemd's + ``PrivateTmp=yes`` makes it per-unit-invisible — learned the hard way + during the bearer-forwarding debug saga. + """ + override = os.environ.get("PALLAS_LOG_FILE") + if override: + return Path(override).expanduser() + xdg_state = os.environ.get("XDG_STATE_HOME") + base = Path(xdg_state) if xdg_state else Path.home() / ".local" / "state" + return base / "pallas" / "pallas.log" + + def setup_logging() -> None: """Configure Pallas logging. @@ -107,11 +131,22 @@ def setup_logging() -> None: ``pallas.auth`` loggers — essential when troubleshooting Mnemosyne / workspace-scoped agent calls. + Handlers attached: + + * ``RotatingFileHandler`` → ``PALLAS_LOG_FILE`` (or + ``~/.local/state/pallas/pallas.log``). Durable capture that survives + Rich's console takeover — fast-agent's ``progress_display`` hijacks + stdout and swallows plain ``print`` / stderr writes mid-render, so a + file sink is the only guaranteed way to see DEBUG diagnostics. + * ``StreamHandler`` → ``sys.__stderr__``. Uses the *original* stderr + file descriptor captured before Rich installed its Live display, so + records bypass the progress renderer and land in the terminal or + journal verbatim. Fine for production where Rich is off. + - ``httpx`` / ``httpcore``: WARNING (prevent request-level debug flooding) - ``uvicorn.access``: health path filter applied """ - handler = logging.StreamHandler() - handler.setFormatter(_JSONFormatter()) + formatter = _JSONFormatter() level_name = ( os.environ.get("PALLAS_LOG_LEVEL") @@ -122,10 +157,40 @@ def setup_logging() -> None: pallas_logger = logging.getLogger("pallas") pallas_logger.setLevel(level) - if not pallas_logger.handlers: - pallas_logger.addHandler(handler) pallas_logger.propagate = False + if not pallas_logger.handlers: + # File sink — always present so DEBUG output is never lost to a + # Rich-owned terminal. Rotate at 10 MiB, keep 5 archives (≈50 MiB + # max per agent) which easily spans a multi-day debugging session. + try: + log_file = _resolve_log_file() + log_file.parent.mkdir(parents=True, exist_ok=True) + file_handler = logging.handlers.RotatingFileHandler( + log_file, + maxBytes=10 * 1024 * 1024, + backupCount=5, + encoding="utf-8", + ) + file_handler.setFormatter(formatter) + pallas_logger.addHandler(file_handler) + # Announce the sink so operators can tail the right path without + # guessing — emitted at INFO so even a WARNING-only deployment + # won't see it; at DEBUG it's easy to grep for. + pallas_logger.info("log file: %s", log_file) + except Exception as exc: # pragma: no cover — never fatal + # Fall back silently; the stderr handler below still works. + logging.getLogger(__name__).warning( + "could not attach file log handler: %s", exc + ) + + # Stderr sink — writes to the *original* FD Rich captured at import + # time, so our records skip the progress display and hit the TTY + # (or systemd journal) directly. + stream_handler = logging.StreamHandler(stream=sys.__stderr__) + stream_handler.setFormatter(formatter) + pallas_logger.addHandler(stream_handler) + # Silence noisy HTTP client internals — only surface warnings and above. for noisy in ("httpx", "httpcore"): logging.getLogger(noisy).setLevel(logging.WARNING)