diff --git a/CHANGELOG.md b/CHANGELOG.md index 4025140c..fd23a38d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -40,6 +40,8 @@ breaking changes may land in a minor release. writes count as session activity for the idle notice (#858). - Name the tool call an idle Claude session is waiting on: `session-idle` carries `in_tool`, and the TUI shows `· idle · in ` (#858). +- Add `[verify] command_timeout_min` (default 30): per-command verify timeout, + previously fixed at 30 minutes (#857). ### Changed @@ -54,6 +56,8 @@ breaking changes may land in a minor release. run-state reference pages live in docs/reference/ (the settings tables generated from the schema); sweep and escalation recovery have their own guides; a docs hygiene test guards links, anchors, tracker refs, block length and the catalog shape. +- Name the per-command time limit in a timed-out verify command's failure reason; + `--reverify` also names the key to raise. ### Fixed diff --git a/docs/FEATURES.md b/docs/FEATURES.md index 089673ea..16fc233c 100644 --- a/docs/FEATURES.md +++ b/docs/FEATURES.md @@ -53,7 +53,7 @@ bmad-loop drives a BMAD sprint unattended: a deterministic Python loop launches - With probes configured, a failing, timed-out or unstartable probe stops verification before any `[verify]` command runs. - `bmad-loop validate --probes` runs every probe, not stopping at the first failure, and fails validate if any probe fails. - A `repo_root` key in `_bmad/bmm/config.yaml` moves verify commands and git checks to a monorepo's code root. -- **Config:** `[verify] commands`, `[verify] env_fault_rc`, `[environment] probes`, `[environment] probe_timeout_s`; `bmad-loop validate --probes` +- **Config:** `[verify] commands`, `[verify] command_timeout_min`, `[verify] env_fault_rc`, `[environment] probes`, `[environment] probe_timeout_s`; `bmad-loop validate --probes` - **Tested by:** `tests/test_verify.py`, `tests/test_engine.py`, `tests/test_cli.py`, `tests/test_bmadconfig.py` - **Docs:** [Configuration: [verify]](reference/configuration.md#verify), [Configuration: [environment]](reference/configuration.md#environment), [Environment faults](escalations-guide.md#environment-faults), [Re-verify kept work](escalations-guide.md#resolve-reverify) diff --git a/docs/reference/configuration.md b/docs/reference/configuration.md index ff6f125b..6da226ea 100644 --- a/docs/reference/configuration.md +++ b/docs/reference/configuration.md @@ -101,6 +101,7 @@ Post-implementation verification commands. | Key | Type | Default | Allowed | Description | | --- | --- | --- | --- | --- | | `commands` | array of strings | `[]` | | | +| `command_timeout_min` | integer | `30` | ≥ 1 | per-command wall-clock bound; a command running past it is killed and counts as an ordinary (fixable) verify failure · a graceful stop waits for the running command | | `stream_capture_kb` | integer | `256` | ≥ 0 | per-stream cap on the verifier stdout/stderr retained under the run's verify/ directory (the tail is kept; the journal records the full size and a truncation flag) · 0 = capture nothing | | `env_fault_rc` | integer | `0` | 0–255 | exit status a verify command uses to declare an environment fault (pause, attempt not charged) instead of a code failure · 0 = disabled; 75 (EX_TEMPFAIL) is a good choice | diff --git a/src/bmad_loop/cli.py b/src/bmad_loop/cli.py index 792f0815..9b6b7e31 100644 --- a/src/bmad_loop/cli.py +++ b/src/bmad_loop/cli.py @@ -5744,6 +5744,14 @@ def _reverify(project: Path, cwd: Path) -> str | None: f"(rc={result.returncode}, [verify] env_fault_rc)" ) return f"{result.command!r} could not run: {fault}" + if verify._timed_out_leg(result): + # Operator-facing, unlike the engine's neutral reason: naming the key + # here is the point — only the operator decides the gate is slow. + return ( + f"{result.command!r} timed out after {pol.verify.command_timeout_min} min — " + "raise [verify] command_timeout_min in policy.toml if this gate is " + "legitimately this slow" + ) if result.returncode != 0: return f"{result.command!r} failed (rc {result.returncode}):\n{result.output_tail}" print(" verify commands passed") diff --git a/src/bmad_loop/data/settings/core.toml b/src/bmad_loop/data/settings/core.toml index 8ea213b7..18aab9f6 100644 --- a/src/bmad_loop/data/settings/core.toml +++ b/src/bmad_loop/data/settings/core.toml @@ -208,6 +208,13 @@ description = "post-implementation verification commands" key = "commands" kind = "lines" [[section.field]] +key = "command_timeout_min" +kind = "int" +minimum = 1 +default_ref = "VerifyPolicy.command_timeout_min" +label = "command timeout (min)" +description = "per-command wall-clock bound; a command running past it is killed and counts as an ordinary (fixable) verify failure · a graceful stop waits for the running command" +[[section.field]] key = "stream_capture_kb" kind = "int" minimum = 0 diff --git a/src/bmad_loop/engine.py b/src/bmad_loop/engine.py index b494c123..d3f6037f 100644 --- a/src/bmad_loop/engine.py +++ b/src/bmad_loop/engine.py @@ -6411,7 +6411,10 @@ def _verify_commands_with_results( sequence = self._journal_verify_command_results(task, verification_stage, results) self._stop_if_verify_interrupted(results) outcome = verify.verify_command_results_outcome( - list(results), self.workspace.root, env_fault_rc=self.policy.verify.env_fault_rc + list(results), + self.workspace.root, + env_fault_rc=self.policy.verify.env_fault_rc, + command_timeout_min=self.policy.verify.command_timeout_min, ) return outcome, VerifyCommandRecords( results=results, stage=verification_stage, sequence=sequence diff --git a/src/bmad_loop/policy.py b/src/bmad_loop/policy.py index 49aff59f..a0e9c0c5 100644 --- a/src/bmad_loop/policy.py +++ b/src/bmad_loop/policy.py @@ -180,6 +180,12 @@ class LimitsPolicy: @dataclass(frozen=True) class VerifyPolicy: commands: tuple[str, ...] = () + # command_timeout_min is the wall-clock bound on EACH [verify] command, in + # minutes, across the dev, review and --reverify passes. A command running + # past it is killed and fails as an ordinary, fixable verify failure — the + # same leg as a nonzero exit — so a slow-but-healthy gate (a mutation suite) + # needs a bigger bound, not a different failure class. + command_timeout_min: int = 30 # stream_capture_kb bounds, per stream, the verifier stdout/stderr retained # under the run's `verify/` directory for plugins and post-mortems (#641). # A tail is kept, matching every other bound on this output — the merged @@ -191,8 +197,8 @@ class VerifyPolicy: # 256 KiB is chosen against what the store is FOR: a repair session or a # plugin reading a failing suite's tail. A verbose pytest/ruff failure runs # tens of KB, so the cap is generous enough that the realistic case is never - # cut, while a chatty command under COMMAND_TIMEOUT_S (30 minutes) can no - # longer emit hundreds of MB per attempt. Worst case is bounded and small: + # cut, while a chatty command under [verify] command_timeout_min (default + # 30 minutes) can no longer emit hundreds of MB per attempt. Worst case is bounded and small: # commands x 2 streams x attempts x 256 KiB. It sits far under the file-store # precedent it is modelled on (scm.failed_diff_max_mb = 5) and far above the # inline-journal caps, which is the right side of both. @@ -1062,11 +1068,18 @@ def loads(text: str, plugin_schemas: dict[str, Any] | None = None) -> Policy: verify = VerifyPolicy( commands=_typed_str_tuple(verify_d, "verify", "commands") or (), + command_timeout_min=_typed_int( + verify_d, "verify", "command_timeout_min", VerifyPolicy.command_timeout_min + ), stream_capture_kb=_typed_int( verify_d, "verify", "stream_capture_kb", VerifyPolicy.stream_capture_kb ), env_fault_rc=_typed_int(verify_d, "verify", "env_fault_rc", VerifyPolicy.env_fault_rc), ) + if verify.command_timeout_min < 1: + raise PolicyError( + f"verify.command_timeout_min must be >= 1: got {verify.command_timeout_min}" + ) if verify.stream_capture_kb < 0: raise PolicyError(f"verify.stream_capture_kb must be >= 0: got {verify.stream_capture_kb}") if not 0 <= verify.env_fault_rc <= 255: @@ -1456,6 +1469,7 @@ def _fold_deprecated_engine( [verify] # Deterministic gates run by the orchestrator after a clean review, before commit. commands = [] # e.g. ["pytest -q", "ruff check ."] +command_timeout_min = 30 # per-command wall-clock bound (minutes); a command running past it is killed and fails as an ordinary verify failure stream_capture_kb = 256 # per-stream cap (KiB) on the verifier stdout/stderr retained under the run's verify/ directory; the TAIL is kept and the journal records the full byte count plus a truncation flag. 0 = capture nothing (records still land, with null pointers) env_fault_rc = 0 # exit status a [verify] command uses to declare an environment fault (pause, attempt not charged) instead of a code failure. 0 = disabled; 75 (EX_TEMPFAIL) is a good choice diff --git a/src/bmad_loop/runsetup.py b/src/bmad_loop/runsetup.py index ba1b9130..5d38cd5c 100644 --- a/src/bmad_loop/runsetup.py +++ b/src/bmad_loop/runsetup.py @@ -159,8 +159,9 @@ def config_digest( surface. Hashed only when non-empty, for the ``session_id_flag`` reason below: an unset list runs nothing, and leaving the key out keeps the payload byte-identical to a digest stamped before the field existed. - ``verify.env_fault_rc`` and ``environment.probe_timeout_s`` are not: they - classify or bound a command's run, and neither can name a program. + ``verify.env_fault_rc``, ``verify.command_timeout_min`` and + ``environment.probe_timeout_s`` are not: they classify or bound a + command's run, and none can name a program. * ``sorted(plugins.enabled)`` — set semantics, so order is not meaningful. * per :data:`ROLES`, every field that decides **which program runs and with what flags and environment**. That rule, not a hand-picked list, is what diff --git a/src/bmad_loop/verify.py b/src/bmad_loop/verify.py index 8574daec..6ea7b917 100644 --- a/src/bmad_loop/verify.py +++ b/src/bmad_loop/verify.py @@ -69,7 +69,6 @@ from .sprintstatus import STATUS_ORDER, story_status GIT_TIMEOUT_S = 120 -COMMAND_TIMEOUT_S = 30 * 60 # The oldest git bmad-loop SUPPORTS — the version this project tests against, writes # code against, and will help you with. INCLUSIVE: 2.34 itself clears it. (The @@ -9566,16 +9565,21 @@ def run_verify_commands(policy: Policy, cwd: Path) -> list[CommandResult]: Every child runs through :func:`childrun.run_child`, which kills the whole process tree on a timeout or a hard stop (DW-353). A hard stop is read off the ambient probe the outermost ``Engine.run()`` installs; outside an engine - run (``cli._reverify``) none is installed and no command is ever interrupted.""" + run (``cli._reverify``) none is installed and no command is ever interrupted. + + Each command is bounded by ``[verify] command_timeout_min`` on its own, not + the pass as a whole: a command running past it is killed and lands on the + timeout leg, and the next command still gets its full bound.""" results = [] interrupted = False + # One per-command bound for the whole pass, passed positionally: test fakes + # of _run_shell_command take (command, cwd, timeout). + timeout_s = policy.verify.command_timeout_min * 60 for command in policy.verify.commands: if interrupted: results.append(_interrupted_result(command, "", "", tail=_NOT_STARTED_TAIL)) continue - # COMMAND_TIMEOUT_S is read here, at call time, so a patched module - # value reaches the child. - result = _run_shell_command(command, cwd, COMMAND_TIMEOUT_S) + result = _run_shell_command(command, cwd, timeout_s) interrupted = result.interrupted results.append(result) return results @@ -9715,7 +9719,11 @@ def _env_fault_outcome(result: CommandResult, reason: str, cause: str) -> Verify def verify_command_results_outcome( - results: list[CommandResult], cwd: Path, *, env_fault_rc: int = 0 + results: list[CommandResult], + cwd: Path, + *, + env_fault_rc: int = 0, + command_timeout_min: int | None = None, ) -> VerifyOutcome: """Classify already-observed verifier results without discarding them. @@ -9730,6 +9738,15 @@ def verify_command_results_outcome( broken environment. Note the first loop inspects rc=0 results too — on Windows an unrunnable command is a silent pass, not a failure (#302). + A command killed at its time limit (:func:`_timed_out_leg`) is an ordinary + fixable failure like any other nonzero exit. When ``command_timeout_min`` is + given, the reason's second line names that limit instead of the bare + ``"timed out"`` tail, so a reader learns a time limit was hit and which. The + wording stays neutral on purpose: this reason is written verbatim into the + repair session's feedback, and it must not invite the agent to raise the + limit in policy.toml — that is the operator's call (``--reverify`` names the + key). The first line is unchanged on every leg. + An interrupted result (DW-353) is not classifiable at all and raises :class:`VerifyInterrupted` before anything else is read: the engine raises ``RunStopped`` on one before reaching here, so this is a backstop.""" @@ -9745,9 +9762,13 @@ def verify_command_results_outcome( return _env_fault_outcome(result, reason, cause) for result in results: if result.returncode != 0: + detail = result.output_tail + if command_timeout_min is not None and _timed_out_leg(result): + detail = ( + f"timed out after {command_timeout_min} min (the per-command verify time limit)" + ) return VerifyOutcome.retry( - f"verify command failed (rc={result.returncode}): {result.command}\n" - f"{result.output_tail}", + f"verify command failed (rc={result.returncode}): {result.command}\n{detail}", fixable=True, ) return VerifyOutcome.passed() @@ -9789,9 +9810,10 @@ def preflight_required(policy: Policy) -> bool: return bool(policy.verify.commands) and bool(policy.environment.probes) -def _probe_timed_out(result: CommandResult) -> bool: - # `_run_shell_command`'s timeout leg: rc -1 with the literal tail. A - # signal-killed child (rc -1 is SIGHUP) carries its own output instead. +def _timed_out_leg(result: CommandResult) -> bool: + # `_run_shell_command`'s timeout leg — for a probe and a [verify] command + # alike: rc -1 with the literal tail. A signal-killed child (rc -1 is + # SIGHUP) carries its own output instead. return result.returncode == -1 and result.output_tail == "timed out" and not result.spawn_error @@ -9802,7 +9824,7 @@ def probe_failure_reason(result: CommandResult, timeout_s: int, *, cwd: Path | N #302) name why; without it that leg reads ``"rc=0"``.""" if result.spawn_error is not None: return f"could not be started: {result.spawn_error}" - if _probe_timed_out(result): + if _timed_out_leg(result): return f"timed out after {timeout_s}s" if result.returncode == 0 and cwd is not None: unrunnable = env_fault_reason(result, cwd) @@ -9815,7 +9837,7 @@ def _probe_failed(result: CommandResult, cwd: Path) -> bool: return ( result.spawn_error is not None or result.returncode != 0 - or _probe_timed_out(result) + or _timed_out_leg(result) # rc 0 is not proof on win32: cmd exits 0 for a file it cannot execute or env_fault_reason(result, cwd) is not None ) @@ -9876,7 +9898,7 @@ def check_environment_probes(policy: Policy, cwd: Path) -> tuple[ProbeCheck, ... nothing, and is not one of the compositions tests/test_portability_guard.py pins to the preflight runners. What it shares with the run is the verdict — the same :func:`_run_shell_command` runner, ``probe_timeout_s`` bound, - :func:`_probe_timed_out`/:func:`_probe_failed` predicates and + :func:`_timed_out_leg`/:func:`_probe_failed` predicates and :func:`probe_failure_reason` phrasing — so validate and the run cannot disagree on a given probe RESULT. They can still see different environments: validate probes the run's code root (``repo_root``), which is where the run @@ -9891,7 +9913,7 @@ def check_environment_probes(policy: Policy, cwd: Path) -> tuple[ProbeCheck, ... if result.interrupted: checks.append(ProbeCheck(result, "interrupted", "interrupted by a hard stop request")) break - if _probe_timed_out(result): + if _timed_out_leg(result): checks.append( ProbeCheck(result, "timeout", probe_failure_reason(result, timeout_s, cwd=cwd)) ) @@ -9965,7 +9987,12 @@ def verify_commands_outcome( results = run_verify_commands(policy, cwd) if on_results is not None: on_results(tuple(results)) - return verify_command_results_outcome(results, cwd, env_fault_rc=policy.verify.env_fault_rc) + return verify_command_results_outcome( + results, + cwd, + env_fault_rc=policy.verify.env_fault_rc, + command_timeout_min=policy.verify.command_timeout_min, + ) def _verify_review_commands( diff --git a/tests/test_cli.py b/tests/test_cli.py index bb83b7bb..732fd5ad 100644 --- a/tests/test_cli.py +++ b/tests/test_cli.py @@ -14481,6 +14481,30 @@ def test_reverify_answers_with_the_first_ordinary_failure_not_a_later_one(tmp_pa assert "verify commands passed" not in capsys.readouterr().out +def test_reverify_timeout_names_the_limit_and_the_key(tmp_path, monkeypatch): + """A `--reverify` command killed at its time limit is reported to the + OPERATOR with the limit and the key that sets it — unlike the engine's + neutral reason, which reaches an agent. The configured minutes reach the + runner as seconds. Faked runner; nothing sleeps toward a deadline. + Ablation: revert the timeout arm in `_reverify` and the message falls back to + `failed (rc -1)` with neither the limit nor the key.""" + timeouts: list[float] = [] + + def timed_out(command, cwd, timeout): + timeouts.append(timeout) + return verify.CommandResult(command, -1, "timed out") + + monkeypatch.setattr(verify, "_run_shell_command", timed_out) + _write_policy(tmp_path, '[verify]\ncommands = ["slow-gate"]\ncommand_timeout_min = 7\n') + + reason = cli._reverify(tmp_path, tmp_path) + + assert timeouts == [420] + assert reason is not None + assert repr("slow-gate") in reason + assert "7 min" in reason and "[verify] command_timeout_min" in reason + + def test_reverify_walks_every_command_when_they_all_pass(tmp_path, capsys): """The control for the two rows above: with nothing to return on, the walk reaches the end and reports the pass. diff --git a/tests/test_engine.py b/tests/test_engine.py index a1d4099e..6a7885be 100644 --- a/tests/test_engine.py +++ b/tests/test_engine.py @@ -457,8 +457,8 @@ def _sole_verify_record(engine): def test_verify_stream_capture_retains_a_bounded_tail(project): """A chatty command is cut to `verify.stream_capture_kb`, and the record says so. - COMMAND_TIMEOUT_S is 30 minutes, so an uncapped retain is hundreds of MB per - attempt with no GC behind it. The cut keeps the TAIL — the direction every + `[verify] command_timeout_min` defaults to 30 minutes, so an uncapped retain + is hundreds of MB per attempt with no GC behind it. The cut keeps the TAIL — the direction every other bound on this output takes, and where a failing suite puts its failure. Ablation: have `_bounded_stream_tail` return `(text, full, full)` @@ -3103,6 +3103,50 @@ def test_dev_retry_notice_folds_a_multiline_reason(project, monkeypatch): assert "FAILED tests/test_b.py::test_two" in decision["reason"] +def test_dev_retry_feedback_names_the_verify_time_limit(project, monkeypatch): + """A dev-pass verify command killed at its time limit reaches the repair + session's feedback naming that limit — and only neutrally: the feedback must + never point the agent at policy.toml, since a limit it raised there would + survive the attempt unaccounted. Ablation: drop the `command_timeout_min` + keyword from the engine's classifier call and the feedback reverts to the + bare `timed out` tail.""" + write_sprint(project, {"epic-1": "backlog", "1-1-a": "ready-for-dev"}) + engine, _ = make_engine( + project, + [ + dev_effect(project, "1-1-a", followup_review=False), + dev_effect(project, "1-1-a", followup_review=False), + ], + policy=Policy( + gates=GatesPolicy(mode="none"), + notify=QUIET, + review=ReviewPolicy(enabled=False), + limits=LimitsPolicy(max_dev_attempts=2), + verify=VerifyPolicy(commands=["pytest -q"], command_timeout_min=45), + ), + ) + # time out exactly the first invocation, pass every later one (see the + # multiline-reason row above for why the script must not run dry) + failing = iter([[verify.CommandResult("pytest -q", -1, "timed out")]]) + monkeypatch.setattr( + verify, + "run_verify_commands", + scripted_verify_runner( + project.repo_root, + lambda: next(failing, [verify.CommandResult("pytest -q", 0, "ok")]), + ), + ) + + assert engine.run().done == 1 + + feedback = sorted((engine.run_dir / "feedback").glob("*.md")) + assert feedback # else the content checks below are vacuous + text = "".join(path.read_text(encoding="utf-8") for path in feedback) + assert "verify command failed (rc=-1): pytest -q" in text + assert "timed out after 45 min" in text + assert "policy.toml" not in text + + def test_exhaustion_defer_folds_a_multiline_verify_reason_into_one_attention_line( project, monkeypatch ): diff --git a/tests/test_policy.py b/tests/test_policy.py index 410d2457..722102ca 100644 --- a/tests/test_policy.py +++ b/tests/test_policy.py @@ -1385,6 +1385,36 @@ def test_environment_probe_timeout_must_be_positive(bad): policy.loads(f"[environment]\nprobe_timeout_s = {bad}\n") +def test_verify_command_timeout_default_parse_and_template(): + import tomllib + + assert policy.loads("").verify.command_timeout_min == 30 + assert policy.loads("[verify]\ncommand_timeout_min = 60\n").verify.command_timeout_min == 60 + # a partial table keeps the default + assert policy.loads('[verify]\ncommands = ["pytest -q"]\n').verify.command_timeout_min == 30 + # the emitted template documents the knob at its dataclass default + doc = tomllib.loads(policy.POLICY_TEMPLATE) + assert doc["verify"]["command_timeout_min"] == policy.VerifyPolicy.command_timeout_min + + +@pytest.mark.parametrize("bad", [0, -5]) +def test_verify_command_timeout_must_be_positive(bad): + """A 0-minute bound would kill every verify command before it could answer, + and core.toml's `minimum = 1` is not enforced at load. Ablation: drop the + `command_timeout_min < 1` check and both rows parse.""" + with pytest.raises(policy.PolicyError, match=r"verify\.command_timeout_min must be >= 1"): + policy.loads(f"[verify]\ncommand_timeout_min = {bad}\n") + + +@pytest.mark.parametrize("bad", ["true", "2.5", '"60"']) +def test_verify_command_timeout_rejects_non_integers(bad): + """`true` would read as a 1-minute bound and a string as a type error mid-run. + Ablation: read the value with `.get` instead of `_typed_int` and every row + loads or fails with something other than a PolicyError naming the key.""" + with pytest.raises(policy.PolicyError, match=r"verify\.command_timeout_min"): + policy.loads(f"[verify]\ncommand_timeout_min = {bad}\n") + + @pytest.mark.parametrize("bad", ['[""]', '[" "]', '["pg_isready", "\\t"]']) def test_environment_probes_reject_blank_entries(bad): """A blank probe is `sh -c ""`, which exits 0 — a check of nothing that reads diff --git a/tests/test_verify.py b/tests/test_verify.py index b2a4d8c0..00721bb6 100644 --- a/tests/test_verify.py +++ b/tests/test_verify.py @@ -2547,6 +2547,84 @@ def timed_out(command, cwd, timeout): assert probe.reason == "timed out after 1s" +def test_verify_command_timeout_reaches_the_runner(tmp_path, monkeypatch): + """`[verify] command_timeout_min` reaches the runner in seconds, once per + command — the bound is per command, not per pass. Faked runner; no test sleeps + toward a deadline. Ablation: hard-code 1800 in `run_verify_commands`, or drop + the `* 60`, and a row goes red.""" + timeouts: list[float] = [] + + def records(command, cwd, timeout): + timeouts.append(timeout) + return verify.CommandResult(command, 0, "") + + monkeypatch.setattr(verify, "_run_shell_command", records) + + verify.run_verify_commands( + Policy(verify=VerifyPolicy(commands=("a", "b"), command_timeout_min=45)), tmp_path + ) + assert timeouts == [2700, 2700] + + timeouts.clear() + verify.run_verify_commands(Policy(verify=VerifyPolicy(commands=("a",))), tmp_path) + assert timeouts == [1800] # the default 30 minutes + + +def test_verify_timeout_reason_names_the_limit_neutrally(tmp_path): + """A timed-out command's reason names the per-command limit it hit, in words + that never point the repair agent at policy.toml — this text is written + verbatim into its feedback, and raising the limit is the operator's call. + The first line stays byte-identical and the failure stays an ordinary fixable + retry. + + Ablation: key the note on `rc == -1` alone and the Hangup and spawn-error rows + gain it; delete the note branch and the positive row loses it.""" + out = verify.verify_command_results_outcome( + [verify.CommandResult("slow", -1, "timed out")], tmp_path, command_timeout_min=45 + ) + assert out.reason.startswith("verify command failed (rc=-1): slow\n") + assert "timed out after 45 min (the per-command verify time limit)" in out.reason + assert "policy.toml" not in out.reason + assert "command_timeout_min" not in out.reason + assert not out.ok and out.retryable and out.fixable and not out.env_fault + + # rc -1 from a signal (SIGHUP) is not the timeout leg: its own output stays + hangup = verify.verify_command_results_outcome( + [verify.CommandResult("x", -1, "Hangup")], tmp_path, command_timeout_min=45 + ) + assert hangup.reason == "verify command failed (rc=-1): x\nHangup" + + # a timed-out-shaped result that never spawned is not the timeout leg either + shaped = verify.CommandResult("x", -1, "timed out", spawn_error="child not started") + assert not verify._timed_out_leg(shaped) + noted = verify.verify_command_results_outcome([shaped], tmp_path, command_timeout_min=45) + assert "min (the per-command verify time limit)" not in noted.reason + + # without the keyword, today's exact text + bare = verify.verify_command_results_outcome( + [verify.CommandResult("slow", -1, "timed out")], tmp_path + ) + assert bare.reason == "verify command failed (rc=-1): slow\ntimed out" + + +def test_review_composition_passes_the_configured_limit_to_the_reason(tmp_path, monkeypatch): + """`verify_commands_outcome` — the review gates' composition — hands the + configured limit to the classifier. Ablation: drop the `command_timeout_min` + keyword there and the reason reverts to the bare tail.""" + monkeypatch.setattr( + verify, + "_run_shell_command", + lambda command, cwd, timeout: verify.CommandResult(command, -1, "timed out"), + ) + + out = verify.verify_commands_outcome( + Policy(verify=VerifyPolicy(commands=("slow",), command_timeout_min=45)), tmp_path + ) + + assert not out.ok and out.fixable + assert "timed out after 45 min" in out.reason + + def test_probe_spawn_fault_is_a_failure(tmp_path): """A probe that cannot even be started (unusable cwd) fails the pass.""" policy = Policy(environment=EnvironmentPolicy(probes=(_OK,))) @@ -2793,7 +2871,10 @@ def test_timeout_stays_an_ordinary_fixable_retry_with_no_spawn_error(tmp_path, m Ablation: set `SPAWN_FAULT_RC = -1` and the sentinel assertion below stops discriminating; set `spawn_error` on the timeout leg and the classification flips to `env_fault`.""" - monkeypatch.setattr(verify, "COMMAND_TIMEOUT_S", 0.5) + real = verify._run_shell_command + monkeypatch.setattr( + verify, "_run_shell_command", lambda command, cwd, timeout: real(command, cwd, 0.5) + ) sleeper = tmp_path / "sleeper.py" sleeper.write_text("import time\ntime.sleep(30)\n", encoding="utf-8") policy = Policy(verify=VerifyPolicy(commands=(f'"{sys.executable}" "{sleeper}"',))) @@ -2829,7 +2910,10 @@ def test_completed_timed_out_and_never_spawned_legs_survive_one_another(tmp_path exception escapes before the fifth command runs; set `SPAWN_FAULT_RC = -1` and the two no-exit-status legs stop being distinguishable by rc. """ - monkeypatch.setattr(verify, "COMMAND_TIMEOUT_S", 0.5) + real = verify._run_shell_command + monkeypatch.setattr( + verify, "_run_shell_command", lambda command, cwd, timeout: real(command, cwd, 0.5) + ) sleeper = tmp_path / "sleeper.py" sleeper.write_text("import time\ntime.sleep(30)\n", encoding="utf-8") hangs = f'"{sys.executable}" "{sleeper}"' @@ -3080,7 +3164,8 @@ def test_verify_commands_timeout_output_matches_the_completed_path(tmp_path): "from pathlib import Path\n" "from bmad_loop import verify\n" "from bmad_loop.policy import Policy, VerifyPolicy\n" - "verify.COMMAND_TIMEOUT_S = 1.0\n" + "_real = verify._run_shell_command\n" + "verify._run_shell_command = lambda command, cwd, timeout: _real(command, cwd, 1.0)\n" "def run(mode):\n" ' cmd = \'"%s" "%s" %s\' % (sys.executable, sys.argv[1], mode)\n' " (r,) = verify.run_verify_commands(\n"