diff --git a/CHANGELOG.md b/CHANGELOG.md index dcad42f3..46a247c2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -90,6 +90,42 @@ 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 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. 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 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 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`, 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..44e3ff50 100644 --- a/src/bmad_loop/adapters/base.py +++ b/src/bmad_loop/adapters/base.py @@ -83,6 +83,29 @@ 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. + # + # 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 @dataclass(frozen=True) @@ -112,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 ce28585e..ac9535ad 100644 --- a/src/bmad_loop/adapters/generic.py +++ b/src/bmad_loop/adapters/generic.py @@ -67,6 +67,18 @@ # 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. 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 class _SnapVerdict(enum.Enum): @@ -179,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, @@ -187,6 +209,39 @@ 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, 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 `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 stop_seen: + 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, @@ -197,14 +252,36 @@ 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 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 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", + 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, @@ -212,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: @@ -391,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:], @@ -398,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. @@ -441,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 @@ -488,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: @@ -557,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 @@ -573,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) @@ -604,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 @@ -620,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, @@ -648,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 @@ -700,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 @@ -714,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 ( @@ -734,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( @@ -742,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 @@ -755,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) @@ -777,8 +887,31 @@ 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: + """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. + + 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: + 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 @@ -1050,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__``.""" @@ -1116,6 +1258,27 @@ 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: + # 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, 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. # 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 +1295,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 +1423,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 +1481,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 +1517,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 +1827,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 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.stop_seen): + 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", @@ -1618,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/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..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) @@ -2262,6 +2272,42 @@ 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. + # + # 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 + # 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 + and str(task.spec_file) in prompt + ) + 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..5daa9711 100644 --- a/tests/test_engine.py +++ b/tests/test_engine.py @@ -2142,6 +2142,108 @@ 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 _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_generic_tmux.py b/tests/test_generic_tmux.py index 5c12462b..f626bf46 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 @@ -2550,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() @@ -2582,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 @@ -2896,13 +2910,27 @@ 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" + # 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" @@ -2942,6 +2970,104 @@ 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, 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). + # + # 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(): + 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" + ) + + 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 — 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. + assert (adapter.logs_dir / "t-silent.log").stat().st_size <= ( + generic.PROOF_OF_WORK_MIN_LOG_BYTES + ) + + # ------------------------------- missing-marker fallback (#224) # # A session (in practice: the follow-up review leg) can finalize the spec's @@ -3782,3 +3908,408 @@ 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_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 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( + "---\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, 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. 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( + "---\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_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). + # + # 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" + 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" + 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.""" + 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 + + +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) + + +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 + # 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 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