log: add RotatingFileHandler so DEBUG output survives Rich's console takeover

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.
This commit is contained in:
2026-05-05 14:32:27 -04:00
parent 7932c72660
commit 541b59b4e3

View File

@@ -17,8 +17,10 @@ Level conventions (Ouranos Lab — Python services use UPPERCASE):
import json import json
import logging import logging
import logging.handlers
import os import os
import re import re
import sys
from datetime import datetime, timezone from datetime import datetime, timezone
from pathlib import Path from pathlib import Path
@@ -92,6 +94,28 @@ def _level_from_fastagent_config() -> str | None:
return str(level) if level else 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: def setup_logging() -> None:
"""Configure Pallas logging. """Configure Pallas logging.
@@ -107,11 +131,22 @@ def setup_logging() -> None:
``pallas.auth`` loggers — essential when troubleshooting Mnemosyne / ``pallas.auth`` loggers — essential when troubleshooting Mnemosyne /
workspace-scoped agent calls. 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) - ``httpx`` / ``httpcore``: WARNING (prevent request-level debug flooding)
- ``uvicorn.access``: health path filter applied - ``uvicorn.access``: health path filter applied
""" """
handler = logging.StreamHandler() formatter = _JSONFormatter()
handler.setFormatter(_JSONFormatter())
level_name = ( level_name = (
os.environ.get("PALLAS_LOG_LEVEL") os.environ.get("PALLAS_LOG_LEVEL")
@@ -122,10 +157,40 @@ def setup_logging() -> None:
pallas_logger = logging.getLogger("pallas") pallas_logger = logging.getLogger("pallas")
pallas_logger.setLevel(level) pallas_logger.setLevel(level)
if not pallas_logger.handlers:
pallas_logger.addHandler(handler)
pallas_logger.propagate = False 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. # Silence noisy HTTP client internals — only surface warnings and above.
for noisy in ("httpx", "httpcore"): for noisy in ("httpx", "httpcore"):
logging.getLogger(noisy).setLevel(logging.WARNING) logging.getLogger(noisy).setLevel(logging.WARNING)