diff --git a/tests/tools/test_terminal_tool_requirements.py b/tests/tools/test_terminal_tool_requirements.py index b87bca9da4..bdf85c9d04 100644 --- a/tests/tools/test_terminal_tool_requirements.py +++ b/tests/tools/test_terminal_tool_requirements.py @@ -360,3 +360,34 @@ class TestCheckFnTransientFailureSuppression: assert "terminal" not in names assert "execute_code" not in names + + +class TestUnscopedSecretReadLogging: + """#100697: with multiplexing on, boot-time check_fns run before any + profile secret scope exists, so get_secret fails closed with + UnscopedSecretError. That expected signal must not be logged like a + crashed check_fn (WARNING + traceback); an unscoped read reported while + the scope was *resolved* is a genuinely lost scope and stays loud.""" + + def test_expected_fail_closed_probe_is_quiet_but_lost_scope_stays_loud(self, caplog): + import logging + + import tools.registry as reg + from agent.secret_scope import get_secret, set_multiplex_active + + def probe(): + return bool(get_secret("REGISTRY_LOG_PROBE_TOKEN", "")) + + set_multiplex_active(True) + try: + with caplog.at_level(logging.DEBUG, logger="tools.registry"): + assert reg._run_check_fn_uncached(probe, unresolved_scope=True) is False + boot = [r for r in caplog.records if r.name == "tools.registry"] + caplog.clear() + assert reg._run_check_fn_uncached(probe, unresolved_scope=False) is False + lost = [r for r in caplog.records if r.name == "tools.registry"] + finally: + set_multiplex_active(False) + + assert boot and all(r.levelno == logging.DEBUG and r.exc_info is None for r in boot) + assert any(r.levelno >= logging.WARNING and r.exc_info for r in lost) diff --git a/tools/registry.py b/tools/registry.py index bf6d52f2ee..7107b3ad31 100644 --- a/tools/registry.py +++ b/tools/registry.py @@ -348,8 +348,33 @@ def check_fn_cache_scope() -> Optional[str]: def _run_check_fn_uncached(fn: Callable, *, unresolved_scope: bool = False) -> bool: """Run an availability check without cache/grace handling.""" + from agent.secret_scope import UnscopedSecretError + try: return bool(fn()) + except UnscopedSecretError: + if unresolved_scope: + # Expected fail-closed probe: with multiplexing on, boot-time + # check_fns run before any profile secret scope exists, so + # get_secret raises by design. The tool re-probes on the first + # scoped turn — log without a traceback so this cannot be + # mistaken for a crashed check_fn (#100697). + logger.debug( + "check_fn %s hit the multiplex fail-closed path with no " + "profile secret scope active; dependent tools re-probe on " + "the first scoped turn", + getattr(fn, "__qualname__", fn), + ) + return False + # The scope resolved but the read still failed closed: a genuinely + # lost scope. Keep the loud crash-style report. + logger.warning( + "check_fn %s raised UnscopedSecretError while the profile cache " + "scope was resolved; dependent tools will be unavailable this turn", + getattr(fn, "__qualname__", fn), + exc_info=True, + ) + return False except Exception: detail = " while profile cache scope was unresolved" if unresolved_scope else "" logger.warning(