log: decouple root level from Pallas level; dial noisy libs to WARNING

When Pallas runs with logger.level=debug (as Kottos does during the
bearer-forwarding shakedown), setting the root logger to DEBUG opens
the floodgates for every third-party library to emit DEBUG records.
openai._base_client, sse_starlette.sse, mcp, and anthropic each log
one line per HTTP request / SSE chunk / JSON-RPC frame; with fast-agent's
logger.type=console handler attached to root those lines splatter into
the Rich TUI and make the chat unusable.

Split the two knobs:
  * PALLAS_LOG_LEVEL (or fastagent.config logger.level) — drives the
    pallas.* loggers + file sink.  Unchanged.
  * Root logger level — defaults to the higher of (level, INFO) so
    third-party DEBUG never bleeds through by default.  PALLAS_ROOT_LOG_LEVEL
    overrides for operators who genuinely want everything at DEBUG.

Also extend the noisy-logger list so openai/anthropic/sse_starlette/mcp
are individually pinned at WARNING regardless of root — belt-and-braces
for the common case.
This commit is contained in:
2026-05-06 20:34:28 -04:00
parent dde7d4fa30
commit 89870f4bdc

View File

@@ -186,6 +186,8 @@ def setup_logging() -> None:
""" """
formatter = _JSONFormatter() formatter = _JSONFormatter()
# Pallas's own diagnostics level — drives the ``pallas.*`` loggers and
# the file sink verbosity. Unchanged behaviour for operators.
level_name = ( level_name = (
os.environ.get("PALLAS_LOG_LEVEL") os.environ.get("PALLAS_LOG_LEVEL")
or _level_from_fastagent_config() or _level_from_fastagent_config()
@@ -193,6 +195,22 @@ def setup_logging() -> None:
).upper() ).upper()
level = getattr(logging, level_name, logging.INFO) level = getattr(logging, level_name, logging.INFO)
# Root logger level is separate: in interactive ``fast-agent go``
# sessions, leaving the root logger at DEBUG lets every third-party
# library (``openai``, ``sse_starlette``, ``mcp``, ``anthropic``, …)
# spray plain-text DEBUG records straight into the terminal, which
# corrupts fast-agent's Rich TUI regardless of whether *our* stderr
# handler is attached — the libraries install their own handlers
# independently. Default the root to the higher of (level, INFO) so
# we never drag the whole process into DEBUG just because Pallas
# wants detailed forwarding traces. Operators who truly need every
# library at DEBUG can opt back in with ``PALLAS_ROOT_LOG_LEVEL=DEBUG``.
root_level_name = (
os.environ.get("PALLAS_ROOT_LOG_LEVEL")
or ("INFO" if level < logging.INFO else level_name)
).upper()
root_level = getattr(logging, root_level_name, logging.INFO)
# Build the shared handlers once — they get attached to both the # Build the shared handlers once — they get attached to both the
# ``pallas`` logger (with ``propagate=False``) *and* the root logger, # ``pallas`` logger (with ``propagate=False``) *and* the root logger,
# so third-party libraries' records land in the same file sink. # so third-party libraries' records land in the same file sink.
@@ -226,12 +244,14 @@ def setup_logging() -> None:
stream_handler.setFormatter(formatter) stream_handler.setFormatter(formatter)
handlers.append(stream_handler) handlers.append(stream_handler)
# Root logger carries everything from libraries we do NOT own. # Root logger carries everything from libraries we do NOT own. We
# We set the level low enough to accept our configured level; each # keep it at ``root_level`` (INFO by default) rather than ``level``,
# noisy namespace is dialled back below. Handlers are attached here, # so Pallas's own DEBUG diagnostics don't drag third-party libraries
# not on child loggers, so records propagate to a single sink. # with them. Noisy namespaces are dialled back further below.
# Handlers are attached here, not on child loggers, so records
# propagate to a single sink.
root = logging.getLogger() root = logging.getLogger()
root.setLevel(level) root.setLevel(root_level)
# Avoid duplicate handlers across re-entrant setup_logging() calls # Avoid duplicate handlers across re-entrant setup_logging() calls
# (e.g. if the agent subprocess re-imports pallas with an altered # (e.g. if the agent subprocess re-imports pallas with an altered
# config). We tag ours so a safe idempotent re-attach is possible. # config). We tag ours so a safe idempotent re-attach is possible.
@@ -262,9 +282,33 @@ def setup_logging() -> None:
# won't see it; at DEBUG it's easy to grep for. # won't see it; at DEBUG it's easy to grep for.
pallas_logger.info("log file: %s", log_file) pallas_logger.info("log file: %s", log_file)
# Silence noisy HTTP client internals — only surface warnings and above. # Silence noisy HTTP/LLM client internals — only surface warnings and
# Applied *after* root-level configuration so these win. # above. Applied *after* root-level configuration so these win.
for noisy in ("httpx", "httpcore"): #
# ``openai``, ``anthropic``: their ``_base_client`` emits a DEBUG line
# per request ("Sending HTTP Request: POST ...") that floods the TUI.
# ``sse_starlette``: logs every SSE chunk at DEBUG, one line per
# notifications/progress payload — i.e. every tool-call progress tick.
# ``mcp``: the MCP Python SDK debugs raw JSON-RPC traffic.
# ``httpx`` / ``httpcore``: request-level debug flood.
#
# If we're running at DEBUG intentionally for Pallas diagnostics, we
# still don't want these libraries spraying DEBUG output; operators
# can re-enable a specific one with ``logging.getLogger(...).setLevel``
# in their own environment.
for noisy in (
"httpx",
"httpcore",
"openai",
"openai._base_client",
"anthropic",
"anthropic._base_client",
"sse_starlette",
"sse_starlette.sse",
"mcp",
"mcp.client",
"mcp.server",
):
logging.getLogger(noisy).setLevel(logging.WARNING) logging.getLogger(noisy).setLevel(logging.WARNING)
# Suppress successful health probe access log entries. # Suppress successful health probe access log entries.