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

A flaky external probe in a tool's check_fn (e.g. check_terminal_requirements
running `docker version` with a 5s timeout, momentarily timing out under load)
would return False for a single get_tool_definitions() call. Because file
tools delegate their check_fn to the terminal check, that one flake silently
stripped read_file/write_file/patch/search_files AND terminal from whatever
agent was being constructed at that instant — most visibly a delegate_task
subagent, which then reported "Tool read_file does not exist". This explains
both the intermittent (~80% success) user-session failures and the
deterministic cron failures in #21658 / #5304.

The existing _check_fn TTL cache made this worse: it cached the transient
False for the full 30s window, poisoning every subagent spawned in that span.

Fix: remember the last time each check_fn returned True; when a fresh probe
fails within a short grace window of that success, treat it as a flake —
serve the last-good True and do NOT cache the failure (so the next call
re-probes). A failure with no recent success, or past the grace window, is
honored normally so a backend that genuinely went down stops advertising its
tools. Probe failures now log at WARNING regardless of quiet mode, making the
previously-silent tool loss diagnosable in subagent (quiet) sessions.

Co-authored-by: Stuart Horner <5261694+djstunami@users.noreply.github.com>
This commit is contained in:
teknium1 2026-06-27 18:51:50 -07:00 committed by Teknium
parent 505bc27d8d
commit 926a1b915d
3 changed files with 192 additions and 3 deletions

View file

@ -47,6 +47,7 @@ ACP_REGISTRY_MANIFEST = REPO_ROOT / "acp_registry" / "agent.json"
AUTHOR_MAP = {
"der@konsi.org": "konsisumer", # PR #19608 salvage (read-modify-write merge in write_credential_pool to preserve concurrently-added credentials; #19566)
"linyubin@users.noreply.github.com": "linyubin", # PR #50228 salvage (eager fallback on persistent transport timeout/overloaded; #22277)
"5261694+djstunami@users.noreply.github.com": "djstunami", # PR #5316 salvage / co-author (suppress transient check_fn flakes so subagents keep file/terminal tools; #21658 / #5304)
"dale@dalenguyen.me": "dalenguyen", # PR #53678 salvage (strip VIRTUAL_ENV/CONDA_PREFIX from terminal subprocess env; #23473)
"blaryx@gmail.com": "Blaryxoff", # PR #32602 salvage (deep-merge PUT /api/config to preserve unrelated sections; #13396)
"diamondeyesfox@gmail.com": "DiamondEyesFox", # PR #53351 salvage (rebaseline in-place compression flushes to prevent duplicate compacted rows; #9096)

View file

@ -64,3 +64,135 @@ class TestTerminalRequirements:
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
)

View file

@ -116,15 +116,40 @@ class ToolEntry:
# 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: