Intermittent tool loss in subagents from check_fn failures

Fixes on record

Merged to main. A stamp counts the issues a fix is linked to.

• #53904 fix(tools): suppress transient check_fn flakes so subagents keep file/terminal tools

  merged to main

  files: scripts/release.py, tests/tools/test_terminal_tool_requirements.py, tools/registry.py

  Show the diff

  • scripts/release.py

    @@ -47,6 +47,7 @@
     AUTHOR_MAP = {
         "[redacted:email]": "konsisumer",  # PR #19608 salvage (read-modify-write merge in write_credential_pool to preserve concurrently-added credentials; #19566)
         "[email protected]": "linyubin",  # PR #50228 salvage (eager fallback on persistent transport timeout/overloaded; #22277)
    +    "[email protected]": "djstunami",  # PR #5316 salvage / co-author (suppress transient check_fn flakes so subagents keep file/terminal tools; #21658 / #5304)
         "[redacted:email]": "dalenguyen",  # PR #53678 salvage (strip VIRTUAL_ENV/CONDA_PREFIX from terminal subprocess env; #23473)
         "[redacted:email]": "Blaryxoff",  # PR #32602 salvage (deep-merge PUT /api/config to preserve unrelated sections; #13396)
         "[redacted:email]": "DiamondEyesFox",  # PR #53351 salvage (rebaseline in-place compression flushes to prevent duplicate compacted rows; #9096)

  • tests/tools/test_terminal_tool_requirements.py

    @@ -64,3 +64,135 @@ def test_terminal_and_execute_code_tools_resolve_for_managed_modal(self, monkeyp
     
             assert "terminal" in names
             assert "execute_code" in names
    +
    +
    +class TestCheckFnTransientFailureSuppression:
    +    """The check_fn TTL cache should absorb transient probe failures.
    +
    +    Regression coverage for #21658 / #5304: a single flaky
    +    ``check_terminal_requirements()`` (Docker daemon busy, probe timeout)
    +    must not silently strip the terminal/file toolset from a subagent. After
    +    a recent success, a transient False is treated as a flake; a failure with
    +    no recent success — or past the grace window — is honored.
    +    """
    +
    +    @pytest.fixture(autouse=True)
    +    def _reset(self):
    +        from tools.registry import invalidate_check_fn_cache
    +
    +        invalidate_check_fn_cache()
    +        yield
    +        invalidate_check_fn_cache()
    +
    +    def test_transient_failure_after_success_is_suppressed(self, monkeypatch):
    +        import tools.registry as reg
    +
    +        calls = {"n": 0}
    +
    +        def flaky():
    +            calls["n"] += 1
    +            # First call succeeds, second flakes (False).
    +            return calls["n"] == 1
    +
    +        # Pin the cache clock so the TTL doesn't serve a stale entry between
    +        # the two probes — we want both to actually run.
    +        t = {"now": 1000.0}
    +        monkeypatch.setattr(reg.time, "monotonic", lambda: t["now"])
    +
    +        assert reg._check_fn_cached(flaky) is True  # records last-good
    +        t["now"] += reg._CHECK_FN_TTL_SECONDS + 1  # expire the TTL cache
    +        # Within grace window of the success → flake suppressed, stays True.
    +        assert reg._check_fn_cached(flaky) is True
    +        assert calls["n"] == 2  # the probe actually ran (not just cached)
    +
    +    def test_persistent_failure_after_grace_is_honored(self, monkeypatch):
    +        import tools.registry as reg
    +
    +        def good():
    +            return True
    +
    +        def bad():
    +            return False
    +
    +        t = {"now": 1000.0}
    +        monkeypatch.setattr(reg.time, "monotonic", lambda: t["now"])
    +
    +        assert reg._check_fn_cached(good) is True
    +        # Advance past the failure grace window, then fail.
    +        t["now"] += reg._CHECK_FN_FAILURE_GRACE_SECONDS + 1
    +        # Different fn so last-good for `good` doesn't apply; bad has no success.
    +        assert reg._check_fn_cached(bad) is False
    +
    +    def test_failure_with_no_prior_success_is_honored(self, monkeypatch):
    +        import tools.registry as reg
    +
    +        def never():
    +            return False
    +
    +        t = {"now": 1000.0}
    +        monkeypatch.setattr(reg.time, "monotonic", lambda: t["now"])
    +        assert reg._check_fn_cached(never) is False
    +
    +    def test_grace_expiry_lets_real_outage_through(self, monkeypatch):
    +        import tools.registry as reg
    +
    +        state = {"ok": True}
    +
    +        def probe():
    +            return state["ok"]
    +
    +        t = {"now": 1000.0}
    +        monkeypatch.setattr(reg.time, "monotonic", lambda: t["now"])
    +
    +        assert reg._check_fn_cached(probe) is True
    +        state["ok"] = False
    +        # Just past TTL, within grace → flake suppressed.
    +        t["now"] += reg._CHECK_FN_TTL_SECONDS + 1
    +        assert reg._check_fn_cached(probe) is True
    +        # Now move well past the grace window since the last success → honored.
    +        t["now"] += reg._CHECK_FN_FAILURE_GRACE_SECONDS + 1
    +        assert reg._check_fn_cached(probe) is False
    +
    +    def test_subagent_keeps_file_tools_through_docker_flake(self, monkeypatch):
    +        """End-to-end: a docker probe that flakes on the 2nd build keeps the
    +        file/terminal toolset available for the subagent being constructed."""
    +        import tools.registry as reg
    +
    +        flake = {"first": True}
    +
    +        def flaky_terminal_check():
    +            if flake["first"]:
    +                flake["first"] = False
    +                return True
    +            return False  # transient flake on the subagent build
    +
    +        monkeypatch.setattr(
    +            terminal_tool_module, "check_terminal_requirements", flaky_terminal_check
    +        )
    +        # file tools delegate to the same check via tools.check_file_requirements.
    +        import tools as tools_pkg
    +
    +        monkeypatch.setattr(
    +            tools_pkg, "check_file_requirements", flaky_terminal_check
    +        )
    +
    +        t = {"now": 5000.0}
    +        monkeypatch.setattr(reg.time, "monotonic", lambda: t["now"])
    +
    +        from model_tools import get_tool_definitions, _clear_tool_defs_cache
    +
    +        reg.invalidate_check_fn_cache()
    +        _clear_tool_defs_cache()
    +        # Parent build (probe ok) → records last-good.
    +        parent = get_tool_definitions(enabled_toolsets=["terminal", "file"], quiet_mode=True)
    +        assert "read_file" in {x["function"]["name"] for x in parent}
    +
    +        # Subagent build moments later: TTL expired, probe flakes False, but
    +        # within grace → file/terminal tools must still resolve.
    +        t["now"] += reg._CHECK_FN_TTL_SECONDS + 1
    +        _clear_tool_defs_cache()
    +        child = get_tool_definitions(enabled_toolsets=["terminal", "file"], quiet_mode=True)
    +        child_names = {x["function"]["name"] for x in child}
    +        assert {"read_file", "write_file", "patch", "search_files", "terminal"}.issubset(
    +            child_names
    +        )

  • tools/registry.py

    @@ -116,15 +116,40 @@ def __init__(self, name, toolset, schema, handler, check_fn,
     # timescales. Cache results for ~30 s so env-var flips via ``hermes tools``
     # or live credential file changes propagate within a turn or two without
     # requiring any explicit invalidation.
    +#
    +# Transient-failure suppression (issue #21658 / #5304): these probes can flap.
    +# A single ``subprocess.run([docker, "version"], timeout=5)`` that times out
    +# under load returns False for one call, which would silently strip the entire
    +# terminal+file toolset from whatever agent is being built at that instant —
    +# most visibly a delegate_task subagent, which then reports "Tool read_file
    +# does not exist". To absorb such flakes WITHOUT pinning a permanently-stale
    +# "available" verdict, we remember the last time each check returned True and,
    +# when a fresh probe fails within a short grace window of that last success,
    +# we serve the last-good True instead of caching the failure. A failure that
    +# persists past the grace window is honored normally, so a backend that really
    +# went down stops advertising its tools.
     # ---------------------------------------------------------------------------
     
     _CHECK_FN_TTL_SECONDS = 30.0
    +# How long after a successful check a subsequent transient failure is treated
    +# as a flake (last-good True is served) rather than a real outage. Kept short
    +# so a genuinely-down backend is reflected within a couple of turns.
    +_CHECK_FN_FAILURE_GRACE_SECONDS = 60.0
     _check_fn_cache: Dict[Callable, tuple[float, bool]] = {}
    +# Monotonic timestamp of the most recent True result per check_fn.
    +_check_fn_last_good: Dict[Callable, float] = {}
     _check_fn_cache_lock = threading.Lock()
     
     
     def _check_fn_cached(fn: Callable) -> bool:
    -    """Return bool(fn()), TTL-cached across calls. Swallows exceptions as False."""
    +    """Return bool(fn()), TTL-cached across calls.
    +
    +    Exceptions are swallowed as False. A transient False/exception within
    +    ``_CHECK_FN_FAILURE_GRACE_SECONDS`` of the last True is suppressed (the
    +    last-good True is returned and the failure is NOT cached, so the next call
    +    re-probes) to keep flaky external checks (Docker daemon busy, socket
    +    contention, probe timeout) from silently stripping tools mid-session.
    +    """
         now = time.monotonic()
         with _check_fn_cache_lock:
             cached = _check_fn_cache.get(fn)
    @@ -132,13 +157,43 @@ def _check_fn_cached(fn: Callable) -> bool:
                 ts, value = cached
                 if now - ts < _CHECK_FN_TTL_SECONDS:
                     return value
    +
    +    raised = False
         try:
             value = bool(fn())
         except Exception:
             value = False
    +        raised = True
    +
         with _check_fn_cache_lock:
    -        _check_fn_cache[fn] = (now, value)
    -    return value
    +        if value:
    +            _check_fn_last_good[fn] = now
    +            _check_fn_cache[fn] = (now, True)
    +            return True
    +
    +        last_good = _check_fn_last_good.get(fn)
    +        if last_good is not None and now - last_good < _CHECK_FN_FAILURE_GRACE_SECONDS:
    +            # Recent success → treat this failure as a flake. Serve last-good
    +            # True and do NOT cache the failure, so the next call re-probes
    +            # rather than pinning a stale verdict for the full TTL.
    +            logger.warning(
    +                "check_fn %s failed (%s) within %.0fs of last success; "
    +                "treating as transient and keeping tool(s) available",
    +                getattr(fn, "__qualname__", fn),
    +                "raised" if raised else "returned False",
    +                _CHECK_FN_FAILURE_GRACE_SECONDS,
    +            )
    +            return True
    +
    +        # No recent success (or grace expired) — honor the failure. Log it so
    +        # silent tool loss in quiet mode (subagents) is diagnosable.
    +        logger.warning(
    +            "check_fn %s %s; dependent tools will be unavailable this turn",
    +            getattr(fn, "__qualname__", fn),
    +            "raised" if raised else "returned False",
    +        )
    +        _check_fn_cache[fn] = (now, False)
    +        return False
     
     
     def invalidate_check_fn_cache() -> None:
    @@ -146,6 +201,7 @@ def invalidate_check_fn_cache() -> None:
         affect tool availability (e.g. ``hermes tools enable``)."""
         with _check_fn_cache_lock:
             _check_fn_cache.clear()
    +        _check_fn_last_good.clear()
     
     
     class ToolRegistry: