From 5b0d2eadf3faf2349c7b0208e29518170c1368b6 Mon Sep 17 00:00:00 2001 From: pbean Date: Fri, 24 Jul 2026 20:13:50 -0700 Subject: [PATCH 1/8] fix(adapters,engine): pin the read-back to the spec the session owes (#261) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Closes #261. The generic dev/review read-back located "the artifact this session produced" by scanning the implementation-artifacts dir for the most-recently-modified qualifying *.md, with nothing tying the match to the story being driven. That dir is shared: under worktree isolation the search also covers the main checkout's copy, and with isolation="none" it IS that copy. A foreign story's spec landing there after launch (a concurrent run's merge-back, a human edit, a sweep) won on mtime and became this session's result — a review that produced nothing was scored completed:done and merged unreviewed code, and on the dev leg its followup_review_recommended: false skipped the review entirely. Unlike the rest of this family (#88/#127/#160/#224) it failed toward LANDING bad work. Part 1 — authoritative-path read-back. Where the orchestrator already knows which spec the session owes (every review leg and every dev retry, via StoryTask.spec_file — the path it hands the session in its own prompt), SessionSpec.expected_spec pins the read-back to that one file and the scan is never reached. Fix by subtraction: stories mode already resolved by id rather than mtime, so this closes an asymmetry. The #224 missing-marker fallback (a second mtime-only scan of the same shared dir, added after the issue was filed) goes through the same seam via its new `only` parameter. devcontract keeps its semantics; find_result_artifact / find_frontmatter_candidates are refactored onto per-path predicates (is_result_artifact / is_frontmatter_candidate) so a caller holding the owed path can test one file instead of a directory. Deliberately NOT a filename/story-key rule: spec names come from an LLM-derived slug, so a prefix check risks trading this unsafe failure for a lossy one — and a pinned path needs no exemption for the bmad-dev-auto-result-* fallback or for sweep bundles, which legitimately adopt a differently-named story spec (#161). Withheld from injected plugin-workflow sessions, which owe the completion marker rather than the story spec. A dev attempt 1 has no recorded spec and keeps the scan. Part 2 — proof-of-work gate. A read-back artifact may no longer upgrade a dead session to completed when it shows no evidence it ran at all: no hook event arrived AND its pane log never grew past PROOF_OF_WORK_MIN_LOG_BYTES. The two signals are ORed because each has a blind spot (a misbound pane sink still fires hooks (#254/#217); a hook-less profile still logs), and no signal at all leaves the gate inert (unknown never blocks). Applies to the crash path and to _post_kill_reconcile — the call path the issue's second occurrence took — and journals readback-refused-no-proof-of-work. The floor is not zero: the report's wedged windows left 0-byte AND 2-byte logs. test_tmux_timeout_with_flushed_spec_rescued_post_kill's fake CLI now renders to its pane before writing the spec. Measured, the silent fake produced a 0-byte log with zero hook events — byte-identical to the wedge this issue is about, so it was unfaithful to the #61 scenario it stands for (that run logged 1.4 MB). Its new companion, test_tmux_timeout_silent_session_not_rescued, pins the complementary refusal on the same call path. --- CHANGELOG.md | 27 +++ src/bmad_loop/adapters/base.py | 19 ++ src/bmad_loop/adapters/generic.py | 167 ++++++++++++++- src/bmad_loop/devcontract.py | 92 +++++--- src/bmad_loop/engine.py | 17 ++ tests/test_engine.py | 21 ++ tests/test_generic_tmux.py | 345 +++++++++++++++++++++++++++++- 7 files changed, 651 insertions(+), 37 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index dcad42f3..d585b5d8 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -90,6 +90,33 @@ breaking changes may land in a minor release. ### Fixed +- **A session's read-back could adopt another story's spec (#261).** The generic dev/review + read-back located "the artifact this session produced" by scanning the implementation-artifacts + dir for the most-recently-modified qualifying `*.md`, with nothing tying the match to the story + being driven. That dir is shared: under worktree isolation the search also covers the main + checkout's copy, and with `isolation="none"` it _is_ that copy. A foreign story's spec landing + there after launch — a concurrent run's merge-back, a human edit, a sweep — won on mtime and + became this session's result, so a review that produced nothing was scored `completed:done` + (merging unreviewed code) and, on the dev leg, its `followup_review_recommended: false` skipped + the review entirely. Unlike the rest of this family (#88/#127/#160/#224) it failed toward + _landing_ unverified work. Two fixes, both in the adapter: + - **Authoritative-path read-back.** Where the orchestrator already knows which spec the session + owes — every review leg and every dev retry, via `StoryTask.spec_file`, the path it hands the + session in its own prompt — `SessionSpec.expected_spec` pins the read-back to that one file and + the directory scan is never reached. This closes the asymmetry with stories mode, which already + resolved by id rather than by mtime, and covers the #224 missing-marker fallback (a second + mtime-only scan of the same shared dir) through the same seam. Deliberately not a filename + rule: spec names come from an LLM-derived slug, so a prefix check risks trading this unsafe + failure for a lossy one — and a pinned path needs no exemption for the `bmad-dev-auto-result-*` + fallback or for sweep bundles, which legitimately adopt a differently-named story spec (#161). + A dev attempt 1 has no recorded spec yet and keeps the scan. + - **Proof-of-work gate.** A read-back artifact may no longer upgrade a dead session to + `completed` when that session shows no evidence it ran at all — no hook event arrived _and_ its + pane log never grew past a small floor. The two signals are ORed because each has a blind spot + (a misbound pane sink still fires hooks; a hook-less profile still logs), and no signal at all + leaves the gate inert. Applies to both the crash path and `_post_kill_reconcile`, and journals + `readback-refused-no-proof-of-work`. + - **`validate` requires the review skills your `bmad-dev-auto` actually invokes (#260).** The preflight held every project to a fixed catalog that included `bmad-review-verification-gap`, which no tagged BMAD-METHOD release ships (absent from v6.10.0; on current sources only a diff --git a/src/bmad_loop/adapters/base.py b/src/bmad_loop/adapters/base.py index a13b7890..1420a876 100644 --- a/src/bmad_loop/adapters/base.py +++ b/src/bmad_loop/adapters/base.py @@ -83,6 +83,25 @@ class SessionSpec: # every non-review session and on a crash-resume (process-transient — see # SpecSnapshot). Kept LAST so positional SessionSpec constructions stay valid. spec_snapshot: SpecSnapshot | None = None + # The spec path this session is REQUIRED to write, when the orchestrator + # already knows it (#261): `StoryTask.spec_file`, recorded by verify_dev / + # verify_dev_bundle on dev success and handed to the review session in its own + # prompt. Set for every leg with a recorded spec — always a review, and a dev + # retry — and None on a dev attempt 1, whose spec does not exist yet. + # + # When set, the generic adapter reads back from THIS path instead of scanning + # the implementation-artifacts dir for the newest qualifying `*.md`. That scan + # is shared with every concurrent run: a foreign story's spec landing there + # after launch (a merge-back into the main checkout, a human edit, a sweep) + # wins on mtime and is adopted as this session's result, so a review that + # produced nothing is scored `completed:done` and unreviewed code merges. + # + # Deliberately independent of `spec_snapshot`, which degrades to None on a torn + # read: the identity constraint must not silently disappear with it. Process- + # transient for the same reason as SpecSnapshot (not persisted); a crash-resume + # reconstructing the SessionSpec carries none and falls back to the scan. Kept + # LAST alongside spec_snapshot so positional constructions stay valid. + expected_spec: str | None = None @dataclass(frozen=True) diff --git a/src/bmad_loop/adapters/generic.py b/src/bmad_loop/adapters/generic.py index ce28585e..8d3f7878 100644 --- a/src/bmad_loop/adapters/generic.py +++ b/src/bmad_loop/adapters/generic.py @@ -67,6 +67,14 @@ # a session mid-edit cannot produce. A dead window skips the counter entirely: # the kill settled liveness, so the frontmatter is as final as it will ever get. FM_FALLBACK_MIN_OBS = 2 +# Proof-of-work gate (#261): pane-log size, in bytes, above which a session counts +# as having produced SOMETHING — the floor a dead session must clear before a +# read-back artifact may upgrade its verdict to `completed`. Not zero: the three +# wedged sessions in #261 left logs of 0 and 2 bytes, so `size > 0` would have +# cleared one of them. Any session that reached the agent loop echoes at least its +# own prompt (hundreds of bytes) into the pane, and a real one logs megabytes, so +# this sits far below a genuine session and far above a wedge. +PROOF_OF_WORK_MIN_LOG_BYTES = 256 class _SnapVerdict(enum.Enum): @@ -187,6 +195,35 @@ def _result_json(self, handle: SessionHandle, spec: SessionSpec, *, wait: bool) on-disk artifact.""" return self._await_result(handle.task_id) if wait else self._read_result(handle.task_id) + def _produced_work( + self, handle: SessionHandle, session_id: str | None, transcript: str | None + ) -> bool: + """Whether this session shows ANY evidence it actually ran, for the #261 + proof-of-work gate. Deliberately a very low bar — it separates "the CLI + wedged before it did anything" from "the CLI worked", not good work from bad. + + Two independent signals, ORed, because each has a known blind spot: + a hook event having arrived (``session_id``/``transcript`` are populated only + from one) covers an adapter whose pane sink is misbound (#254/#217, where a + HEALTHY session still logs zero bytes), and pane-log growth covers a profile + whose hooks never fire. Requiring both to be absent is what makes the gate + safe to apply to a `completed` upgrade. + + Unknown never blocks: `_log_evidence` returns None when there is no signal at + all (no pane log — the opencode-http transport, and every unit-test fixture), + and that reads as evidence-present, preserving current behavior exactly.""" + if session_id or transcript: + return True + evidence = self._log_evidence(handle) + return True if evidence is None else evidence + + def _log_evidence(self, handle: SessionHandle) -> bool | None: + """Tristate pane-log proof-of-work signal: True = the log grew past a + trivial floor, False = the log exists and did not, None = no such signal for + this transport. Base: None (inert). Overridden by `GenericAdapter`, which + tees a pane log.""" + return None + def _final( self, handle: SessionHandle, @@ -205,6 +242,21 @@ def _final( ``budget_weighted`` (a tripped session-budget guard's sample) rides every exit so the engine can journal it whatever the verdict.""" result_json = self._result_json(handle, spec, wait=False) if accept_result else None + if result_json is not None and not self._produced_work(handle, session_id, transcript): + # Proof-of-work gate (#261): this session is gone and produced no + # observable output at all — no hook event ever arrived AND its pane log + # never grew. A read-back artifact is then not evidence THIS session + # finished; it is evidence that SOMETHING wrote a qualifying file in a + # directory we share. Keep the fallback verdict rather than upgrade a + # dead-on-arrival session to `completed`. + self._note_lifecycle( + handle.task_id, + "readback-refused-no-proof-of-work", + fallback=fallback, + spec=str(result_json.get("spec_file", "")), + status=str(result_json.get("status", "")), + ) + result_json = None status = "completed" if result_json is not None else fallback return SessionResult( status=status, @@ -779,6 +831,23 @@ def wait_for_completion(self, handle: SessionHandle, spec: SessionSpec) -> Sessi budget_weighted=budget_weighted, ) + def _log_evidence(self, handle: SessionHandle) -> bool | None: + """Pane-log half of the #261 proof-of-work gate (see + `_ResultFileMixin._produced_work`). The pane is tee'd to a stable inode, so + its size is a direct measure of how much the session emitted. + + None when the log does not exist — no signal, and the gate stays inert. + Otherwise True iff the log exceeded `PROOF_OF_WORK_MIN_LOG_BYTES`. The floor + is not zero on purpose: the wedged sessions in #261 left 0-byte AND 2-byte + logs, so `size > 0` would have missed one of them. Any session that reached + the agent loop echoes at least its own (multi-hundred-byte) prompt into the + pane, so the floor sits far below a real session and far above a wedge.""" + try: + size = (self.logs_dir / f"{handle.task_id}.log").stat().st_size + except OSError: + return None + return size > PROOF_OF_WORK_MIN_LOG_BYTES + def _log_activity_key(self, task_id: str) -> tuple[int, int] | None: """Activity signature of the tee'd pane log: (mtime_ns, size), or None if it does not yet exist. The pane is piped via append to a stable inode, so @@ -1116,6 +1185,18 @@ def _synth_result( # frontmatter-authoritative, so it needs no missing-marker fallback.) if spec.env.get("BMAD_LOOP_SPEC_FOLDER"): return self._stories_synth_result(handle, spec, wait=wait) + # Authoritative-path read-back (#261): when the orchestrator already knows + # which spec this session owes — every review leg and every dev retry, see + # SessionSpec.expected_spec — read THAT file and never the directory scan + # below. The scan asks "what is the newest qualifying *.md here" of a + # directory shared with every concurrent run; the question is "what did THIS + # session write for THIS story", and here we were told the answer at launch. + if spec.expected_spec: + return self._known_spec_synth_result( + handle, spec, Path(spec.expected_spec), wait=wait, dead_window=dead_window + ) + # Dev attempt 1 only: no spec exists yet (the skill creates it), so the + # mtime-floor scan is the sole way to find it. # 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. @@ -1132,6 +1213,44 @@ def _synth_result( ) time.sleep(RESULT_POLL_S) + def _known_spec_synth_result( + self, + handle: SessionHandle, + spec: SessionSpec, + path: Path, + *, + wait: bool, + dead_window: bool, + ) -> devcontract.SynthResult | None: + """Read back from the ONE spec the session was required to write (#261). + + Structurally the scan path with the candidate source replaced: poll the + marker predicate on this single file over the same ``RESULT_GRACE_S`` flush + window, then hand the same file to the missing-marker fallback (#224) via + its ``only`` seam, so the stability fingerprint, the M2 transition + observation and the M1 launch-snapshot gate all still apply — scoped to the + one legitimate path instead of a shared directory. + + No launch-snapshot gate is needed on the marker branch itself: the + pre-review-launch strip (`Engine._reset_spec_for_review`) REMOVES the + marker, so a spec carrying one again has necessarily changed bytes since the + snapshot and the gate would be a no-op (`_snapshot_verdict` → NEUTRAL). + + Note this deliberately does NOT fall back to the scan when the expected spec + yields nothing: a session that did not write the spec it owed produced no + result, and any other qualifying file in that directory belongs to someone + else. Returning None routes to the dev-stall grace / crashed verdict — the + safe direction, and the verdict the two control stories in #261 received.""" + deadline = time.monotonic() + RESULT_GRACE_S + while True: + if devcontract.is_result_artifact(path, since_ns=handle.launched_ns): + return self._synthesize_from(path, spec) + if not wait or time.monotonic() >= deadline: + return self._frontmatter_fallback( + handle, spec, [], wait=wait, dead_window=dead_window, only=path + ) + time.sleep(RESULT_POLL_S) + def _synthesize_from(self, spec_path: Path, spec: SessionSpec) -> devcontract.SynthResult: """Shared synthesis call for the marker scan and the missing-marker fallback, so both stamp the session's story key and — for bundle dev @@ -1222,6 +1341,7 @@ def _frontmatter_fallback( *, wait: bool, dead_window: bool, + only: Path | None = None, ) -> devcontract.SynthResult | None: """Missing-marker rescue (#224): synthesize from a spec this session finalized to a terminal frontmatter ``status:`` without appending the @@ -1279,13 +1399,33 @@ def _frontmatter_fallback( touching no stall counters, so an mtime bump that resets ``observations`` to 1 never re-nudges. A compliant append is harvested by the ordinary marker scan on a later Stop, leaving synthesis as the backstop. + + ``only`` (#261) replaces the directory scan with the single spec the + orchestrator knows this session owed: the candidate set becomes that file + if it qualifies, else empty, and ``search_dirs`` is unused. Every gate + below is unchanged — the point is purely that a foreign story's + marker-less terminal spec, sitting in the same shared artifacts dir, is no + longer a candidate at all, so the "refuse to guess between several" branch + becomes unreachable. """ task_id = handle.task_id candidates: list[Path] = [] - for artifacts in search_dirs: - candidates.extend( - devcontract.find_frontmatter_candidates(artifacts, since_ns=handle.launched_ns) - ) + if only is not None: + # Authoritative-path mode (#261): the caller knows the ONE spec this + # session owed, so the candidate set is that file if it qualifies and + # nothing otherwise. `len(candidates) > 1` is unreachable here — the + # "refuse to guess" branch exists for the scan, which cannot know which + # of several specs is this session's; with a known path there is nothing + # to guess between. + if devcontract.is_frontmatter_candidate(only, since_ns=handle.launched_ns): + candidates.append(only) + where = str(only) + else: + for artifacts in search_dirs: + candidates.extend( + devcontract.find_frontmatter_candidates(artifacts, since_ns=handle.launched_ns) + ) + where = ", ".join(str(d) for d in search_dirs) if not candidates: # No marker-less terminal spec either (the common resultless Stop — # e.g. a review that flipped to `in-review` and is mid-work): clear @@ -1295,8 +1435,7 @@ def _frontmatter_fallback( self._note_resultless_stop( task_id, "no-artifact", - "no result artifact newer than session launch under: " - + ", ".join(str(d) for d in search_dirs), + "no result artifact newer than session launch under: " + where, ) return None if len(candidates) > 1: @@ -1606,6 +1745,22 @@ def _post_kill_reconcile( rj.get("status") == devcontract.DONE or rj.get("plan_halt") is True ): return result + # Proof-of-work gate (#261), the same one the crash path applies in `_final`: + # this rescue exists for a session that finished but lost its Stop, not for + # one that never ran. A session with no hook event and a pane log that never + # grew produced nothing, so a qualifying artifact is not its output — keep + # the stall/timeout verdict. This is the call path the issue's second + # occurrence (story i-11) took. + if not self._produced_work(handle, result.session_id, result.transcript_path): + self._note_lifecycle( + handle.task_id, + "readback-refused-no-proof-of-work", + fallback=result.status, + spec=str(rj.get("spec_file", "")), + status=str(rj.get("status", "")), + dead_window=True, + ) + return result rj["post_kill_reconciled"] = True return SessionResult( status="completed", diff --git a/src/bmad_loop/devcontract.py b/src/bmad_loop/devcontract.py index b50e6d44..c46e3bcb 100644 --- a/src/bmad_loop/devcontract.py +++ b/src/bmad_loop/devcontract.py @@ -304,27 +304,41 @@ def find_result_artifact(impl_artifacts: Path, *, since_ns: int) -> Path | None: mtime_ns = path.stat().st_mtime_ns except OSError: continue - if mtime_ns < since_ns: + if not is_result_artifact(path, since_ns=since_ns): continue - # The no-spec fallback is recognized by name (it has no Auto Run Result - # heading); every other artifact must carry a real (non-fenced) terminal - # section — a fence-quoted example must not qualify the spec (#52). - if not path.name.startswith(FALLBACK_RESULT_PREFIX): - try: - text = path.read_text(encoding="utf-8") - 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 if best is None or mtime_ns > best[0]: best = (mtime_ns, path) return best[1] if best else None +def is_result_artifact(path: Path, *, since_ns: int) -> bool: + """Whether ONE file qualifies as a session's result artifact — the per-path + predicate `find_result_artifact` applies to each glob hit, factored out so a + caller that already KNOWS which spec the session owed (the orchestrator hands + the review session its path in the prompt) can test that one file instead of + scanning a directory shared with every concurrent run (#261). + + Qualifies when the file was modified at/after ``since_ns`` (the session-launch + floor) AND either is the by-name no-spec fallback (`bmad-dev-auto-result-*`, + which carries no heading by design) or carries a real, non-fenced + ``## Auto Run Result`` heading — a fence-quoted example must not qualify the + spec (#52). An unreadable/undecodable candidate cannot be SHOWN to carry a + terminal section, so it does not qualify (UnicodeDecodeError is a ValueError, + so a bare ``except OSError`` let a torn mid-write spec crash the scan).""" + try: + if path.stat().st_mtime_ns < since_ns: + return False + except OSError: + return False + if path.name.startswith(FALLBACK_RESULT_PREFIX): + return True + try: + text = path.read_text(encoding="utf-8") + except (OSError, UnicodeDecodeError): + return False + return bool(_section_headings(text)) + + def find_frontmatter_candidates(impl_artifacts: Path, *, since_ns: int) -> list[Path]: """Missing-marker fallback scan (#224): specs this session finalized to a terminal frontmatter ``status:`` WITHOUT appending the ``## Auto Run Result`` @@ -345,31 +359,49 @@ def find_frontmatter_candidates(impl_artifacts: Path, *, since_ns: int) -> list[ return [] found: list[tuple[int, Path]] = [] for path in impl_artifacts.glob("*.md"): - if path.name.startswith(FALLBACK_RESULT_PREFIX): - continue try: mtime_ns = path.stat().st_mtime_ns except OSError: continue - if mtime_ns < since_ns: - continue - try: - text = path.read_text(encoding="utf-8") - except (OSError, UnicodeDecodeError): - continue - if _section_headings(text): - continue # carries a real marker — the normal scan's territory - try: - fm = read_frontmatter(path) - except OSError: - continue - if str(fm.get("status", "")).strip().lower() not in (DONE, BLOCKED): + if not is_frontmatter_candidate(path, since_ns=since_ns): continue found.append((mtime_ns, path)) found.sort(key=lambda t: t[0], reverse=True) return [p for _, p in found] +def is_frontmatter_candidate(path: Path, *, since_ns: int) -> bool: + """Whether ONE file qualifies for the missing-marker fallback — the per-path + predicate `find_frontmatter_candidates` applies to each glob hit, factored out + for the same reason as `is_result_artifact`: a caller holding the spec path the + session actually owed can test that file alone instead of a shared directory + (#261). + + Qualifies when the file is modified at/after ``since_ns``, is NOT the no-spec + fallback (already matched by name on the marker path), carries ZERO real + (non-fenced) marker headings — one would put it in `find_result_artifact`'s + territory — and has a frontmatter ``status:`` of ``done`` or ``blocked``. Any + unreadable/undecodable read degrades to False, never an exception.""" + if path.name.startswith(FALLBACK_RESULT_PREFIX): + return False + try: + if path.stat().st_mtime_ns < since_ns: + return False + except OSError: + return False + try: + text = path.read_text(encoding="utf-8") + except (OSError, UnicodeDecodeError): + return False + if _section_headings(text): + return False # carries a real marker — the normal scan's territory + try: + fm = read_frontmatter(path) + except OSError: + return False + return str(fm.get("status", "")).strip().lower() in (DONE, BLOCKED) + + def _atomic_write_spec(spec_path: Path, text: str) -> None: """Rewrite ``spec_path`` with ``text`` via a same-directory temp file + atomic rename, so an interrupted / short / disk-full write can never truncate the diff --git a/src/bmad_loop/engine.py b/src/bmad_loop/engine.py index 33e20387..f6b31fa7 100644 --- a/src/bmad_loop/engine.py +++ b/src/bmad_loop/engine.py @@ -2262,6 +2262,23 @@ def _run_session( # Launch-state snapshot of a review session's spec (#276 M1); None for # every other session and on a crash-resume (process-transient). spec_snapshot=spec_snapshot, + # The spec this session is required to write, when already known (#261), + # so the adapter reads THAT path back instead of mtime-scanning a + # directory shared with every concurrent run. Same `_generic_dev()` guard + # as the snapshot above, so the two can never disagree about whether the + # devcontract read-back is in play. + # + # Withheld from an injected plugin-workflow session (`label` set — e.g. a + # TEA pre_commit_gate): it runs the generic adapter but owes the + # WORKFLOW_COMPLETION_CONTRACT marker above, not the story spec, so + # pinning it to task.spec_file would point the read-back at the wrong + # file. Same doctrine as StoriesEngine withholding BMAD_LOOP_SPEC_FOLDER + # from labeled sessions. + expected_spec=( + task.spec_file + if (label is None and self._generic_dev() and task.spec_file) + else None + ), ) self.journal.set_active_log(task_id) self.journal.append( diff --git a/tests/test_engine.py b/tests/test_engine.py index 78703b72..8c358f12 100644 --- a/tests/test_engine.py +++ b/tests/test_engine.py @@ -2142,6 +2142,27 @@ def capturing_review(spec): assert snap.sha256 == captured["digest"] +def test_expected_spec_threaded_onto_review_session(project): + """#261: the engine pins the review session's read-back to the spec it recorded + on dev success — the same path it hands the session in its prompt — so the + adapter never mtime-scans the shared artifacts dir. The dev leg that precedes it + has no recorded spec yet and carries none.""" + write_sprint(project, {"epic-1": "backlog", "1-1-a": "ready-for-dev"}) + engine, adapter = make_engine( + project, + [dev_effect(project, "1-1-a"), review_effect(project, "1-1-a", clean=True)], + ) + summary = engine.run() + + assert summary.done == 1 + dev_spec, review_spec = adapter.sessions + assert dev_spec.role == "dev" and dev_spec.expected_spec is None + assert review_spec.expected_spec == str(spec_path(project, "1-1-a")) + # It must not silently ride on the snapshot, which degrades to None on a torn + # read — the two are captured independently. + assert review_spec.expected_spec == review_spec.spec_snapshot.path + + def test_review_launch_snapshot_degrades_on_unreadable_spec(project): """A spec path that cannot be read degrades the snapshot capture to None and journals `spec-read-failed` at site `review-launch-snapshot`. A directory where diff --git a/tests/test_generic_tmux.py b/tests/test_generic_tmux.py index 5c12462b..43d7f7e8 100644 --- a/tests/test_generic_tmux.py +++ b/tests/test_generic_tmux.py @@ -2896,13 +2896,22 @@ def test_tmux_timeout_with_flushed_spec_rescued_post_kill(tmp_path): 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.""" + through a real tmux probe + scan. + + The fake renders to its pane before writing the spec. That is not decoration: + the #261 proof-of-work gate refuses to upgrade a session that emitted NOTHING + (no hook event AND no pane-log growth), and a CLI that genuinely implemented a + story always renders — the run this test stands in for logged 1.4 MB. A silent + fake would be byte-identical to the wedge #261 is about (0-byte log, zero + events), which is precisely what must NOT be rescued; see the companion + test_tmux_timeout_silent_session_not_rescued.""" 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" + 'for i in $(seq 1 20); do echo "implementing story 3-1: step $i of 20 ..."; done\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" @@ -2942,6 +2951,64 @@ def test_tmux_timeout_with_flushed_spec_rescued_post_kill(tmp_path): assert result.result_json["post_kill_reconciled"] is True +@pytest.mark.skipif(not HAVE_TMUX, reason="tmux not available") +def test_tmux_timeout_silent_session_not_rescued(tmp_path): + """The #261 counterpart of the rescue above, same call path, one delta: the CLI + wedges instantly and renders NOTHING. A qualifying spec still appears in the + shared artifacts dir — here written by a concurrent process, exactly as a + parallel run's merge-back did in the report — and it is newer than launch, so + the mtime scan would adopt it and the post-kill reconcile would score a session + that never ran as `completed:done`. + + Proof-of-work refuses it: no hook event ever arrived AND the pane log never + grew (0 bytes — measured, the same signature as the report's wedged review + windows). The verdict stays `timeout`, which is what the report's two control + stories correctly received.""" + impl = tmp_path / "impl" + impl.mkdir() + fake = tmp_path / "fake-cli" + # Wedges immediately: no output, no events, no writes of its own. + fake.write_text("#!/bin/bash\nsleep 60\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-silent", + 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-silent", + "BMAD_LOOP_STORY_KEY": "3-1", + }, + timeout_s=6.0, + ) + # A FOREIGN story's finished spec lands mid-window (the concurrent merge-back). + (impl / "spec-9-9-someone-elses-story.md").write_text( + "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" + "## Auto Run Result\n\nStatus: done\nImplemented.\n" + ) + try: + result = adapter.run(spec) + finally: + subprocess.run(["tmux", "kill-session", "-t", adapter.session_name], capture_output=True) + + assert result.status == "timeout" + assert result.result_json is None + assert (adapter.logs_dir / "t-silent.log").stat().st_size == 0 + + # ------------------------------- missing-marker fallback (#224) # # A session (in practice: the follow-up review leg) can finalize the spec's @@ -3782,3 +3849,279 @@ def test_wait_loop_contract_nudge_then_skill_appends_marker(tmp_path, monkeypatc assert rj["status"] == "done" assert "synthesized_from_frontmatter" not in rj assert len(sent) == 1 # no second nudge + + +# ------------------------------- authoritative-path read-back (#261) +# +# The read-back located "the artifact this session produced" by scanning the +# implementation-artifacts dir for the newest qualifying `*.md`. Under worktree +# isolation that search also covers the MAIN checkout's dir, which every +# concurrent run shares; with isolation="none" it IS that shared dir. So a +# foreign story's spec landing there after launch (a parallel run's merge-back, +# a human edit, a sweep) won on mtime and was adopted as this session's result: +# a review that produced nothing was scored `completed:done` and unreviewed code +# merged. +# +# Where the orchestrator already knows which spec the session owes — every review +# leg and every dev retry, via StoryTask.spec_file, which it literally hands the +# session in its own prompt — SessionSpec.expected_spec pins the read-back to +# that one file and the scan is never reached. + +_FOREIGN_DONE = ( + "---\nstatus: done\nbaseline_revision: deadbeef\n---\n\n" + "# Someone else's story\n\n## Auto Run Result\n\nStatus: done\nImplemented.\n" +) + + +def _expecting(tmp_path, spec_file: Path, story_key="3-1") -> SessionSpec: + """A review SessionSpec pinned to the spec the orchestrator recorded (#261), + carrying its launch snapshot too — exactly what the engine threads for a + review leg whose story already has a spec_file.""" + return dataclasses.replace( + _snapshotted_spec(tmp_path, spec_file, story_key), expected_spec=str(spec_file) + ) + + +def test_expected_spec_ignores_foreign_marker_spec(tmp_path, monkeypatch): + """The #261 regression, marker path. Our own spec sits stripped of its marker + (the #160 pre-review-launch strip) and the session died without rewriting it; a + FOREIGN story's finished spec is newer. The scan would return the foreign spec + and score it as this story's `done`.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + ours = impl / "spec-3-1-foo.md" + ours.write_text("---\nstatus: done\nbaseline_revision: abc123\n---\n\n# Story\n") + foreign = impl / "spec-9-9-someone-elses-story.md" + foreign.write_text(_FOREIGN_DONE) + os.utime(foreign, ns=(2_000_000_000, 2_000_000_000)) # newest: the scan would win here + + spec = _expecting(tmp_path, ours) + assert adapter._result_json(_dev_handle(), spec, wait=False) is None + # ...and the unpinned spec is exactly what the bug looked like. + assert adapter._result_json(_dev_handle(), _dev_spec(tmp_path), wait=False) is not None + + +def test_expected_spec_never_reaches_the_scan(tmp_path, monkeypatch): + """Structural: with expected_spec set, the directory scan is not merely + out-voted, it is never called.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + + def boom(*a, **k): + raise AssertionError("find_result_artifact must not run with expected_spec set") + + monkeypatch.setattr(generic.devcontract, "find_result_artifact", boom) + monkeypatch.setattr(generic.devcontract, "find_frontmatter_candidates", boom) + ours = impl / "spec-3-1-foo.md" + ours.write_text("---\nstatus: done\n---\n\n# Story\n") + (impl / "spec-9-9-someone-elses-story.md").write_text(_FOREIGN_DONE) + assert adapter._result_json(_dev_handle(), _expecting(tmp_path, ours), wait=False) is None + + +def test_expected_spec_synthesizes_its_own_marker_spec(tmp_path, monkeypatch): + """Over-refusal guard: when THIS session wrote the spec it owed, the pinned + read-back synthesizes exactly as the scan did — and stamps the session's own + story key, not the foreign spec's.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + ours = impl / "spec-3-1-foo.md" + ours.write_text("---\nstatus: done\nbaseline_revision: abc123\n---\n\n# Story\n") + spec = _expecting(tmp_path, ours) # snapshot taken of the stripped spec + (impl / "spec-9-9-someone-elses-story.md").write_text(_FOREIGN_DONE) + ours.write_text( # the review then finishes and appends its marker + "---\nstatus: done\nbaseline_revision: abc123\n---\n\n# Story\n\n" + "## Auto Run Result\n\nStatus: done\nReviewed.\n" + ) + rj = adapter._result_json(_dev_handle(), spec, wait=False) + assert rj is not None and rj["status"] == "done" + assert rj["story_key"] == "3-1" + assert rj["spec_file"] == str(ours) + + +def test_expected_spec_ignores_foreign_markerless_spec(tmp_path, monkeypatch): + """Same regression through the #224 missing-marker fallback, which #261 predates + but which added a second identical mtime-only scan of the shared dir. A foreign + marker-less `status: done` spec must not be a candidate at all — under a dead + window it would otherwise synthesize on a single sighting.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + ours = impl / "spec-3-1-foo.md" + ours.write_text("---\nstatus: in-review\n---\n\n# Story\n") # non-terminal: still working + (impl / "spec-9-9-someone-elses-story.md").write_text(_MARKERLESS_DONE) + + spec = _expecting(tmp_path, ours) + assert adapter._synth_result(_dev_handle(), spec, wait=False, dead_window=True) is None + # Unpinned, the foreign spec is adopted on the dead window's single sighting. + unpinned = dataclasses.replace(_dev_spec(tmp_path), role="review") + assert adapter._synth_result(_dev_handle(), unpinned, wait=False, dead_window=True) is not None + + +def test_expected_spec_markerless_own_spec_still_synthesizes(tmp_path, monkeypatch): + """Over-refusal guard for the fallback: our OWN marker-less terminal spec is + still harvested under a dead window, and the M1/M2 gates still apply to it.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + ours = impl / "spec-3-1-foo.md" + ours.write_text("---\nstatus: in-review\n---\n\n# Story\n") + spec = _expecting(tmp_path, ours) # snapshot of the in-review bytes + ours.write_text(_MARKERLESS_DONE) # this session finalized it, marker omitted + sr = adapter._synth_result(_dev_handle(), spec, wait=False, dead_window=True) + assert sr is not None and sr.result_json["status"] == "done" + assert sr.result_json["synthesized_from_frontmatter"] is True + + +def test_expected_spec_absent_file_is_no_result(tmp_path, monkeypatch): + """A session that never wrote the spec it owed produced no result — and the + pinned read-back deliberately does NOT fall back to the scan, so a foreign + artifact cannot stand in for it.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + (impl / "spec-9-9-someone-elses-story.md").write_text(_FOREIGN_DONE) + spec = dataclasses.replace( + _dev_spec(tmp_path), role="review", expected_spec=str(impl / "spec-3-1-foo.md") + ) + assert adapter._result_json(_dev_handle(), spec, wait=False) is None + + +def test_expected_spec_breadcrumb_names_the_pinned_path(tmp_path, monkeypatch): + """The give-up crumb points at the spec that was owed, not at a directory list — + the diagnostic that would have made #261 obvious in the journal.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + ours = impl / "spec-3-1-foo.md" + ours.write_text("---\nstatus: in-review\n---\n\n# Story\n") + (impl / "spec-9-9-someone-elses-story.md").write_text(_FOREIGN_DONE) + assert adapter._result_json(_dev_handle(), _expecting(tmp_path, ours), wait=True) is None + (crumb,) = _breadcrumbs(adapter) + assert crumb["verdict"] == "no-artifact" + assert str(ours) in crumb["detail"] + assert "someone-elses" not in crumb["detail"] + + +def test_dev_attempt_one_keeps_the_scan(tmp_path, monkeypatch): + """Unchanged where it must be: a dev attempt 1 has no recorded spec yet (the + skill creates it), so expected_spec is None and the mtime scan still runs.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + (impl / "spec-3-1-foo.md").write_text( + "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" + "## Auto Run Result\n\nStatus: done\nImplemented.\n" + ) + spec = _dev_spec(tmp_path) + assert spec.expected_spec is None + rj = adapter._result_json(_dev_handle(), spec, wait=False) + assert rj is not None and rj["status"] == "done" + + +# ------------------------------- proof-of-work gate (#261) + + +def _pane_log(adapter, task_id: str, size: int) -> Path: + adapter.logs_dir.mkdir(parents=True, exist_ok=True) + log = adapter.logs_dir / f"{task_id}.log" + log.write_bytes(b"x" * size) + return log + + +def test_proof_of_work_refuses_silent_dead_session(tmp_path, monkeypatch): + """A dead session with no hook event and a pane log that never grew produced + nothing, so a read-back artifact is not its output. Keep the crash verdict.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + (impl / "spec-3-1-foo.md").write_text( + "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" + "## Auto Run Result\n\nStatus: done\nImplemented.\n" + ) + _pane_log(adapter, "3-1-dev-1", 0) + res = adapter._final(_dev_handle(), _dev_spec(tmp_path), "crashed", None, None) + assert res.status == "crashed" + assert res.result_json is None + + +def test_proof_of_work_two_byte_log_is_not_work(tmp_path, monkeypatch): + """The floor is not zero: the report's wedged windows left 0-byte AND 2-byte + logs, so `size > 0` would have cleared one of them.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + (impl / "spec-3-1-foo.md").write_text( + "---\nstatus: done\n---\n\n## Auto Run Result\n\nStatus: done\n" + ) + _pane_log(adapter, "3-1-dev-1", 2) + assert adapter._final(_dev_handle(), _dev_spec(tmp_path), "crashed", None, None).status == ( + "crashed" + ) + + +def test_proof_of_work_pane_log_growth_is_evidence(tmp_path, monkeypatch): + """A session that rendered to its pane ran, so its artifact is honoured.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + (impl / "spec-3-1-foo.md").write_text( + "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" + "## Auto Run Result\n\nStatus: done\nImplemented.\n" + ) + _pane_log(adapter, "3-1-dev-1", generic.PROOF_OF_WORK_MIN_LOG_BYTES + 1) + res = adapter._final(_dev_handle(), _dev_spec(tmp_path), "crashed", None, None) + assert res.status == "completed" + assert res.result_json["status"] == "done" + + +def test_proof_of_work_hook_event_is_evidence_despite_empty_log(tmp_path, monkeypatch): + """The two signals are ORed for a reason: on a misbound pane sink (#254/#217) a + HEALTHY session logs zero bytes. A hook event having arrived carries it.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + (impl / "spec-3-1-foo.md").write_text( + "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" + "## Auto Run Result\n\nStatus: done\nImplemented.\n" + ) + _pane_log(adapter, "3-1-dev-1", 0) + res = adapter._final(_dev_handle(), _dev_spec(tmp_path), "crashed", "sess-1", None) + assert res.status == "completed" + + +def test_proof_of_work_no_pane_log_is_inert(tmp_path, monkeypatch): + """Unknown never blocks: with no pane log at all there is no signal, and the + gate preserves the previous behavior exactly.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + (impl / "spec-3-1-foo.md").write_text( + "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" + "## Auto Run Result\n\nStatus: done\nImplemented.\n" + ) + assert not (adapter.logs_dir / "3-1-dev-1.log").exists() + res = adapter._final(_dev_handle(), _dev_spec(tmp_path), "crashed", None, None) + assert res.status == "completed" + + +def test_proof_of_work_gates_post_kill_reconcile(tmp_path, monkeypatch): + """The i-11 call path: the rescue is for a session that finished and lost its + Stop, not for one that never ran.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + adapter._window_alive = lambda handle: False + (impl / "spec-3-1-foo.md").write_text( + "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" + "## Auto Run Result\n\nStatus: done\nImplemented.\n" + ) + _pane_log(adapter, "3-1-dev-1", 0) + stalled = SessionResult(status="stalled") + assert adapter._post_kill_reconcile(_dev_handle(), _dev_spec(tmp_path), stalled) is stalled + + _pane_log(adapter, "3-1-dev-1", generic.PROOF_OF_WORK_MIN_LOG_BYTES + 1) + rescued = adapter._post_kill_reconcile(_dev_handle(), _dev_spec(tmp_path), stalled) + assert rescued.status == "completed" + assert rescued.result_json["post_kill_reconciled"] is True + + +def test_proof_of_work_journals_the_refusal(tmp_path, monkeypatch): + """The refusal is observable — a silent downgrade would be its own #261.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + (impl / "spec-3-1-foo.md").write_text( + "---\nstatus: done\n---\n\n## Auto Run Result\n\nStatus: done\n" + ) + _pane_log(adapter, "3-1-dev-1", 0) + adapter._final(_dev_handle(), _dev_spec(tmp_path), "crashed", None, None) + events = (adapter.tasks_dir / "3-1-dev-1" / "session-lifecycle.jsonl").read_text() + assert "readback-refused-no-proof-of-work" in events From 0729d2a31ed4bdd9403581cf6cf33d8b70d2b95a Mon Sep 17 00:00:00 2001 From: pbean Date: Fri, 24 Jul 2026 20:25:51 -0700 Subject: [PATCH 2/8] fix(tests,adapters): de-race the rescue fixture; expected_spec survives resume MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit CI py3.11/py3.12 failed test_tmux_timeout_with_flushed_spec_rescued_post_kill (3.13/3.14 and both Windows jobs passed). The fake CLI emitted its pane output as one burst at startup, which can finish before pipe_pane attaches to the freshly created window — leaving a 0-byte log and tripping the new proof-of-work gate. Spread the output across ~2s (40 lines x 50ms, still well inside the 6s session timeout) so some of it always lands after the sink exists. Stable over 5 local repeats. Its silent companion now asserts "at or below the floor" rather than exactly zero: below the floor is the invariant, zero is incidental. Also, two corrections to the expected_spec seam: - The SessionSpec.expected_spec comment claimed the field is process-transient like SpecSnapshot and that a crash-resume falls back to the scan. That is wrong in the direction that matters: StoryTask.spec_file round-trips through state.json and WorktreeFlow.reopen_unit re-absolutizes it before any session launches, so the engine re-derives expected_spec on every launch and a resumed run IS protected. Documented as the property it is. - Rebase a relative expected_spec against spec.cwd, the same idiom the stories read-back uses for BMAD_LOOP_SPEC_FOLDER. The engine always threads an absolute path, but a relative one would resolve against the process CWD, miss, and read as "the session wrote nothing" — turning this guard into exactly the silent work-losing failure it exists to prevent. --- src/bmad_loop/adapters/base.py | 12 ++++++++---- src/bmad_loop/adapters/generic.py | 11 ++++++++++- tests/test_generic_tmux.py | 30 ++++++++++++++++++++++++++++-- 3 files changed, 46 insertions(+), 7 deletions(-) diff --git a/src/bmad_loop/adapters/base.py b/src/bmad_loop/adapters/base.py index 1420a876..d3c6b177 100644 --- a/src/bmad_loop/adapters/base.py +++ b/src/bmad_loop/adapters/base.py @@ -97,10 +97,14 @@ class SessionSpec: # produced nothing is scored `completed:done` and unreviewed code merges. # # Deliberately independent of `spec_snapshot`, which degrades to None on a torn - # read: the identity constraint must not silently disappear with it. Process- - # transient for the same reason as SpecSnapshot (not persisted); a crash-resume - # reconstructing the SessionSpec carries none and falls back to the scan. Kept - # LAST alongside spec_snapshot so positional constructions stay valid. + # read: the identity constraint must not silently disappear with it. + # + # Unlike SpecSnapshot this SURVIVES a crash-resume. The field itself is not + # persisted, but its source is: `StoryTask.spec_file` round-trips through + # state.json (stored relative to the worktree, re-absolutized by + # WorktreeFlow on resume), and the engine re-derives this on every launch. So a + # resumed run is protected too — always an absolute path by the time it lands + # here. Kept LAST alongside spec_snapshot so positional constructions stay valid. expected_spec: str | None = None diff --git a/src/bmad_loop/adapters/generic.py b/src/bmad_loop/adapters/generic.py index 8d3f7878..d6f8cf0e 100644 --- a/src/bmad_loop/adapters/generic.py +++ b/src/bmad_loop/adapters/generic.py @@ -1192,8 +1192,17 @@ def _synth_result( # directory shared with every concurrent run; the question is "what did THIS # session write for THIS story", and here we were told the answer at launch. if spec.expected_spec: + # The engine always threads an absolute path (StoryTask.spec_file is + # re-absolutized against the worktree on resume). Rebase a relative one + # against spec.cwd anyway, the same way the stories read-back handles + # BMAD_LOOP_SPEC_FOLDER: a path resolved against the process CWD would + # simply miss and read as "the session wrote nothing", turning this + # guard into the silent work-losing failure it exists to avoid. + owed = Path(spec.expected_spec) + if not owed.is_absolute(): + owed = Path(spec.cwd) / owed return self._known_spec_synth_result( - handle, spec, Path(spec.expected_spec), wait=wait, dead_window=dead_window + handle, spec, owed, wait=wait, dead_window=dead_window ) # Dev attempt 1 only: no spec exists yet (the skill creates it), so the # mtime-floor scan is the sole way to find it. diff --git a/tests/test_generic_tmux.py b/tests/test_generic_tmux.py index 43d7f7e8..ce041661 100644 --- a/tests/test_generic_tmux.py +++ b/tests/test_generic_tmux.py @@ -2911,7 +2911,12 @@ def test_tmux_timeout_with_flushed_spec_rescued_post_kill(tmp_path): fake.write_text( "#!/bin/bash\n" "# finished work, but hooks are 'misconfigured': no event files at all\n" - 'for i in $(seq 1 20); do echo "implementing story 3-1: step $i of 20 ..."; done\n' + # Emit OVER TIME, not in one burst at startup: pipe_pane attaches after the + # window is created, so a burst can finish before the sink exists and leave + # a 0-byte log on a fast runner (observed on CI py3.11/3.12 while 3.13/3.14 + # passed). Spread across ~2s, well inside the 6s session timeout below. + 'for i in $(seq 1 40); do echo "implementing story 3-1: step $i of 40 ..."; ' + "sleep 0.05; done\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" @@ -3006,7 +3011,10 @@ def test_tmux_timeout_silent_session_not_rescued(tmp_path): assert result.status == "timeout" assert result.result_json is None - assert (adapter.logs_dir / "t-silent.log").stat().st_size == 0 + # Below the floor is the invariant; exactly zero is merely what it happens to be. + assert (adapter.logs_dir / "t-silent.log").stat().st_size <= ( + generic.PROOF_OF_WORK_MIN_LOG_BYTES + ) # ------------------------------- missing-marker fallback (#224) @@ -4125,3 +4133,21 @@ def test_proof_of_work_journals_the_refusal(tmp_path, monkeypatch): adapter._final(_dev_handle(), _dev_spec(tmp_path), "crashed", None, None) events = (adapter.tasks_dir / "3-1-dev-1" / "session-lifecycle.jsonl").read_text() assert "readback-refused-no-proof-of-work" in events + + +def test_expected_spec_relative_path_is_rebased_on_cwd(tmp_path, monkeypatch): + """A relative expected_spec resolves against the session cwd, not the process + CWD. The engine always threads an absolute path, so this is a guard against a + future caller quietly turning the #261 fix into a work-losing false refusal.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + ours = impl / "spec-3-1-foo.md" + ours.write_text( + "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" + "## Auto Run Result\n\nStatus: done\nImplemented.\n" + ) + spec = dataclasses.replace( + _dev_spec(tmp_path), role="review", expected_spec=str(ours.relative_to(tmp_path)) + ) + rj = adapter._result_json(_dev_handle(), spec, wait=False) + assert rj is not None and rj["spec_file"] == str(ours) From 1f4d1c81a7fac7211aeddb16f774f3b745f9bd8d Mon Sep 17 00:00:00 2001 From: pbean Date: Fri, 24 Jul 2026 20:30:08 -0700 Subject: [PATCH 3/8] docs(adapters): state only what the proof-of-work floor is evidenced to prove MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The threshold comment claimed "any session that reached the agent loop echoes at least its own prompt into the pane". That is an inference and it is wrong as stated: the prompt is delivered by send-keys, and a program that never echoes it leaves a 0-byte log (measured with the silent fake CLI). The floor measures the CLI's OWN rendering, not that the session was launched — which is precisely why _produced_work ORs it with the hook-event signal instead of trusting it alone. Restated around the observed separation (1.4 MB working vs 0/2 bytes wedged), and noted that the exact value is therefore not load-bearing. --- src/bmad_loop/adapters/generic.py | 19 +++++++++++-------- 1 file changed, 11 insertions(+), 8 deletions(-) diff --git a/src/bmad_loop/adapters/generic.py b/src/bmad_loop/adapters/generic.py index d6f8cf0e..cd119043 100644 --- a/src/bmad_loop/adapters/generic.py +++ b/src/bmad_loop/adapters/generic.py @@ -71,9 +71,13 @@ # as having produced SOMETHING — the floor a dead session must clear before a # read-back artifact may upgrade its verdict to `completed`. Not zero: the three # wedged sessions in #261 left logs of 0 and 2 bytes, so `size > 0` would have -# cleared one of them. Any session that reached the agent loop echoes at least its -# own prompt (hundreds of bytes) into the pane, and a real one logs megabytes, so -# this sits far below a genuine session and far above a wedge. +# cleared one of them. The separation is wide in the observed data — that run's +# working dev session logged 1.4 MB against the wedged reviews' 0 and 2 — so the +# exact value is not load-bearing; it only has to sit above the noise a pane can +# accumulate without the CLI rendering anything. Note the floor measures the CLI's +# OWN output: the orchestrator's prompt is delivered by send-keys and a program +# that never echoes it leaves the log empty (measured), so this is not a proxy for +# "the session was launched" — only for "the CLI rendered something". PROOF_OF_WORK_MIN_LOG_BYTES = 256 @@ -837,11 +841,10 @@ def _log_evidence(self, handle: SessionHandle) -> bool | None: its size is a direct measure of how much the session emitted. None when the log does not exist — no signal, and the gate stays inert. - Otherwise True iff the log exceeded `PROOF_OF_WORK_MIN_LOG_BYTES`. The floor - is not zero on purpose: the wedged sessions in #261 left 0-byte AND 2-byte - logs, so `size > 0` would have missed one of them. Any session that reached - the agent loop echoes at least its own (multi-hundred-byte) prompt into the - pane, so the floor sits far below a real session and far above a wedge.""" + Otherwise True iff the log exceeded `PROOF_OF_WORK_MIN_LOG_BYTES` (see that + constant for why the floor is not zero, and for what it does and does not + prove). This measures rendering, not liveness, which is why `_produced_work` + ORs it with the hook-event signal rather than trusting it alone.""" try: size = (self.logs_dir / f"{handle.task_id}.log").stat().st_size except OSError: From 97b054bd5775b69a9949a0cd23015286b54250ba Mon Sep 17 00:00:00 2001 From: pbean Date: Fri, 24 Jul 2026 20:35:16 -0700 Subject: [PATCH 4/8] test(adapters): pin _log_evidence MRO resolution against a silent gate death MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit _log_evidence is declared inert on _ResultFileMixin and overridden on GenericAdapter, which owns the pane log. Both mixins sit ahead of the concrete adapter in the MRO, and this file already documents that shadowing hazard for send_text. C3 puts GenericAdapter first today (it subclasses _ResultFileMixin), but a future base reshuffle that let the inert stub win would silently disable the proof-of-work gate everywhere. Assert both resolutions, including that OpencodeDevAdapter — which has no pane log — keeps the inert one. --- tests/test_generic_tmux.py | 14 ++++++++++++++ 1 file changed, 14 insertions(+) diff --git a/tests/test_generic_tmux.py b/tests/test_generic_tmux.py index ce041661..b1cd3c30 100644 --- a/tests/test_generic_tmux.py +++ b/tests/test_generic_tmux.py @@ -4151,3 +4151,17 @@ def test_expected_spec_relative_path_is_rebased_on_cwd(tmp_path, monkeypatch): ) rj = adapter._result_json(_dev_handle(), spec, wait=False) assert rj is not None and rj["spec_file"] == str(ours) + + +def test_log_evidence_mro_is_not_shadowed_by_the_mixin(): + """`_log_evidence` is declared inert on `_ResultFileMixin` and overridden on + `GenericAdapter`, which owns the pane log. Both mixins sit ahead of the concrete + adapter in the MRO, and this file already documents that hazard for `send_text` — + so pin the resolution: if a future base reshuffle let the inert stub win, the + proof-of-work gate would silently go dead everywhere instead of failing loudly. + OpencodeDevAdapter has no pane log and must keep the inert one.""" + from bmad_loop.adapters.generic import GenericAdapter, _ResultFileMixin + from bmad_loop.adapters.opencode_http import OpencodeDevAdapter + + assert GenericDevAdapter._log_evidence is GenericAdapter._log_evidence + assert OpencodeDevAdapter._log_evidence is _ResultFileMixin._log_evidence From e88076859028c1287011d4a554a9145415a508ba Mon Sep 17 00:00:00 2001 From: pbean Date: Fri, 24 Jul 2026 20:42:30 -0700 Subject: [PATCH 5/8] test(adapters): make the silent-session e2e actually exercise the gate (#298 review) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit CodeRabbit caught that test_tmux_timeout_silent_session_not_rescued proved nothing. The foreign spec was written BEFORE adapter.run(), which is where start_session stamps launched_ns — so its mtime sat below the since_ns floor, find_result_artifact discarded it outright, and the read-back never produced a candidate for the proof-of-work gate to refuse. Verified by ablation: the test passed with the gate entirely removed. That is the same vacuously-satisfiable-gate failure mode this whole issue is about, in the test written to prove the fix. The merge-back now lands mid-window from a separate thread (1s into a 6s window), so the foreign spec post-dates launch exactly as the report's did, plus an explicit assertion that it IS a qualifying candidate. Re-verified by ablation: with the gate disabled the test now FAILS with status=completed — the foreign spec adopted through post-kill reconcile, i.e. a genuine end-to-end reproduction of #261 through real tmux. Stable over 6 local repeats. --- tests/test_generic_tmux.py | 28 +++++++++++++++++++++++----- 1 file changed, 23 insertions(+), 5 deletions(-) diff --git a/tests/test_generic_tmux.py b/tests/test_generic_tmux.py index b1cd3c30..c454d8bc 100644 --- a/tests/test_generic_tmux.py +++ b/tests/test_generic_tmux.py @@ -14,6 +14,7 @@ import shutil import subprocess import sys +import threading import time import uuid from pathlib import Path @@ -21,6 +22,7 @@ import pytest import regex +from bmad_loop import devcontract from bmad_loop.adapters import generic, tmux_base from bmad_loop.adapters.base import SessionHandle, SessionResult, SessionSpec, SpecSnapshot from bmad_loop.adapters.generic import GenericDevAdapter, GenericTmuxAdapter @@ -2999,16 +3001,32 @@ def test_tmux_timeout_silent_session_not_rescued(tmp_path): }, timeout_s=6.0, ) - # A FOREIGN story's finished spec lands mid-window (the concurrent merge-back). - (impl / "spec-9-9-someone-elses-story.md").write_text( - "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" - "## Auto Run Result\n\nStatus: done\nImplemented.\n" - ) + # A FOREIGN story's finished spec lands MID-WINDOW, from a separate thread + # standing in for the concurrent run's merge-back. It must be written after + # `run()` stamps `launched_ns`, or its mtime sits below the `since_ns` floor, + # `find_result_artifact` discards it on that alone, and the read-back never + # produces a candidate for the gate to refuse — the test would then pass with + # the proof-of-work gate entirely removed (verified: it did). + foreign = impl / "spec-9-9-someone-elses-story.md" + + def merge_back(): + time.sleep(1.0) # inside the 6s session window + foreign.write_text( + "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" + "## Auto Run Result\n\nStatus: done\nImplemented.\n" + ) + + writer = threading.Thread(target=merge_back, daemon=True) + writer.start() try: result = adapter.run(spec) finally: + writer.join(timeout=10) subprocess.run(["tmux", "kill-session", "-t", adapter.session_name], capture_output=True) + # The foreign spec really is a candidate the read-back would otherwise adopt: + # it exists, qualifies, and post-dates launch. Only the gate rejects it. + assert devcontract.is_result_artifact(foreign, since_ns=0) assert result.status == "timeout" assert result.result_json is None # Below the floor is the invariant; exactly zero is merely what it happens to be. From a84bc4458c2937adb1af5ec2a39f17c8a55af86b Mon Sep 17 00:00:00 2001 From: pbean Date: Fri, 24 Jul 2026 22:35:23 -0700 Subject: [PATCH 6/8] fix(engine): pin expected_spec only when the dispatch names the path (#298 review) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The #261 read-back may demand a spec back solely because the session was told to write it. `_run_session` derived the pin from any recorded `task.spec_file`, but knowing a spec exists is not the same as having pointed a session at it: a from-scratch re-drive after an escalation or deferral carries a spec recorded by `_record_dev_spec` and dispatches a bare story key. Pinning there polls a stale path while the re-drive's real output goes unread — trading #261's unsafe failure for a work-losing one, the exact trade this fix exists to avoid. Same shape for a sweep bundle (dispatches intent.md) and stories mode (folder+id). Pin iff the dispatched prompt names the path. One rule, covering all three engines without per-engine plumbing since each already builds its own prompt; it reads the post-gate text so a plugin rewrite cannot desynchronize the pin from the contract that justifies it. A miss falls back to the scan — the pre-#261 behavior, and the safe direction. Also stop recording the skill's `bmad-dev-auto-result-*` no-spec fallback as a story's spec. It is not one, and every consumer misroutes on it: the escalation re-arm flips frontmatter on a marker no re-drive reads, the repair leg re-opens it as the frozen intent contract, and the read-back then pins to it. Ablation-verified: reverting the rule to the old `task.spec_file` presence check fails the routing tests; dropping the `label is None` guard fails the labeled-workflow test on its own; removing the marker filter fails its test. --- src/bmad_loop/engine.py | 33 ++++++++++++++++- tests/test_engine.py | 81 +++++++++++++++++++++++++++++++++++++++++ tests/test_sweep.py | 26 +++++++++++++ 3 files changed, 138 insertions(+), 2 deletions(-) diff --git a/src/bmad_loop/engine.py b/src/bmad_loop/engine.py index f6b31fa7..e99b7984 100644 --- a/src/bmad_loop/engine.py +++ b/src/bmad_loop/engine.py @@ -1271,13 +1271,23 @@ def _record_dev_spec(self, task: StoryTask, result_json: dict | None) -> None: have no spec path to act on, so the re-drive HALTs on the stale ``blocked`` status. The synthesized result names the spec even on a HALT (``devcontract.synthesize_result``). No-op once set or when the claimed - spec is absent.""" + spec is absent. + + The skill's no-spec fallback artifact (``bmad-dev-auto-result-*``, written + when intent was too unclear to even CREATE a spec) is refused: it is not the + story's spec, so every consumer here misreads it. ``rearm_escalation`` would + flip frontmatter on a marker no re-drive reads, ``_reset_spec_for_repair`` + would re-open it as if it were the frozen intent contract, and the repair + prompt would point the session at it — which the #261 read-back then pins to, + polling a stale marker while the re-drive's real spec goes unread.""" if task.spec_file: return spec_file = (result_json or {}).get("spec_file") if not spec_file: return spec_path = verify.resolve_spec_path(str(spec_file), self.workspace.paths) + if spec_path.name.startswith(devcontract.FALLBACK_RESULT_PREFIX): + return if spec_path.is_file(): task.spec_file = str(spec_path) @@ -2268,6 +2278,20 @@ def _run_session( # as the snapshot above, so the two can never disagree about whether the # devcontract read-back is in play. # + # Pinned ONLY when the dispatched prompt NAMES that path — the read-back + # may demand a file back solely because the session was told to write it. + # Knowing a spec exists is not the same as having pointed a session at it: + # a from-scratch re-drive after an escalation/deferral has `task.spec_file` + # recorded (`_record_dev_spec`) but dispatches a bare story key, a sweep + # bundle dispatches `intent.md`, and StoriesEngine dispatches folder+id. + # Pinning those would poll a path the session never promised to rewrite + # and score its real output as "wrote nothing" — trading #261's unsafe + # failure for a work-LOSING one, the exact trade this fix exists to avoid. + # Testing the prompt keeps the pin and the contract that justifies it in + # one place across all three engines (each builds its own prompt), and + # reads the post-gate text, so a plugin rewrite cannot desynchronize them. + # A miss simply falls back to the scan — the pre-#261 behavior. + # # Withheld from an injected plugin-workflow session (`label` set — e.g. a # TEA pre_commit_gate): it runs the generic adapter but owes the # WORKFLOW_COMPLETION_CONTRACT marker above, not the story spec, so @@ -2276,7 +2300,12 @@ def _run_session( # from labeled sessions. expected_spec=( task.spec_file - if (label is None and self._generic_dev() and task.spec_file) + if ( + label is None + and self._generic_dev() + and task.spec_file + and str(task.spec_file) in prompt + ) else None ), ) diff --git a/tests/test_engine.py b/tests/test_engine.py index 8c358f12..5daa9711 100644 --- a/tests/test_engine.py +++ b/tests/test_engine.py @@ -2163,6 +2163,87 @@ def test_expected_spec_threaded_onto_review_session(project): assert review_spec.expected_spec == review_spec.spec_snapshot.path +def _pin_probe(project, prompt: str, *, spec_file: str | None, role="dev", label=None): + """The `expected_spec` a session dispatched with ``prompt`` would carry, for a + task whose recorded spec is ``spec_file``. Drives the real `_run_session` seam + and reads what actually reached the adapter.""" + engine, adapter = make_engine(project, [SessionResult(status="crashed")]) + task = StoryTask(story_key="1-1-a", epic=1, spec_file=spec_file) + engine._run_session(task, role=role, prompt=prompt, seq=1, label=label) + return adapter.sessions[-1].expected_spec + + +def test_expected_spec_pinned_only_when_the_prompt_names_the_spec(project): + """#261 pins the read-back to the spec the session owes — and the ONLY thing + that makes a session owe one is having been pointed at it. Knowing a spec exists + is not the same: `_record_dev_spec` sets `task.spec_file` when a story escalates + or defers, but the re-drive that follows dispatches a bare story key. Pinning + there would poll a stale path while the re-drive's real output went unread — + trading #261's unsafe failure for a work-losing one (#298 review). + + Both directions are asserted against the REAL prompt builders, so the rule and + the contract it reads cannot drift apart.""" + write_sprint(project, {"epic-1": "backlog", "1-1-a": "ready-for-dev"}) + owed_path = spec_path(project, "1-1-a") + write_spec(owed_path, "done", "abc123") # the repair leg re-opens it in place + owed = str(owed_path) + engine, _ = make_engine(project, []) + task = StoryTask(story_key="1-1-a", epic=1, spec_file=owed) + feedback = project.project / "feedback.md" + + # Pinned: every dispatch that hands the session the path. + assert _pin_probe(project, engine._review_prompt(task), spec_file=owed) == owed + assert _pin_probe(project, engine._dev_prompt(task, feedback), spec_file=owed) == owed + restoring = dataclasses.replace(task, restore_patch="/tmp/attempt.patch") + assert _pin_probe(project, engine._dev_prompt(restoring, None), spec_file=owed) == owed + + # NOT pinned: the from-scratch re-drive after an escalation/deferral. The task + # carries a recorded spec, but the dispatch is a bare story key — the session is + # free to write a different spec, and the scan is the only way to find it. + fresh = engine._dev_prompt(task, None) + assert fresh == "/bmad-dev-auto 1-1-a" + assert _pin_probe(project, fresh, spec_file=owed) is None + + +def test_expected_spec_withheld_from_labeled_workflow_session(project): + """An injected plugin-workflow session (a TEA pre_commit_gate) runs the generic + adapter but owes the completion MARKER, not the story spec — and its prompt gets + the spec path appended to it by nothing, so the naming rule alone would already + withhold the pin. The explicit `label is None` guard is what keeps that true if a + plugin's workflow prompt ever quotes the spec path as context.""" + write_sprint(project, {"epic-1": "backlog", "1-1-a": "ready-for-dev"}) + owed = str(spec_path(project, "1-1-a")) + pinned = _pin_probe( + project, + f"Run the pre-commit gate against `{owed}`.", + spec_file=owed, + label="tea.pre_commit_gate", + ) + assert pinned is None + + +def test_record_dev_spec_refuses_the_no_spec_fallback_marker(project): + """`bmad-dev-auto-result-*` is the skill's "intent too unclear to even create a + spec" artifact. Recording it as the story's spec misroutes every consumer: the + escalation re-arm flips frontmatter on a marker nothing reads, the repair leg + re-opens it as the frozen intent contract, and the #261 read-back then pins to + it — polling a stale marker while the re-drive's real spec goes unread.""" + engine, _ = make_engine(project, []) + task = StoryTask(story_key="1-1-a", epic=1) + marker = project.implementation_artifacts / "bmad-dev-auto-result-1-1-a-dev-1.md" + marker.write_text("---\nstatus: blocked\n---\n\nIntent unclear.\n") + + engine._record_dev_spec(task, {"spec_file": str(marker)}) + assert task.spec_file is None + + # A real spec on the same call path is still recorded — this is a filter, not + # a disabling of the capture escalation resolution depends on. + real = spec_path(project, "1-1-a") + write_spec(real, "blocked", "abc123") + engine._record_dev_spec(task, {"spec_file": str(real)}) + assert task.spec_file == str(real) + + def test_review_launch_snapshot_degrades_on_unreadable_spec(project): """A spec path that cannot be read degrades the snapshot capture to None and journals `spec-read-failed` at site `review-launch-snapshot`. A directory where diff --git a/tests/test_sweep.py b/tests/test_sweep.py index bb045a31..b77f97a0 100644 --- a/tests/test_sweep.py +++ b/tests/test_sweep.py @@ -2379,3 +2379,29 @@ def test_graceful_stop_between_cycles_skips_next_triage(project): entries = ledger_entries(project) assert entries["DW-1"].status.startswith("done") and entries["DW-2"].open assert stops[-1]["remaining"] == 1 # DW-2, generated in cycle 1, still open + + +def test_bundle_dispatch_does_not_pin_expected_spec(project, tmp_path): + """A sweep bundle's fresh dispatch points at `intent.md`, never at a spec — the + session is free to CREATE one, and #161 has it legitimately adopting a + pre-existing story spec under a different name. So the #261 read-back must stay + on the scan here even when a prior attempt recorded `task.spec_file`; pinning + would poll a path this dispatch never promised to rewrite. + + Falls out of the naming rule rather than a sweep-specific carve-out, which is + exactly why it needs pinning down: nothing in sweep.py mentions expected_spec.""" + engine, adapter = make_sweep(project, [SessionResult(status="crashed")]) + intent = tmp_path / "bundles" / "fix" / "intent.md" + intent.parent.mkdir(parents=True) + intent.write_text("# bundle intent\n") + task = StoryTask( + story_key="dw-fix", + epic=0, + bundle_file=str(intent), + spec_file=str(project.implementation_artifacts / "spec-adopted-elsewhere.md"), + ) + + prompt = engine._dev_prompt(task, None) + assert str(intent) in prompt and task.spec_file not in prompt + engine._run_session(task, role="dev", prompt=prompt, seq=1) + assert adapter.sessions[-1].expected_spec is None From 91b6b6897f6c5b4b6779b70dda0c36dde49ef65a Mon Sep 17 00:00:00 2001 From: pbean Date: Fri, 24 Jul 2026 22:35:36 -0700 Subject: [PATCH 7/8] fix(adapters): make the proof-of-work gate bite where it was inert (#298 review) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Three defects, all the same shape: the #261 gate was inert exactly where it was needed and over-broad where it was not. 1. Launch metadata was read as proof of work. `session_id`/`transcript_path` are populated by SessionStart and SessionEnd too, both of which a CLI that launched and wedged emits — so only a session with literally ZERO hook events ever reached the gate. Track a `Stop` event (a turn that ENDED) as its own signal instead; `SessionResult.stop_seen` carries it to `_post_kill_reconcile`. The #254/#217 rationale is untouched: a healthy session ends its turn. 2. A missing pane log failed the gate OPEN. `pipe_pane` tolerates a window that already died and then attaches no tee, so a dead-on-arrival session left no log at all — the "this transport has no pane signal" state, which the gate treats as inert. `start_session` now creates the log empty before the window exists, so no-tee-ever-attached reports False (rendered nothing) rather than None. The inert state now means only "a handle this adapter never launched". 3. The gate applied to authoritative task-scoped results. It lived in `_ResultFileMixin._final`, shared by every adapter whose skill writes `tasks//result.json` — a file unique to the task and unlinked at launch, which no foreign writer can reach. Gating it could only ever discard a real completion. Scoped to `_DevSynthesisMixin`, the one read-back that scans a shared directory. The silent-session e2e is also de-raced: its merge-back thread waited a fixed 1s from before `run()`, but the gap to `launched_ns` covers a real `tmux new-session` and a loaded box can outrun any margin picked in advance, silently restoring the vacuous pass. It now waits on the actual launch and asserts qualification against the floor the session recorded, not a permissive 0. Ablation-verified, each mechanism separately: disabling `_produced_work` fails all 7 refusal tests; restoring the any-hook-metadata rule fails the SessionStart-only test; removing the log pre-create fails the dead-on-arrival test; gating the base mixin fails the task-scoped-result test. One new test was itself vacuous on first write (the foreign spec predated launch, so `since_ns` rejected it before the gate saw it) and was caught by exactly this pass. --- CHANGELOG.md | 31 ++++--- src/bmad_loop/adapters/base.py | 10 ++- src/bmad_loop/adapters/generic.py | 129 +++++++++++++++++++++------ tests/test_generic_tmux.py | 143 +++++++++++++++++++++++++++--- 4 files changed, 259 insertions(+), 54 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index d585b5d8..46a247c2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -100,22 +100,31 @@ breaking changes may land in a minor release. (merging unreviewed code) and, on the dev leg, its `followup_review_recommended: false` skipped the review entirely. Unlike the rest of this family (#88/#127/#160/#224) it failed toward _landing_ unverified work. Two fixes, both in the adapter: - - **Authoritative-path read-back.** Where the orchestrator already knows which spec the session - owes — every review leg and every dev retry, via `StoryTask.spec_file`, the path it hands the - session in its own prompt — `SessionSpec.expected_spec` pins the read-back to that one file and - the directory scan is never reached. This closes the asymmetry with stories mode, which already - resolved by id rather than by mtime, and covers the #224 missing-marker fallback (a second - mtime-only scan of the same shared dir) through the same seam. Deliberately not a filename + - **Authoritative-path read-back.** Where the orchestrator has pointed the session at the spec it + owes — every review leg, every dev repair, every patch-restore re-drive — `SessionSpec.expected_spec` + pins the read-back to that one file and the directory scan is never reached. The pin is taken only + when the dispatched prompt names the path: a from-scratch re-drive after an escalation or deferral + has a recorded `StoryTask.spec_file` but dispatches a bare story key, and pinning there would poll a + stale path while the re-drive's real output went unread. This closes the asymmetry with stories mode, + which already resolved by id rather than by mtime, and covers the #224 missing-marker fallback (a + second mtime-only scan of the same shared dir) through the same seam. Deliberately not a filename rule: spec names come from an LLM-derived slug, so a prefix check risks trading this unsafe failure for a lossy one — and a pinned path needs no exemption for the `bmad-dev-auto-result-*` fallback or for sweep bundles, which legitimately adopt a differently-named story spec (#161). - A dev attempt 1 has no recorded spec yet and keeps the scan. + A dev attempt 1 has no recorded spec yet and keeps the scan. Relatedly, the skill's no-spec + fallback marker is no longer recorded as a story's spec at all — it is not one, and every + consumer of `task.spec_file` misroutes on it. - **Proof-of-work gate.** A read-back artifact may no longer upgrade a dead session to - `completed` when that session shows no evidence it ran at all — no hook event arrived _and_ its + `completed` when that session shows no evidence it ran at all — no turn ever ended _and_ its pane log never grew past a small floor. The two signals are ORed because each has a blind spot - (a misbound pane sink still fires hooks; a hook-less profile still logs), and no signal at all - leaves the gate inert. Applies to both the crash path and `_post_kill_reconcile`, and journals - `readback-refused-no-proof-of-work`. + (a misbound pane sink still ends turns; a hook-less profile still logs). The hook signal is a + `Stop` event specifically: `SessionStart` and `SessionEnd` are emitted by a CLI that launched + and wedged, so reading either as work would leave the gate satisfied in exactly the case it is + for. For the same reason the pane log is created empty at launch, so a window that dies before + the tee attaches reports "rendered nothing" rather than "no pane signal here". Scoped to the + shared-directory read-back: a task-scoped `result.json` is unique to its session and cleared at + launch, so it stays authoritative. Applies to both the crash path and `_post_kill_reconcile`, + and journals `readback-refused-no-proof-of-work`. - **`validate` requires the review skills your `bmad-dev-auto` actually invokes (#260).** The preflight held every project to a fixed catalog that included `bmad-review-verification-gap`, diff --git a/src/bmad_loop/adapters/base.py b/src/bmad_loop/adapters/base.py index d3c6b177..44e3ff50 100644 --- a/src/bmad_loop/adapters/base.py +++ b/src/bmad_loop/adapters/base.py @@ -135,10 +135,16 @@ class SessionResult: # was post-mortem-matched as an *environment fault* (the coding CLI lost its # API connection and idled out the session clock instead of doing real work). # Set by the _classify_env_fault hook; env_fault_evidence carries the matched, - # ANSI-stripped log line. These two MUST stay the LAST fields so every - # positional SessionResult construction in the codebase stays valid. + # ANSI-stripped log line. New fields are APPENDED below these, never inserted + # among them, so every positional SessionResult construction stays valid. env_fault: bool = False env_fault_evidence: str | None = None + # Whether a `Stop` hook event arrived during this session — the hook half of the + # #261 proof-of-work gate (see `_ResultFileMixin._produced_work`). Deliberately + # NOT `session_id is not None`: SessionStart and SessionEnd populate that too, + # and both fire on a CLI that launched and wedged without doing anything. Stop + # is the only canonical event that means a turn actually ended. + stop_seen: bool = False class CodingCLIAdapter(ABC): diff --git a/src/bmad_loop/adapters/generic.py b/src/bmad_loop/adapters/generic.py index cd119043..ac9535ad 100644 --- a/src/bmad_loop/adapters/generic.py +++ b/src/bmad_loop/adapters/generic.py @@ -191,6 +191,16 @@ class _ResultFileMixin: # tells the type checker the host attribute this mixin reads. tasks_dir: Path + # Whether `_final` applies the #261 proof-of-work gate to its read-back. False + # here, and that is not a conservative default — it is the correct answer for + # this mixin's own read-back. `tasks//result.json` is task-unique and + # `start_session` unlinks it before launch, so its presence is already proof + # THIS session wrote it; a foreign writer cannot reach it. Gating it could only + # ever downgrade an authoritative completion. Overridden True by + # `_DevSynthesisMixin`, whose read-back scans a directory shared with every + # concurrent run — the one place a result can belong to somebody else. + _READBACK_NEEDS_PROOF_OF_WORK = False + def _result_json(self, handle: SessionHandle, spec: SessionSpec, *, wait: bool) -> dict | None: """Acquire this session's result dict. Base behavior: read the skill-written ``result.json`` (briefly awaiting it on the Stop event, @@ -199,24 +209,28 @@ def _result_json(self, handle: SessionHandle, spec: SessionSpec, *, wait: bool) on-disk artifact.""" return self._await_result(handle.task_id) if wait else self._read_result(handle.task_id) - def _produced_work( - self, handle: SessionHandle, session_id: str | None, transcript: str | None - ) -> bool: + def _produced_work(self, handle: SessionHandle, stop_seen: bool) -> bool: """Whether this session shows ANY evidence it actually ran, for the #261 proof-of-work gate. Deliberately a very low bar — it separates "the CLI wedged before it did anything" from "the CLI worked", not good work from bad. - Two independent signals, ORed, because each has a known blind spot: - a hook event having arrived (``session_id``/``transcript`` are populated only - from one) covers an adapter whose pane sink is misbound (#254/#217, where a - HEALTHY session still logs zero bytes), and pane-log growth covers a profile - whose hooks never fire. Requiring both to be absent is what makes the gate - safe to apply to a `completed` upgrade. + Two independent signals, ORed, because each has a known blind spot: a `Stop` + event having arrived covers an adapter whose pane sink is misbound (#254/#217, + where a HEALTHY session still logs zero bytes), and pane-log growth covers a + profile whose hooks never fire. Requiring both to be absent is what makes the + gate safe to apply to a `completed` upgrade. + + The hook signal is `Stop` specifically — a turn that ENDED — not "a hook + event arrived". Of the three canonical events, `SessionStart` fires before + the session does anything and `SessionEnd` fires when it stops being one; + both are emitted by a CLI that launched and wedged, so accepting either + would leave the gate satisfied in exactly the case it exists to catch. The + #254/#217 rationale is unaffected: a healthy session ends its turn. Unknown never blocks: `_log_evidence` returns None when there is no signal at all (no pane log — the opencode-http transport, and every unit-test fixture), and that reads as evidence-present, preserving current behavior exactly.""" - if session_id or transcript: + if stop_seen: return True evidence = self._log_evidence(handle) return True if evidence is None else evidence @@ -238,21 +252,28 @@ def _final( *, accept_result: bool = True, budget_weighted: int | None = None, + stop_seen: bool = False, ) -> SessionResult: """Session is gone or done responding: completed if the result file landed anyway, otherwise the fallback status. ``accept_result=False`` (a stall verdict reached under a live window) pins the fallback: an artifact that appeared without a Stop or window death is not trusted. ``budget_weighted`` (a tripped session-budget guard's sample) rides - every exit so the engine can journal it whatever the verdict.""" + every exit so the engine can journal it whatever the verdict. + ``stop_seen`` is the proof-of-work hook signal, threaded separately from + ``session_id``/``transcript`` because those are also set by a mere launch.""" result_json = self._result_json(handle, spec, wait=False) if accept_result else None - if result_json is not None and not self._produced_work(handle, session_id, transcript): + if ( + result_json is not None + and self._READBACK_NEEDS_PROOF_OF_WORK + and not self._produced_work(handle, stop_seen) + ): # Proof-of-work gate (#261): this session is gone and produced no - # observable output at all — no hook event ever arrived AND its pane log - # never grew. A read-back artifact is then not evidence THIS session - # finished; it is evidence that SOMETHING wrote a qualifying file in a - # directory we share. Keep the fallback verdict rather than upgrade a - # dead-on-arrival session to `completed`. + # observable output at all — no turn ever ended AND its pane log never + # grew. A read-back artifact is then not evidence THIS session finished; + # it is evidence that SOMETHING wrote a qualifying file in a directory we + # share. Keep the fallback verdict rather than upgrade a dead-on-arrival + # session to `completed`. self._note_lifecycle( handle.task_id, "readback-refused-no-proof-of-work", @@ -268,6 +289,7 @@ def _final( session_id=session_id, transcript_path=transcript, budget_weighted=budget_weighted, + stop_seen=stop_seen, ) def _result_path(self, task_id: str) -> Path: @@ -447,6 +469,22 @@ def start_session(self, spec: SessionSpec) -> SessionHandle: # wait_for_completion ignores anything older than this floor so a reused # task_id's earlier Stop event cannot replay. launched_ns = time.time_ns() + log_file = self.logs_dir / f"{spec.task_id}.log" + # A re-armed run reuses task_ids and both mux backends append; drop the prior + # cycle's tee so the #194 tail scan can't match a stale transport error (mirrors + # the result.json unlink above; journal.py already assumes "next session replaces it"). + log_file.unlink(missing_ok=True) + # ...then create it EMPTY, before the window exists. `pipe_pane` below tolerates + # a window that already died and then attaches no tee, so without this a + # dead-on-arrival session leaves NO log at all — and an absent log is the + # `_log_evidence` "this transport has no pane signal" state, which the #261 + # proof-of-work gate treats as inert. The gate would fail OPEN in exactly the + # case it exists to catch. A 0-byte file says something truer and stronger: + # this transport does tee a pane, and this session rendered nothing into it. + # (Both backends append, so pre-creating cannot truncate a live tee. Stall + # detection is unaffected: `_log_activity_key` reports (mtime, 0) instead of + # None, and every reader compares signatures rather than testing existence.) + log_file.touch() window_id = self.mux.new_window( self.session_name, spec.task_id[-40:], @@ -454,11 +492,6 @@ def start_session(self, spec: SessionSpec) -> SessionHandle: {**self.profile.env, **spec.env}, self.build_command(spec), ) - log_file = self.logs_dir / f"{spec.task_id}.log" - # A re-armed run reuses task_ids and both mux backends append; drop the prior - # cycle's tee so the #194 tail scan can't match a stale transport error (mirrors - # the result.json unlink above; journal.py already assumes "next session replaces it"). - log_file.unlink(missing_ok=True) # pipe_pane tolerates the window having already died (a CLI that crashes on # launch can take it down before the tee attaches); the dead window is then # reported as a crash in wait_for_completion. @@ -497,6 +530,12 @@ def wait_for_completion(self, handle: SessionHandle, spec: SessionSpec) -> Sessi # forever: after cap total nudges it is declared stalled. cap=None # (raw constructor default) skips the check. stall_nudges_sent = 0 + # latched on the first accepted `Stop`: the hook half of the #261 proof-of-work + # gate. Tracked apart from session_id/transcript_path — those are populated by + # SessionStart and SessionEnd too, which a CLI that launched and wedged emits + # without doing any work. Rides out on every exit (see SessionResult.stop_seen) + # so `_post_kill_reconcile` reads the same signal after run() kills the window. + stop_seen = False # internal observability counter: counts ticks where the liveness probe # raised a transport error (e.g. a 30s tmux hang). It deliberately does # NOT escalate to "crashed" — a transient transport hiccup is not proof @@ -544,6 +583,7 @@ def wait_for_completion(self, handle: SessionHandle, spec: SessionSpec) -> Sessi timeout_fired_at=time.time(), timeout_expired_clock=expired, budget_weighted=budget_weighted, + stop_seen=stop_seen, ) now = time.monotonic() if last_heartbeat is None or now - last_heartbeat >= HEARTBEAT_INTERVAL_S: @@ -613,6 +653,7 @@ def wait_for_completion(self, handle: SessionHandle, spec: SessionSpec) -> Sessi session_id, transcript_path, budget_weighted=weighted, + stop_seen=stop_seen, ) except MultiplexerError: pass @@ -629,6 +670,7 @@ def wait_for_completion(self, handle: SessionHandle, spec: SessionSpec) -> Sessi session_id=session_id, transcript_path=transcript_path, budget_weighted=weighted, + stop_seen=stop_seen, ) try: self.send_text(handle, BUDGET_NUDGE_TEXT) @@ -660,6 +702,7 @@ def wait_for_completion(self, handle: SessionHandle, spec: SessionSpec) -> Sessi session_id, transcript_path, budget_weighted=budget_weighted, + stop_seen=stop_seen, ) except MultiplexerError: pass @@ -676,6 +719,7 @@ def wait_for_completion(self, handle: SessionHandle, spec: SessionSpec) -> Sessi session_id=session_id, transcript_path=transcript_path, budget_weighted=budget_weighted, + stop_seen=stop_seen, ) event = self.watcher.wait_for( handle.task_id, @@ -704,6 +748,7 @@ def wait_for_completion(self, handle: SessionHandle, spec: SessionSpec) -> Sessi session_id, transcript_path, budget_weighted=budget_weighted, + stop_seen=stop_seen, ) if stall_deadline is not None: # No artifact shortcut here: the window is alive on this tick @@ -756,6 +801,7 @@ def wait_for_completion(self, handle: SessionHandle, spec: SessionSpec) -> Sessi session_id, transcript_path, budget_weighted=budget_weighted, + stop_seen=stop_seen, ) except MultiplexerError: pass @@ -770,6 +816,7 @@ def wait_for_completion(self, handle: SessionHandle, spec: SessionSpec) -> Sessi transcript_path, accept_result=False, budget_weighted=budget_weighted, + stop_seen=stop_seen, ) continue if ( @@ -790,6 +837,11 @@ def wait_for_completion(self, handle: SessionHandle, spec: SessionSpec) -> Sessi if event.event == "SessionStart": continue if event.event == "Stop": + # A turn ENDED — the one canonical event that proves the CLI did + # something, and so the hook half of the #261 proof-of-work gate. + # Latched after the subagent filter above, which rejects a stop that + # is not the main session's turn-end. Never cleared. + stop_seen = True result_json = self._result_json(handle, spec, wait=True) if result_json is not None: return SessionResult( @@ -798,6 +850,7 @@ def wait_for_completion(self, handle: SessionHandle, spec: SessionSpec) -> Sessi session_id=session_id, transcript_path=transcript_path, budget_weighted=budget_weighted, + stop_seen=stop_seen, ) if nudges_left > 0: nudges_left -= 1 @@ -811,6 +864,7 @@ def wait_for_completion(self, handle: SessionHandle, spec: SessionSpec) -> Sessi session_id, transcript_path, budget_weighted=budget_weighted, + stop_seen=stop_seen, ) # A result-less Stop, but the session may have ended its turn to # await a background process (a Unity PlayMode run, a slow test) @@ -833,6 +887,7 @@ def wait_for_completion(self, handle: SessionHandle, spec: SessionSpec) -> Sessi session_id, transcript_path, budget_weighted=budget_weighted, + stop_seen=stop_seen, ) def _log_evidence(self, handle: SessionHandle) -> bool | None: @@ -840,11 +895,17 @@ def _log_evidence(self, handle: SessionHandle) -> bool | None: `_ResultFileMixin._produced_work`). The pane is tee'd to a stable inode, so its size is a direct measure of how much the session emitted. - None when the log does not exist — no signal, and the gate stays inert. - Otherwise True iff the log exceeded `PROOF_OF_WORK_MIN_LOG_BYTES` (see that - constant for why the floor is not zero, and for what it does and does not - prove). This measures rendering, not liveness, which is why `_produced_work` - ORs it with the hook-event signal rather than trusting it alone.""" + True iff the log exceeded `PROOF_OF_WORK_MIN_LOG_BYTES` (see that constant for + why the floor is not zero, and for what it does and does not prove). This + measures rendering, not liveness, which is why `_produced_work` ORs it with + the turn-ended signal rather than trusting it alone. + + None when the log does not exist — no signal, gate inert. `start_session` + creates it empty before the window exists, precisely so a session that died + on arrival reports False (rendered nothing) rather than None (no such signal): + the DOA case is the gate's whole purpose and must not read as unknown. What + is left in the None state is a handle this adapter never launched — unit + fixtures — for which "unknown never blocks" is the right and only answer.""" try: size = (self.logs_dir / f"{handle.task_id}.log").stat().st_size except OSError: @@ -1122,6 +1183,15 @@ class _DevSynthesisMixin(_ResultFileMixin): # sends through it. send_text: Callable[[SessionHandle, str], None] + # This mixin's read-back is where #261 lives: the skill writes no task-scoped + # result.json, so a result is synthesized from a *.md in an implementation- + # artifacts dir shared with every concurrent run and with the human. A pinned + # `expected_spec` closes that for the sessions the orchestrator can name, but + # dev attempt 1 (no spec exists yet) and the labeled-workflow marker still scan. + # There a qualifying file can belong to someone else, so a dead session must + # show it ran before its "result" is honored. See `_produced_work`. + _READBACK_NEEDS_PROOF_OF_WORK = True + def _configure_dev_knobs(self) -> None: """Override the base result-file knobs for the bmad-dev-auto contract; hosts call this at the end of ``__init__``.""" @@ -1759,11 +1829,11 @@ def _post_kill_reconcile( return result # Proof-of-work gate (#261), the same one the crash path applies in `_final`: # this rescue exists for a session that finished but lost its Stop, not for - # one that never ran. A session with no hook event and a pane log that never + # one that never ran. A session that ended no turn and whose pane log never # grew produced nothing, so a qualifying artifact is not its output — keep # the stall/timeout verdict. This is the call path the issue's second # occurrence (story i-11) took. - if not self._produced_work(handle, result.session_id, result.transcript_path): + if not self._produced_work(handle, result.stop_seen): self._note_lifecycle( handle.task_id, "readback-refused-no-proof-of-work", @@ -1785,6 +1855,7 @@ def _post_kill_reconcile( timeout_fired_at=result.timeout_fired_at, timeout_expired_clock=result.timeout_expired_clock, budget_weighted=result.budget_weighted, + stop_seen=result.stop_seen, ) diff --git a/tests/test_generic_tmux.py b/tests/test_generic_tmux.py index c454d8bc..872253ec 100644 --- a/tests/test_generic_tmux.py +++ b/tests/test_generic_tmux.py @@ -2552,7 +2552,12 @@ def test_run_reconcile_upgrade_is_not_reclassified(tmp_path): (impl / "spec-3-1-foo.md").write_text(_DONE_SPEC) # a done artifact to rescue _write_task_log( adapter, - b"API Error: Unable to connect (ECONNREFUSED)\n", # would match if scanned + # Padded past PROOF_OF_WORK_MIN_LOG_BYTES: this fixture stands in for a + # session that implemented the story and then lost its Stop, and such a + # session renders. A log holding ONLY the error line would be a session that + # rendered ~44 bytes total, which the #261 gate correctly declines to rescue + # — it would make this ordering test depend on a scenario it is not about. + b"working...\n" * 32 + b"API Error: Unable to connect (ECONNREFUSED)\n", task_id="3-1-dev-1", ) adapter.start_session = lambda spec: _dev_handle() @@ -2584,18 +2589,25 @@ def test_start_session_resets_reused_task_log(tmp_path): logs/.log, so a prior cycle's transport-failure line would linger in the 64 KiB tail and mis-flag a later unrelated timeout. start_session drops the stale tee before re-piping (mirroring the result.json unlink), so the reused path holds - only the current session's output.""" + only the current session's output. + + It then re-creates the file EMPTY rather than leaving it absent, so a window that + dies before pipe_pane attaches still reports "rendered nothing" to the #261 + proof-of-work gate instead of "no pane signal here" (#298 review). The invariant + this pins is that no stale BYTE survives — not that no file does.""" mux = _StartSessionMux() adapter = make_adapter(tmp_path, mux=mux) adapter._ensure_session = lambda cwd: None # skip the tmux server plumbing task_id = _ENV_FAULT_TASK _write_task_log(adapter, b"API Error: Unable to connect (ECONNREFUSED)\n", task_id=task_id) log_path = adapter.logs_dir / f"{task_id}.log" - assert log_path.exists() # the prior cycle's tee is present... + assert log_path.stat().st_size > 0 # the prior cycle's tee is present... adapter.start_session(make_spec(tmp_path, task_id=task_id)) - assert not log_path.exists() # ...and start_session unlinked it before re-piping + # ...and start_session dropped every stale byte before re-piping, leaving the + # empty file the proof-of-work gate needs to read a dead-on-arrival window. + assert log_path.read_bytes() == b"" assert mux.piped == [("@1", log_path)] # the fresh tee attaches to the same path # a re-driven session that times out with no NEW matching output is not misclassified assert _classify(adapter, "timeout", task_id=task_id).env_fault is False @@ -3007,10 +3019,29 @@ def test_tmux_timeout_silent_session_not_rescued(tmp_path): # `find_result_artifact` discards it on that alone, and the read-back never # produces a candidate for the gate to refuse — the test would then pass with # the proof-of-work gate entirely removed (verified: it did). + # + # So the writer waits on the ACTUAL launch rather than a fixed sleep: the gap + # from `run()` to `launched_ns` covers `_ensure_session`, a real `tmux + # new-session`, and a slow or loaded box can push that past any margin picked + # in advance — silently restoring the vacuous pass (#298 review). Capturing the + # handle also gives the assertion below the real floor to test against. foreign = impl / "spec-9-9-someone-elses-story.md" + launched: list[SessionHandle] = [] + launch_stamped = threading.Event() + real_start_session = adapter.start_session + + def spy_start_session(session_spec): + handle = real_start_session(session_spec) + launched.append(handle) + launch_stamped.set() + return handle + + adapter.start_session = spy_start_session def merge_back(): - time.sleep(1.0) # inside the 6s session window + if not launch_stamped.wait(timeout=10): + return # the run failed to launch; the assertions below will say so + time.sleep(0.5) # comfortably inside the 6s session window foreign.write_text( "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" "## Auto Run Result\n\nStatus: done\nImplemented.\n" @@ -3024,9 +3055,11 @@ def merge_back(): writer.join(timeout=10) subprocess.run(["tmux", "kill-session", "-t", adapter.session_name], capture_output=True) - # The foreign spec really is a candidate the read-back would otherwise adopt: - # it exists, qualifies, and post-dates launch. Only the gate rejects it. - assert devcontract.is_result_artifact(foreign, since_ns=0) + # The foreign spec really is a candidate the read-back would otherwise adopt: it + # exists, qualifies, and — tested against the launch floor this session actually + # recorded, not a permissive 0 — post-dates launch. Only the gate rejects it. + assert launched, "start_session never ran" + assert devcontract.is_result_artifact(foreign, since_ns=launched[0].launched_ns) assert result.status == "timeout" assert result.result_json is None # Below the floor is the invariant; exactly zero is merely what it happens to be. @@ -4092,9 +4125,9 @@ def test_proof_of_work_pane_log_growth_is_evidence(tmp_path, monkeypatch): assert res.result_json["status"] == "done" -def test_proof_of_work_hook_event_is_evidence_despite_empty_log(tmp_path, monkeypatch): +def test_proof_of_work_ended_turn_is_evidence_despite_empty_log(tmp_path, monkeypatch): """The two signals are ORed for a reason: on a misbound pane sink (#254/#217) a - HEALTHY session logs zero bytes. A hook event having arrived carries it.""" + HEALTHY session logs zero bytes. A turn having ENDED carries it.""" adapter, impl = make_dev_adapter(tmp_path) monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) (impl / "spec-3-1-foo.md").write_text( @@ -4102,13 +4135,42 @@ def test_proof_of_work_hook_event_is_evidence_despite_empty_log(tmp_path, monkey "## Auto Run Result\n\nStatus: done\nImplemented.\n" ) _pane_log(adapter, "3-1-dev-1", 0) - res = adapter._final(_dev_handle(), _dev_spec(tmp_path), "crashed", "sess-1", None) + res = adapter._final( + _dev_handle(), _dev_spec(tmp_path), "crashed", "sess-1", None, stop_seen=True + ) assert res.status == "completed" +def test_proof_of_work_session_id_alone_is_not_evidence(tmp_path, monkeypatch): + """`session_id`/`transcript_path` are populated by SessionStart and SessionEnd, + which a CLI that launched and wedged emits without doing anything. Reading them + as proof left the gate satisfied in exactly the case it exists to catch (#298 + review): only `stop_seen` — a turn that ENDED — is the hook-side evidence.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + (impl / "spec-9-9-someone-elses-story.md").write_text( + "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" + "## Auto Run Result\n\nStatus: done\nImplemented.\n" + ) + _pane_log(adapter, "3-1-dev-1", 0) + res = adapter._final( + _dev_handle(), + _dev_spec(tmp_path), + "crashed", + "sess-1", # SessionStart handed us a session id... + "/t.jsonl", # ...and a transcript path. Neither means work happened. + stop_seen=False, + ) + assert res.status == "crashed" + assert res.result_json is None + + def test_proof_of_work_no_pane_log_is_inert(tmp_path, monkeypatch): """Unknown never blocks: with no pane log at all there is no signal, and the - gate preserves the previous behavior exactly.""" + gate preserves the previous behavior exactly. Reachable only for a handle this + adapter never launched — `start_session` always leaves a log behind (see the + dead-on-arrival test below), which is what keeps this state from swallowing the + case the gate is for.""" adapter, impl = make_dev_adapter(tmp_path) monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) (impl / "spec-3-1-foo.md").write_text( @@ -4120,6 +4182,56 @@ def test_proof_of_work_no_pane_log_is_inert(tmp_path, monkeypatch): assert res.status == "completed" +def test_proof_of_work_dead_on_arrival_window_is_refused(tmp_path, monkeypatch): + """A window that dies before `pipe_pane` attaches tees NOTHING, so before #298 + it left no log file at all — the inert state above — and the gate failed open on + precisely the dead-on-arrival session it exists to refuse. `start_session` now + creates the log empty up front, so "no tee ever attached" reports as `False` + (rendered nothing) rather than `None` (no pane signal here). + + Driven through the REAL `start_session` with a mux whose `pipe_pane` writes + nothing — the faithful stand-in for attaching a tee to a corpse.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + adapter._ensure_session = lambda cwd: None # skip the tmux server plumbing + adapter.mux = _StartSessionMux() + + handle = adapter.start_session(_dev_spec(tmp_path)) + assert (adapter.logs_dir / "3-1-dev-1.log").stat().st_size == 0 + + # The foreign spec must land AFTER launch, or its mtime sits below the + # `since_ns` floor, the scan discards it there, and the gate is never reached — + # the test would pass with the gate removed (verified by ablation: it did). + foreign = impl / "spec-9-9-someone-elses-story.md" + foreign.write_text( + "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" + "## Auto Run Result\n\nStatus: done\nImplemented.\n" + ) + assert devcontract.is_result_artifact(foreign, since_ns=handle.launched_ns) + + res = adapter._final(handle, _dev_spec(tmp_path), "crashed", None, None) + assert res.status == "crashed" + assert res.result_json is None + + +def test_proof_of_work_leaves_task_scoped_result_json_alone(tmp_path): + """The gate is scoped to the shared-directory read-back, not to `_final` at + large (#298 review). A base adapter's `tasks//result.json` is unique to + this task and unlinked at launch, so its presence already proves THIS session + wrote it — no foreign writer can reach it. Gating it could only ever discard an + authoritative completion, so `_ResultFileMixin` declines the gate outright.""" + adapter = make_adapter(tmp_path) + task_dir = adapter.tasks_dir / "1-1-a-dev-1" + task_dir.mkdir(parents=True) + (task_dir / "result.json").write_text('{"status": "done", "workflow": "dev"}') + _pane_log(adapter, "1-1-a-dev-1", 0) # no rendering, and no Stop below + + handle = SessionHandle(task_id="1-1-a-dev-1", native_id="@1") + res = adapter._final(handle, make_spec(tmp_path), "crashed", None, None) + assert res.status == "completed" + assert res.result_json["status"] == "done" + + def test_proof_of_work_gates_post_kill_reconcile(tmp_path, monkeypatch): """The i-11 call path: the rescue is for a session that finished and lost its Stop, not for one that never ran.""" @@ -4183,3 +4295,10 @@ def test_log_evidence_mro_is_not_shadowed_by_the_mixin(): assert GenericDevAdapter._log_evidence is GenericAdapter._log_evidence assert OpencodeDevAdapter._log_evidence is _ResultFileMixin._log_evidence + # Same hazard, same reason: the gate applies to the shared-directory read-back + # the dev mixin owns and to nothing else. An MRO that let the base default win + # for a dev adapter would silently disarm it; one that let the dev value leak + # onto a base adapter would start discarding authoritative task-scoped results. + assert GenericDevAdapter._READBACK_NEEDS_PROOF_OF_WORK is True + assert OpencodeDevAdapter._READBACK_NEEDS_PROOF_OF_WORK is True + assert GenericTmuxAdapter._READBACK_NEEDS_PROOF_OF_WORK is False From 5c922fdab6a2234ddd18982a5a1e57795d222421 Mon Sep 17 00:00:00 2001 From: pbean Date: Fri, 24 Jul 2026 22:49:53 -0700 Subject: [PATCH 8/8] test(adapters): establish the launch floor by re-stamp, not by ordering (#298 review) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit CI Windows/py3.14 only. The dead-on-arrival test asserts its foreign spec is a candidate the read-back would otherwise adopt — a precondition assertion, so that setup drift fails loudly instead of passing vacuously. It established that by writing the file after `start_session` returned, which is not sufficient on Windows: `launched_ns` comes from `time.time_ns()` (a precise clock) while an NTFS mtime is stamped from the coarse system-time tick (~15.6 ms), so a file written a millisecond later can carry an mtime BELOW the floor. Re-stamp until the precondition actually holds, bounded, instead of assuming the two clocks are comparable. Production is unaffected: no session writes its terminal spec within 15 ms of launch. Re-ablated after the change — with `_produced_work` short-circuited the test still fails, so the fix did not turn it into a test that agrees for free. --- tests/test_generic_tmux.py | 21 ++++++++++++++++----- 1 file changed, 16 insertions(+), 5 deletions(-) diff --git a/tests/test_generic_tmux.py b/tests/test_generic_tmux.py index 872253ec..f626bf46 100644 --- a/tests/test_generic_tmux.py +++ b/tests/test_generic_tmux.py @@ -4202,12 +4202,23 @@ def test_proof_of_work_dead_on_arrival_window_is_refused(tmp_path, monkeypatch): # The foreign spec must land AFTER launch, or its mtime sits below the # `since_ns` floor, the scan discards it there, and the gate is never reached — # the test would pass with the gate removed (verified by ablation: it did). + # + # Writing it "after start_session returned" is not enough to establish that on + # Windows: `launched_ns` comes from `time.time_ns()` (a precise clock) while an + # NTFS mtime is stamped from the coarse system-time tick (~15.6 ms), so a file + # written a millisecond later can carry an mtime BELOW the floor. Re-stamp until + # the precondition actually holds rather than assuming the two clocks agree. foreign = impl / "spec-9-9-someone-elses-story.md" - foreign.write_text( - "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" - "## Auto Run Result\n\nStatus: done\nImplemented.\n" - ) - assert devcontract.is_result_artifact(foreign, since_ns=handle.launched_ns) + deadline = time.monotonic() + 5.0 + while True: + foreign.write_text( + "---\nstatus: done\nbaseline_revision: abc123\n---\n\n" + "## Auto Run Result\n\nStatus: done\nImplemented.\n" + ) + if devcontract.is_result_artifact(foreign, since_ns=handle.launched_ns): + break + assert time.monotonic() < deadline, "foreign spec never cleared the launch floor" + time.sleep(0.02) res = adapter._final(handle, _dev_spec(tmp_path), "crashed", None, None) assert res.status == "crashed"