Compare commits

...

2 Commits

Author SHA1 Message Date
Teknium
077b2f4829 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.
2026-06-15 15:47:53 -04:00
tuancookiez-hub
9c25fbd01f 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 <tuancookiez@gmail.com>
2026-06-15 13:49:14 -04:00
4 changed files with 78 additions and 3 deletions

View File

@@ -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

View File

@@ -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]

View File

@@ -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)

26
uv.lock generated
View File

@@ -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"
@@ -1394,6 +1406,7 @@ version = "0.16.0"
source = { editable = "." }
dependencies = [
{ name = "certifi" },
{ name = "concurrent-log-handler", marker = "sys_platform == 'win32'" },
{ name = "croniter" },
{ name = "fastapi" },
{ name = "fire" },
@@ -1600,6 +1613,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" },
@@ -2787,6 +2801,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"