From 9a157188364572dd393e251a4de6584c6b7bd2a1 Mon Sep 17 00:00:00 2001 From: pbean Date: Mon, 27 Jul 2026 22:47:17 -0700 Subject: [PATCH 1/4] feat(engine): warn on max_tokens_per_story at session boundaries The advisory per-story cap was read once, inside _finalize_commit_phase and past advance(task, Phase.DONE): an overrun surfaced only after every token was spent, and a story that deferred or escalated was never checked at all. Re-check the story-cumulative weighted spend at every session boundary in _run_session instead, where task.tokens is fresh and story-cumulative and every run type funnels through. The first crossing journals (now with a `budget` field) and raises an ATTENTION + desktop notice; a persisted StoryTask.token_budget_warned latch keeps it one notice per story across resumes. Still advisory - nothing is terminated, and the #158 per-session guard is untouched. Closes #336 --- CHANGELOG.md | 10 +++ README.md | 2 +- docs/FEATURES.md | 2 +- docs/tui-guide.md | 2 +- src/bmad_loop/data/settings/core.toml | 2 + src/bmad_loop/engine.py | 62 +++++++++++++-- src/bmad_loop/model.py | 10 +++ src/bmad_loop/policy.py | 6 +- tests/test_engine.py | 107 +++++++++++++++++++++++--- tests/test_model.py | 11 +++ 10 files changed, 191 insertions(+), 23 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 7f14ea81..63bc9057 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -101,6 +101,16 @@ story `, the same annotation a sweep bundle writes. Both sprint and stories ### Changed +- **The story token budget is checked while the story runs (#336).** `max_tokens_per_story` was + read once, after the story had already been marked done — so an overrun was reported only after + every token was spent, and a story that deferred or escalated was never checked at all (one field + report burned 8.35M weighted against a 2M cap in silence). The cumulative weighted spend is now + re-checked at every session boundary, on every path a story can take, and the first crossing + raises an ATTENTION + desktop notice naming the spend and the cap. Latched per story and + persisted, so a resume does not re-notify. Still advisory: nothing is terminated — the + session-ending cap remains `limits.max_tokens_per_session`. The `token-budget-exceeded` journal + entry gains a `budget` field. + - **A failed worktree snapshot now blocks the rollback reset (#340).** The two preserve steps were asymmetric: an auto-rollback refused to reset past commits it could not park, but a failed _uncommitted_-work snapshot was journaled and the `reset --hard` ran anyway — destroying the diff --git a/README.md b/README.md index 6e03d71d..4a9f0f47 100644 --- a/README.md +++ b/README.md @@ -594,7 +594,7 @@ One generic driver (`adapters/generic.py`) runs any coding CLI that fits the inj **Copilot — pin a capable model:** Copilot's free default (GPT-5 mini) is unreliable for the multi-step dev/review skills — it silently skips steps mid-workflow and fails the story. Set a capable model in policy, e.g. `[adapter] model = "claude-sonnet-4-6"` (passed through as `--model`), for end-to-end reliability. Because Copilot fires `agentStop` per response turn, a thorough multi-turn review needs more than one nudge to finish; the profile ships `stop_without_result_nudges = 5`, and you can tune it per stage (e.g. `[adapter.review] stop_without_result_nudges = …`). Both knobs are editable in the settings TUI under `[adapter]`. -**On budgets:** agentic sessions are dominated by cache reads (80–90%+ of raw tokens), which every supported vendor bills at ~0.1x base input. The `max_tokens_per_story` check therefore uses a cost-weighted total — cache reads count at `limits.cache_read_weight` (default 0.1). Every display leads with that same weighted figure and names both units, so what you read tracks spend rather than context re-reads: the run-finished summary (stdout, `ATTENTION`, desktop notification) and `bmad-loop status` read ` weighted tokens ( raw incl. cache reads)`, the TUI pairs a weighted `tokens` column with a `raw` one, and each `session-end` journal entry carries `tokens` (raw) beside `tokens_weighted`. Set the weight to 1.0 to budget — and display — raw tokens. Editing the weight and then resuming a paused run re-weights that run's _whole_ accumulated history, not just the sessions after the resume: totals are recomputed from raw counts at the resuming process's weight. That is what the budget has always done (`max_tokens_per_story` weights cumulative raw counts with the live policy), so the displays now match enforcement instead of drifting from it; the `run-resume` journal entry records both weights, so per-session totals written under the old one stay reconstructible. A separate mid-session guard (`limits.max_tokens_per_session`, default 4M weighted; `limits.session_budget_mode` = `off`/`warn`/`enforce`, default `warn`) samples a _running_ session's spend every ~30s and, in enforce mode, nudges it to wrap up and then terminates it `over_budget` (ordinary retry→defer) if it doesn't finish within `limits.session_budget_grace_s`. Mid-session sampling is live-verified on `claude`; other transcript-reading profiles sample the same cumulative files best-effort (mid-turn flush behavior unverified), and profiles with no mid-session usage signal (`usage_parser = "none"`, Copilot's shutdown-only flush) leave the guard inert. +**On budgets:** agentic sessions are dominated by cache reads (80–90%+ of raw tokens), which every supported vendor bills at ~0.1x base input. The `max_tokens_per_story` check therefore uses a cost-weighted total — cache reads count at `limits.cache_read_weight` (default 0.1). The story's cumulative spend is re-checked after every session it runs, so a story that blows its budget says so while it is still running rather than after it lands — and a story that defers or escalates is checked just like one that commits. The first crossing raises one ATTENTION + desktop notice (`story token budget exceeded: `); the cap is advisory, so nothing is terminated and the story runs on — stop the run yourself if the spend is no longer worth it. The warning is latched per story and persisted, so a resumed run does not repeat it. Every display leads with that same weighted figure and names both units, so what you read tracks spend rather than context re-reads: the run-finished summary (stdout, `ATTENTION`, desktop notification) and `bmad-loop status` read ` weighted tokens ( raw incl. cache reads)`, the TUI pairs a weighted `tokens` column with a `raw` one, and each `session-end` journal entry carries `tokens` (raw) beside `tokens_weighted`. Set the weight to 1.0 to budget — and display — raw tokens. Editing the weight and then resuming a paused run re-weights that run's _whole_ accumulated history, not just the sessions after the resume: totals are recomputed from raw counts at the resuming process's weight. That is what the budget has always done (`max_tokens_per_story` weights cumulative raw counts with the live policy), so the displays now match enforcement instead of drifting from it; the `run-resume` journal entry records both weights, so per-session totals written under the old one stay reconstructible. A separate mid-session guard (`limits.max_tokens_per_session`, default 4M weighted; `limits.session_budget_mode` = `off`/`warn`/`enforce`, default `warn`) samples a _running_ session's spend every ~30s and, in enforce mode, nudges it to wrap up and then terminates it `over_budget` (ordinary retry→defer) if it doesn't finish within `limits.session_budget_grace_s`. Mid-session sampling is live-verified on `claude`; other transcript-reading profiles sample the same cumulative files best-effort (mid-turn flush behavior unverified), and profiles with no mid-session usage signal (`usage_parser = "none"`, Copilot's shutdown-only flush) leave the guard inert. **Shared prerequisites:** the `bmad-loop-*` skills must be present in `.agents/skills/` (codex and gemini read it; Claude Code reads `.claude/skills/`), and each CLI must have been run once interactively in the project for auth/trust — `bmad-loop init --cli codex --cli gemini` installs the skills into `.agents/skills/`, registers the hook relay, and prints the per-CLI first-run steps. diff --git a/docs/FEATURES.md b/docs/FEATURES.md index 640eed44..bb5ec71a 100644 --- a/docs/FEATURES.md +++ b/docs/FEATURES.md @@ -143,7 +143,7 @@ See [README.md](../README.md) for the narrative overview and [setup-guide.md](se ### Budgeting & cost tracking - Mid-session per-session token budget (`max_tokens_per_session`, default 4M weighted): both adapter wait loops sample cumulative usage on the ~30s heartbeat cadence and trip once on crossing the cap, per `session_budget_mode` — `warn` (default) raises an ATTENTION + lifecycle breadcrumb only; `enforce` additionally sends a wrap-up nudge, grants `session_budget_grace_s` (default 240s) to finish, then terminates the session `over_budget` (ordinary retry→defer routing; an artifact flushed at kill time is still honored). Mid-session sampling is live-verified on `claude`; other transcript-reading profiles sample the same cumulative files best-effort (early transcript-path delivery and mid-turn flush behavior are unverified vendor behavior), the wrap-up nudge into a busy pane is best-effort everywhere (the termination is the guarantee, the nudge a courtesy), and adapters with no mid-session usage signal (`usage_parser = "none"`, Copilot's shutdown-only flush) leave the guard inert. -- Per-story token budget (`max_tokens_per_story`, advisory, checked post-done) using the same cost-weighted total — cache reads counted at `cache_read_weight` (default 0.1, matching ~0.1x vendor billing). Every operator-facing total leads with that weighted figure and labels both units — the run-finished summary and `bmad-loop status` read ` weighted tokens ( raw incl. cache reads)`, the TUI pairs a weighted `tokens` column with a `raw` one, and `session-end` journal entries carry `tokens` beside `tokens_weighted`. +- Per-story token budget (`max_tokens_per_story`, default 2M weighted, advisory) using the same cost-weighted total — cache reads counted at `cache_read_weight` (default 0.1, matching ~0.1x vendor billing). The story's cumulative spend is re-checked at **every session boundary**, so an overrun surfaces while the story is still running and regardless of how it ends — a story that defers or escalates is judged like one that commits. The first crossing raises one ATTENTION + desktop notice (`story token budget exceeded: `) and a `token-budget-exceeded` journal entry carrying `weighted`, `total` and `budget`; the warning is latched per story (and persisted, so a resume does not re-notify) and nothing is terminated — advisory means the story runs on. Every operator-facing total leads with that weighted figure and labels both units — the run-finished summary and `bmad-loop status` read ` weighted tokens ( raw incl. cache reads)`, the TUI pairs a weighted `tokens` column with a `raw` one, and `session-end` journal entries carry `tokens` beside `tokens_weighted`. - Token usage read from each CLI's local session transcript (per-profile `usage_parser`), aggregated per story (`bmad-loop status`). ### Configuration (`.bmad-loop/policy.toml`) diff --git a/docs/tui-guide.md b/docs/tui-guide.md index dacb4668..e693b233 100644 --- a/docs/tui-guide.md +++ b/docs/tui-guide.md @@ -558,7 +558,7 @@ behavior. | `limits.dev_stall_nudges` | int ≥ 0 | 2 | wake-nudges on grace expiry before stalling; a Stop response restores the budget · 0 = stall on grace expiry | | `limits.dev_stall_nudges_cap` | int ≥ 0 | 6 | total (never-restored) wake-nudges per dev/review session — bounds the refill loop when the reply to a nudge is itself a result-less Stop | | `limits.workflow_stall_nudges_cap` | int ≥ 0 | 3 | same monotonic cap for an injected plugin-workflow session that finished its work but never wrote its completion marker · 0 = stall on first grace expiry | -| `limits.max_tokens_per_story` | int ≥ 1 | 2000000 | cost-weighted budget | +| `limits.max_tokens_per_story` | int ≥ 1 | 2000000 | advisory cost-weighted cap on a story's cumulative spend, re-checked at every session boundary; one ATTENTION + desktop notice per story on the crossing, nothing terminated | | `limits.cache_read_weight` | float 0.0–1.0 | 0.1 | cache-read weight in every token total, budgets and displays alike; 1.0 = raw | | `limits.session_budget_mode` | select | `warn` | mid-session per-session budget guard: `off` (no sampling) / `warn` (one ATTENTION + breadcrumb) / `enforce` (wrap-up nudge, then `over_budget` termination → retry/defer) | | `limits.max_tokens_per_session` | int ≥ 1 | 4000000 | weighted per-session cap sampled every ~30s mid-session; healthy sessions run ~1–2.5M weighted, so the default trips only true runaways | diff --git a/src/bmad_loop/data/settings/core.toml b/src/bmad_loop/data/settings/core.toml index 58559d1c..b50db617 100644 --- a/src/bmad_loop/data/settings/core.toml +++ b/src/bmad_loop/data/settings/core.toml @@ -153,6 +153,8 @@ key = "max_tokens_per_story" kind = "int" minimum = 1 default_ref = "LimitsPolicy.max_tokens_per_story" +label = "story budget (weighted tokens)" +description = "advisory cap on one story's cumulative weighted spend across all its sessions, re-checked at every session boundary · crossing it raises one ATTENTION + desktop notice per story and nothing else — the story runs on · for a cap that can END a session see session budget mode below" [[section.field]] key = "cache_read_weight" kind = "float" diff --git a/src/bmad_loop/engine.py b/src/bmad_loop/engine.py index 8bbac822..8d48ff10 100644 --- a/src/bmad_loop/engine.py +++ b/src/bmad_loop/engine.py @@ -1799,14 +1799,6 @@ def _finalize_commit_phase(self, task: StoryTask) -> None: self.journal.append("story-done", story_key=task.story_key, commit=task.commit_sha) self._emit("post_commit", task) self._save() - weighted = task.tokens.weighted_total(self.policy.limits.cache_read_weight) - if weighted > self.policy.limits.max_tokens_per_story: - self.journal.append( - "token-budget-exceeded", - story_key=task.story_key, - weighted=weighted, - total=task.tokens.total, - ) # ----------------------------------------------------- override seams # SweepEngine reuses the dev/review pipeline for deferred-work bundles by @@ -2750,6 +2742,7 @@ def _run_session( except Exception: # nosec B110 pass self._save() + self._note_story_token_budget(task) self._emit( "post_session", task, @@ -2762,6 +2755,59 @@ def _run_session( ) return result # pyright: ignore[reportReturnType] + def _note_story_token_budget(self, task: StoryTask) -> None: + """Warn once when a story's cost-weighted spend crosses + ``limits.max_tokens_per_story``, at the session boundary that crossed it. + + The cap is advisory by contract (docs/FEATURES.md) — this warns, it never + terminates. Enforcement is the separate mid-session guard (#158, + ``max_tokens_per_session``), a different cap with its own latch, untouched + here. + + Placement is the whole point of #336. The predecessor check sat in + ``_finalize_commit_phase`` past ``advance(task, Phase.DONE)``, so it saw + only stories that committed and only after their last token was spent: the + reported 4x overrun happened on a story that DEFERRED, which produced no + record at all — total silence, not late silence. Every session of every run + type funnels through ``_run_session``, so judging here covers the deferring + and escalating stories too, and SweepEngine/StoriesEngine inherit it + unchanged. + + Called after the tail ``_save()``, where ``task.tokens`` is both fresh + (``attach_session_usage`` folded this session in above) and + story-cumulative (it is the task's running total, not the session's). A + session that aborted never reaches here — the exception propagates past the + ``finally`` — so no story is judged on a usage read that did not happen. + + Weight comes from live ``self.policy``, not ``state.cache_read_weight()``: + this is the enforcement side of the split documented at ``summary()`` — + displays must reproduce from state.json, budgets bind at the policy the + running process enforces.""" + if task.token_budget_warned: + return + budget = self.policy.limits.max_tokens_per_story + weighted = task.tokens.weighted_total(self.policy.limits.cache_read_weight) + if weighted <= budget: + return + task.token_budget_warned = True + self.journal.append( + "token-budget-exceeded", + story_key=task.story_key, + weighted=weighted, + total=task.tokens.total, + budget=budget, + ) + gates.notify( + self.policy, + self.run_dir, + f"story token budget exceeded: {task.story_key}", + f"{weighted} weighted tokens ({task.tokens.total} raw incl. cache reads) " + f"past the {budget} `limits.max_tokens_per_story` cap — advisory: the " + f"story continues. Stop the run with `bmad-loop stop` if the spend is " + f"no longer worth it.", + ) + self._save() + def _dev_prompt(self, task: StoryTask, feedback: Path | None) -> str: return self._generic_dev_prompt(task, feedback) diff --git a/src/bmad_loop/model.py b/src/bmad_loop/model.py index b3addec5..a12bc308 100644 --- a/src/bmad_loop/model.py +++ b/src/bmad_loop/model.py @@ -253,6 +253,14 @@ class StoryTask: branch: str = "" sessions: list[SessionRecord] = field(default_factory=list) tokens: TokenUsage = field(default_factory=TokenUsage) + # latched the first time this story's cost-weighted spend crossed + # limits.max_tokens_per_story at a session boundary, so the advisory notice + # fires once per STORY rather than once per session after the crossing + # (every later session of an overrunning story is over the cap too). Never + # cleared: the crossing is a fact about the story's spend, and the raw + # counts it was computed from stay in `tokens`. Persisted precisely so a + # resumed run does not re-notify what the pre-pause process already did. + token_budget_warned: bool = False @property def terminal(self) -> bool: @@ -306,6 +314,7 @@ def to_dict(self) -> dict[str, Any]: "branch": self.branch, "sessions": [s.to_dict() for s in self.sessions], "tokens": self.tokens.to_dict(), + "token_budget_warned": self.token_budget_warned, } def _serialized_spec_file(self) -> str | None: @@ -355,6 +364,7 @@ def from_dict(cls, d: dict[str, Any]) -> "StoryTask": branch=str(d.get("branch", "")), sessions=[SessionRecord.from_dict(s) for s in d.get("sessions", [])], tokens=TokenUsage.from_dict(d.get("tokens", {})), + token_budget_warned=bool(d.get("token_budget_warned", False)), ) diff --git a/src/bmad_loop/policy.py b/src/bmad_loop/policy.py index 901ff5db..f80a95cd 100644 --- a/src/bmad_loop/policy.py +++ b/src/bmad_loop/policy.py @@ -141,6 +141,9 @@ class LimitsPolicy: # for a session that never complies. True enables it; False keeps the pre-M4 # behavior (synthesis only). dev_contract_nudge: bool = True + # advisory cost-weighted cap on a whole STORY's cumulative spend, re-checked + # at every session boundary and warned about once per story (#336). Nothing + # is terminated on the crossing — enforcement is max_tokens_per_session below. max_tokens_per_story: int = 2_000_000 # weight of cache-read tokens in the budget check (1.0 = count raw) cache_read_weight: float = 0.1 @@ -153,7 +156,8 @@ class LimitsPolicy: session_budget_mode: str = "warn" # weighted (cache_read_weight-discounted) per-SESSION cap the adapter wait # loops sample cumulative usage against every ~30s heartbeat tick. Distinct - # from the advisory post-done max_tokens_per_story. + # from the advisory per-story max_tokens_per_story: this one is per session + # and can end it; that one spans a story's sessions and only warns. max_tokens_per_session: int = 4_000_000 # enforce mode: seconds a tripped session gets to wrap up after the nudge # before it is terminated over_budget. 0 = terminate at trip, no nudge. diff --git a/tests/test_engine.py b/tests/test_engine.py index 2529797c..83a39d60 100644 --- a/tests/test_engine.py +++ b/tests/test_engine.py @@ -1232,18 +1232,21 @@ def test_session_end_journals_weighted_beside_raw(project): assert end["tokens_weighted"] == 660 # 100 + 50 + 10 + round(1000 * 0.5) -def test_token_budget_exceeded_journals_weighted(project): +def _budget_engine(project, script, *, budget, usage=None): + """A one-story run whose weighted per-session spend is 80k, against `budget`.""" write_sprint(project, {"epic-1": "backlog", "1-1-a": "ready-for-dev"}) - usage = TokenUsage(input_tokens=15_000, output_tokens=5_000, cache_read_tokens=600_000) run_dir = project.project / ".bmad-loop" / "runs" / "test-run" adapter = MockAdapter( - [dev_effect(project, "1-1-a"), review_effect(project, "1-1-a", clean=True)], - usage_per_session=usage, + script, + usage_per_session=usage + or TokenUsage(input_tokens=15_000, output_tokens=5_000, cache_read_tokens=600_000), ) policy = Policy( gates=GatesPolicy(mode="none"), notify=QUIET, - limits=LimitsPolicy(max_tokens_per_story=100_000), # < 2 x 80k weighted + # the deferring-story case needs the retry/defer continuation path + scm=ScmPolicy(rollback_on_failure=True), + limits=LimitsPolicy(max_tokens_per_story=budget), ) engine = Engine( paths=project, @@ -1253,15 +1256,97 @@ def test_token_budget_exceeded_journals_weighted(project): journal=Journal(run_dir), state=RunState(run_id="test-run", project=str(project.project), started_at="now"), ) + return engine, policy + + +def _budget_entries(engine): + return [e for e in engine.journal.entries() if e["kind"] == "token-budget-exceeded"] + + +def test_token_budget_exceeded_journals_weighted(project): + """The crossing is judged at the session boundary that crossed it — here the + second of two sessions — and warns exactly once with the story-cumulative + figure, the cap it was compared against, and an operator-facing notice.""" + engine, _ = _budget_engine( + project, + [dev_effect(project, "1-1-a"), review_effect(project, "1-1-a", clean=True)], + budget=100_000, # < 2 x 80k weighted, > 1 x 80k + ) engine.run() - entries = [ - line - for line in (run_dir / "journal.jsonl").read_text().splitlines() - if "token-budget-exceeded" in line - ] + entries = _budget_entries(engine) + assert len(entries) == 1 + assert entries[0]["weighted"] == 160_000 + assert entries[0]["total"] == 2 * 620_000 + assert entries[0]["budget"] == 100_000 + attention = (engine.run_dir / "ATTENTION").read_text() + assert "story token budget exceeded: 1-1-a" in attention + assert "160000 weighted tokens" in attention + assert "advisory" in attention + assert engine.state.tasks["1-1-a"].token_budget_warned is True + + +def test_token_budget_warns_on_a_story_that_never_commits(project): + """The reported overrun (#336) was on a story that DEFERRED. The predecessor + check ran past `advance(task, Phase.DONE)`, so only committing stories were + ever judged and this one produced no record at all.""" + engine, _ = _budget_engine( + project, + [SessionResult(status="stalled"), SessionResult(status="stalled")], + budget=100_000, + ) + summary = engine.run() + + assert summary.deferred == 1 + assert engine.state.tasks["1-1-a"].phase == Phase.DEFERRED + entries = _budget_entries(engine) + assert len(entries) == 1 + assert entries[0]["weighted"] == 160_000 + + +def test_token_budget_warns_once_per_story(project): + """The latch is per story, not per session: every session AFTER the crossing + is over the cap too, so without it an overrunning story would re-notify for + the rest of its life.""" + engine, _ = _budget_engine( + project, + [dev_effect(project, "1-1-a"), review_effect(project, "1-1-a", clean=True)], + budget=1, # every session boundary is over + ) + summary = engine.run() + + assert summary.done == 1 + entries = _budget_entries(engine) assert len(entries) == 1 - assert '"weighted": 160000' in entries[0] + # the FIRST crossing, not the run total — the notice is not re-sent per session + assert entries[0]["weighted"] == 80_000 + + +def test_token_budget_latch_survives_resume(project): + """The latch is persisted, so the crossing stays a one-time event per story + rather than per process — a resumed run inherits "already warned".""" + engine, policy = _budget_engine(project, [dev_effect(project, "1-1-a")], budget=1) + + original_emit = engine._emit + + def crashing_emit(stage, *args, **kwargs): + # die in the post-session window, just past the budget note + if stage == "post_session": + raise RuntimeError("host died in the post-session window") + return original_emit(stage, *args, **kwargs) + + engine._emit = crashing_emit + assert engine.run().crashed + assert load_state(engine.run_dir).tasks["1-1-a"].token_budget_warned is True + + resumed, _ = resume_engine( + project, engine, [review_effect(project, "1-1-a", clean=True)], policy=policy + ) + assert resumed.run().done == 1 + + # the resumed review session is over the cap on the story's persisted totals; + # only the inherited latch keeps it quiet. + assert len(_budget_entries(resumed)) == 1 # ------------------------------ mid-session token-budget guard (#158) diff --git a/tests/test_model.py b/tests/test_model.py index 6ff09369..1a676588 100644 --- a/tests/test_model.py +++ b/tests/test_model.py @@ -193,6 +193,17 @@ def test_preserve_ref_defaults_none_for_legacy_state(): assert restored.preserve_ref is None and restored.preserve_partial is False +def test_token_budget_warned_round_trips(): + task = StoryTask(story_key="1-1-a", epic=1, token_budget_warned=True) + assert StoryTask.from_dict(task.to_dict()).token_budget_warned is True + + +def test_token_budget_warned_defaults_false_for_legacy_state(): + doc = StoryTask(story_key="1-1-a", epic=1).to_dict() + del doc["token_budget_warned"] # state.json from before the field existed + assert StoryTask.from_dict(doc).token_budget_warned is False + + def test_stopped_round_trips(): state = _state(stopped=True) assert RunState.from_dict(state.to_dict()).stopped is True From 2771189fb93ab0941e1ec5b7784e4eca72be0ed1 Mon Sep 17 00:00:00 2001 From: pbean Date: Mon, 27 Jul 2026 23:33:28 -0700 Subject: [PATCH 2/4] fix(engine): journal the story budget overrun before latching the warning `token_budget_warned` was set before the journal.append it suppresses. Journal.append is unguarded IO, and _run_inner's finally persists the task on every abort arm, so an OSError there made the latch durable with no journal entry and no notice - the story's overrun suppressed forever, which is #336 itself. Unlike the phase _record_defer/_escalate set before their own writes, this bit is rendered on no surface, so a lost record is unrecoverable. Latch after the append instead; the journal -> notify -> save emit order is unchanged. _save() deliberately stays last: at-least-once is the right bias for an anti-silence warning, and the run-level finally already covers every in-process abort. --- src/bmad_loop/engine.py | 24 ++++++++++++++++++++++-- tests/test_engine.py | 29 +++++++++++++++++++++++++++++ 2 files changed, 51 insertions(+), 2 deletions(-) diff --git a/src/bmad_loop/engine.py b/src/bmad_loop/engine.py index 8d48ff10..fe917c40 100644 --- a/src/bmad_loop/engine.py +++ b/src/bmad_loop/engine.py @@ -2782,14 +2782,17 @@ def _note_story_token_budget(self, task: StoryTask) -> None: Weight comes from live ``self.policy``, not ``state.cache_read_weight()``: this is the enforcement side of the split documented at ``summary()`` — displays must reproduce from state.json, budgets bind at the policy the - running process enforces.""" + running process enforces. + + Emit order is load-bearing at both ends — see the comments below. The + invariant: never latch a suppression bit before the record it suppresses + is durable.""" if task.token_budget_warned: return budget = self.policy.limits.max_tokens_per_story weighted = task.tokens.weighted_total(self.policy.limits.cache_read_weight) if weighted <= budget: return - task.token_budget_warned = True self.journal.append( "token-budget-exceeded", story_key=task.story_key, @@ -2797,6 +2800,16 @@ def _note_story_token_budget(self, task: StoryTask) -> None: total=task.tokens.total, budget=budget, ) + # Latch only once the record it suppresses is durable. Unlike the phase + # this method's siblings set before their own journal write + # (`_record_defer`, `_escalate`), `token_budget_warned` is rendered on no + # surface — it is a pure suppression bit, so "latch persisted, record + # lost" is a story that overran in total silence, i.e. #336 itself. The + # append above is unguarded IO (journal.py) and the run-level `finally` + # in `_run_inner` persists whatever the task carries on EVERY abort arm, + # so latching first would bury the overrun for good on an OSError there. + # Leaving it unlatched costs at most a duplicate notice next boundary. + task.token_budget_warned = True gates.notify( self.policy, self.run_dir, @@ -2806,6 +2819,13 @@ def _note_story_token_budget(self, task: StoryTask) -> None: f"story continues. Stop the run with `bmad-loop stop` if the spend is " f"no longer worth it.", ) + # ...and `_save()` stays AFTER the notice, the emit order every + # record-a-decision site shares. That same run-level `finally` already + # makes the latch durable on any in-process abort in this window, so only + # a SIGKILL can re-warn — and at-least-once is the right bias for a + # warning whose whole purpose is to not be silent: a duplicate ATTENTION + # line is cosmetic, a lost one is the bug. Do not hoist this above the + # emit pair; that trades the cosmetic failure for the silent one. self._save() def _dev_prompt(self, task: StoryTask, feedback: Path | None) -> str: diff --git a/tests/test_engine.py b/tests/test_engine.py index 83a39d60..d4ca51aa 100644 --- a/tests/test_engine.py +++ b/tests/test_engine.py @@ -1349,6 +1349,35 @@ def crashing_emit(stage, *args, **kwargs): assert len(_budget_entries(resumed)) == 1 +def test_token_budget_latch_waits_for_the_durable_record(project): + """The latch is a pure suppression bit — it must never outlive a failed + journal write. `Journal.append` is unguarded IO, and the run-level `finally` + persists whatever the task carries on every abort arm, so latching before the + record would leave a story that overran suppressed forever with nothing + written anywhere: #336 again, from an ordinary OSError.""" + engine, policy = _budget_engine(project, [dev_effect(project, "1-1-a")], budget=1) + + real_append = engine.journal.append + + def failing_append(kind, **fields): + if kind == "token-budget-exceeded": + raise OSError("journal.jsonl is not writable") + return real_append(kind, **fields) + + engine.journal.append = failing_append + assert engine.run().crashed + # the record never landed, so the bit that would suppress it must not have + assert load_state(engine.run_dir).tasks["1-1-a"].token_budget_warned is False + + engine.journal.append = real_append # the resumed engine reuses this Journal + resumed, _ = resume_engine( + project, engine, [review_effect(project, "1-1-a", clean=True)], policy=policy + ) + assert resumed.run().done == 1 + # still owed, so still delivered — one entry, from the resumed session + assert len(_budget_entries(resumed)) == 1 + + # ------------------------------ mid-session token-budget guard (#158) From 5cbb7d191abb343932d997b82ae47f78fb5f1e92 Mon Sep 17 00:00:00 2001 From: pbean Date: Mon, 27 Jul 2026 23:33:34 -0700 Subject: [PATCH 3/4] fix(gates): never let an unwritable ATTENTION file crash the run notify() documented "never raises", but only the desktop half was guarded - the ATTENTION append was bare IO. An unwritable run dir therefore turned an advisory notice into a run crash at every record-a-decision site (defer, escalate, plugin veto, manual-recovery pause, budget warnings), several of which notify after already journaling a decision they cannot unwind. Degrade the file sink like the desktop one, per the observe-degrade rule the adapter budget guards already apply to this same call. The journal entry each caller writes first stays the durable record. --- src/bmad_loop/gates.py | 14 ++++++++++++-- tests/test_gates.py | 17 +++++++++++++++++ 2 files changed, 29 insertions(+), 2 deletions(-) diff --git a/src/bmad_loop/gates.py b/src/bmad_loop/gates.py index 5e6860c0..bf4eb110 100644 --- a/src/bmad_loop/gates.py +++ b/src/bmad_loop/gates.py @@ -91,8 +91,18 @@ def notify(policy: Policy, run_dir: Path, title: str, message: str) -> None: at the command-construction level; verify visual delivery manually per OS.""" if policy.notify.file: stamp = time.strftime("%Y-%m-%d %H:%M:%S") - with (run_dir / ATTENTION_FILE).open("a", encoding="utf-8") as f: - f.write(f"[{stamp}] {title}: {message}\n") + try: + with (run_dir / ATTENTION_FILE).open("a", encoding="utf-8") as f: + f.write(f"[{stamp}] {title}: {message}\n") + except OSError: + # observe-degrade: an unwritable ATTENTION file is observability, + # never a reason to break the loop (the _write_heartbeat doctrine, + # already applied to this same call in the adapter budget guards). + # Without it the "never raises" contract above was false for the + # file half, and an unwritable run dir turned an advisory notice + # into a run crash at every record-a-decision site. The journal + # entry each caller writes first stays the durable record. + pass # Native desktop notification per platform: osascript (macOS), a best-effort # WinRT PowerShell toast (Windows), notify-send (Linux). None → silently skip; # `validate` and run start warn separately when notify.desktop is inert here. diff --git a/tests/test_gates.py b/tests/test_gates.py index 8354a43f..ecbcb2f8 100644 --- a/tests/test_gates.py +++ b/tests/test_gates.py @@ -38,6 +38,23 @@ def test_notify_file_appends_attention_line(tmp_path): assert "worktree-open-failed: mount lost" in line +def test_notify_file_swallows_an_unwritable_attention_path(tmp_path, monkeypatch): + """The "never raises" contract covers the file sink too. An unwritable + ATTENTION path is observability degrading, not a reason to break the run — + every engine caller notifies on a path where a raise would crash the run or + unwind a decision it has already journaled. + + A directory at the ATTENTION path is the portable way to make the append + fail: IsADirectoryError on POSIX, PermissionError on Windows, both OSError. + chmod would not do it under root (CI) or on Windows. + """ + (tmp_path / gates.ATTENTION_FILE).mkdir() + # the desktop half must not be what absorbs this + monkeypatch.setattr(gates, "desktop_notifier_kind", lambda: None) + + gates.notify(_policy(desktop=False, file=True), tmp_path, "story deferred: 1-1-a", "verify") + + # ------------------------------------------------ desktop_notifier_kind() From fcc510f3515ac70c5ffcfdb3819c11c68ce1d9ee Mon Sep 17 00:00:00 2001 From: pbean Date: Mon, 27 Jul 2026 23:33:39 -0700 Subject: [PATCH 4/4] fix(policy): validate max_tokens_per_story like the session cap The field was parsed with a bare int(): `true` coerced to a 1-token story cap and `0` was accepted, both against the documented int >= 1 (core.toml already sets minimum = 1, so the settings TUI could not produce either). max_tokens_per_session has carried the bool/int and >= 1 guards since #158; mirror them. Pre-existing, but the session-boundary check makes it loud: a 0/1 cap now warns at the first session boundary of every story instead of once post-done. Rejects a policy.toml that previously loaded - there is no 0 = off semantic. --- CHANGELOG.md | 14 ++++++++++++++ src/bmad_loop/policy.py | 17 +++++++++++++---- tests/test_policy.py | 21 +++++++++++++++++++++ 3 files changed, 48 insertions(+), 4 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 63bc9057..5911a336 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -174,6 +174,20 @@ story `, the same annotation a sweep bundle writes. Both sprint and stories ### Fixed +- **An unwritable `ATTENTION` file can no longer crash a run.** `gates.notify` promised "never + raises", but only its desktop half was guarded — the `ATTENTION` append was bare IO, so an + unwritable run dir turned an advisory notice into a run crash at every site that journals a + decision and then announces it (defer, escalate, plugin veto, manual-recovery pause, budget + warnings). The file sink now degrades like the desktop one, matching the observe-degrade rule the + adapter budget guards already applied to the same call. The journal entry each caller writes + first remains the durable record. + +- **`limits.max_tokens_per_story` is validated like its per-session sibling.** It was parsed with a + bare `int()`, so `true` silently became a 1-token story cap and `0` was accepted — both against + the documented `int >= 1`. Non-integers and values below 1 now raise `PolicyError` at load, the + same rule `max_tokens_per_session` has always used. Note this rejects a `policy.toml` that + previously loaded; there is no `0 = off` semantic (set the cap high instead — it only warns). + - **A pause inside a defer's rollback no longer loses the defer record (#342).** `_defer` advanced the task to terminal DEFERRED before recovering the tree, so a rollback that paused instead (rollback OFF — the default — or a preserve/snapshot failure) unwound past the tail forever: no diff --git a/src/bmad_loop/policy.py b/src/bmad_loop/policy.py index f80a95cd..12feecd7 100644 --- a/src/bmad_loop/policy.py +++ b/src/bmad_loop/policy.py @@ -699,7 +699,14 @@ def loads(text: str, plugin_schemas: dict[str, Any] | None = None) -> Policy: # the budget knobs gate enforce-mode termination, so a coerced bool/float # (true -> 1 token) must be rejected, not silently accepted (same rule as - # scm.preserve_keep below) + # scm.preserve_keep below). The per-story cap is checked here on the same + # terms even though it only warns: a coerced `true` caps a whole story at 1 + # token, which now fires at the first session boundary of every story. + max_tokens_per_story = limits_d.get("max_tokens_per_story", LimitsPolicy.max_tokens_per_story) + if isinstance(max_tokens_per_story, bool) or not isinstance(max_tokens_per_story, int): + raise PolicyError( + f"limits.max_tokens_per_story must be an integer: got {max_tokens_per_story!r}" + ) max_tokens_per_session = limits_d.get( "max_tokens_per_session", LimitsPolicy.max_tokens_per_session ) @@ -740,9 +747,7 @@ def loads(text: str, plugin_schemas: dict[str, Any] | None = None) -> Policy: dev_contract_nudge=bool( limits_d.get("dev_contract_nudge", LimitsPolicy.dev_contract_nudge) ), - max_tokens_per_story=int( - limits_d.get("max_tokens_per_story", LimitsPolicy.max_tokens_per_story) - ), + max_tokens_per_story=max_tokens_per_story, cache_read_weight=float(limits_d.get("cache_read_weight", LimitsPolicy.cache_read_weight)), session_budget_mode=str( limits_d.get("session_budget_mode", LimitsPolicy.session_budget_mode) @@ -781,6 +786,10 @@ def loads(text: str, plugin_schemas: dict[str, Any] | None = None) -> Policy: f"limits.session_budget_mode must be one of {sorted(SESSION_BUDGET_MODES)}: " f"got {limits.session_budget_mode!r}" ) + if limits.max_tokens_per_story < 1: + raise PolicyError( + f"limits.max_tokens_per_story must be >= 1: got {limits.max_tokens_per_story}" + ) if limits.max_tokens_per_session < 1: raise PolicyError( f"limits.max_tokens_per_session must be >= 1: got {limits.max_tokens_per_session}" diff --git a/tests/test_policy.py b/tests/test_policy.py index 87615cb5..169c404b 100644 --- a/tests/test_policy.py +++ b/tests/test_policy.py @@ -437,6 +437,27 @@ def test_invalid_session_budget_mode(): policy.loads('[limits]\nsession_budget_mode = "sometimes"\n') +def test_max_tokens_per_story_default_and_parse(): + assert policy.loads("").limits.max_tokens_per_story == 2_000_000 + assert policy.loads("[limits]\nmax_tokens_per_story = 500\n").limits.max_tokens_per_story == 500 + + +@pytest.mark.parametrize("bad", [0, -1]) +def test_max_tokens_per_story_must_be_positive(bad): + """Documented as int >= 1 (core.toml `minimum = 1`), but the parser used a + bare int() and took 0 — which now warns on every story at its first session + boundary rather than once post-done.""" + with pytest.raises(policy.PolicyError, match=r"limits\.max_tokens_per_story"): + policy.loads(f"[limits]\nmax_tokens_per_story = {bad}\n") + + +@pytest.mark.parametrize("bad", ["true", "2.5", '"2M"']) +def test_max_tokens_per_story_rejects_non_integers(bad): + """Same rule as the per-session cap: `true` coerced to a 1-token story cap.""" + with pytest.raises(policy.PolicyError, match=r"limits\.max_tokens_per_story"): + policy.loads(f"[limits]\nmax_tokens_per_story = {bad}\n") + + def test_max_tokens_per_session_default_parse_and_template(): import tomllib