diff --git a/CHANGELOG.md b/CHANGELOG.md index 8bfbca4..3c0635f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -31,6 +31,18 @@ breaking changes may land in a minor release. ### Fixed +- **A finished session whose final `Stop` hook was lost no longer loses its work.** A dev/review + session that wrote its terminal spec but never delivered the `Stop` ended `stalled` — or `timeout`, + when hooks were misconfigured and no event ever arrived — and the on-disk result was discarded. + The adapter now re-reads the spec after the window is provably dead, rescuing a self-consistent + successful terminal; every rescue still faces the full deterministic verify, and the journal records + `session-rescued-post-kill` so it stays distinguishable from a live completion. (#95, closes #61) +- **A corrupt terminal artifact no longer crashes the whole run.** A spec truncated mid-write (a + multi-byte UTF-8 sequence cut in half) raised out of the read-back and past the per-task boundary, + marking the run `CRASHED` and abandoning every remaining story. The read-back now degrades an + undecodable spec to "no result yet" — the session retries or keeps its verdict — and the post-kill + rescue additionally keeps its verdict on _any_ read fault, so a best-effort rescue can never make + things worse. The repair path still raises on purpose. (#95, closes #96) - **Windows installs now pull `psutil` automatically** — moved from the opt-in `non-linux` extra to a platform-scoped core dependency (`sys_platform == 'win32'`), so the TUI liveness column no longer shows every run as `?` on a stock install. macOS keeps the `non-linux` extra; Linux stays dep-free. diff --git a/src/bmad_loop/adapters/base.py b/src/bmad_loop/adapters/base.py index 8655219..4efbc5a 100644 --- a/src/bmad_loop/adapters/base.py +++ b/src/bmad_loop/adapters/base.py @@ -91,6 +91,20 @@ def read_usage(self, result: SessionResult) -> TokenUsage | None: def run(self, spec: SessionSpec) -> SessionResult: handle = self.start_session(spec) try: - return self.wait_for_completion(handle, spec) + result = self.wait_for_completion(handle, spec) finally: self.kill(handle) + return self._post_kill_reconcile(handle, spec, result) + + def _post_kill_reconcile( + self, handle: SessionHandle, spec: SessionSpec, result: SessionResult + ) -> SessionResult: + """Last-chance reconcile after the session's window has been torn down. + + Runs only on the normal return path — a raising wait_for_completion + still kills the window and propagates without reaching this hook. + Base behavior: identity. Adapters whose completion trust keys on + window death (see GenericDevAdapter) may re-inspect on-disk state here, + now that the kill has settled the liveness question a live-window + verdict had to leave open.""" + return result diff --git a/src/bmad_loop/adapters/generic.py b/src/bmad_loop/adapters/generic.py index 919016d..555ecc7 100644 --- a/src/bmad_loop/adapters/generic.py +++ b/src/bmad_loop/adapters/generic.py @@ -459,12 +459,18 @@ def _artifact_dirs(self, cwd: Path) -> list[Path]: return dirs def _result_json(self, handle: SessionHandle, spec: SessionSpec, *, wait: bool) -> dict | None: + sr = self._synth_result(handle, spec, wait=wait) + return sr.result_json if sr is not None else None + + def _synth_result( + self, handle: SessionHandle, spec: SessionSpec, *, wait: bool + ) -> devcontract.SynthResult | None: # Stories mode (folder+id dispatch): the story spec lives at a # deterministic id-keyed path, so resolve it directly instead of the # mtime-floor scan. The engine exports BMAD_LOOP_SPEC_FOLDER only for # stories runs, so sprint/sweep runs keep the scan path below unchanged. if spec.env.get("BMAD_LOOP_SPEC_FOLDER"): - return self._stories_result_json(handle, spec, wait=wait) + return self._stories_synth_result(handle, spec, wait=wait) # Mirror the base _await_result poll: the skill's terminal spec may not be # flushed to disk the instant the Stop event fires, so briefly await it when # wait=True instead of reading once and mis-reporting a stall. @@ -482,14 +488,14 @@ def _result_json(self, handle: SessionHandle, spec: SessionSpec, *, wait: bool) dw_ids = [tok for tok in (i.strip() for i in raw_dw_ids) if tok] return devcontract.synthesize_result( spec_path, story_key=story_key, dw_ids=dw_ids or None - ).result_json + ) if not wait or time.monotonic() >= deadline: return None time.sleep(RESULT_POLL_S) - def _stories_result_json( + def _stories_synth_result( self, handle: SessionHandle, spec: SessionSpec, *, wait: bool - ) -> dict | None: + ) -> devcontract.SynthResult | None: """Deterministic stories-mode read-back: resolve ``/stories/ -*.md`` by id (never the mtime scan) and synthesize from it. @@ -530,9 +536,9 @@ def _stories_result_json( and self._written_this_session(state.path, handle.launched_ns) ): try: - result_json = devcontract.synthesize_result( + sr = devcontract.synthesize_result( state.path, story_key=story_key or None, plan_halt=plan_halt - ).result_json + ) except UnicodeDecodeError: # A non-UTF-8 read is either a torn glimpse of a spec still # being written (keep polling — a later pass sees the finished @@ -541,9 +547,9 @@ def _stories_result_json( # wedge (resolve_story_spec degrades an undecodable PRESENT # spec to status "" → pause for resolve), never a crash of # the read-back poll. - result_json = None - if result_json is not None: - return result_json + sr = None + if sr is not None and sr.result_json is not None: + return sr if not wait or time.monotonic() >= deadline: return None time.sleep(RESULT_POLL_S) @@ -560,6 +566,70 @@ def _written_this_session(spec_path: Path, launched_ns: int) -> bool: except OSError: return False + def _post_kill_reconcile( + self, handle: SessionHandle, spec: SessionSpec, result: SessionResult + ) -> SessionResult: + """Rescue a finished-but-unvouched session once its window is dead (#61). + + A session that wrote its terminal spec but whose final Stop event was + lost ends ``stalled`` (nudge-unresponsive under a live window, where + the artifact is advisory — the #48/#53 invariant), or ``timeout`` when + no hook event ever arrived (hook misconfig, events-dir write failure — + that path never arms the stall grace at all). Both verdicts discard + the on-disk result solely because the window was alive to distrust; + ``run()``'s kill has since settled that the way window death already + vouches for the crash path. So: re-probe, and only on a provably dead + window re-run the same read-back a delivered Stop would have run. + + The gate is deliberately stricter than the crash path's + accept-any-terminal: the synthesis must be self-consistent + (``status_consistent`` — "no active disagreement"; a blank frontmatter + with prose ``done`` passes, exactly what a delivered Stop would have + synthesized, and the engine's reconcile repairs the lag) and a + *successful* terminal — ``done``, or the stories plan-halt leg (a + deliberate widening of #61's literal done-only wording). A ``blocked`` + terminal is never rescued: it carries no finished work, and + blocked-plus-nudge-unresponsive is weak evidence of anything. Every + rescue still runs the engine's full deterministic verify downstream, + so a bogus upgrade degrades into an ordinary verify-failed retry. A + cap-exhausted injected-workflow stall whose marker landed before the + kill is rescued by the same trust model.""" + if result.status not in ("stalled", "timeout") or result.result_json is not None: + return result + try: + if self._window_alive(handle): + # The kill silently failed (best-effort teardown): the window + # is still alive, so the live-window invariant still applies. + return result + except MultiplexerError: + return result # liveness unknowable: unknown is not dead + try: + sr = self._synth_result(handle, spec, wait=False) + except (OSError, UnicodeDecodeError): + # An unreadable artifact is not evidence a session finished. This + # hook runs right after run()'s finally-kill — the moment a spec the + # CLI was mid-write is truncated, possibly through a multi-byte UTF-8 + # sequence — so a corrupt read is the *expected* fault here, not an + # anomaly. Keep the verdict: a best-effort rescue must never escalate + # a clean stall/timeout into an exception, which the engine does not + # contain per-task (it fails the whole run). UnicodeDecodeError is a + # ValueError, so both must be named. + return result + if sr is None or sr.result_json is None or not sr.status_consistent: + return result + rj = sr.result_json + if rj.get("escalations") or not ( + rj.get("status") == devcontract.DONE or rj.get("plan_halt") is True + ): + return result + rj["post_kill_reconciled"] = True + return SessionResult( + status="completed", + result_json=rj, + session_id=result.session_id, + transcript_path=result.transcript_path, + ) + # Back-compat alias: the adapter was ``GenericTmuxAdapter`` before tmux moved # behind the multiplexer seam. Keeps existing imports stable. diff --git a/src/bmad_loop/devcontract.py b/src/bmad_loop/devcontract.py index c1b3d3b..c537ecd 100644 --- a/src/bmad_loop/devcontract.py +++ b/src/bmad_loop/devcontract.py @@ -174,6 +174,25 @@ class SynthResult: status_consistent: bool +def _read_text_or_empty(path: Path) -> str: + """Read a spec on the *read-back* path, degrading an unreadable file to "". + + An absent, binary/truncated, or unreadable spec carries no parseable result + section, so it reads exactly like a spec that has not terminated yet — the + caller then waits, nudges, or keeps its verdict. Never a crash: this runs on + the observation path, where the orchestrator's job is to classify what it + finds, not to trust it. (UnicodeDecodeError is a ValueError, not an OSError.) + + The *repair* path deliberately does the opposite — `reset_spec_status` and + `strip_auto_run_result` let an unreadable spec raise, because silently + skipping a rewrite leaves the spec in a state the caller believes it fixed. + """ + try: + return path.read_text(encoding="utf-8") + except (OSError, UnicodeDecodeError): + return "" + + def synthesize_result( spec_path: Path, *, @@ -207,9 +226,7 @@ def synthesize_result( """ fm = read_frontmatter(spec_path) fm_status = str(fm.get("status", "")).strip().lower() - arr = parse_auto_run_result( - spec_path.read_text(encoding="utf-8") if spec_path.is_file() else "" - ) + arr = parse_auto_run_result(_read_text_or_empty(spec_path)) terminal = (DONE, BLOCKED, PLAN_HALT_STATUS) if plan_halt else (DONE, BLOCKED) # Not terminal yet: no result section AND frontmatter not at a terminal state. @@ -284,7 +301,11 @@ def find_result_artifact(impl_artifacts: Path, *, since_ns: int) -> Path | None: if not path.name.startswith(FALLBACK_RESULT_PREFIX): try: text = path.read_text(encoding="utf-8") - except OSError: + except (OSError, UnicodeDecodeError): + # A binary/truncated candidate cannot be shown to carry a terminal + # section, so it does not qualify — skip it exactly like an + # unreadable one. UnicodeDecodeError is a ValueError, so a bare + # `except OSError` let a torn mid-write spec crash the scan. continue if not _section_headings(text): continue diff --git a/src/bmad_loop/engine.py b/src/bmad_loop/engine.py index 1a8dc9d..799e129 100644 --- a/src/bmad_loop/engine.py +++ b/src/bmad_loop/engine.py @@ -2066,6 +2066,10 @@ def _run_session( self.journal.set_active_log(task_id) self.journal.append("session-start", task_id=task_id, role=role, prompt=prompt) result = adapter.run(spec) + # A post-kill rescue (#61) is otherwise indistinguishable from a normal + # completion in the journal; leave a breadcrumb for forensics. + if result.result_json is not None and result.result_json.get("post_kill_reconciled"): + self.journal.append("session-rescued-post-kill", task_id=task_id, role=role) # Only dev/review sessions are resumable — `_resumable_session` matches # exactly those task ids under DEV_RUNNING/REVIEW_RUNNING. For everything # else (triage/sweep, labeled plugin-workflow sessions) the payload is diff --git a/tests/test_devcontract.py b/tests/test_devcontract.py index 4f3fe95..4ba2f31 100644 --- a/tests/test_devcontract.py +++ b/tests/test_devcontract.py @@ -1,5 +1,6 @@ """Tests for the generic bmad-dev-auto -> result.json translation shim.""" +import os from pathlib import Path import pytest @@ -339,6 +340,43 @@ def test_find_artifact_ignores_heading_in_longer_outer_fence(tmp_path): assert devcontract.find_result_artifact(tmp_path, since_ns=0) is None +# The read-back decodes artifacts as UTF-8. A spec truncated mid-write (the CLI +# was killed) can end inside a multi-byte sequence; `read_text(encoding="utf-8")` +# then raises UnicodeDecodeError — a ValueError, NOT an OSError. +_BAD_UTF8 = b"\xff\xfe\x00\x01 not utf-8 \x80\x81" + + +def test_find_artifact_skips_non_utf8_spec(tmp_path): + """A binary/truncated candidate cannot be shown to carry a terminal section, so + it does not qualify — and must be skipped, not raised on, even though it is the + newest file. An older qualifying spec still wins.""" + good = tmp_path / "spec-1-1-a.md" + good.write_text("---\nstatus: done\n---\n\n## Auto Run Result\n\nStatus: done\n") + torn = tmp_path / "spec-1-1-b.md" + torn.write_bytes(_BAD_UTF8) + os.utime(good, ns=(1_000_000_000, 1_000_000_000)) + os.utime(torn, ns=(2_000_000_000, 2_000_000_000)) # newest, but unreadable + assert devcontract.find_result_artifact(tmp_path, since_ns=0) == good + + +def test_find_artifact_skips_only_candidate_when_non_utf8(tmp_path): + (tmp_path / "spec-1-1-a.md").write_bytes(_BAD_UTF8) + assert devcontract.find_result_artifact(tmp_path, since_ns=0) is None + + +def test_synthesize_result_non_utf8_fallback_marker_is_not_terminal(tmp_path): + """The no-spec fallback marker is matched by NAME, so the finder hands it back + without ever reading it — the decode fault lands here instead. An unreadable + spec carries no parseable result, so it reads exactly like one that has not + terminated yet: no result_json, no crash.""" + marker = tmp_path / "bmad-dev-auto-result-unclear-1234.md" + marker.write_bytes(_BAD_UTF8) + assert devcontract.find_result_artifact(tmp_path, since_ns=0) == marker + sr = devcontract.synthesize_result(marker, story_key="1-1") + assert sr.result_json is None + assert sr.status_consistent is True + + # ----------------------------------------------------------- reset_spec_status diff --git a/tests/test_engine.py b/tests/test_engine.py index 1d16e3b..47a6e95 100644 --- a/tests/test_engine.py +++ b/tests/test_engine.py @@ -570,6 +570,35 @@ def test_happy_path(project): assert adapter.sessions[1].prompt.startswith("/bmad-dev-auto ") +def test_post_kill_rescued_result_flows_and_journals(project): + """A result rescued by the adapter's post-kill reconcile (#61) reaches the + engine as an ordinary completed result — it must flow the completed path + (reconcile/verify/commit) unchanged, with the extra breadcrumb key riding + along harmlessly — plus one forensic journal entry, since the rescue is + otherwise indistinguishable from a live completion.""" + write_sprint(project, {"epic-1": "backlog", "1-1-a": "ready-for-dev"}) + + inner = dev_effect(project, "1-1-a", followup_review=False) + + def rescued_dev(spec): + result = inner(spec) + # what GenericDevAdapter._post_kill_reconcile returns: a synthesized + # result (status included) stamped with the rescue breadcrumb + result.result_json["status"] = "done" + result.result_json["post_kill_reconciled"] = True + return result + + engine, _ = make_engine(project, [rescued_dev]) + summary = engine.run() + + assert summary.done == 1 and summary.deferred == 0 and not summary.paused + task = engine.state.tasks["1-1-a"] + assert task.phase == Phase.DONE + assert task.commit_sha and task.commit_sha != task.baseline_commit + kinds = [e["kind"] for e in engine.journal.entries()] + assert "session-rescued-post-kill" in kinds + + def test_inplace_ready_gate_veto_defers_before_any_session(project): """A plugin gating pre_ready_gate in non-isolated (in-place) mode — e.g. a shared-mode Unity engine waiting on the live Editor — defers the unit via the diff --git a/tests/test_generic_tmux.py b/tests/test_generic_tmux.py index 925bc43..57bdf0b 100644 --- a/tests/test_generic_tmux.py +++ b/tests/test_generic_tmux.py @@ -28,6 +28,11 @@ HAVE_TMUX = sys.platform != "win32" and shutil.which("tmux") is not None +# The read-back decodes artifacts as UTF-8. A spec truncated mid-write (the CLI was +# killed) can end inside a multi-byte sequence; `read_text(encoding="utf-8")` then +# raises UnicodeDecodeError — a ValueError, NOT an OSError. +_BAD_UTF8 = b"\xff\xfe\x00\x01 not utf-8 \x80\x81" + FAKE_CLI = """#!/bin/bash # fake CLI: last positional arg is the prompt; env comes from tmux -e prompt="${@: -1}" @@ -355,6 +360,23 @@ def test_generic_dev_fallback_done_marker_frontmatter_only(tmp_path): assert rj["status"] == "done" +def test_scan_readback_non_utf8_spec_returns_none(tmp_path): + """The scan-path twin of the stories read-back guard: a binary/truncated spec + (or a torn glimpse of one still being written) degrades to a result-less + read-back on the Stop path too, so the session nudges/stalls instead of + crashing the run. find_result_artifact's `except OSError` never caught this.""" + adapter, impl = make_dev_adapter(tmp_path) + (impl / "spec-3-1-foo.md").write_bytes(_BAD_UTF8) + assert adapter._result_json(_dev_handle(), _dev_spec(tmp_path), wait=False) is None + + +def test_scan_readback_non_utf8_fallback_marker_returns_none(tmp_path): + """The fallback marker is name-matched, so it reaches synthesize_result unread.""" + adapter, impl = make_dev_adapter(tmp_path) + (impl / "bmad-dev-auto-result-3-1-dev-1.md").write_bytes(_BAD_UTF8) + assert adapter._result_json(_dev_handle(), _dev_spec(tmp_path), wait=False) is None + + def test_generic_dev_ignores_pre_launch_artifact(tmp_path, monkeypatch): """A spec left by a prior cycle (mtime below the launch floor) is not this session's output and must not be read as a stale completion.""" @@ -513,7 +535,7 @@ def test_stories_readback_non_utf8_spec_returns_none(tmp_path): adapter, _ = make_dev_adapter(tmp_path) d = tmp_path / "epic" / "stories" d.mkdir(parents=True, exist_ok=True) - (d / "1-slug.md").write_bytes(b"\xff\xfe\x00\x01 not utf-8 \x80\x81") + (d / "1-slug.md").write_bytes(_BAD_UTF8) assert adapter._result_json(_dev_handle(), _stories_spec(tmp_path), wait=False) is None @@ -1080,6 +1102,278 @@ def script(call_n): assert sent == [generic.STALL_NUDGE_TEXT] # the cap was already exhausted +# ----------------------------------------------- post-kill reconcile (#61) +# +# A session that finished its work but lost its final Stop ends "stalled" +# (nudge-unresponsive under a live window), or "timeout" when no hook event +# ever arrived (total hook loss never arms the stall grace). Both verdicts +# discard the on-disk result — correctly, at verdict time, because the window +# was alive to distrust. run()'s finally-kill settles that question: +# _post_kill_reconcile re-probes and, on a provably dead window, re-runs the +# read-back and rescues a self-consistent successful terminal. These drive the +# hook in isolation, plus through run() for the kill-before-scan ordering. + +_DONE_SPEC = ( + "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" + "## Auto Run Result\n\nStatus: done\nImplemented.\n" +) + + +def _unvouched(status="stalled") -> SessionResult: + return SessionResult(status=status, session_id="sess", transcript_path="/t.jsonl") + + +def test_post_kill_reconcile_rescues_consistent_done_artifact(tmp_path): + adapter, impl = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: False + (impl / "spec-3-1-foo.md").write_text(_DONE_SPEC) + result = adapter._post_kill_reconcile(_dev_handle(), _dev_spec(tmp_path), _unvouched()) + assert result.status == "completed" + assert result.result_json["status"] == "done" + assert result.result_json["post_kill_reconciled"] is True + # the stall verdict's identity is preserved on the rescued result + assert result.session_id == "sess" + assert result.transcript_path == "/t.jsonl" + + +def test_post_kill_reconcile_rescues_timeout(tmp_path): + """Total hook loss (misconfigured hooks, events-dir write failure) never arms + the stall grace — the session exits `timeout` with no artifact check at all. + The same post-kill rescue must cover it.""" + adapter, impl = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: False + (impl / "spec-3-1-foo.md").write_text(_DONE_SPEC) + result = adapter._post_kill_reconcile(_dev_handle(), _dev_spec(tmp_path), _unvouched("timeout")) + assert result.status == "completed" + assert result.result_json["post_kill_reconciled"] is True + + +def test_post_kill_reconcile_leaves_other_statuses_alone(tmp_path): + """completed and crashed already had their artifact read at verdict time; + the hook must not touch them (nor re-scan for a completed result).""" + adapter, impl = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: False + (impl / "spec-3-1-foo.md").write_text(_DONE_SPEC) + for status in ("completed", "crashed"): + original = _unvouched(status) + assert ( + adapter._post_kill_reconcile(_dev_handle(), _dev_spec(tmp_path), original) is original + ) + + +def test_post_kill_reconcile_keeps_stall_when_window_alive_after_kill(tmp_path): + """kill_window is best-effort; a window that survived it is still live, so the + live-window invariant (#48/#53) still applies — no rescue.""" + adapter, impl = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: True + (impl / "spec-3-1-foo.md").write_text(_DONE_SPEC) + original = _unvouched() + result = adapter._post_kill_reconcile(_dev_handle(), _dev_spec(tmp_path), original) + assert result is original + assert result.status == "stalled" + assert result.result_json is None + + +def test_post_kill_reconcile_probe_error_keeps_stall(tmp_path): + """A transport failure on the post-kill probe means liveness is unknowable — + and unknown is not dead (tri-state): never upgrade on a guess.""" + adapter, impl = make_dev_adapter(tmp_path) + + def boom(handle): + raise MultiplexerError("tmux hang") + + adapter._window_alive = boom + (impl / "spec-3-1-foo.md").write_text(_DONE_SPEC) + original = _unvouched() + assert adapter._post_kill_reconcile(_dev_handle(), _dev_spec(tmp_path), original) is original + + +def test_post_kill_reconcile_inconsistent_status_keeps_stall(tmp_path): + """Frontmatter and prose actively disagreeing is exactly the low-trust state + the stricter-than-crash gate exists for: keep the stall verdict.""" + adapter, impl = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: False + (impl / "spec-3-1-foo.md").write_text( + "---\nstatus: done\n---\n\n## Auto Run Result\n\nStatus: in-progress\n" + ) + original = _unvouched() + assert adapter._post_kill_reconcile(_dev_handle(), _dev_spec(tmp_path), original) is original + + +def test_post_kill_reconcile_blocked_artifact_keeps_stall(tmp_path): + """A blocked terminal carries no finished work to preserve, and blocked-plus- + nudge-unresponsive is weak evidence — not rescued.""" + adapter, impl = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: False + (impl / "spec-3-1-foo.md").write_text( + "---\nstatus: blocked\n---\n\n## Auto Run Result\n\nStatus: blocked\nStuck.\n" + ) + original = _unvouched() + assert adapter._post_kill_reconcile(_dev_handle(), _dev_spec(tmp_path), original) is original + + +def test_post_kill_reconcile_no_artifact_keeps_stall(tmp_path): + adapter, _ = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: False + original = _unvouched() + assert adapter._post_kill_reconcile(_dev_handle(), _dev_spec(tmp_path), original) is original + + +def test_post_kill_reconcile_ignores_pre_launch_artifact(tmp_path): + """The launch floor still applies: a terminal spec predating this session is a + stale prior artifact, not evidence this session finished.""" + adapter, impl = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: False + spec_file = impl / "spec-3-1-foo.md" + spec_file.write_text(_DONE_SPEC) + handle = _dev_handle(launched_ns=spec_file.stat().st_mtime_ns + 1) + original = _unvouched() + assert adapter._post_kill_reconcile(handle, _dev_spec(tmp_path), original) is original + + +# ---- corrupt / unreadable artifacts: the rescue must never make things worse. +# +# The hook is the one path guaranteed to read a file immediately after run()'s +# finally-kill — precisely when a spec the CLI was mid-write is truncated, quite +# possibly through a multi-byte UTF-8 sequence. An escaping exception is NOT +# contained per-task: it unwinds past adapter.run() to the engine's broad +# `except Exception`, which marks the whole RUN crashed and abandons every +# remaining story. So a read fault keeps the original verdict, like every other +# keep-verdict branch. + + +def test_post_kill_reconcile_synth_read_error_keeps_stall(tmp_path, monkeypatch): + """The load-bearing guard, pinned independently of devcontract's internals: + whatever the read-back raises, the hook returns the verdict it was given. + OSError and UnicodeDecodeError share no base class below Exception.""" + adapter, impl = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: False + (impl / "spec-3-1-foo.md").write_text(_DONE_SPEC) + for exc in (OSError("I/O error"), UnicodeDecodeError("utf-8", b"\xff", 0, 1, "invalid")): + + def raising(handle, spec, *, wait, _exc=exc): + raise _exc + + monkeypatch.setattr(adapter, "_synth_result", raising) + original = _unvouched() + assert ( + adapter._post_kill_reconcile(_dev_handle(), _dev_spec(tmp_path), original) is original + ) + + +def test_post_kill_reconcile_non_utf8_scan_artifact_keeps_stall(tmp_path): + """A truncated/binary `spec-*.md` on the mtime-scan path: find_result_artifact + reads it to check for a terminal section, and its `except OSError` never + catches a decode error.""" + adapter, impl = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: False + (impl / "spec-3-1-foo.md").write_bytes(_BAD_UTF8) + original = _unvouched() + assert adapter._post_kill_reconcile(_dev_handle(), _dev_spec(tmp_path), original) is original + + +def test_post_kill_reconcile_non_utf8_fallback_marker_keeps_stall(tmp_path): + """The no-spec fallback marker is matched by NAME, so the finder hands it back + without ever reading it — the decode fault lands in synthesize_result instead. + This is the artifact an injected-workflow session writes, and a `timeout` + verdict reaches this hook having never read anything at all.""" + adapter, impl = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: False + (impl / "bmad-dev-auto-result-3-1-dev-1.md").write_bytes(_BAD_UTF8) + original = _unvouched("timeout") + assert adapter._post_kill_reconcile(_dev_handle(), _dev_spec(tmp_path), original) is original + + +def test_post_kill_reconcile_non_utf8_stories_spec_keeps_stall(tmp_path): + """Stories mode resolves the spec by id, not by scan; the same fault must + degrade to a kept verdict there too.""" + adapter, _ = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: False + d = tmp_path / "epic" / "stories" + d.mkdir(parents=True, exist_ok=True) + (d / "1-slug.md").write_bytes(_BAD_UTF8) + original = _unvouched() + assert ( + adapter._post_kill_reconcile(_dev_handle(), _stories_spec(tmp_path), original) is original + ) + + +def test_post_kill_reconcile_blank_frontmatter_prose_done_rescues(tmp_path): + """status_consistent is "no active disagreement": a blank frontmatter with prose + `done` is exactly what a delivered Stop would have synthesized (the engine's + reconcile repairs the lagging frontmatter downstream) — rescued.""" + adapter, impl = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: False + (impl / "spec-3-1-foo.md").write_text("## Auto Run Result\n\nStatus: done\nDone.\n") + result = adapter._post_kill_reconcile(_dev_handle(), _dev_spec(tmp_path), _unvouched()) + assert result.status == "completed" + assert result.result_json["status"] == "done" + + +def test_post_kill_reconcile_rescues_stories_spec(tmp_path): + adapter, _ = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: False + _write_story_spec( + tmp_path, + "1", + "foo", + "---\nstatus: done\nbaseline_revision: story1base\n---\n\n" + "## Auto Run Result\n\nStatus: done\nImplemented.\n", + ) + result = adapter._post_kill_reconcile(_dev_handle(), _stories_spec(tmp_path), _unvouched()) + assert result.status == "completed" + assert result.result_json["status"] == "done" + assert result.result_json["baseline_commit"] == "story1base" + + +def test_post_kill_reconcile_rescues_stories_plan_halt_leg(tmp_path): + """The plan-halt leg's `ready-for-dev` is a successful terminal (marked + plan_halt, no escalation) — a lost Stop on that leg is rescued too. This + deliberately widens #61's literal done-only wording.""" + adapter, _ = make_dev_adapter(tmp_path) + adapter._window_alive = lambda handle: False + _write_story_spec(tmp_path, "1", "foo", "---\nstatus: ready-for-dev\n---\n\nplan\n") + spec = _stories_spec(tmp_path) + spec.env["BMAD_LOOP_PLAN_HALT"] = "1" + result = adapter._post_kill_reconcile(_dev_handle(), spec, _unvouched()) + assert result.status == "completed" + assert result.result_json["plan_halt"] is True + assert result.result_json["post_kill_reconciled"] is True + + +def test_run_kills_before_the_post_kill_probe(tmp_path): + """run() must tear the window down before the hook probes/scans — the rescue's + trust rests on the kill having settled liveness.""" + adapter, impl = make_dev_adapter(tmp_path) + (impl / "spec-3-1-foo.md").write_text(_DONE_SPEC) + order = [] + adapter.start_session = lambda spec: _dev_handle() + adapter.wait_for_completion = lambda handle, spec: _unvouched() + adapter.kill = lambda handle: order.append("kill") + adapter._window_alive = lambda handle: (order.append("probe"), False)[1] + result = adapter.run(_dev_spec(tmp_path)) + assert order == ["kill", "probe"] + assert result.status == "completed" + + +def test_run_exception_kills_without_reconcile(tmp_path): + """A raising wait_for_completion (e.g. RunStopped) must still kill the window + and propagate — the hook only runs on the normal return path.""" + adapter, _ = make_dev_adapter(tmp_path) + calls = [] + adapter.start_session = lambda spec: _dev_handle() + + def raising_wait(handle, spec): + raise RuntimeError("stop requested") + + adapter.wait_for_completion = raising_wait + adapter.kill = lambda handle: calls.append("kill") + adapter._post_kill_reconcile = lambda handle, spec, result: calls.append("hook") + with pytest.raises(RuntimeError, match="stop requested"): + adapter.run(_dev_spec(tmp_path)) + assert calls == ["kill"] + + def test_wait_for_completion_tolerates_transient_liveness_probe_failure(tmp_path, monkeypatch): """A transient transport hang (the liveness probe raising MultiplexerError, e.g. a 30s tmux hang) must never be read as a dead window -> crash. The tick is @@ -1353,3 +1647,55 @@ def test_tmux_crash_detected(tmp_path): subprocess.run(["tmux", "kill-session", "-t", adapter.session_name], capture_output=True) assert result.status == "crashed" assert result.result_json is None + + +@pytest.mark.skipif(not HAVE_TMUX, reason="tmux not available") +def test_tmux_timeout_with_flushed_spec_rescued_post_kill(tmp_path): + """End-to-end #61 (total hook loss): the session writes its terminal spec but + never emits any hook event, so the wait loop idles to `timeout` — a path that + never arms the stall grace and checks no artifact. run()'s real kill then + settles liveness, and the post-kill reconcile rescues the finished work + through a real tmux probe + scan.""" + impl = tmp_path / "impl" + impl.mkdir() + fake = tmp_path / "fake-cli" + fake.write_text( + "#!/bin/bash\n" + "# finished work, but hooks are 'misconfigured': no event files at all\n" + f"printf -- '---\\nstatus: done\\nbaseline_revision: abc123\\n---\\n\\n" + f"## Auto Run Result\\n\\nStatus: done\\nImplemented.\\n' > {impl}/spec-3-1-foo.md\n" + "sleep 60 # stay alive so the wait loop times out under a live window\n" + ) + fake.chmod(0o755) + adapter = GenericDevAdapter( + run_dir=tmp_path / f"run-{uuid.uuid4().hex[:8]}", + policy=Policy(limits=LimitsPolicy()), + profile=get_profile("claude"), + binary=str(fake), + extra_args=(), + paths=ProjectPaths( + project=tmp_path, + implementation_artifacts=impl, + planning_artifacts=tmp_path / "plan", + ), + ) + spec = SessionSpec( + task_id="t-rescue", + role="dev", + prompt="/bmad-dev-auto 3-1", + cwd=tmp_path, + env={ + "BMAD_LOOP_RUN_DIR": str(adapter.run_dir), + "BMAD_LOOP_TASK_ID": "t-rescue", + "BMAD_LOOP_STORY_KEY": "3-1", + }, + timeout_s=6.0, + ) + try: + result = adapter.run(spec) + finally: + subprocess.run(["tmux", "kill-session", "-t", adapter.session_name], capture_output=True) + + assert result.status == "completed" + assert result.result_json["status"] == "done" + assert result.result_json["post_kill_reconciled"] is True diff --git a/tests/test_stories_e2e.py b/tests/test_stories_e2e.py index e7bcbef..ee4d230 100644 --- a/tests/test_stories_e2e.py +++ b/tests/test_stories_e2e.py @@ -5,7 +5,7 @@ reproducible. The fake fakes both the CLI and its Stop hook (it writes the SessionStart/Stop event files itself), so no `bmad-loop init` is needed; it leaves the id-keyed story spec on disk and the `GenericDevAdapter` synthesizes -the result from it (`_stories_result_json`, keyed on `BMAD_LOOP_SPEC_FOLDER`). +the result from it (`_stories_synth_result`, keyed on `BMAD_LOOP_SPEC_FOLDER`). The fake routes on the story spec's frontmatter status, like `bmad-dev-auto` step-01: no spec / `ready-for-dev` → implement to `done`; `BMAD_LOOP_PLAN_HALT`