fix(logging): use ConcurrentRotatingFileHandler to fix Windows rollover PermissionError (#44873)

hermes_logging.py

@@ -11,8 +11,10 @@
     gui.log     — INFO+, dashboard/websocket/TUI-gateway events
                   (created when mode="gui")
 
-All files use ``RotatingFileHandler`` with ``RedactingFormatter`` so
-secrets are never written to disk.
+All files use a size-based rotating file handler (``ConcurrentRotatingFileHandler``
+from ``concurrent-log-handler`` when available, falling back to stdlib
+``RotatingFileHandler``) with ``RedactingFormatter`` so secrets are never
+written to disk.  The handler choice matters on Windows: see issue #44873.
 
 Component separation:
     gateway.log only receives records from ``gateway.*`` loggers —
@@ -36,6 +38,21 @@
 from pathlib import Path
 from typing import Optional, Sequence
 
+try:
+    from concurrent_log_handler import ConcurrentRotatingFileHandler
+
+    # On Windows, stdlib ``RotatingFileHandler.doRollover()`` uses
+    # ``os.rename()`` which requires exclusive access to the source file and
+    # fails with ``PermissionError [WinError 32]`` whenever another thread
+    # in the same process holds an append-mode handle — which is essentially
+    # always in Hermes (gateway, agent loop, TTS, subagent RPC all log
+    # concurrently). ``ConcurrentRotatingFileHandler`` swaps the rename for
+    # copy-then-truncate on Windows (works while the source is open) and
+    # keeps the atomic rename on POSIX. See issue #44873.
+    _ROTATING_BASE: type = ConcurrentRotatingFileHandler
+except ImportError:  # pragma: no cover - dep is in pyproject.toml
+    _ROTATING_BASE = RotatingFileHandler
+
 from hermes_constants import get_config_path, get_hermes_home
 
 # Sentinel to track whether setup_logging() has already run.  The function
@@ -355,7 +372,7 @@ def setup_verbose_logging() -> None:
 # Internal helpers
 # ---------------------------------------------------------------------------
 
-class _ManagedRotatingFileHandler(RotatingFileHandler):
+class _ManagedRotatingFileHandler(_ROTATING_BASE):
     """RotatingFileHandler that ensures group-writable perms in managed mode
     AND survives external rotation.
 
@@ -467,7 +484,17 @@ def _open(self):
         return stream
 
     def doRollover(self):
-        super().doRollover()
+        try:
+            super().doRollover()
+        except PermissionError:
+            # Windows: another thread still holds the source file. The next
+            # rollover check (on the next emit) will retry; the file just
+            # gets briefly over the size limit. Stdlib's Handler.handleError
+            # would print a full traceback on every emit if we let this
+            # propagate, which is the noisy symptom fixed by issue #44873.
+            # Swallow silently — the first failure already surfaces a
+            # warning via stdlib's own handler before we catch it.
+            return
         self._chmod_if_managed()
         # Our own rollover writes a new baseFilename; refresh the snapshot
         # so the next emit doesn't mistake it for external rotation.
@@ -496,7 +523,7 @@ def _add_rotating_handler(
     resolved = path.resolve()
     for existing in logger.handlers:
         if (
-            isinstance(existing, RotatingFileHandler)
+            isinstance(existing, _ROTATING_BASE)
             and Path(getattr(existing, "baseFilename", "")).resolve() == resolved
         ):
             return  # already attached

pyproject.toml

@@ -112,6 +112,23 @@ dependencies = [
   # install rather than gating it behind an extra + a mid-session lazy install
   # (which deadlocked the CLI under prompt_toolkit — see #40490).
   "Pillow==12.2.0",
+  # Log rotation on Windows. The stdlib ``RotatingFileHandler.doRollover()``
+  # calls ``os.rename()`` to atomically swap ``agent.log`` → ``agent.log.1``;
+  # on Windows this requires exclusive access to the source and fails with
+  # ``PermissionError [WinError 32]`` whenever any other thread in the same
+  # process still holds an append-mode handle (which is essentially always
+  # in Hermes — gateway, agent loop, TTS, subagent RPC all log concurrently).
+  # The result is that ``agent.log`` pins at the 5 MiB threshold and stderr
+  # is flooded with a full traceback on every subsequent emit (see #44873).
+  # ``concurrent-log-handler`` swaps the rename for copy-then-truncate on
+  # Windows (which works while the source is open) and keeps the atomic
+  # rename on POSIX. Apache-2.0, 110M+ PyPI downloads, ~10 years old, used
+  # by Django and AWS CLI for the same reason. Pure-Python on top of
+  # ``portalocker`` (also pure-Python, no compiled extensions), so it's
+  # safe to ship in the base install — every Windows user hits this once
+  # ``agent.log`` reaches 5 MiB, and gating it behind an extra would mean
+  # the bug survives the very first session.
+  "concurrent-log-handler==0.9.29",
 ]
 
 [project.optional-dependencies]

tests/test_hermes_logging.py

@@ -33,7 +33,7 @@ def _reset_logging_state():
     # pollute our counts.
     pre_existing = []
     for h in list(root.handlers):
-        if isinstance(h, RotatingFileHandler):
+        if isinstance(h, hermes_logging._ROTATING_BASE):
             root.removeHandler(h)
             h.close()
         else:
@@ -76,7 +76,7 @@ def test_creates_agent_log_handler(self, hermes_home):
 
         agent_handlers = [
             h for h in root.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
             and "agent.log" in getattr(h, "baseFilename", "")
         ]
         assert len(agent_handlers) == 1
@@ -88,7 +88,7 @@ def test_creates_errors_log_handler(self, hermes_home):
 
         error_handlers = [
             h for h in root.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
             and "errors.log" in getattr(h, "baseFilename", "")
         ]
         assert len(error_handlers) == 1
@@ -101,7 +101,7 @@ def test_idempotent_no_duplicate_handlers(self, hermes_home):
         root = logging.getLogger()
         agent_handlers = [
             h for h in root.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
             and "agent.log" in getattr(h, "baseFilename", "")
         ]
         assert len(agent_handlers) == 1
@@ -115,7 +115,7 @@ def test_force_reinitializes(self, hermes_home):
         root = logging.getLogger()
         agent_handlers = [
             h for h in root.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
             and "agent.log" in getattr(h, "baseFilename", "")
         ]
         assert len(agent_handlers) == 1
@@ -126,7 +126,7 @@ def test_custom_log_level(self, hermes_home):
         root = logging.getLogger()
         agent_handlers = [
             h for h in root.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
             and "agent.log" in getattr(h, "baseFilename", "")
         ]
         assert agent_handlers[0].level == logging.DEBUG
@@ -139,7 +139,7 @@ def test_custom_max_size_and_backup(self, hermes_home):
         root = logging.getLogger()
         agent_handlers = [
             h for h in root.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
             and "agent.log" in getattr(h, "baseFilename", "")
         ]
         assert agent_handlers[0].maxBytes == 10 * 1024 * 1024
@@ -205,7 +205,7 @@ def test_reads_config_yaml(self, hermes_home):
         root = logging.getLogger()
         agent_handlers = [
             h for h in root.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
             and "agent.log" in getattr(h, "baseFilename", "")
         ]
         assert agent_handlers[0].level == logging.DEBUG
@@ -223,7 +223,7 @@ def test_explicit_params_override_config(self, hermes_home):
         root = logging.getLogger()
         agent_handlers = [
             h for h in root.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
             and "agent.log" in getattr(h, "baseFilename", "")
         ]
         assert agent_handlers[0].level == logging.WARNING
@@ -249,7 +249,7 @@ def test_gateway_log_created(self, hermes_home):
 
         gw_handlers = [
             h for h in root.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
             and "gateway.log" in getattr(h, "baseFilename", "")
         ]
         assert len(gw_handlers) == 1
@@ -260,7 +260,7 @@ def test_gateway_log_not_created_in_cli_mode(self, hermes_home):
 
         gw_handlers = [
             h for h in root.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
             and "gateway.log" in getattr(h, "baseFilename", "")
         ]
         assert len(gw_handlers) == 0
@@ -273,7 +273,7 @@ def test_gateway_log_created_after_cli_init(self, hermes_home):
         root = logging.getLogger()
         gw_handlers = [
             h for h in root.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
             and "gateway.log" in getattr(h, "baseFilename", "")
         ]
         assert len(gw_handlers) == 1
@@ -296,7 +296,7 @@ def test_gateway_log_created_after_cli_init_without_duplicate_handlers(self, her
         root = logging.getLogger()
         gw_handlers = [
             h for h in root.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
             and "gateway.log" in getattr(h, "baseFilename", "")
         ]
         assert len(gw_handlers) == 1
@@ -368,7 +368,7 @@ def test_gui_log_created(self, hermes_home):
 
         gui_handlers = [
             h for h in root.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
             and "gui.log" in getattr(h, "baseFilename", "")
         ]
         assert len(gui_handlers) == 1
@@ -380,7 +380,7 @@ def test_gui_log_created_after_cli_init(self, hermes_home):
         root = logging.getLogger()
         gui_handlers = [
             h for h in root.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
             and "gui.log" in getattr(h, "baseFilename", "")
         ]
         assert len(gui_handlers) == 1
@@ -625,7 +625,7 @@ def test_adds_stream_handler(self, hermes_home):
         verbose_handlers = [
             h for h in root.handlers
             if isinstance(h, logging.StreamHandler)
-            and not isinstance(h, RotatingFileHandler)
+            and not isinstance(h, hermes_logging._ROTATING_BASE)
             and getattr(h, "_hermes_verbose", False)
         ]
         assert len(verbose_handlers) == 1
@@ -640,7 +640,7 @@ def test_idempotent(self, hermes_home):
         verbose_handlers = [
             h for h in root.handlers
             if isinstance(h, logging.StreamHandler)
-            and not isinstance(h, RotatingFileHandler)
+            and not isinstance(h, hermes_logging._ROTATING_BASE)
             and getattr(h, "_hermes_verbose", False)
         ]
         assert len(verbose_handlers) == 1
@@ -663,7 +663,7 @@ def test_creates_directory(self, tmp_path):
         assert log_path.parent.is_dir()
         # Clean up
         for h in list(logger.handlers):
-            if isinstance(h, RotatingFileHandler):
+            if isinstance(h, hermes_logging._ROTATING_BASE):
                 logger.removeHandler(h)
                 h.close()
 
@@ -685,12 +685,12 @@ def test_no_duplicate_for_same_path(self, tmp_path):
 
         rotating_handlers = [
             h for h in logger.handlers
-            if isinstance(h, RotatingFileHandler)
+            if isinstance(h, hermes_logging._ROTATING_BASE)
         ]
         assert len(rotating_handlers) == 1
         # Clean up
         for h in list(logger.handlers):
-            if isinstance(h, RotatingFileHandler):
+            if isinstance(h, hermes_logging._ROTATING_BASE):
                 logger.removeHandler(h)
                 h.close()
 
@@ -708,12 +708,12 @@ def test_log_filter_attached(self, tmp_path):
             log_filter=component_filter,
         )
 
-        handlers = [h for h in logger.handlers if isinstance(h, RotatingFileHandler)]
+        handlers = [h for h in logger.handlers if isinstance(h, hermes_logging._ROTATING_BASE)]
         assert len(handlers) == 1
         assert component_filter in handlers[0].filters
         # Clean up
         for h in list(logger.handlers):
-            if isinstance(h, RotatingFileHandler):
+            if isinstance(h, hermes_logging._ROTATING_BASE):
                 logger.removeHandler(h)
                 h.close()
 
@@ -729,7 +729,7 @@ def test_no_session_filter_on_handler(self, tmp_path):
             formatter=formatter,
         )
 
-        handlers = [h for h in logger.handlers if isinstance(h, RotatingFileHandler)]
+        handlers = [h for h in logger.handlers if isinstance(h, hermes_logging._ROTATING_BASE)]
         assert len(handlers) == 1
         # No _SessionFilter on the handler — record factory handles it
         assert len(handlers[0].filters) == 0
@@ -743,7 +743,7 @@ def test_no_session_filter_on_handler(self, tmp_path):
 
         # Clean up
         for h in list(logger.handlers):
-            if isinstance(h, RotatingFileHandler):
+            if isinstance(h, hermes_logging._ROTATING_BASE):
                 logger.removeHandler(h)
                 h.close()
 
@@ -767,7 +767,7 @@ def test_managed_mode_initial_open_sets_group_writable(self, tmp_path):
         assert stat.S_IMODE(log_path.stat().st_mode) == 0o660
 
         for h in list(logger.handlers):
-            if isinstance(h, RotatingFileHandler):
+            if isinstance(h, hermes_logging._ROTATING_BASE):
                 logger.removeHandler(h)
                 h.close()
 
@@ -785,7 +785,7 @@ def test_managed_mode_rollover_sets_group_writable(self, tmp_path):
                     formatter=formatter,
                 )
                 handler = next(
-                    h for h in logger.handlers if isinstance(h, RotatingFileHandler)
+                    h for h in logger.handlers if isinstance(h, hermes_logging._ROTATING_BASE)
                 )
                 logger.info("a" * 256)
                 handler.flush()
@@ -796,7 +796,7 @@ def test_managed_mode_rollover_sets_group_writable(self, tmp_path):
         assert stat.S_IMODE(log_path.stat().st_mode) == 0o660
 
         for h in list(logger.handlers):
-            if isinstance(h, RotatingFileHandler):
+            if isinstance(h, hermes_logging._ROTATING_BASE):
                 logger.removeHandler(h)
                 h.close()