diff --git a/CHANGELOG.md b/CHANGELOG.md index aa01e055..bf8ca6fd 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -38,6 +38,12 @@ breaking changes may land in a minor release. - Escalate an environment fault at the review-budget rescue gate instead of deferring the story as unconverged (DW-523). +- Explain that unpinned result-artifact scans search only the configured artifact + directories themselves, so a nested story spec no longer produces an opaque + `no-artifact` breadcrumb (#780). +- Surface why a sprint-mode dev session found no result: `session-end` carries + the last resultless verdict, the `no-artifact` crumb names specs found one level + down, and `validate` warns `queue.nested-specs` on a nested spec layout (#780). ## [0.13.1] — 2026-10-01 diff --git a/docs/FEATURES.md b/docs/FEATURES.md index 51a6ae34..82d48342 100644 --- a/docs/FEATURES.md +++ b/docs/FEATURES.md @@ -85,6 +85,7 @@ See [README.md](../README.md) for the narrative overview and [setup-guide.md](se - Hook events from a nested coding CLI are attributed, not trusted (#767). A CLI process started from inside a session inherits the relay environment, so its `SessionStart`/`Stop`/`SessionEnd` land in the parent's event stream under the parent's task id and could complete or crash it. The generic adapter applies a second layer after the task-id filter (`SessionAttribution`): the first `SessionStart` is the launched session's — identified or not, so an anonymous start (a payload the relay could not read) still takes the parent's slot — and a later `SessionStart` with a new id marks that id foreign, unless its `source` is `clear` or `compact`, which is the launched session rotating its id and rebinds (`resume` and `startup` stay foreign). `source` alone does not rebind: an id already found foreign stays foreign (a child compacting), and a `clear` start right after a foreign id's `SessionEnd` is that child clearing, so its new id is foreign too. A foreign id's events are dropped before they can complete the session, re-point its transcript, spend nudges or re-arm the stall timer; the first drop per foreign id writes a `foreign-hook-event-ignored` breadcrumb (`hook_event`, `foreign_session_id`, `dropped_so_far`), every drop counts into `foreign_hook_events` on `heartbeat.json` and the `timeout-fired` crumb, and the sweep's failed-session diagnostic replays the same rule (`hook_foreign_ids`, `; foreign ignored: N` in the escalation suffix). The rule fails toward acceptance: id-less events, ids that never announced a `SessionStart` (a rotated id, a copilot `toolu_…` subagent `Stop`) and everything before the first start — including an identified `SessionEnd` from a CLI that exited before its `SessionStart` fired (#727) — are admitted, so attribution only ever drops a known child's events and never adds a completion path. A profile declaring `session_id_flag` pins the launched session's id instead (DW-505/508): the `claude` profile ships `--session-id`, so the adapter mints a UUID4 per launch, passes it on the command line and knows the parent before any event arrives — every id ever bound (the pin and each `clear`/`compact` rebind) is the launched session's own, and an identified `SessionStart` or `SessionEnd` from any other id is foreign, including a child `SessionEnd` whose child never announced a start; other events (`Stop` included) from an unannounced id are still admitted. If the CLI does not honour the pin — its first identified `SessionStart` that is not a `clear`/`compact` rotation reports another id (a future claude ignoring `--session-id`, or an `extra_args`/`launch_args` overlay adding `--resume`, `--continue` or `--fork-session`) — attribution treats the launched session as foreign, so its own `Stop` is dropped and it ends only on window death or its timeout. One `pinned-session-id-mismatch` breadcrumb (`pinned_session_id`, `reported_session_id`, `source`) makes that visible (DW-509). It is observation only and leaves the attribution rules unchanged. A start the pin rejects and the relay tags `mismatch` (a nested CLI, e.g. one a parallel `SessionStart` hook launched, reaching the events directory first) is not checked; the next start is. So a CLI whose own starts all read `mismatch` (a miscalibrated relay, below) and that ignores the pin writes no crumb. The check needs the launched session's own identified start: if that start was anonymous (a payload the relay could not read) or was lost behind a `clear`/`compact` rotation, the next identified non-rotation start is the first one checked, and it may be a nested child's. The crumb then names the child's id while the launched session completes normally, so read it as "the pin was not confirmed" rather than as proof the session is stuck. Accepted limitation, for profiles without `session_id_flag` (codex, gemini, copilot, antigravity): a child `SessionEnd` whose child never announced a `SessionStart` is indistinguishable from the parent's own and is admitted; nested CLIs announce their start. The sweep's failed-session diagnostic always replays the unpinned rule. A profile that maps no `SessionStart` (Stop-only, e.g. `antigravity`) gets no nested-CLI protection. A relay vendored before this change forwards no `source`, so there a `clear`/`compact` start with a new id reads as foreign and the session falls back to window death or its timeout — re-run `bmad-loop init` to re-vendor the relay. Relay-side lineage closes the remaining gap (DW-507). A tmux launch runs the window command behind a POSIX prelude, `/bin/sh -c 'BMAD_LOOP_LAUNCH_PID=$$; export BMAD_LOOP_LAUNCH_PID; exec "${SHELL:-/bin/sh}" -c "$1"' sh `, so the variable holds the launched pid and the command runs under tmux's `default-shell` exactly as before (tmux sets `SHELL` to it in every pane), so whatever that shell sources for a `-c` command (fish's `config.fish`, zsh's `.zshenv`) still applies. Both relays (`bmad-loop relay` and the legacy copied script) tag every event `lineage`: `match` when the launched CLI itself fired the hook, `mismatch` when a nested CLI did, `unknown` when that cannot be read. The relay walks its parent chain from `/proc` and skips only two kinds of process: the launch chain — any process started within 5 s of the launched pid, which covers a shell that forks the CLI (fish, or dash as Debian/Ubuntu `/bin/sh`: the launched pid is the shell, the CLI its child) and a node shim's real binary a level below (a limitation: anything the CLI itself starts at launch, such as an MCP server or a project `SessionStart` hook running another CLI, is inside the window too and reads `match`, so only the rules above apply to it) — and a hook-command wrapper, read structurally from its argv: a shell (`sh`, `bash`, `zsh`, `fish`, …) whose `-c` command string holds the relay invocation (`…/bmad-loop relay` or `…/bmad_loop_hook.py`) followed by the event name as consecutive words, split on whitespace, quotes and shell operators (so `sh -c '…/bmad-loop relay Stop && true'` counts), or a runner whose argv ends in it (`uv run --no-project python …/bmad_loop_hook.py Stop`). Nothing else in a process's argv is read, so a nested CLI whose prompt merely names the relay is still a nested CLI. Any other process on the way means a nested CLI. The relays only tag, never drop. The launched session's own first `SessionStart` calibrates lineage (with a pin, the first identified start the pin admits, so a child's start that reaches the events directory first calibrates nothing, identified or anonymous): tagged `match`, it is trusted, and every later `mismatch` event is foreign — id-less events and a child's `clear`/`compact` rotation without a preceding `SessionEnd` included, which the rules above alone would admit or rebind. Tagged `mismatch` (the CLI's hook architecture defeats the walk) or `unknown`/untagged (psmux on Windows and macOS have no `/proc`; a relay that predates the tag sends none), lineage is ignored for the attempt, the rules above apply unchanged, and one `hook-lineage-untrusted` breadcrumb (`reason`: `miscalibrated` or `unavailable`, `lineage`: the first start's tag) records the degrade. Lineage needs a `SessionStart` to calibrate on: a Stop-only profile (e.g. `antigravity`) never engages it and writes no crumb. An event carrying one of the launched session's own ids is never made foreign by lineage, and events before calibration ignore it. Id-less drops share one `foreign-hook-event-ignored` crumb with `foreign_session_id: null`, and the sweep's failed-session diagnostic, which replays the same rule, counts them as `hook_foreign_idless` (`; foreign id-less events ignored: N` in the escalation suffix). - Transport faults in the generic (multiplexer-driven) adapter leave crumbs instead of healthy-looking answers (DW-447/449/453/454). Like `session-probe-failed`, a window-liveness probe that raises `MultiplexerError` never reads as death, and every verdict is unchanged; what changes is the record. `liveness-probe-failed` (`site`, `error`) is written by the `tick` site at a wait-loop streak's first failed tick only, never once per tick, and by the one-shot sites (`over-budget`, `stall`, `post-kill`) once per verdict probe that raised. `liveness-probe-recovered` (`failures`) closes a tick streak when a later tick probes cleanly; a session that ends mid-streak (Stop, SessionEnd, abort, over-budget) leaves no recovered crumb. `heartbeat.json` carries the running streak as `probe_failures`, and `timeout-fired` carries the final one. `over-budget-fired` and `kill-escalated` gain `liveness_unknown`, which is true when the probe behind that verdict (for the kill, the last poll before escalation) raised. A stall, budget, stop or contract nudge whose send raised writes `nudge-send-failed` (`nudge`, `error`) and is never reported as sent: `stall_nudges_sent` on the heartbeat counts delivered nudges, `stall_nudges_failed` counts the failed attempts, and `contract-nudge-sent` is written only after a successful send (a failed contract nudge is still not retried). The stall-nudge cap and the #727 activity window count attempts, delivered or not. A post-kill rescue abandoned on unknown liveness or an unreadable artifact writes `post-kill-rescue-abandoned` (`reason` = `liveness-unknown` / `unreadable-artifact`, `status`, plus `error` for the read fault). The opencode HTTP adapter's heartbeat carries neither new key (its `stall_nudges_sent` counts attempts), but its nudges are crumbed the same way (DW-503): its `send_text` raises a `MultiplexerError` when the prompt POST fails, so an undelivered contract nudge writes `nudge-send-failed` instead of `contract-nudge-sent`, and its own budget, stall and stop nudges write `nudge-send-failed` and carry on exactly as before. Its dev sessions do share the post-kill reconcile, so they write `post-kill-rescue-abandoned` too, on the `unreadable-artifact` arm only (their liveness probe never answers "unknown"). - Three generic-adapter observation folds are crumbed the same way, verdicts unchanged (DW-448/450/451). A stall-expiry look at the pane whose capture raises `MultiplexerError`, or whose parked-prompt search blows `PARKED_PROMPT_MATCH_TIMEOUT_S`, still reads as "not parked", and writes `parked-probe-failed` (`reason` = `capture-failed` / `match-timeout`, `pattern` for a timeout, `error`) once per expiry; a profile with no `parked_prompt_patterns` or a backend without `capture_pane` stays silent. A pane-log stat fault other than absence still leaves the #261/#727 proof-of-work signal unknown, and writes `log-evidence-failed` (`error`) once per session however many verdict sites consult it. A present `result.json` the read-back refuses (unreadable, unparseable, not an object) still reads as no result: the Stop read-back's give-up record in `resultless-stops.jsonl` says `malformed-result-json` with the refusal instead of `no-result-json`, once per give-up rather than per poll, and the exit read-back writes `result-json-refused` (`error`). The opencode HTTP adapter shares the `resultless-stops.jsonl` verdict but not the other crumbs. +- A nested sprint spec explains its own timeout (#780). The unpinned sprint-mode dev read-back reads only specs directly under the artifacts dir, never its subdirectories — widening the scan would widen the #261 shared-dir hazard — so a spec kept in, say, `implementation-artifacts/stories/` is never found and the session rides to timeout. The `no-artifact` crumb in `resultless-stops.jsonl` now names any qualifying spec one level down ("qualifying spec(s) found in subdirectories, which are never read back: … — move the spec directly under the artifacts dir, or use stories mode ([stories] source) for a stories/ layout"); a nested hit is named, never read back as a result, and a nested `*.md` the probe cannot read, or a subdirectory it cannot list, is reported as a probe fault rather than read as "nothing nested". A dev session that ends non-completed carries the last such verdict on its `session-end` journal entry as `resultless_verdict` / `resultless_detail` (present-only, diagnostic, never routing), so the reason surfaces without opening the task dir. `bmad-loop validate` warns `queue.nested-specs` in sprint mode on a `*.md` with a non-empty frontmatter `status:` one level down, before any tokens are spent (a nested `*.md` it cannot read, or a subdirectory it cannot list, is warned on too, never silently skipped); stories mode never warns, since `stories/` is its own layout. - Four more generic-adapter folds are crumbed, verdicts unchanged (DW-452/455/456/457). A budget usage sample whose transcript read raises still reads as "no sample" — with a persistent fault, `token_budget_mode = "enforce"` stays off for the session — and its streak writes `usage-sample-failed` (`error`) at the first failure and `usage-sample-recovered` (`failures`) at the next clean sample, never once per tick (one torn mid-append read is one pair); `heartbeat.json` carries the running count as `usage_sample_failures`. A #727 transcript activity scan that raises still counts as no model-side evidence, with its streak crumbed the same way (`transcript-scan-failed` / `transcript-scan-recovered`). A launch-snapshot fault that turns the #276 M1 refuse gate inert — the identity check's `resolve()` raising (the 3.11 symlink-loop `RuntimeError` included, which used to escape) or the digest read raising — still reads NEUTRAL, and writes `spec-identity-unreadable` (`spec`, `snapshot`, `error`) or `spec-digest-unreadable` (`spec`, `error`) once per read-back, not per grace poll. A spec read-back that gives up on a fault says so: `stat-failed` for a stat fault the stories read-back used to file as `stale-mtime`, `unreadable-spec` for an unreadable or undecodable spec it filed as `not-terminal` (and the scan fallback as `no-artifact`), each with the error, in `resultless-stops.jsonl` on a Stop read-back and as `spec-readback-failed` (`reason`, `spec`, `error`) on a one-shot or dead-window (post-kill reconcile) read, which recorded nothing before. - CRITICAL resolution: `bmad-loop resolve ` opens an interactive resolve agent seeded with the escalation + frozen spec; you disambiguate, it re-arms the story (`escalated → pending`, spec reset to `ready-for-dev`) and resumes. `--no-interactive` skips to re-arm if you fixed the spec yourself. A DEFERRED or environment-fault escalated story whose kept work is sound takes [`--reverify`](#resolve-reverify) instead, which replays verification rather than re-driving a dev session. The re-arm advances the story's baseline in the **code tree** and is honest when it cannot: a failed advance is narrowed to typed git diff --git a/docs/tui-guide.md b/docs/tui-guide.md index 51b59440..3f7f738b 100644 --- a/docs/tui-guide.md +++ b/docs/tui-guide.md @@ -326,7 +326,9 @@ One row per story (or sweep bundle/triage task) in the selected run: read fault, with the error), `ambiguous-frontmatter`, `unmodified-since-launch` — the spec's bytes were unchanged since review launch, so it is a prior `done` re-opened, not this - session's output (#276) — or `terminal-frontmatter-pending`). + session's output (#276) — or `terminal-frontmatter-pending`). A dev session + that ends non-completed also shows the last of these on its `session-end` + journal entry, as `resultless_verdict` / `resultless_detail` (#780). - **Log** — the active agent session's pane output (`logs/.log`), ANSI colors preserved, starting with a dim `— .log —` header. The active task is the last `session-start` without a matching `session-end` diff --git a/src/bmad_loop/adapters/base.py b/src/bmad_loop/adapters/base.py index 173c08ff..f67507e9 100644 --- a/src/bmad_loop/adapters/base.py +++ b/src/bmad_loop/adapters/base.py @@ -308,6 +308,15 @@ class SessionResult: # into the same prompt. `parked_evidence` names what matched. APPENDED. parked: bool = False parked_evidence: str | None = None + # Why the dev read-back last came up empty (#780): the verdict and detail of + # the session's last `resultless-stops.jsonl` crumb, folded in by + # `_DevSynthesisMixin.run` when the session ends non-completed. That file has + # no reader, so a spec nested one directory down rode to timeout with no + # visible reason; the engine journals these on `session-end` instead. + # Diagnostic only: never read by routing, never set on a completed result. + # APPENDED. + resultless_verdict: str | None = None + resultless_detail: str | None = None class CodingCLIAdapter(ABC): diff --git a/src/bmad_loop/adapters/generic.py b/src/bmad_loop/adapters/generic.py index ddc982cc..6c71ad33 100644 --- a/src/bmad_loop/adapters/generic.py +++ b/src/bmad_loop/adapters/generic.py @@ -2275,13 +2275,19 @@ def _configure_dev_knobs(self) -> None: # Both fail closed at the affected scope without letting an unrelated bad # Markdown file suppress a newly created, readable story spec. # - # The heaviest of the four stores, and the reason the eviction seam exists: + # The heaviest of the five stores, and the reason the eviction seam exists: # an unpinned launch captures one entry per `*.md` in the artifacts dir, so # retaining a snapshot per session would grow O(sessions x files) for the - # adapter's lifetime (DW-96) where the three stores above grow O(sessions). - # All four are evicted the same way, by `_evict_task_state` from `run()`'s + # adapter's lifetime (DW-96) where the other four stores grow O(sessions). + # All five are evicted the same way, by `_evict_task_state` from `run()`'s # `finally`; the bound is in-flight scope, not a cap or an LRU. self._launch_auto_run_results: dict[str, dict[str, tuple[int, str] | None] | None] = {} + # Last resultless-stop crumb per session (#780): task_id -> (verdict, + # detail), overwritten by every `_note_resultless_stop` so it always holds + # the latest. Read once, by `run()` folding it onto a non-completed result + # before its `finally` evicts it (`_evict_task_state`); same lifetime + # doctrine as the stores above. + self._last_resultless: dict[str, tuple[str, str]] = {} @staticmethod def _marker_path_key(path: Path) -> str: @@ -2332,14 +2338,29 @@ def start_session(self, spec: SessionSpec) -> SessionHandle: # base that could alter method resolution. return cast(_SessionHost, super()).start_session(spec) + def _note_resultless_stop(self, task_id: str, verdict: str, detail: str = "") -> None: + super()._note_resultless_stop(task_id, verdict, detail) + self._last_resultless[task_id] = (verdict, detail) + def run(self, spec: SessionSpec) -> SessionResult: try: - return cast(_SessionHost, super()).run(spec) + result = cast(_SessionHost, super()).run(spec) + # Surface why the read-back came up empty (#780) on the result the + # engine journals; the crumb file alone has no reader. Here, after + # `_post_kill_reconcile`, a rescued result is already `completed` and + # stays unannotated. Diagnostic only — the status is untouched. + last = self._last_resultless.get(spec.task_id) + if result.status != "completed" and last is not None: + verdict, detail = last + return dataclasses.replace( + result, resultless_verdict=verdict, resultless_detail=detail + ) + return result finally: self._evict_task_state(spec.task_id) def _evict_task_state(self, task_id: str) -> None: - """Retention bound for the four per-task stores named below (DW-96, + """Retention bound for the five per-task stores named below (DW-96, DW-106, DW-107). One documented eviction site rather than a pop scattered per store; hosts owning a store this mixin cannot reach (OpencodeDev- Adapter's `_server_procs`) override this and delegate up. @@ -2375,6 +2396,7 @@ def _evict_task_state(self, task_id: str) -> None: self._fm_fallback_obs.pop(task_id, None) self._fm_transition_obs.pop(task_id, None) self._contract_nudge_sent.discard(task_id) + self._last_resultless.pop(task_id, None) def _park_marker_session_authored(self, spec_path: Path, spec: SessionSpec) -> bool: """Whether the live marker differs from this session's launch marker.""" @@ -2664,6 +2686,33 @@ def _snapshot_verdict( return _SnapVerdict.REFUSE return _SnapVerdict.NEUTRAL + @staticmethod + def _nested_spec_hint(search_dirs: list[Path], *, since_ns: int) -> str: + """The unpinned ``no-artifact`` crumb's #780 suffix: name specs one level + below a searched dir that would have qualified directly in it (a + ``stories/`` layout rides to timeout otherwise, with nothing saying why). + Diagnosis only — the paths are named, never read back as a result. A probe + fault is reported as such rather than read as "nothing nested". Returns "" + when there is nothing to say.""" + hits: list[Path] = [] + faults: list[str] = [] + for d in dict.fromkeys(search_dirs): + found, fault = devcontract.find_nested_result_hints(d, since_ns=since_ns) + hits += [p for p in found if p not in hits] + if fault is not None: + faults.append(fault) + hint = "" + if hits: + hint += ( + "; qualifying spec(s) found in subdirectories, which are never read back: " + + ", ".join(str(p) for p in hits) + + " — move the spec directly under the artifacts dir, or use stories" + " mode ([stories] source) for a stories/ layout" + ) + if faults: + hint += "; subdirectory probe failed: " + "; ".join(faults) + return hint + def _frontmatter_fallback( self, handle: SessionHandle, @@ -2772,7 +2821,14 @@ def _frontmatter_fallback( self._note_resultless_stop( task_id, "no-artifact", - "no result artifact newer than session launch under: " + where, + ( + f"no result artifact newer than session launch at: {where}" + if only is not None + else "no result artifact newer than session launch directly under: " + + where + + " (subdirectories are not searched)" + + self._nested_spec_hint(search_dirs, since_ns=handle.launched_ns) + ), ) return None if len(candidates) > 1: @@ -2971,6 +3027,13 @@ def note_snapshot_fault(event: str, **fields: str) -> None: # read FAULT (DW-457) — `stat-failed` / `unreadable-spec`, never filed # as the genuine `stale-mtime` / `not-terminal` answers it used to be. verdict, detail = state.kind, str(state.path or base) + if state.kind == stories.KIND_PENDING: + # Name the glob and its flatness (#780): a spec one folder deeper + # is never resolved, and a bare dir left that unsaid. + detail = ( + f"no {story_key}-*.md directly under {base / stories.STORIES_SUBDIR}" + " (subdirectories are not searched)" + ) fault: tuple[Path, str] | None = None if state.kind in (stories.KIND_PRESENT, stories.KIND_SENTINEL) and state.path: try: diff --git a/src/bmad_loop/checks.py b/src/bmad_loop/checks.py index 36aa48e8..1fe59a4d 100644 --- a/src/bmad_loop/checks.py +++ b/src/bmad_loop/checks.py @@ -68,6 +68,9 @@ "adapter.external-profile", "queue.sprint-status", "queue.sprint-status-unknown-keys", + # spec-like files one level under the artifacts dir: the sprint-mode dev + # read-back never searches subdirectories (#780) + "queue.nested-specs", "queue.stories-manifest", "git.worktree-clean", "git.probe", diff --git a/src/bmad_loop/cli.py b/src/bmad_loop/cli.py index 99809cbb..a03c1082 100644 --- a/src/bmad_loop/cli.py +++ b/src/bmad_loop/cli.py @@ -555,6 +555,7 @@ def cmd_validate(args: argparse.Namespace) -> int: f"unknown keys ignored: {', '.join(ss.unknown_keys)}", {"unknown_keys": list(ss.unknown_keys)}, ) + _validate_nested_specs(paths.implementation_artifacts, report) except sprintstatus.SprintStatusError as e: report.fail("queue.sprint-status", str(e)) @@ -1860,6 +1861,85 @@ def _validate_plugin_manifests(root: Path, report: ValidationReport) -> None: ) +def _nested_spec_files(impl: Path) -> tuple[list[Path], list[tuple[Path, str]]]: + """Spec-like files ONE level below `impl` (#780): `*.md` in an immediate, + non-symlinked subdirectory whose frontmatter carries a non-empty `status:`. + + Sprint mode's dev read-back globs only `impl` itself, so a spec kept in, say, + `impl/stories/` is never found and the session rides to timeout. Deliberately + broader than the adapter's `devcontract.find_nested_result_hints` (any status, + no launch floor): this is a preflight over the layout, not a judgment about one + session's result. Returns `(spec_like, unreadable)`: a nested `*.md` whose read + raised, or a subdirectory that could not be listed, is returned with its fault + rather than dropped, since it may hold the very spec the layout hides. An + OSError while listing `impl` itself propagates, so the caller reports the fault + instead of an empty answer.""" + if not impl.is_dir(): + return [], [] + found: list[Path] = [] + unreadable: list[tuple[Path, str]] = [] + for child in sorted(impl.iterdir()): + if child.is_symlink() or not child.is_dir(): + continue + # `Path.glob` swallows a listing fault and yields nothing, so an + # unlistable subdirectory would pass as empty: list it explicitly. + try: + os.listdir(child) + except OSError as e: + unreadable.append((child, f"{type(e).__name__}: {e}")) + continue + for path in sorted(child.glob("*.md")): + try: + fm = frontmatter.read_frontmatter(path) + except OSError as e: + unreadable.append((path, f"{type(e).__name__}: {e}")) + continue + if frontmatter.status_of(fm): + found.append(path) + return found, unreadable + + +def _validate_nested_specs(impl: Path, report: ValidationReport) -> None: + """Warn on a nested spec layout in sprint mode (#780). Never a failure — nothing + here gates a run — and silent when nothing is nested, the same no-`ok`-twin + reasoning as `policy.isolation-shared-artifact-dir`. A nested `*.md` that could + not be read is its own warning: silence would claim a clean layout the scan + never checked.""" + try: + nested, unreadable = _nested_spec_files(impl) + except OSError as e: + report.warn( + "queue.nested-specs", + f"could not list subdirectories of {impl}: {type(e).__name__}: {e}", + {"path": str(impl), "error": f"{type(e).__name__}: {e}"}, + ) + return + if unreadable: + shown = unreadable[:3] + report.warn( + "queue.nested-specs", + f"could not read {len(unreadable)} path(s) in subdirectories of " + f"{impl}, so they were not checked for a nested spec layout (e.g. " + f"{'; '.join(f'{p}: {err}' for p, err in shown)})", + { + "path": str(impl), + "count": len(unreadable), + "unreadable": [{"path": str(p), "error": err} for p, err in shown], + }, + ) + if not nested: + return + examples = nested[:3] + report.warn( + "queue.nested-specs", + f"{len(nested)} spec-like file(s) in subdirectories of {impl} (e.g. " + f"{', '.join(str(p) for p in examples)}); sprint-mode dev sessions only read " + "specs directly under it — move them up, or use stories mode ([stories] " + "source) for a stories/ layout", + {"count": len(nested), "examples": [str(p) for p in examples]}, + ) + + def _validate_operator_registry( project: Path, paths: bmadconfig.ProjectPaths, report: ValidationReport ) -> None: diff --git a/src/bmad_loop/devcontract.py b/src/bmad_loop/devcontract.py index ea54365d..09807473 100644 --- a/src/bmad_loop/devcontract.py +++ b/src/bmad_loop/devcontract.py @@ -681,6 +681,79 @@ def find_frontmatter_candidates(impl_artifacts: Path, *, since_ns: int) -> list[ return [p for _, p in found] +def find_nested_result_hints( + impl_artifacts: Path, *, since_ns: int, limit: int = 3 +) -> tuple[list[Path], str | None]: + """Diagnosis only (#780): specs ONE level below `impl_artifacts` that would + have qualified had they sat directly in it — so a `no-artifact` breadcrumb + can name the nested file instead of leaving the operator to guess why a + `stories/` layout rode to timeout. Nothing returned here is ever harvested: + the result scans stay flat (widening them would widen the #261 shared-dir + hazard), and a nested hit is named, never read back. + + Probes each immediate, non-symlinked subdirectory in sorted order with the + existing finders — `find_result_artifact` then `find_frontmatter_candidates` + — so it adds no qualification logic of its own. Returns at most `limit` + distinct paths, plus a fault string when listing the directory or one of its + subdirectories failed, probing a subdirectory raised, or a nested `*.md` + at/after the launch floor could not be read: the fault is reported, never folded into an empty + "nothing nested" answer, and a fault in one subdirectory keeps the hits + already found in others. (The finders degrade an unreadable file to "no + match" by contract, so a non-hit is probed once more here, purely to tell + "not a spec" from "could not look".) A missing `impl_artifacts` is not a + fault — the flat scan already says so. + """ + if not impl_artifacts.is_dir(): + return [], None + hits: list[Path] = [] + faults: list[str] = [] + try: + children = sorted(impl_artifacts.iterdir()) + except OSError as e: + return [], f"{type(e).__name__}: {e}" + for child in children: + try: + # 3.11 floor: Path.is_dir has no follow_symlinks=, so test the link first. + if child.is_symlink() or not child.is_dir(): + continue + # `Path.glob` (the finders' and ours below) swallows a listing fault + # and yields nothing, so an unlistable subdir would read as empty: + # list it explicitly first so the fault reaches the handler below. + os.listdir(child) + marker = find_result_artifact(child, since_ns=since_ns) + found = [marker] if marker is not None else [] + found += find_frontmatter_candidates(child, since_ns=since_ns) + for path in found: + if path not in hits: + hits.append(path) + if len(hits) >= limit: + return hits, "; ".join(faults) or None + for path in sorted(child.glob("*.md")): + if path not in found and (fault := _unreadable(path, since_ns=since_ns)): + faults.append(fault) + except OSError as e: + faults.append(f"could not probe {child}: {type(e).__name__}: {e}") + return hits, "; ".join(faults) or None + + +def _unreadable(path: Path, *, since_ns: int) -> str | None: + """A read fault on ONE nested `*.md` the finders passed over, or None when it + is readable, older than the launch floor, or gone (a file deleted between the + glob and the probe is not a fault).""" + try: + if path.stat().st_mtime_ns < since_ns: + return None + # Read, not just open: the finders fail on the read too (EIO after a + # successful open), and a decode error is "not a spec", not a fault. + with path.open("rb") as f: + f.read() + except FileNotFoundError: + return None + except OSError as e: + return f"could not read {path}: {type(e).__name__}: {e}" + return None + + 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 diff --git a/src/bmad_loop/engine.py b/src/bmad_loop/engine.py index 0dd67838..33a2d332 100644 --- a/src/bmad_loop/engine.py +++ b/src/bmad_loop/engine.py @@ -7852,6 +7852,14 @@ def _session_end_extras(self, result: SessionResult) -> dict: extras["parked"] = True if result.parked_evidence: extras["parked_evidence"] = result.parked_evidence + # empty read-back diagnosis (#780): same present-only convention. The + # last resultless-stop verdict lands here because nothing reads the + # crumb file, so a spec nested out of the read-back's reach timed out + # with no visible reason. + if result.resultless_verdict: + extras["resultless_verdict"] = result.resultless_verdict + if result.resultless_detail: + extras["resultless_detail"] = result.resultless_detail return extras @staticmethod diff --git a/tests/test_cli.py b/tests/test_cli.py index d7749b74..b6b194fb 100644 --- a/tests/test_cli.py +++ b/tests/test_cli.py @@ -11988,6 +11988,258 @@ def test_validate_json_every_emitted_check_is_registered(project, capsys, monkey assert emitted <= VALIDATE_CHECKS +# --- queue.nested-specs: a sprint spec layout the dev read-back never searches (#780) --- + +_NESTED_SPEC = "---\nstatus: ready-for-dev\n---\n# Story 1.1\n" + + +def _nested_impl(project): + """The artifacts dir exactly as `cmd_validate` resolves it, so path assertions + compare like with like (a tmp_path under a symlinked /tmp resolves elsewhere).""" + return bmadconfig.load_paths(project.project).implementation_artifacts + + +def _commit_nested(project, msg="nested spec fixture"): + git(project.project, "add", "-A") # keep git.worktree-clean green: rc stays the verdict + git(project.project, "commit", "-q", "-m", msg) + + +def _nested_findings(doc): + return [f for f in doc["findings"] if f["check"] == "queue.nested-specs"] + + +def test_validate_warns_nested_specs_in_sprint_mode(project, capsys, monkeypatch): + """#780: a sprint spec kept in `impl/stories/` is never found by the flat dev + read-back, so the session rides to timeout. validate names the file before any + tokens are spent — as a warning, so rc stays 0. + + Ablation: drop the `_validate_nested_specs` call from `cmd_validate` and this + reddens.""" + _make_validate_pass(project, monkeypatch, capsys) + impl = _nested_impl(project) + nested = impl / "stories" / "1-1-x.md" + nested.parent.mkdir(parents=True) + nested.write_text(_NESTED_SPEC, encoding="utf-8") + _commit_nested(project) + + doc = machine_json(["validate", "--project", str(project.project), "--json"], capsys) + + assert doc["ok"] is True # a warning is not a problem + (hit,) = _nested_findings(doc) + assert hit["severity"] == "warning" + assert str(nested) in hit["message"] + assert str(impl) in hit["message"] + assert "only read specs directly under it" in hit["message"] + assert hit["detail"] == {"count": 1, "examples": [str(nested)]} + + +def test_validate_nested_specs_caps_examples_at_three(project, capsys, monkeypatch): + """The count is the whole layout; the examples are a sample, so a big stories/ + dir cannot flood the line.""" + _make_validate_pass(project, monkeypatch, capsys) + impl = _nested_impl(project) + (impl / "stories").mkdir() + specs = [impl / "stories" / f"1-{i}-x.md" for i in range(1, 6)] + for spec in specs: + spec.write_text(_NESTED_SPEC, encoding="utf-8") + _commit_nested(project) + + doc = machine_json(["validate", "--project", str(project.project), "--json"], capsys) + + (hit,) = _nested_findings(doc) + assert hit["detail"] == {"count": 5, "examples": [str(p) for p in specs[:3]]} + assert str(specs[3]) not in hit["message"] + + +def test_validate_no_nested_specs_warning_on_stock_project(project, capsys, monkeypatch): + """Nothing bmad-loop itself lays down (init, hooks, the sprint board) may read + as a nested spec — a false positive here would fire on every project.""" + _make_validate_pass(project, monkeypatch, capsys) + assert _nested_impl(project).is_dir(), "premise: the scanned dir exists" + + doc = machine_json(["validate", "--project", str(project.project), "--json"], capsys) + + assert doc["ok"] is True + assert _nested_findings(doc) == [] + + +def test_validate_nested_specs_ignores_plain_md(project, capsys, monkeypatch): + """Only a `*.md` whose frontmatter carries a non-empty `status:` is spec-like: + notes, a frontmatter-less doc, and a blank `status:` are not counted. One real + spec beside them pins the count, so the filter — not an empty scan — is what + keeps them out. + + Ablation: drop the `status_of` gate in `_nested_spec_files` and count reddens.""" + _make_validate_pass(project, monkeypatch, capsys) + impl = _nested_impl(project) + notes = impl / "notes" + notes.mkdir() + (notes / "readme.md").write_text("# just notes\n", encoding="utf-8") + (notes / "blank.md").write_text("---\nstatus:\ntitle: x\n---\n", encoding="utf-8") + (notes / "other.txt").write_text("---\nstatus: done\n---\n", encoding="utf-8") + spec = notes / "spec.md" + spec.write_text(_NESTED_SPEC, encoding="utf-8") + _commit_nested(project) + + doc = machine_json(["validate", "--project", str(project.project), "--json"], capsys) + + (hit,) = _nested_findings(doc) + assert hit["detail"] == {"count": 1, "examples": [str(spec)]} + + +def test_validate_nested_specs_does_not_follow_symlinked_dirs( + project, capsys, monkeypatch, tmp_path +): + """A symlinked subdirectory is not part of the layout the read-back would scan, + and following one could walk anywhere — it is skipped. + + Ablation: drop the `is_symlink()` skip in `_nested_spec_files` and a finding + appears.""" + _make_validate_pass(project, monkeypatch, capsys) + impl = _nested_impl(project) + outside = tmp_path / "outside-specs" + outside.mkdir() + (outside / "1-1-x.md").write_text(_NESTED_SPEC, encoding="utf-8") + try: + (impl / "stories").symlink_to(outside, target_is_directory=True) + except (OSError, NotImplementedError) as exc: + pytest.skip(f"directory symlinks unavailable: {exc}") + _commit_nested(project) + + doc = machine_json(["validate", "--project", str(project.project), "--json"], capsys) + + assert _nested_findings(doc) == [] + + +def test_validate_stories_mode_never_warns_nested_specs(project, capsys, monkeypatch): + """`stories/` IS the stories-mode layout (read directly through the spec folder), + so the sprint-mode warning must never fire there. + + Ablation: run `_validate_nested_specs` in the stories branch too and this + reddens.""" + _make_validate_pass(project, monkeypatch, capsys) + _setup_stories_fixture(project, [_stories_entry("1")]) + nested = _nested_impl(project) / "stories" / "1-1-x.md" + nested.parent.mkdir(parents=True) + nested.write_text(_NESTED_SPEC, encoding="utf-8") + _commit_nested(project) + + argv = ["validate", "--project", str(project.project), "--spec", STORIES_SPEC_FOLDER] + cli.main([*argv, "--json"]) # the rc is the stories gates' verdict, not this check's + doc = json.loads(capsys.readouterr().out) + + assert doc["mode"] == "stories" + assert _nested_findings(doc) == [] + + +def test_validate_nested_specs_reports_a_listing_fault(tmp_path, monkeypatch): + """An OSError while listing is a warning naming the fault — not a crash, and not + an empty "nothing nested" answer a caller could not tell from a clean layout.""" + impl = tmp_path / "impl" + impl.mkdir() + real_iterdir = Path.iterdir + + def boom(self): + if self == impl: + raise PermissionError(13, "denied", str(self)) + return real_iterdir(self) + + monkeypatch.setattr(Path, "iterdir", boom) + report = cli.ValidationReport() + + cli._validate_nested_specs(impl, report) + + (finding,) = report.findings + assert finding.check == "queue.nested-specs" + assert finding.severity == "warning" + assert "PermissionError" in finding.message + assert finding.detail is not None and finding.detail["path"] == str(impl) + + +def _deny_reads_of(monkeypatch, *denied): + real_read = cli.frontmatter.read_frontmatter + + def flaky(path): + if path in denied: + raise PermissionError(13, "denied", str(path)) + return real_read(path) + + monkeypatch.setattr(cli.frontmatter, "read_frontmatter", flaky) + + +def test_nested_spec_files_returns_an_unreadable_file_with_its_fault(tmp_path, monkeypatch): + """One unreadable file is returned with its fault, not counted as spec-like; + its readable siblings still are.""" + impl = tmp_path / "impl" + (impl / "stories").mkdir(parents=True) + bad = impl / "stories" / "1-1-bad.md" + good = impl / "stories" / "1-2-good.md" + for spec in (bad, good): + spec.write_text(_NESTED_SPEC, encoding="utf-8") + _deny_reads_of(monkeypatch, bad) + + found, unreadable = cli._nested_spec_files(impl) + + assert found == [good] + ((path, err),) = unreadable + assert path == bad + assert err.startswith("PermissionError") + + +def test_validate_nested_specs_reports_an_unreadable_sole_candidate(tmp_path, monkeypatch): + """When the only nested `*.md` cannot be read, the scan checked nothing — so it + must warn, not stay silent the way a clean layout does. + + Ablation: drop the `unreadable` warning from `_validate_nested_specs` and no + finding is emitted.""" + impl = tmp_path / "impl" + (impl / "stories").mkdir(parents=True) + bad = impl / "stories" / "1-1-x.md" + bad.write_text(_NESTED_SPEC, encoding="utf-8") + _deny_reads_of(monkeypatch, bad) + report = cli.ValidationReport() + + cli._validate_nested_specs(impl, report) + + (finding,) = report.findings + assert finding.check == "queue.nested-specs" + assert finding.severity == "warning" + assert str(bad) in finding.message + assert "PermissionError" in finding.message + assert finding.detail is not None + assert finding.detail["count"] == 1 + assert finding.detail["unreadable"][0]["path"] == str(bad) + + +@pytest.mark.skipif( + os.name == "nt" or os.geteuid() == 0, reason="POSIX permissions; root bypasses them" +) +def test_validate_nested_specs_reports_an_unlistable_subdir(tmp_path): + """`Path.glob` swallows a listing fault and yields nothing, so a subdirectory + that cannot be listed would pass as a clean layout. It is warned on instead. + + Ablation: drop the explicit `os.listdir(child)` in `_nested_spec_files` and no + finding is emitted.""" + impl = tmp_path / "impl" + locked = impl / "stories" + locked.mkdir(parents=True) + (locked / "1-1-x.md").write_text(_NESTED_SPEC, encoding="utf-8") + locked.chmod(0o000) + report = cli.ValidationReport() + try: + cli._validate_nested_specs(impl, report) + finally: + locked.chmod(0o755) + + (finding,) = report.findings + assert finding.check == "queue.nested-specs" + assert finding.severity == "warning" + assert str(locked) in finding.message + assert "PermissionError" in finding.message + assert finding.detail is not None + assert finding.detail["unreadable"][0]["path"] == str(locked) + + @pytest.mark.parametrize("exit_code", [2, 127], ids=["rc-2", "rc-127"]) def test_validate_warns_when_a_binary_on_path_refuses_to_run( project, capsys, monkeypatch, tmp_path, exit_code diff --git a/tests/test_devcontract.py b/tests/test_devcontract.py index 1ca5e4be..4f6b3dec 100644 --- a/tests/test_devcontract.py +++ b/tests/test_devcontract.py @@ -1028,6 +1028,193 @@ def test_find_artifact_ignores_heading_in_longer_outer_fence(tmp_path): assert devcontract.find_result_artifact(tmp_path, since_ns=0) is None +# ------------------------------------------------------- find_nested_result_hints + + +def _deep_spec(path: Path, **kwargs) -> Path: + path.parent.mkdir(parents=True, exist_ok=True) + return _spec(path, **kwargs) + + +def test_nested_hints_names_marker_and_frontmatter_specs_one_level_down(tmp_path): + marked = _deep_spec(tmp_path / "a" / "spec-1-1-x.md", auto_run="done") + bare = _deep_spec(tmp_path / "b" / "spec-1-2-y.md", auto_run=None) + _deep_spec(tmp_path / "spec-flat.md") # directly in the dir: the flat scan's job, not a hint + _deep_spec(tmp_path / "a" / "deeper" / "spec-1-3-z.md") # two levels down: never probed + assert devcontract.find_nested_result_hints(tmp_path, since_ns=0) == ([marked, bare], None) + + +def test_nested_hints_keep_the_launch_floor(tmp_path): + old = _deep_spec(tmp_path / "stories" / "spec-1-1-x.md") + os.utime(old, ns=(1_000_000_000, 1_000_000_000)) + assert devcontract.find_nested_result_hints(tmp_path, since_ns=5_000_000_000) == ([], None) + + +def test_nested_hints_cap_at_limit(tmp_path): + for i in range(5): + _deep_spec(tmp_path / f"d{i}" / f"spec-1-{i}-x.md") + hits, fault = devcontract.find_nested_result_hints(tmp_path, since_ns=0, limit=2) + assert fault is None + assert hits == [tmp_path / "d0" / "spec-1-0-x.md", tmp_path / "d1" / "spec-1-1-x.md"] + + +def test_nested_hints_dedupe_preserving_order(tmp_path, monkeypatch): + """The two finders never overlap today (a marker excludes a spec from the + frontmatter scan), so overlap is forced: a later finder repeating a path must + neither duplicate it nor spend the limit on it.""" + (tmp_path / "stories").mkdir() + a, b = tmp_path / "stories" / "a.md", tmp_path / "stories" / "b.md" + monkeypatch.setattr(devcontract, "find_result_artifact", lambda d, *, since_ns: a) + monkeypatch.setattr(devcontract, "find_frontmatter_candidates", lambda d, *, since_ns: [a, b]) + assert devcontract.find_nested_result_hints(tmp_path, since_ns=0) == ([a, b], None) + + +def test_nested_hints_non_dir_input_is_not_a_fault(tmp_path): + assert devcontract.find_nested_result_hints(tmp_path / "ghost", since_ns=0) == ([], None) + (tmp_path / "file.md").write_text("x", encoding="utf-8") + assert devcontract.find_nested_result_hints(tmp_path / "file.md", since_ns=0) == ([], None) + + +def test_nested_hints_skip_symlinked_subdirs(tmp_path): + outside = tmp_path / "outside" + _deep_spec(outside / "spec-1-1-x.md") + impl = tmp_path / "impl" + impl.mkdir() + try: + (impl / "stories").symlink_to(outside, target_is_directory=True) + except OSError as exc: + pytest.skip(f"directory symlinks unavailable: {exc}") + assert devcontract.find_nested_result_hints(impl, since_ns=0) == ([], None) + + +def test_nested_hints_listing_fault_is_reported_not_empty(tmp_path, monkeypatch): + _deep_spec(tmp_path / "stories" / "spec-1-1-x.md") + + def boom(self): + raise PermissionError("denied") + + monkeypatch.setattr(Path, "iterdir", boom) + assert devcontract.find_nested_result_hints(tmp_path, since_ns=0) == ( + [], + "PermissionError: denied", + ) + + +def _deny_open_of(monkeypatch, denied: Path) -> None: + real_open = Path.open + + def guarded(self, *args, **kwargs): + if self == denied: + raise PermissionError(13, "denied", str(self)) + return real_open(self, *args, **kwargs) + + monkeypatch.setattr(Path, "open", guarded) + + +def test_nested_hints_report_an_unreadable_file_beside_a_hit(tmp_path, monkeypatch): + """A nested `*.md` that cannot be opened is a fault, not "no match" — it may be + the very spec the layout hides. Its readable sibling is still named. The denied + file is non-terminal, so the finders pass over it on every Python whether or not + their reads route through `Path.open`. + + Ablation: drop the `_unreadable` probe loop and the fault is None.""" + hit = _deep_spec(tmp_path / "stories" / "spec-1-1-x.md") + bad = _deep_spec(tmp_path / "stories" / "spec-1-2-y.md", status="in-progress", auto_run=None) + _deny_open_of(monkeypatch, bad) + + hits, fault = devcontract.find_nested_result_hints(tmp_path, since_ns=0) + + assert hits == [hit] + assert fault is not None + assert f"could not read {bad}: PermissionError" in fault + + +def test_nested_hints_ignore_an_unreadable_file_below_the_launch_floor(tmp_path, monkeypatch): + """A file older than the launch floor could not have been this session's spec, + so failing to open it is not worth a fault.""" + old = _deep_spec(tmp_path / "stories" / "spec-1-1-x.md", status="in-progress", auto_run=None) + os.utime(old, ns=(1_000_000_000, 1_000_000_000)) + _deny_open_of(monkeypatch, old) + + assert devcontract.find_nested_result_hints(tmp_path, since_ns=5_000_000_000) == ([], None) + + +def test_nested_hints_report_a_read_fault_after_a_successful_open(tmp_path, monkeypatch): + """The finders fail on the read, not just the open (EIO on a flaky mount), so + the probe must read too: a file that opens but cannot be read is a fault. + + Ablation: open without reading and the fault is None.""" + bad = _deep_spec(tmp_path / "stories" / "spec-1-1-x.md", status="in-progress", auto_run=None) + real_open = Path.open + + class _EioReader: + def __enter__(self): + return self + + def __exit__(self, *exc): + return False + + def read(self, *args): + raise OSError(5, "Input/output error") + + def guarded(self, *args, **kwargs): + return _EioReader() if self == bad else real_open(self, *args, **kwargs) + + monkeypatch.setattr(Path, "open", guarded) + + hits, fault = devcontract.find_nested_result_hints(tmp_path, since_ns=0) + + assert hits == [] + assert fault is not None + assert f"could not read {bad}: OSError" in fault + + +def test_nested_hints_keep_earlier_hits_when_a_later_subdir_faults(tmp_path, monkeypatch): + """A fault probing one subdirectory is reported beside the hits already found + in others — never trades the named nested spec for a bare fault. + + Ablation: let the per-child OSError escape the loop and the hits are lost.""" + hit = _deep_spec(tmp_path / "a" / "spec-1-1-x.md") + (tmp_path / "b").mkdir() + real_find = devcontract.find_result_artifact + + def find(d, *, since_ns): + if d.name == "b": + raise PermissionError(13, "denied", str(d)) + return real_find(d, since_ns=since_ns) + + monkeypatch.setattr(devcontract, "find_result_artifact", find) + + hits, fault = devcontract.find_nested_result_hints(tmp_path, since_ns=0) + + assert hits == [hit] + assert fault is not None + assert f"could not probe {tmp_path / 'b'}: PermissionError" in fault + + +@pytest.mark.skipif( + os.name == "nt" or os.geteuid() == 0, reason="POSIX permissions; root bypasses them" +) +def test_nested_hints_report_an_unlistable_subdir(tmp_path): + """`Path.glob` swallows a listing fault and yields nothing, so a subdirectory + that cannot be listed would read as "nothing nested". It is a fault instead, + and a readable sibling's hit is still named. + + Ablation: drop the explicit `os.listdir(child)` and the fault is None.""" + hit = _deep_spec(tmp_path / "a" / "spec-1-1-x.md") + locked = tmp_path / "b" + _deep_spec(locked / "spec-1-2-y.md") + locked.chmod(0o000) + try: + hits, fault = devcontract.find_nested_result_hints(tmp_path, since_ns=0) + finally: + locked.chmod(0o755) + + assert hits == [hit] + assert fault is not None + assert f"could not probe {locked}: PermissionError" in fault + + # The read-back decodes artifacts as UTF-8. A spec truncated mid-write (the CLI # was killed) can end inside a multi-byte sequence; `read_text(encoding="utf-8")` # then raises UnicodeDecodeError — a ValueError, NOT an OSError. diff --git a/tests/test_engine.py b/tests/test_engine.py index 58bab330..b4e33fd8 100644 --- a/tests/test_engine.py +++ b/tests/test_engine.py @@ -14764,6 +14764,42 @@ def test_unparked_session_end_carries_no_parked_key(project): assert dec and all(d["parked"] is False for d in dec) +def test_session_end_extras_carries_resultless_verdict(project): + """#780: the adapter folds the last resultless-stop crumb onto a non-completed + result because nothing reads `resultless-stops.jsonl`; `session-end` is where + an operator finds why a nested spec rode to timeout. Diagnosis, not routing: + the timeout retries and defers exactly as a bare one does. + + ABLATION: delete the resultless block in `_session_end_extras` and the + session-end assertions fail.""" + write_sprint(project, {"1-1-a": "ready-for-dev"}) + detail = "no qualifying spec directly under: impl (subdirectories are not searched)" + timeout = SessionResult( + status="timeout", resultless_verdict="no-artifact", resultless_detail=detail + ) + engine, adapter = make_engine(project, [timeout, timeout]) + engine.run() + + assert len(adapter.sessions) == 2 # the retry ran: routing is untouched + decisions = [e for e in engine.journal.entries() if e["kind"] == "dev-decision"] + assert decisions[0]["action"] == "retry" + ends = [e for e in engine.journal.entries() if e["kind"] == "session-end"] + assert len(ends) == 2 + assert all(e["resultless_verdict"] == "no-artifact" for e in ends) + assert all(e["resultless_detail"] == detail for e in ends) + + +def test_session_end_extras_omits_resultless_when_unset(project): + """Present-only, the `parked` convention: a session without a folded verdict + leaves neither key, so a grep finds exactly the diagnosed sessions.""" + write_sprint(project, {"1-1-a": "ready-for-dev"}) + engine, _ = make_engine(project, [SessionResult(status="timeout")]) + engine.run() + ends = [e for e in engine.journal.entries() if e["kind"] == "session-end"] + assert ends + assert all("resultless_verdict" not in e and "resultless_detail" not in e for e in ends) + + def test_engine_attaches_its_journal_to_every_adapter(project): """The engine hands its `Journal` to the adapters it owns (#680), so an adapter-side `session-idle` lands in the same file with the same diff --git a/tests/test_generic_tmux.py b/tests/test_generic_tmux.py index 1a0f2667..d8d0c2da 100644 --- a/tests/test_generic_tmux.py +++ b/tests/test_generic_tmux.py @@ -1230,12 +1230,128 @@ def test_resultless_stop_breadcrumb_scan_no_artifact(tmp_path, monkeypatch): assert str(impl) in crumb["detail"] # names the searched dirs +def test_resultless_stop_breadcrumb_explains_non_recursive_artifact_scan(tmp_path, monkeypatch): + """A nested result is outside the legacy scan, so the breadcrumb must say so.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + nested = impl / "stories" + nested.mkdir() + (nested / "spec-3-1-foo.md").write_text( + "---\nstatus: done\n---\n\n## Auto Run Result\n\nStatus: done\n", + encoding="utf-8", + ) + + assert adapter._result_json(_dev_handle(), _dev_spec(tmp_path), wait=True) is None + + (crumb,) = _breadcrumbs(adapter) + assert crumb["verdict"] == "no-artifact" + assert str(impl) in crumb["detail"] + assert "subdirectories are not searched" in crumb["detail"] + # The nested file itself is named (#780) — the clause above is unconditional on + # every unpinned no-artifact, so only this line proves the fixture matters. + assert str(nested / "spec-3-1-foo.md") in crumb["detail"] + assert "never read back" in crumb["detail"] + + +def test_resultless_stop_breadcrumb_names_nested_frontmatter_candidate(tmp_path, monkeypatch): + """A marker-less nested spec finalized to a terminal frontmatter would have been + a #224 candidate directly under the dir, so it is named too.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + nested = impl / "stories" + nested.mkdir() + (nested / "spec-3-1-foo.md").write_text("---\nstatus: done\n---\n\n# Story\n", encoding="utf-8") + + assert adapter._result_json(_dev_handle(), _dev_spec(tmp_path), wait=True) is None + + (crumb,) = _breadcrumbs(adapter) + assert crumb["verdict"] == "no-artifact" + assert str(nested / "spec-3-1-foo.md") in crumb["detail"] + + +def test_resultless_stop_breadcrumb_ignores_stale_nested_spec(tmp_path, monkeypatch): + """The nested probe keeps the launch floor: a spec older than the session is a + prior run's artifact, not a hint about this one.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + nested = impl / "stories" + nested.mkdir() + stale = nested / "spec-3-1-foo.md" + stale.write_text(_DONE_SPEC, encoding="utf-8") + launched = stale.stat().st_mtime_ns + 1_000 + os.utime(stale, ns=(launched - 1_000, launched - 1_000)) + + assert adapter._result_json(_dev_handle(launched), _dev_spec(tmp_path), wait=True) is None + + (crumb,) = _breadcrumbs(adapter) + assert crumb["verdict"] == "no-artifact" + assert "subdirectories are not searched" in crumb["detail"] + assert str(stale) not in crumb["detail"] + assert "never read back" not in crumb["detail"] + + +def test_resultless_stop_breadcrumb_does_not_follow_symlinked_subdir(tmp_path, monkeypatch): + """A linked folder is not one level down — it may point anywhere — so the probe + leaves it alone, like every other artifact walk.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + outside = tmp_path / "outside" + outside.mkdir() + (outside / "spec-3-1-foo.md").write_text(_DONE_SPEC, encoding="utf-8") + try: + (impl / "stories").symlink_to(outside, target_is_directory=True) + except OSError as exc: + pytest.skip(f"directory symlinks unavailable: {exc}") + + assert adapter._result_json(_dev_handle(), _dev_spec(tmp_path), wait=True) is None + + (crumb,) = _breadcrumbs(adapter) + assert crumb["verdict"] == "no-artifact" + assert "spec-3-1-foo.md" not in crumb["detail"] + + +def test_resultless_stop_breadcrumb_reports_nested_probe_fault(tmp_path, monkeypatch): + """A probe that could not list the dir says so instead of reading as "nothing + nested".""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + monkeypatch.setattr( + generic.devcontract, + "find_nested_result_hints", + lambda d, *, since_ns: ([], "PermissionError: denied"), + ) + + assert adapter._result_json(_dev_handle(), _dev_spec(tmp_path), wait=True) is None + + (crumb,) = _breadcrumbs(adapter) + assert crumb["verdict"] == "no-artifact" + assert "subdirectory probe failed: PermissionError: denied" in crumb["detail"] + + +def test_nested_result_never_harvested(tmp_path, monkeypatch): + """HARD CONSTRAINT (#780): a nested hit is named, never read back as a result — + not on a Stop, not on the crash path.""" + adapter, impl = make_dev_adapter(tmp_path) + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + nested = impl / "stories" + nested.mkdir() + (nested / "spec-3-1-foo.md").write_text(_DONE_SPEC, encoding="utf-8") + + assert adapter._result_json(_dev_handle(), _dev_spec(tmp_path), wait=False) is None + assert _breadcrumbs(adapter) == [] # wait=False never probes nor crumbs + assert adapter._result_json(_dev_handle(), _dev_spec(tmp_path), wait=True) is None + + def test_resultless_stop_breadcrumb_stories_pending(tmp_path, monkeypatch): adapter, _ = make_dev_adapter(tmp_path) monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) assert adapter._result_json(_dev_handle(), _stories_spec(tmp_path), wait=True) is None (crumb,) = _breadcrumbs(adapter) assert crumb["verdict"] == "pending" + stories_dir = tmp_path / "epic" / "stories" + assert crumb["detail"] == ( + f"no 1-*.md directly under {stories_dir} (subdirectories are not searched)" + ) def test_resultless_stop_breadcrumb_stories_ambiguous(tmp_path): @@ -7586,7 +7702,7 @@ def wait(handle, running_spec): def test_eviction_is_a_noop_when_start_session_raised_pre_capture(tmp_path, monkeypatch): """Eviction must never manufacture an exception. `start_session` runs INSIDE the `try` the mixin's `finally` guards, so a launch that dies before anything was - recorded still reaches `_evict_task_state` with four empty stores — and the + recorded still reaches `_evict_task_state` with five empty stores — and the operator must see the transport fault, not a `KeyError` raised while cleaning up after it. This is why the seam uses `pop(..., None)` / `discard`, never `del` / `remove`: `del` on an absent key would REPLACE the real exception.""" @@ -7609,6 +7725,143 @@ def boom(_cwd): assert adapter._fm_fallback_obs == {} assert adapter._fm_transition_obs == {} assert adapter._contract_nudge_sent == set() + assert adapter._last_resultless == {} + + +# ------------------------------ last resultless verdict on the result (#780) +# +# A spec nested under `impl/stories/` is outside the flat unpinned read-back, so +# every Stop crumbs `no-artifact` into resultless-stops.jsonl and the session rides +# to timeout. Nothing reads that file, so the mixin's `run()` folds the LAST crumb +# onto a non-completed result for the engine's `session-end` entry. Ablations: +# deleting the fold fails the timeout row; dropping the `status != "completed"` +# gate fails the two completed rows; dropping the pop from `_evict_task_state` +# fails the eviction rows. + + +def _stub_dev_lifecycle(adapter, monkeypatch, wait): + monkeypatch.setattr(generic, "RESULT_GRACE_S", 0.0) + monkeypatch.setattr( + generic.GenericAdapter, "start_session", lambda _adapter, _spec: _dev_handle() + ) + adapter.wait_for_completion = wait + adapter.kill = lambda handle: None + adapter._window_alive = lambda handle: False # dead → the post-kill rescue runs + + +def test_run_timeout_carries_last_resultless_verdict(tmp_path, monkeypatch): + """The #780 shape end to end through `run()`: a qualifying spec one directory + down, a real Stop read-back that crumbs `no-artifact`, a timeout the post-kill + rescue cannot upgrade (the scan stays flat). The LAST crumb rides the result, + overwriting an earlier one from the same session.""" + adapter, impl = make_dev_adapter(tmp_path) + nested = impl / "stories" + nested.mkdir() + (nested / "spec-3-1-foo.md").write_text(_DONE_SPEC) + + def wait(handle, running_spec): + adapter._note_resultless_stop(running_spec.task_id, "pending", "an earlier Stop") + assert adapter._result_json(handle, running_spec, wait=True) is None + return _unvouched("timeout") + + _stub_dev_lifecycle(adapter, monkeypatch, wait) + + result = adapter.run(_dev_spec(tmp_path)) + + assert result.status == "timeout" + assert result.result_json is None # diagnosed, never harvested + assert result.resultless_verdict == "no-artifact" + assert result.resultless_detail is not None + assert str(impl) in result.resultless_detail + assert "subdirectories are not searched" in result.resultless_detail + assert _breadcrumbs(adapter)[-1]["detail"] == result.resultless_detail + + +def test_run_completed_carries_no_resultless_verdict(tmp_path, monkeypatch): + """Present-only: a session that completes after an earlier empty Stop leaves + both fields None — the crumb explained a Stop, not the session's outcome.""" + adapter, _impl = make_dev_adapter(tmp_path) + + def wait(handle, running_spec): + assert adapter._result_json(handle, running_spec, wait=True) is None + return SessionResult( + status="completed", + result_json={"status": "done"}, + session_id="sess", + transcript_path="/t.jsonl", + ) + + _stub_dev_lifecycle(adapter, monkeypatch, wait) + + result = adapter.run(_dev_spec(tmp_path)) + + assert len(_breadcrumbs(adapter)) == 1 # the earlier crumb really was written + assert result.status == "completed" + assert result.resultless_verdict is None + assert result.resultless_detail is None + + +def test_run_rescued_result_carries_no_resultless_verdict(tmp_path, monkeypatch): + """The fold sits after `_post_kill_reconcile`, so a stall the rescue upgrades to + `completed` is never annotated with the Stop-time crumb it outgrew.""" + adapter, impl = make_dev_adapter(tmp_path) + + def wait(handle, running_spec): + assert adapter._result_json(handle, running_spec, wait=True) is None + (impl / "spec-3-1-foo.md").write_text(_DONE_SPEC) # written after that Stop + return _unvouched("stalled", stop_seen=True) + + _stub_dev_lifecycle(adapter, monkeypatch, wait) + + result = adapter.run(_dev_spec(tmp_path)) + + assert len(_breadcrumbs(adapter)) == 1 + assert result.status == "completed" + assert result.result_json is not None + assert result.result_json["post_kill_reconciled"] is True + assert result.resultless_verdict is None + assert result.resultless_detail is None + + +def test_last_resultless_evicted_after_run(tmp_path, monkeypatch): + """Same retention bound as the sibling stores: present during the session + (non-vacuous), gone once `run()` returns, scoped to the returning task id.""" + adapter, _impl = make_dev_adapter(tmp_path) + adapter._note_resultless_stop("3-2-dev-1", "no-artifact", "another session in flight") + seen = {} + + def wait(handle, running_spec): + assert adapter._result_json(handle, running_spec, wait=True) is None + seen["present"] = running_spec.task_id in adapter._last_resultless + return _unvouched("timeout") + + _stub_dev_lifecycle(adapter, monkeypatch, wait) + spec = _dev_spec(tmp_path) + + adapter.run(spec) + + assert seen["present"] is True + assert spec.task_id not in adapter._last_resultless + assert adapter._last_resultless["3-2-dev-1"] == ("no-artifact", "another session in flight") + + +def test_last_resultless_evicted_when_wait_raises(tmp_path, monkeypatch): + """A raising `wait_for_completion` skips the fold but not the `finally`; the + exception reaches the caller unchanged.""" + adapter, _impl = make_dev_adapter(tmp_path) + + def raising(handle, running_spec): + assert adapter._result_json(handle, running_spec, wait=True) is None + assert running_spec.task_id in adapter._last_resultless + raise RuntimeError("stop requested") + + _stub_dev_lifecycle(adapter, monkeypatch, raising) + spec = _dev_spec(tmp_path) + + with pytest.raises(RuntimeError, match="stop requested"): + adapter.run(spec) + + assert spec.task_id not in adapter._last_resultless def test_expected_spec_ignores_foreign_markerless_spec(tmp_path, monkeypatch): @@ -7668,9 +7921,30 @@ def test_expected_spec_breadcrumb_names_the_pinned_path(tmp_path, monkeypatch): (crumb,) = _breadcrumbs(adapter) assert crumb["verdict"] == "no-artifact" assert str(ours) in crumb["detail"] + assert "at:" in crumb["detail"] + assert "directly under" not in crumb["detail"] + assert "subdirectories are not searched" not in crumb["detail"] assert "someone-elses" not in crumb["detail"] +def test_expected_spec_breadcrumb_never_probes_subdirectories(tmp_path, monkeypatch): + """The nested probe (#780) belongs to the unpinned scan only: a pinned spec + names the one path owed and never mentions anything one level down.""" + 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") + nested = impl / "stories" + nested.mkdir() + (nested / "spec-3-1-foo.md").write_text(_DONE_SPEC, encoding="utf-8") + 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 str(nested) not in crumb["detail"] + assert "never read back" 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.""" diff --git a/tests/test_runs.py b/tests/test_runs.py index fbc40ed8..f08538ea 100644 --- a/tests/test_runs.py +++ b/tests/test_runs.py @@ -3021,6 +3021,9 @@ def test_run_removal_retries_a_transient_windows_sharing_violation(tmp_path, mon monkeypatch.setattr(platform_util.sys, "platform", real_platform) # restore on teardown sleeps: list[float] = [] monkeypatch.setattr(platform_util.time, "sleep", lambda s: sleeps.append(s)) + # ``time.sleep`` is the process-wide one: the session guard's tmux probe waits + # under a timeout, and ``Popen.wait`` polls with ``time.sleep`` on a slow host. + monkeypatch.setattr(runs, "_refuse_live_session", lambda *_a, **_k: None) real_unlink = os.unlink calls = {"n": 0} @@ -3072,6 +3075,9 @@ def test_run_removal_final_failure_propagates_and_keeps_the_state_dir(tmp_path, state_dir = _seed_state_dir(tmp_path, run_id) sleeps: list[float] = [] monkeypatch.setattr(platform_util.time, "sleep", lambda s: sleeps.append(s)) + # ``time.sleep`` is the process-wide one: the session guard's tmux probe waits + # under a timeout, and ``Popen.wait`` polls with ``time.sleep`` on a slow host. + monkeypatch.setattr(runs, "_refuse_live_session", lambda *_a, **_k: None) real_unlink = os.unlink calls = {"n": 0} denied = PermissionError(13, "Permission denied")