From c7a942e8334ac534c82bc533e646e1e43911fbaa Mon Sep 17 00:00:00 2001 From: John Paul Soliva Date: Tue, 15 Sep 2026 07:33:56 +0900 Subject: [PATCH] fix(logging): a second Hermes home in one process gets a routed log, not an unfiltered handler MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit setup_logging(hermes_home=X) for a home other than the one this process already logs for added another queued file handler with no home filter. In a dashboard or serve backend that builds agents for several profiles, every profile's records were therefore written into every served profile's agent.log and errors.log — the same lines, byte for byte — and with profile routing already on (multiplexed gateway, Desktop cron ticker) a duplicate writer for the secondary home sat on top of the router. Adopt the new home into profile routing instead: enable it for the union of homes when no router exists yet, widen the live routers otherwise, and let _add_rotating_handler recognise a router that already covers a home. --- hermes_logging.py | 45 +++++++++++++++++++++++++++++- tests/test_hermes_logging.py | 54 ++++++++++++++++++++++++++++++++++++ 2 files changed, 98 insertions(+), 1 deletion(-) diff --git a/hermes_logging.py b/hermes_logging.py index d870851151..4de9619a97 100644 --- a/hermes_logging.py +++ b/hermes_logging.py @@ -169,6 +169,37 @@ COMPONENT_PREFIXES = { } +def _known_log_homes() -> set[Path]: + """Homes the queued file handlers already serve: static handlers by their file, routers by + their default home plus every profile home they route. Caller holds ``_queue_state_lock``.""" + homes: set[Path] = set() + for handler in _queued_file_handlers: + if isinstance(handler, _ProfileRoutingFileHandler): + homes.add(handler._default_home) + homes.update(handler._profile_homes) + elif isinstance(handler, RotatingFileHandler): + try: + homes.add(Path(handler.baseFilename).resolve().parent.parent) + except (TypeError, ValueError, OSError): + continue + return homes + + +def _adopt_secondary_home(home: Path) -> bool: + """Route *home*'s records to its own files when this process already logs for another home. + Enables profile routing for the union of homes (or widens the live routers); False when + *home* is the first home seen or is already served.""" + try: + resolved = Path(home).expanduser().resolve() + except (TypeError, ValueError, OSError): + return False + with _queue_state_lock: + known = _known_log_homes() + if not known or resolved in known: + return False + return enable_profile_log_routing([*sorted(known), resolved]) + + def setup_logging( *, hermes_home: Optional[Path] = None, @@ -187,6 +218,13 @@ def setup_logging( global _logging_initialized home = hermes_home or get_hermes_home() log_dir = mkdir_under_hermes_home(home / "logs") + # A second Hermes home in a process that already logs for another one — a dashboard or + # ``hermes serve`` backend building agents for several profiles, a multiplexed gateway — + # gets routed by record home. Stacking another file handler here would hand it EVERY + # profile's records (the handlers carry no home filter), and a duplicate writer on top of + # an existing router. + if _adopt_secondary_home(home): + return log_dir cfg_level, cfg_max_size, cfg_backup = _read_logging_config() level_name = (log_level or cfg_level or "INFO").upper() level = getattr(logging, level_name, logging.INFO) @@ -615,12 +653,17 @@ def _add_rotating_handler( """Register a queued ``RotatingFileHandler`` for *path*; idempotent per resolved path.""" resolved = path.resolve() for existing in _queued_file_handlers: - # Already attached directly, or already covered by the profile router. + # Already attached directly, or already covered by the profile router — for its default + # home or any profile home it routes (a bare handler beside it would take every record). if getattr(existing, "_hermes_routed_log_path", None) == resolved or ( isinstance(existing, RotatingFileHandler) and Path(getattr(existing, "baseFilename", "")).resolve() == resolved ): return + if isinstance(existing, _ProfileRoutingFileHandler) and existing._filename == resolved.name and ( + resolved.parent.parent == existing._default_home or resolved.parent.parent in existing._profile_homes + ): + return handler = _new_file_handler( path, level=level, max_bytes=max_bytes, backup_count=backup_count, formatter=formatter, ) diff --git a/tests/test_hermes_logging.py b/tests/test_hermes_logging.py index 91cf4e4b8b..ca0813ca97 100644 --- a/tests/test_hermes_logging.py +++ b/tests/test_hermes_logging.py @@ -142,6 +142,60 @@ class TestSetupLogging: hermes_home / "logs" / "agent.log" ).read_text() + def test_a_second_home_routes_instead_of_stacking_an_unfiltered_handler(self, hermes_home, tmp_path): + """A dashboard or serve backend builds agents for several profiles in ONE process, and each + one calls setup_logging for its own home. The second home must get a router — a bare file + handler beside the first home's would receive every profile's records.""" + from logging.handlers import RotatingFileHandler + + from hermes_constants import reset_hermes_home_override, set_hermes_home_override + + profile_home = tmp_path / "profile-b" + profile_home.mkdir() + hermes_logging.setup_logging(hermes_home=hermes_home) + hermes_logging.setup_logging(hermes_home=profile_home) + + assert not [h for h in hermes_logging._queued_file_handlers if isinstance(h, RotatingFileHandler)], ( + "the second home must not add an unfiltered file handler") + + logger = logging.getLogger("agent.conversation_loop.second-home-test") + token = set_hermes_home_override(profile_home) + try: + logger.info("turn of profile b") + finally: + reset_hermes_home_override(token) + logger.info("turn of the launch profile") + hermes_logging.flush_log_queue() + + a_log = (hermes_home / "logs" / "agent.log").read_text() + b_log = (profile_home / "logs" / "agent.log").read_text() + assert "turn of profile b" in b_log and "turn of profile b" not in a_log + assert "turn of the launch profile" in a_log and "turn of the launch profile" not in b_log + + def test_setup_for_an_already_routed_home_adds_no_duplicate_writer(self, hermes_home, tmp_path): + """Routing already on (multiplexed gateway, Desktop cron ticker): a profile's agent starting + up must not add a second writer for its home on top of the router.""" + from logging.handlers import RotatingFileHandler + + from hermes_constants import reset_hermes_home_override, set_hermes_home_override + + profile_home = tmp_path / "profile-b" + profile_home.mkdir() + hermes_logging.setup_logging(hermes_home=hermes_home) + assert hermes_logging.enable_profile_log_routing([hermes_home, profile_home]) is True + hermes_logging.setup_logging(hermes_home=profile_home) + + assert not [h for h in hermes_logging._queued_file_handlers if isinstance(h, RotatingFileHandler)] + token = set_hermes_home_override(profile_home) + try: + logging.getLogger("agent.conversation_loop.routed-home-test").info("once please") + finally: + reset_hermes_home_override(token) + hermes_logging.flush_log_queue() + + assert (profile_home / "logs" / "agent.log").read_text().count("once please") == 1 + assert "once please" not in (hermes_home / "logs" / "agent.log").read_text() +