fix(updater): import probe children never resolve external secret sources
The critical-module import probe (`_critical_module_import_failures`) imports `run_agent`, whose module-level `load_hermes_dotenv()` resolves every enabled external secret source. The main-process skip only lived in `hermes_cli.main`'s own dotenv call (`load_external_secrets=sys.argv[1:2] != ["update"]`), so the probe child ran op/bws/command helpers with a 120s per-source budget inside the 120s probe and a healthy install reported "critical-module probe still fails to import after updating: timed out before reporting import health" (#110823). Move the argv check into `_early_recovery._should_skip_external_secret_sources`, which every dotenv load already consults, and stamp `sys.argv = ['hermes', 'update']` into the probe so its imports inherit the updater contract. Invariant test spawns the real probe against a home whose configured helper touches a marker: red on main, green here.
This commit is contained in:
@@ -96,8 +96,17 @@ _UPDATE_RETRY_RECOVERED = False
|
||||
|
||||
|
||||
def _should_skip_external_secret_sources() -> bool:
|
||||
"""Whether this updater already completed its deferred native install."""
|
||||
return _UPDATE_RETRY_RECOVERED
|
||||
"""True inside any ``hermes update`` process (and its import probes).
|
||||
|
||||
Every dotenv load in the process — ``hermes_cli.main``, ``run_agent``, ``cli`` — consults
|
||||
this, so the updater never resolves external secret sources: on Windows they map
|
||||
``cryptography._rust.pyd`` into the process replacing that venv, and everywhere a slow
|
||||
``op``/``bws``/command helper (up to 120s per source) would run inside the updater's
|
||||
120s critical-module import probe and be reported as an import-health timeout.
|
||||
Profile flags are stripped before ``hermes_cli.main`` loads dotenv, so ``argv[1]`` is
|
||||
the authoritative subcommand.
|
||||
"""
|
||||
return _UPDATE_RETRY_RECOVERED or sys.argv[1:2] == ["update"]
|
||||
|
||||
|
||||
def _project_root() -> Path:
|
||||
|
||||
@@ -586,17 +586,10 @@ if sys.platform == "win32":
|
||||
from hermes_cli.config import get_hermes_home
|
||||
from hermes_cli.env_loader import load_hermes_dotenv
|
||||
|
||||
# ``update`` must not import optional secret-manager libs before ``uv``
|
||||
# replaces the environment: on Windows Bitwarden's cryptography import maps
|
||||
# ``_rust.pyd`` and the parent updater then blocks its own child installer.
|
||||
# Profile flags are already stripped, so argv[1] is the authoritative subcommand.
|
||||
# Profile flags have already been stripped above, so the first remaining argument is the authoritative
|
||||
# argparse subcommand. Dotenv/managed config still loads; only external secret fetches are unnecessary for
|
||||
# installation maintenance. See #73381.
|
||||
load_hermes_dotenv(
|
||||
project_env=PROJECT_ROOT / ".env",
|
||||
load_external_secrets=sys.argv[1:2] != ["update"],
|
||||
)
|
||||
# ``update`` must not resolve external secret sources (Windows self-lock via cryptography, slow
|
||||
# helpers inside the import probe) — ``_early_recovery._should_skip_external_secret_sources``
|
||||
# owns that argv check for every dotenv load in the process. See #73381.
|
||||
load_hermes_dotenv(project_env=PROJECT_ROOT / ".env")
|
||||
|
||||
# Bridge security.redact_secrets → HERMES_REDACT_SECRETS BEFORE hermes_logging
|
||||
# imports agent.redact, which snapshots the flag exactly once at import. A
|
||||
|
||||
@@ -58,6 +58,10 @@ def _critical_module_import_failures(
|
||||
marker = f"__HERMES_IMPORT_HEALTH_{secrets.token_hex(16)}__"
|
||||
probe = (
|
||||
"import importlib, json, sys\n"
|
||||
# Importing hermes_cli.main runs the startup dotenv load, which pulls external secret
|
||||
# sources (op/bws/command helpers, up to 120s each) unless argv says ``update``. The
|
||||
# probe only checks importability, so it inherits the updater's own argv contract.
|
||||
"sys.argv = ['hermes', 'update']\n"
|
||||
"failures = []\n"
|
||||
"for name in %r:\n"
|
||||
" try:\n"
|
||||
|
||||
@@ -117,3 +117,27 @@ def test_dotenv_loading_is_preserved_when_external_secrets_are_skipped(
|
||||
assert loaded == [env_file]
|
||||
assert os.environ["UPDATE_TEST_VALUE"] == "from-dotenv"
|
||||
assert applied == ([home] if external_secrets else [])
|
||||
|
||||
|
||||
@pytest.mark.skipif(sys.platform == "win32", reason="the 'command' secret source is POSIX-only")
|
||||
def test_update_probe_children_skip_external_secret_sources(tmp_path):
|
||||
"""The critical-module import probe imports ``run_agent``, whose dotenv load must not run a
|
||||
configured secret helper: a slow helper (op/bws/command, 120s budget) inside the 120s probe
|
||||
surfaced as ``timed out before reporting import health`` on a healthy install (#110823)."""
|
||||
home = tmp_path / "hermes-home"
|
||||
home.mkdir()
|
||||
hit = tmp_path / "helper_hit"
|
||||
(home / "config.yaml").write_text(
|
||||
f"secrets:\n command:\n enabled: true\n command: 'touch {hit}'\n", encoding="utf-8",
|
||||
)
|
||||
result = subprocess.run(
|
||||
[sys.executable, "-c",
|
||||
"import sys; sys.argv = ['hermes', 'update']\n"
|
||||
"from hermes_cli.update_cmd_deps import _validate_critical_modules_import\n"
|
||||
"print('PROBE=' + repr(_validate_critical_modules_import(__import__('os').getcwd())))"],
|
||||
capture_output=True, text=True, timeout=180, cwd=REPO_ROOT,
|
||||
env={**os.environ, "HERMES_HOME": str(home)},
|
||||
)
|
||||
assert result.returncode == 0, result.stderr
|
||||
assert "PROBE=(True, None, None)" in result.stdout, result.stdout + result.stderr
|
||||
assert not hit.exists(), "the import probe resolved external secret sources"
|
||||
|
||||
@@ -604,19 +604,37 @@ class TestExternalRotationRecovery:
|
||||
assert "AFTER rotation" not in rotated.read_text()
|
||||
|
||||
|
||||
def test_eio_from_file_handler_is_suppressed(tmp_path, capsys):
|
||||
"""An unavailable log destination must not print a traceback per record."""
|
||||
handler = hermes_logging._ManagedRotatingFileHandler(
|
||||
str(tmp_path / "agent.log"), maxBytes=1024, backupCount=1, encoding="utf-8",
|
||||
)
|
||||
record = logging.LogRecord("test.eio", logging.INFO, __file__, 0, "message", (), None)
|
||||
try:
|
||||
try:
|
||||
raise OSError(5, "Input/output error")
|
||||
except OSError:
|
||||
handler.handleError(record)
|
||||
def test_eio_from_file_handler_names_the_path_once_then_recovers(tmp_path, capsys):
|
||||
"""A failing log destination is named once (no per-record traceback) and writes resume
|
||||
once the file is reachable again."""
|
||||
import io
|
||||
|
||||
assert "--- Logging error ---" not in capsys.readouterr().err
|
||||
class _SickStream(io.TextIOBase):
|
||||
def writable(self):
|
||||
return True
|
||||
|
||||
def write(self, _s):
|
||||
raise OSError(5, "Input/output error")
|
||||
|
||||
seek = tell = flush = write
|
||||
|
||||
path = tmp_path / "agent.log"
|
||||
handler = hermes_logging._ManagedRotatingFileHandler(
|
||||
str(path), maxBytes=1024, backupCount=1, encoding="utf-8",
|
||||
)
|
||||
handler.setFormatter(logging.Formatter("%(message)s"))
|
||||
try:
|
||||
handler.stream.close()
|
||||
handler.stream = _SickStream()
|
||||
for i in range(5):
|
||||
handler.handle(logging.LogRecord("t", logging.INFO, __file__, 0, f"sick {i}", (), None))
|
||||
err = capsys.readouterr().err
|
||||
assert "--- Logging error ---" not in err
|
||||
assert err.count(str(path)) == 1 and "Input/output error" in err
|
||||
|
||||
# Stream dropped, so the next emit reopens the real file and logging resumes.
|
||||
handler.handle(logging.LogRecord("t", logging.INFO, __file__, 0, "recovered", (), None))
|
||||
assert "recovered" in path.read_text(encoding="utf-8")
|
||||
finally:
|
||||
handler.close()
|
||||
|
||||
|
||||
Reference in New Issue
Block a user