diff --git a/gateway/run.py b/gateway/run.py index a3485ccb59..f28a40eb61 100644 --- a/gateway/run.py +++ b/gateway/run.py @@ -29412,6 +29412,13 @@ def _shutdown_gateway_health_export(runner: Any) -> None: logger.debug("gateway health OTLP export shutdown failed", exc_info=True) +def _gateway_stderr_formatter() -> logging.Formatter: + """Return the redacting formatter used by the gateway stderr stream.""" + from agent.redact import RedactingFormatter + + return RedactingFormatter("%(asctime)s %(levelname)s %(name)s: %(message)s") + + async def start_gateway(config: Optional[GatewayConfig] = None, replace: bool = False, verbosity: Optional[int] = 0) -> bool: """ Start the gateway and run until interrupted. @@ -29641,12 +29648,10 @@ async def start_gateway(config: Optional[GatewayConfig] = None, replace: bool = # verbosity=1 (-v): INFO and above # verbosity=2+ (-vv/-vvv): DEBUG if verbosity is not None: - from agent.redact import RedactingFormatter - _stderr_level = {0: logging.WARNING, 1: logging.INFO}.get(verbosity, logging.DEBUG) _stderr_handler = logging.StreamHandler(_safe_stderr()) _stderr_handler.setLevel(_stderr_level) - _stderr_handler.setFormatter(RedactingFormatter('%(levelname)s %(name)s: %(message)s')) + _stderr_handler.setFormatter(_gateway_stderr_formatter()) logging.getLogger().addHandler(_stderr_handler) # Lower root logger level if needed so DEBUG records can reach the handler if _stderr_level < logging.getLogger().level: diff --git a/hermes_cli/stderr_timestamp.py b/hermes_cli/stderr_timestamp.py index e16c152a39..83e8a20ac5 100644 --- a/hermes_cli/stderr_timestamp.py +++ b/hermes_cli/stderr_timestamp.py @@ -3,6 +3,7 @@ from __future__ import annotations import argparse +import re import signal import subprocess import sys @@ -11,13 +12,20 @@ from pathlib import Path from typing import BinaryIO, Sequence, TextIO +_TIMESTAMP_PREFIX = re.compile( + r"^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3}(?:\s|$)" +) + + def _timestamp() -> str: """Match logging.Formatter's default ``%(asctime)s`` timestamp shape.""" return datetime.now().strftime("%Y-%m-%d %H:%M:%S,%f")[:23] def _write_timestamped_line(log_file: TextIO, line: str) -> None: - log_file.write(f"{_timestamp()} {line.rstrip(chr(10))}\n") + rendered = line.rstrip("\r\n") + prefix = "" if _TIMESTAMP_PREFIX.match(rendered) else f"{_timestamp()} " + log_file.write(f"{prefix}{rendered}\n") log_file.flush() diff --git a/tests/gateway/test_stderr_formatting.py b/tests/gateway/test_stderr_formatting.py new file mode 100644 index 0000000000..1d6b27f53d --- /dev/null +++ b/tests/gateway/test_stderr_formatting.py @@ -0,0 +1,28 @@ +"""Regression tests for operator-visible gateway stderr formatting.""" + +from __future__ import annotations + +import logging +import re + +from gateway.run import _gateway_stderr_formatter + + +def test_gateway_stderr_formatter_includes_timestamp() -> None: + record = logging.LogRecord( + name="gateway.run", + level=logging.ERROR, + pathname=__file__, + lineno=1, + msg="delivery failed", + args=(), + exc_info=None, + ) + + rendered = _gateway_stderr_formatter().format(record) + + assert re.fullmatch( + r"\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} " + r"ERROR gateway\.run: delivery failed", + rendered, + ) diff --git a/tests/hermes_cli/test_stderr_timestamp.py b/tests/hermes_cli/test_stderr_timestamp.py index 10b4c59dc3..6bda125b8f 100644 --- a/tests/hermes_cli/test_stderr_timestamp.py +++ b/tests/hermes_cli/test_stderr_timestamp.py @@ -11,7 +11,8 @@ def test_main_timestamps_each_stderr_line(tmp_path): code = ( "import sys\n" "sys.stderr.write('first failure\\n')\n" - "sys.stderr.write('second failure without newline')\n" + "sys.stderr.write('second failure without newline\\n')\n" + "sys.stderr.write('2026-07-15 12:34:56,789 already timestamped')\n" "sys.exit(7)\n" ) @@ -29,6 +30,7 @@ def test_main_timestamps_each_stderr_line(tmp_path): assert rc == 7 lines = log_path.read_text(encoding="utf-8").splitlines() timestamp = r"\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3}" - assert len(lines) == 2 + assert len(lines) == 3 assert re.fullmatch(f"{timestamp} first failure", lines[0]) assert re.fullmatch(f"{timestamp} second failure without newline", lines[1]) + assert lines[2] == "2026-07-15 12:34:56,789 already timestamped"