From 394cdf48ce2702de224dc95ae73f663076d043bd Mon Sep 17 00:00:00 2001 From: Austin Pickett Date: Wed, 17 Jun 2026 16:39:04 -0400 Subject: [PATCH] fix(logging): alias RotatingFileHandler to concurrent-log-handler (salvage #44921) (#46794) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * fix(logging): alias RotatingFileHandler to concurrent-log-handler On Windows, stdlib RotatingFileHandler.doRollover() uses os.rename(), which fails with PermissionError [WinError 32] whenever another process holds an append-mode handle on agent.log — essentially always in Hermes (TUI, gateway, hy_memory server, MCP servers, and on-demand CLI commands all log from separate processes). This pinned agent.log at the 5 MiB threshold and spammed stderr with a traceback on every emit (#44873). Add concurrent-log-handler==0.9.29 as a core dep and alias its ConcurrentRotatingFileHandler as RotatingFileHandler in hermes_logging.py. It wraps the rename in a cross-process file lock (via portalocker: pywin32 on Windows, fcntl on POSIX) so only one process rotates at a time. Aliasing keeps every existing isinstance/class-declaration reference working unchanged. Co-authored-by: tuancookiez-hub * fix(logging): gate concurrent-log-handler swap to Windows only The initial salvage aliased RotatingFileHandler -> ConcurrentRotatingFileHandler unconditionally, which regressed POSIX: CLH opens lazily and rotates via its own lock path, breaking managed-mode (NixOS) group-writable perms and eager file creation that _ManagedRotatingFileHandler depends on. CI caught it as 2 failures in test_managed_mode_*_group_writable on Linux. The WinError 32 bug (#44873) is Windows-specific — POSIX renames an open file fine, so stdlib already works on Linux/macOS. Gate the swap behind sys.platform == 'win32': Windows uses CLH, POSIX keeps stdlib RotatingFileHandler. - hermes_logging.py: platform-conditional import. - tests/test_hermes_logging.py: import RotatingFileHandler from hermes_logging (single source of truth) so the autouse fixture's isinstance checks match the real handler class on both platforms. - pyproject.toml/uv.lock: mark the dep 'sys_platform == "win32"' so portalocker /pywin32 only ship where used. --------- Co-authored-by: tuancookiez-hub Co-authored-by: Teknium <127238744+teknium1@users.noreply.github.com> --- hermes_logging.py | 31 ++++++++++++++++++++++++++++++- pyproject.toml | 14 ++++++++++++++ tests/test_hermes_logging.py | 10 ++++++++-- uv.lock | 26 ++++++++++++++++++++++++++ 4 files changed, 78 insertions(+), 3 deletions(-) diff --git a/hermes_logging.py b/hermes_logging.py index eee46af37f9..18f49a8b862 100644 --- a/hermes_logging.py +++ b/hermes_logging.py @@ -32,10 +32,39 @@ import logging import os import sys import threading -from logging.handlers import RotatingFileHandler from pathlib import Path from typing import Optional, Sequence +# On Windows, stdlib ``RotatingFileHandler`` calls ``os.rename()`` in +# ``doRollover()`` and fails with ``PermissionError [WinError 32]`` whenever +# another process holds an append-mode handle on ``agent.log`` — which is +# essentially always in Hermes (TUI, gateway, ``hy_memory`` server, MCP +# servers, and on-demand CLI commands all log from separate processes), +# pinning ``agent.log`` at the 5 MiB threshold and spamming stderr with +# a traceback on every emit. ``concurrent-log-handler`` wraps the rename in a +# cross-process file lock (via ``portalocker``: pywin32 on Windows) so only +# one process rotates at a time and the others wait their turn. +# +# This swap is Windows-ONLY and deliberately so: +# * The bug (WinError 32 on rename-while-open) is specific to Windows file +# locking semantics — POSIX renames an open file fine, so stdlib already +# works correctly on Linux/macOS. +# * On POSIX, managed-mode (NixOS) relies on the exact ``_open()`` / +# ``doRollover()`` lifecycle of stdlib ``RotatingFileHandler`` (the +# ``_ManagedRotatingFileHandler`` subclass chmods 0660 after each). CLH +# opens lazily and rotates differently, which breaks the group-writable +# guarantee and the eager file-creation those paths depend on. +# Aliasing keeps every existing ``RotatingFileHandler`` reference in this +# module (class declaration, ``isinstance`` checks, docstring) working +# unchanged. See #44873. +if sys.platform == "win32": + from concurrent_log_handler import ( # noqa: E402 + ConcurrentRotatingFileHandler as RotatingFileHandler, + ) +else: + from logging.handlers import RotatingFileHandler # noqa: E402 + + from hermes_constants import get_config_path, get_hermes_home # Sentinel to track whether setup_logging() has already run. The function diff --git a/pyproject.toml b/pyproject.toml index 4a2ab1c6b7b..9267f61b24b 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -116,6 +116,20 @@ 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", + # Windows log rotation. Stdlib ``RotatingFileHandler.doRollover()`` uses + # ``os.rename()`` which fails with ``PermissionError [WinError 32]`` on + # Windows whenever any other process holds an append-mode handle on + # ``agent.log`` (always the case in Hermes — TUI, gateway, ``hy_memory`` + # server, MCP servers, and on-demand CLI commands all log from separate + # processes), pinning ``agent.log`` at the 5 MiB threshold and spamming + # stderr on every emit (see #44873). ``concurrent-log-handler`` wraps the + # rename in a cross-process file lock (via ``portalocker``: pywin32 on + # Windows) so only one process rotates at a time. ``hermes_logging.py`` + # aliases it ONLY on Windows — POSIX renames an open file fine, so stdlib + # already works there and managed-mode perms depend on its exact lifecycle. + # Hence the ``sys_platform == 'win32'`` marker: the dep (and its portalocker + # / pywin32 tree) ships only where it's actually used. + "concurrent-log-handler==0.9.29; sys_platform == 'win32'", ] [project.optional-dependencies] diff --git a/tests/test_hermes_logging.py b/tests/test_hermes_logging.py index 38672da54f5..0d1a17ab267 100644 --- a/tests/test_hermes_logging.py +++ b/tests/test_hermes_logging.py @@ -1,17 +1,23 @@ """Tests for hermes_logging — centralized logging setup.""" - +import io import logging import os import stat import sys import threading -from logging.handlers import RotatingFileHandler from pathlib import Path from unittest.mock import patch import pytest import hermes_logging +# Use whatever RotatingFileHandler class hermes_logging actually resolved so +# the autouse fixture's isinstance checks (which strip rotating handlers +# between tests) match the real handlers on every platform. hermes_logging +# aliases concurrent-log-handler's ConcurrentRotatingFileHandler on Windows +# (the #44873 fix) but keeps stdlib RotatingFileHandler on POSIX, so importing +# the name from the module under test keeps the two in lockstep. +from hermes_logging import RotatingFileHandler @pytest.fixture(autouse=True) diff --git a/uv.lock b/uv.lock index 385cffe0dd5..ac264e1b222 100644 --- a/uv.lock +++ b/uv.lock @@ -675,6 +675,18 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/d1/d6/3965ed04c63042e047cb6a3e6ed1a63a35087b6a609aa3a15ed8ac56c221/colorama-0.4.6-py2.py3-none-any.whl", hash = "sha256:4f1d9991f5acc0ca119f9d443620b77f9d6b33703e51011c16baf57afb285fc6", size = 25335, upload-time = "2022-10-25T02:36:20.889Z" }, ] +[[package]] +name = "concurrent-log-handler" +version = "0.9.29" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "portalocker" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/9c/2c/ba185acc438cff6b58cd8f8dec27e7f4fcabf6968a1facbb6d0cacbde7fe/concurrent_log_handler-0.9.29.tar.gz", hash = "sha256:bc37a76d3f384cbf4a98f693ebd770543edc0f4cd5c6ab6bc70e9e1d7d582265", size = 42114, upload-time = "2026-02-22T18:18:25.758Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/4a/f3/3e3188fdb3e53c6343fd1c7de41c55d4db626f07db3877eae77b28d58bd2/concurrent_log_handler-0.9.29-py3-none-any.whl", hash = "sha256:0d6c077fbaef2dae49a25975dcf72a602fe0a6a4ce80a3b7c37696d37e10459a", size = 32052, upload-time = "2026-02-22T18:18:24.558Z" }, +] + [[package]] name = "croniter" version = "6.0.0" @@ -1416,6 +1428,7 @@ version = "0.16.0" source = { editable = "." } dependencies = [ { name = "certifi" }, + { name = "concurrent-log-handler", marker = "sys_platform == 'win32'" }, { name = "croniter" }, { name = "fastapi" }, { name = "fire" }, @@ -1627,6 +1640,7 @@ requires-dist = [ { name = "boto3", marker = "extra == 'bedrock'", specifier = "==1.42.89" }, { name = "brotlicffi", marker = "extra == 'messaging'", specifier = "==1.2.0.1" }, { name = "certifi", specifier = "==2026.5.20" }, + { name = "concurrent-log-handler", marker = "sys_platform == 'win32'", specifier = "==0.9.29" }, { name = "croniter", specifier = "==6.0.0" }, { name = "daytona", marker = "extra == 'daytona'", specifier = "==0.155.0" }, { name = "debugpy", marker = "extra == 'dev'", specifier = "==1.8.20" }, @@ -2872,6 +2886,18 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/54/20/4d324d65cc6d9205fabedc306948156824eb9f0ee1633355a8f7ec5c66bf/pluggy-1.6.0-py3-none-any.whl", hash = "sha256:e920276dd6813095e9377c0bc5566d94c932c33b27a3e3945d8389c374dd4746", size = 20538, upload-time = "2025-05-15T12:30:06.134Z" }, ] +[[package]] +name = "portalocker" +version = "3.2.0" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "pywin32", marker = "sys_platform == 'win32'" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/5e/77/65b857a69ed876e1951e88aaba60f5ce6120c33703f7cb61a3c894b8c1b6/portalocker-3.2.0.tar.gz", hash = "sha256:1f3002956a54a8c3730586c5c77bf18fae4149e07eaf1c29fc3faf4d5a3f89ac", size = 95644, upload-time = "2025-06-14T13:20:40.03Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/4b/a6/38c8e2f318bf67d338f4d629e93b0b4b9af331f455f0390ea8ce4a099b26/portalocker-3.2.0-py3-none-any.whl", hash = "sha256:3cdc5f565312224bc570c49337bd21428bba0ef363bbcf58b9ef4a9f11779968", size = 22424, upload-time = "2025-06-14T13:20:38.083Z" }, +] + [[package]] name = "prompt-toolkit" version = "3.0.52"