Efficiency Analysis of run transcripts

cmoriarty commented

2026-10-02 10:35:09 -04:00

Owner

We now have several finished runs for the scratch project. I'd like to analzye the transcript of all the steps in each run and find inefficiencies that we can improve. I'm looking for places the agent didn't correctly follow a brief, or if the agent is duplicating work already done, or when the agent spends time because of some technical problem or missing dependency it has to work around. Really look deeply at all of the transcripts and find problems that we can fix and make the process faster and more reliable, faster is the key! Braid is currently painfully slow, and I have a hunch we are going to find tons of inefficiencies.

Of course, any other problems you can identify should also be analyzed, I'm just provided a few obvious things to look for.

Initially, just present the findings here in a concise, easy to parse by a human kind of way, and I'll decide what to implement as part of this issue, and what to spin off as other issues.

We now have several finished runs for the scratch project. I'd like to analzye the transcript of all the steps in each run and find inefficiencies that we can improve. I'm looking for places the agent didn't correctly follow a brief, or if the agent is duplicating work already done, or when the agent spends time because of some technical problem or missing dependency it has to work around. Really look deeply at all of the transcripts and find problems that we can fix and make the process faster and more reliable, faster is the key! Braid is currently painfully slow, and I have a hunch we are going to find tons of inefficiencies. Of course, any other problems you can identify should also be analyzed, I'm just provided a few obvious things to look for. Initially, just present the findings here in a concise, easy to parse by a human kind of way, and I'll decide what to implement as part of this issue, and what to spin off as other issues.

cmoriarty commented

2026-10-02 15:30:04 -04:00

Author

Owner

Findings: where the scratch runs spend their time

I read every step transcript of the eight finished scratch runs: the plan run 21, the feature runs 22, 23, 25, 26, 36 and 37 (git-flow), and the quick-fix verification run 33. The archived runs 24, 29 and 34 were used only to explain failures. Run numbers are Braid's ledger numbers, not issues. In total that is about 2,100 model turns and 4,100 tool calls. Unless noted, the figures are for the six feature runs: 1,251 min of wall clock.

The short version

The model's thinking is the cost. Inside agent steps, 79% of the time is the model generating, 8% is waiting for the first token and 6% is tools. Of the generated tokens, 79% are reasoning (2.17M reasoning, 0.59M visible). Tests are cheap: the whole backend suite runs in about 10 s.
The GPU runs one stream most of the time. One stream decodes about 48 tok/s. Seven streams each decode about 33 tok/s, roughly 230 tok/s together. Yet 75% of turns had no other stream running.
Failures cost hours. 18% of the wall clock was failed steps, a person's resume, or commit recovery.

Phase	Wall clock	Share
Apply (task groups)	414 min	33%
Verify (reconcile, unit, browser, code review)	318 min	25%
Review (four lenses, revise, round 2)	155 min	12%
Plan (explore, proposal, specs, design, tasks)	120 min	10%
Failed, waiting for a person, commit recovery	223 min	18%

Findings, biggest first

Very long thinking. Reasoning took 918 min across the eight runs. 129 single thoughts of 2 min or more make up 56% of it. The longest ran 15.8 min (114k characters, run 36 review[test]). They are not loops. They are exhaustive deliberation, such as a reviewer walking candidate issues A to Z. Reviewers spend 91% of their output on reasoning.
- Capping each thought at about 2 min (about 5k tokens) would have cut about 250 min of reasoning from the six runs, 91 min of it on steps that run one after another.
- No-think for mechanical work (summarize, reconcile, the test-runner subagent) is the low-risk part. A cap on apply and review needs a quality check.
Apply spends most of its time before its first edit and after its last. Of 355 min of successful apply attempts, 44% passed before the first code edit (median 7 min) and 25% after the last one. The work in between is 31%. Before the first edit come long planning thoughts, baseline suite runs, and re-reads of files the prompt already pastes (139 such reads across all steps, up to 10 in one apply step). Agents also write and debug throwaway scripts such as sim_game.py and probe.py instead of tests they keep (15 in these runs). After the last edit comes the "tick one task at a time" routine: re-run a test, tick, repeat. That was about 16 turns after the work was done in run 37 apply[1].
Verification steps redo each other. reconcile-tasks (7–12 min) changed nothing in each of the last five runs. test.unit (7–14 min) mostly found the tests already written and touched 0–3 files. Code review then re-reads and re-runs everything again. Run 37 ran the full backend suite 13 times and the frontend suite or build 9 times. Its reconcile also ran a browser check, the job test.browser does next.
Review findings that no step acts on. Nine review rounds produced 87 findings: 6 blocking (all in round 1), 45 should-fix and 36 notes. Revise fixes blocking findings only, and the gate auto-approves, so no step is asked to handle should-fix. A few surfaced later by chance: run 25's unit step picked up the test lens's gaps, and run 37's code review noted one and left it. Round 2 re-runs all four lenses over everything. It ran three times, took 10–13 min each, and never found a blocking issue.
Run 37 died over "line": 0. Code review wrote a file-level finding with line: 0, and the schema wants at least 1. With mediate: missing, a report that is present but invalid counts as a deliberate "fail". So there was no retry, and the run failed at its second-to-last step after 2 h 43 min.
Failures then waited for a person. Run 36's browser check used its whole hour without writing a report. The run sat failed for 2 h 22 min until a manual resume, and attempt 2 finished in 20 min. Run 26's feature commit swept in a root .venv, hit a PredicateError, and took 74 min of manual redos. Run 22 lost about 100 min to early bugs and two osfd restarts. Fixed since: #117, #118, #119 (last call, two hours, automatic retry) and #105, #107. Finding 5 is a hole the retry still has.
Browser checks of a five-player game. The browser check took 38 min in run 37 and 80 min over two attempts in run 36.
- In run 37 the browser subagent ran out of steps on a full 10-hand game. The parent then thought for 6.4 and 4.5 min and wrote a websocket script to play the other four seats.
- In run 36 the subagent's first run (21 min) failed on a disconnected "ghost" seat. It blamed "an external connection"; the parent later found it was the subagent's own discarded tab.
- Every browser brief re-reads the app source to learn how seats work, which the parent already knows.
Briefs that disagree with their checks.
- test.unit is told to name each test after its scenario, but the coverage check counts // spec: <capability>/<scenario> tags. So every lane report says 0/55 scenarios covered, 19 ban violations and green: false. The step still passes, because its completion is only paths-exist. Later steps read green: false and deliberate over it. B7 (relative import) also flags Python tests by mistake.
- Spec writers read OpenSpec's validator source in /usr/local/lib/node_modules in three steps to learn the RENAMED and MODIFIED rules. That took about 7 of run 36 spec[deal]'s 12.6 min.
- openspec validate --strict with no change id ran 11 times, answering "Nothing to validate" each time.
- summarize's git diff develop...HEAD failed in 5 runs: only origin/develop exists.
- The plan step is told to run "$OSF_PYTHON" -m osf.pipeline.plan check, but OSF_PYTHON is empty in the agent's shell.
The environment, mostly fixed. In runs 22–26, nearly every apply or test step went looking for a Python with pytest, because python is Braid's own venv. Agents made venvs in four places and pip-installed into the system Python. Fixed since by script.deps (#109), the app tool (#110) and the Chrome fix. Still open in runs 36 and 37: python3 is still Braid's venv, and rg (8 tries) and ps (4 tries) are not installed.
$TMPDIR is advertised but not allowed. There were 36 permission rejections. The rejection message tells agents to use $TMPDIR (<run>/tmp), but only <run>/tmp/opencode is allowed. Neither the app tool's own log (<run>/tmp/braid-app.log) nor the browser screenshots (<run>/screenshots/) can be read, so agents copy them, retry, or give up on looking.
Background tests collide with edits. In run 37 apply[2], a test subagent ran the suite while the parent edited test_flow.py. The suite hung until bash's 600 s timeout, because pytest has no per-test timeout.
Parallelism goes unused. Several steps could overlap: code review with the browser check, test.unit with reconcile, and backend with frontend apply groups when their files are disjoint. Speculative decoding (n-gram or MTP) in vLLM may also lift single-stream speed on edit-heavy turns. That one needs a measurement.

Per run

Run	Change	Wall	Result	Biggest loss
22	walking skeleton	4.8 h	ok	~100 min of attempts redone after early bugs and osfd restarts
23	follow suit	1.6 h	ok	the cleanest run
25	trump and bids	2.0 h	ok	review round 2
26	hand scoring	3.5 h	ok	74 min recovering the feature commit
36	dealer rotation	6.2 h	ok	browser check timed out, then 2 h 22 min waiting for a resume
37	full game	2.7 h	failed	code review's `line: 0`, no retry

Suggested split

Here, in #121 (small and low-risk): 5 (retry an invalid report; allow file-level findings), 8, 9, 10 and 11 (a per-test timeout; no edits under a running test), plus the brief half of 2 (don't re-read pasted files; tick as you go without re-testing). These are brief text, image and permission changes.
Separate issues (each needs a design and a measurement): 1 (a thinking budget, or no-think per step), 3 (removing the verification overlap), 4 (review redesign), 7 (browser-check strategy for multi-user apps) and 12 (parallel steps, speculative decoding).

## Findings: where the scratch runs spend their time I read every step transcript of the eight finished scratch runs: the plan run 21, the feature runs 22, 23, 25, 26, 36 and 37 (git-flow), and the quick-fix verification run 33. The archived runs 24, 29 and 34 were used only to explain failures. Run numbers are Braid's ledger numbers, not issues. In total that is about 2,100 model turns and 4,100 tool calls. Unless noted, the figures are for the six feature runs: 1,251 min of wall clock. ### The short version - **The model's thinking is the cost.** Inside agent steps, 79% of the time is the model generating, 8% is waiting for the first token and 6% is tools. Of the generated tokens, 79% are reasoning (2.17M reasoning, 0.59M visible). Tests are cheap: the whole backend suite runs in about 10 s. - **The GPU runs one stream most of the time.** One stream decodes about 48 tok/s. Seven streams each decode about 33 tok/s, roughly 230 tok/s together. Yet 75% of turns had no other stream running. - **Failures cost hours.** 18% of the wall clock was failed steps, a person's resume, or commit recovery. | Phase | Wall clock | Share | |---|---|---| | Apply (task groups) | 414 min | 33% | | Verify (reconcile, unit, browser, code review) | 318 min | 25% | | Review (four lenses, revise, round 2) | 155 min | 12% | | Plan (explore, proposal, specs, design, tasks) | 120 min | 10% | | Failed, waiting for a person, commit recovery | 223 min | 18% | ### Findings, biggest first 1. **Very long thinking.** Reasoning took 918 min across the eight runs. 129 single thoughts of 2 min or more make up 56% of it. The longest ran 15.8 min (114k characters, run 36 review[test]). They are not loops. They are exhaustive deliberation, such as a reviewer walking candidate issues A to Z. Reviewers spend 91% of their output on reasoning. - Capping each thought at about 2 min (about 5k tokens) would have cut about 250 min of reasoning from the six runs, 91 min of it on steps that run one after another. - No-think for mechanical work (summarize, reconcile, the test-runner subagent) is the low-risk part. A cap on apply and review needs a quality check. 2. **Apply spends most of its time before its first edit and after its last.** Of 355 min of successful apply attempts, 44% passed before the first code edit (median 7 min) and 25% after the last one. The work in between is 31%. Before the first edit come long planning thoughts, baseline suite runs, and re-reads of files the prompt already pastes (139 such reads across all steps, up to 10 in one apply step). Agents also write and debug throwaway scripts such as `sim_game.py` and `probe.py` instead of tests they keep (15 in these runs). After the last edit comes the "tick one task at a time" routine: re-run a test, tick, repeat. That was about 16 turns after the work was done in run 37 apply[1]. 3. **Verification steps redo each other.** reconcile-tasks (7–12 min) changed nothing in each of the last five runs. test.unit (7–14 min) mostly found the tests already written and touched 0–3 files. Code review then re-reads and re-runs everything again. Run 37 ran the full backend suite 13 times and the frontend suite or build 9 times. Its reconcile also ran a browser check, the job test.browser does next. 4. **Review findings that no step acts on.** Nine review rounds produced 87 findings: 6 blocking (all in round 1), 45 should-fix and 36 notes. Revise fixes blocking findings only, and the gate auto-approves, so no step is asked to handle should-fix. A few surfaced later by chance: run 25's unit step picked up the test lens's gaps, and run 37's code review noted one and left it. Round 2 re-runs all four lenses over everything. It ran three times, took 10–13 min each, and never found a blocking issue. 5. **Run 37 died over `"line": 0`.** Code review wrote a file-level finding with `line: 0`, and the schema wants at least 1. With `mediate: missing`, a report that is present but invalid counts as a deliberate "fail". So there was no retry, and the run failed at its second-to-last step after 2 h 43 min. 6. **Failures then waited for a person.** Run 36's browser check used its whole hour without writing a report. The run sat failed for 2 h 22 min until a manual resume, and attempt 2 finished in 20 min. Run 26's feature commit swept in a root `.venv`, hit a PredicateError, and took 74 min of manual redos. Run 22 lost about 100 min to early bugs and two osfd restarts. *Fixed since: #117, #118, #119 (last call, two hours, automatic retry) and #105, #107. Finding 5 is a hole the retry still has.* 7. **Browser checks of a five-player game.** The browser check took 38 min in run 37 and 80 min over two attempts in run 36. - In run 37 the browser subagent ran out of steps on a full 10-hand game. The parent then thought for 6.4 and 4.5 min and wrote a websocket script to play the other four seats. - In run 36 the subagent's first run (21 min) failed on a disconnected "ghost" seat. It blamed "an external connection"; the parent later found it was the subagent's own discarded tab. - Every browser brief re-reads the app source to learn how seats work, which the parent already knows. 8. **Briefs that disagree with their checks.** - test.unit is told to name each test after its scenario, but the coverage check counts `// spec: <capability>/<scenario>` tags. So every lane report says 0/55 scenarios covered, 19 ban violations and `green: false`. The step still passes, because its completion is only `paths-exist`. Later steps read `green: false` and deliberate over it. B7 (relative import) also flags Python tests by mistake. - Spec writers read OpenSpec's validator source in `/usr/local/lib/node_modules` in three steps to learn the RENAMED and MODIFIED rules. That took about 7 of run 36 spec[deal]'s 12.6 min. - `openspec validate --strict` with no change id ran 11 times, answering "Nothing to validate" each time. - summarize's `git diff develop...HEAD` failed in 5 runs: only `origin/develop` exists. - The plan step is told to run `"$OSF_PYTHON" -m osf.pipeline.plan check`, but `OSF_PYTHON` is empty in the agent's shell. 9. **The environment, mostly fixed.** In runs 22–26, nearly every apply or test step went looking for a Python with pytest, because `python` is Braid's own venv. Agents made venvs in four places and pip-installed into the system Python. *Fixed since by script.deps (#109), the app tool (#110) and the Chrome fix.* Still open in runs 36 and 37: `python3` is still Braid's venv, and `rg` (8 tries) and `ps` (4 tries) are not installed. 10. **`$TMPDIR` is advertised but not allowed.** There were 36 permission rejections. The rejection message tells agents to use `$TMPDIR` (`<run>/tmp`), but only `<run>/tmp/opencode` is allowed. Neither the app tool's own log (`<run>/tmp/braid-app.log`) nor the browser screenshots (`<run>/screenshots/`) can be read, so agents copy them, retry, or give up on looking. 11. **Background tests collide with edits.** In run 37 apply[2], a test subagent ran the suite while the parent edited `test_flow.py`. The suite hung until bash's 600 s timeout, because pytest has no per-test timeout. 12. **Parallelism goes unused.** Several steps could overlap: code review with the browser check, test.unit with reconcile, and backend with frontend apply groups when their files are disjoint. Speculative decoding (n-gram or MTP) in vLLM may also lift single-stream speed on edit-heavy turns. That one needs a measurement. ### Per run | Run | Change | Wall | Result | Biggest loss | |---|---|---|---|---| | 22 | walking skeleton | 4.8 h | ok | ~100 min of attempts redone after early bugs and osfd restarts | | 23 | follow suit | 1.6 h | ok | the cleanest run | | 25 | trump and bids | 2.0 h | ok | review round 2 | | 26 | hand scoring | 3.5 h | ok | 74 min recovering the feature commit | | 36 | dealer rotation | 6.2 h | ok | browser check timed out, then 2 h 22 min waiting for a resume | | 37 | full game | 2.7 h | failed | code review's `line: 0`, no retry | ### Suggested split - **Here, in #121 (small and low-risk):** 5 (retry an invalid report; allow file-level findings), 8, 9, 10 and 11 (a per-test timeout; no edits under a running test), plus the brief half of 2 (don't re-read pasted files; tick as you go without re-testing). These are brief text, image and permission changes. - **Separate issues (each needs a design and a measurement):** 1 (a thinking budget, or no-think per step), 3 (removing the verification overlap), 4 (review redesign), 7 (browser-check strategy for multi-user apps) and 12 (parallel steps, speculative decoding).

cmoriarty referenced this issue

2026-10-02 15:49:55 -04:00

Agents spend most of their time thinking: cap the reasoning per turn, or switch it off for mechanical steps #124

cmoriarty referenced this issue

2026-10-02 15:50:17 -04:00

Verification steps redo each other: reconcile, the unit tests and the code review re-read and re-run the same change #125

cmoriarty referenced this issue

2026-10-02 15:50:38 -04:00

Review rounds produce findings no step acts on, and round 2 has never found a blocking issue #126

cmoriarty referenced this issue

2026-10-02 15:51:01 -04:00

The browser check of a multi-player app takes 40–80 min: drive the state with a script and check what people see #127

cmoriarty referenced this issue

2026-10-02 15:51:21 -04:00

Most of the GPU's batch capacity goes unused: run independent steps side by side #128

cmoriarty commented

2026-10-02 15:58:17 -04:00

Author

Owner

Follow-up: one correction, and the split

Correction to finding 8. B7 (the relative-import rule) does not misfire on Python tests. It misfires on a TypeScript test whose import {…} from "./game" spans several lines (frontend/src/game.test.ts). The Python problem is a different one: the spec: tag must start with //, so a Python test cannot carry one at all, and the scenarios it covers can never count as covered.

Going with the suggested split.

Here, as three OpenSpec changes on the branch claude/issue-121 (not pushed yet):
- retry-malformed-reports: finding 5. It also fixes #122, which is the same run 37 failure.
- agent-shell-environment: findings 8 (OSF_PYTHON), 9 and 10.
- sharper-briefs: the brief half of finding 2, and findings 8 and 11.
Split off: #124 (thinking budget, finding 1), #125 (verification overlap, finding 3), #126 (review rounds, finding 4), #127 (browser check of a multi-player app, finding 7) and #128 (parallelism and speculative decoding, finding 12).

### Follow-up: one correction, and the split **Correction to finding 8.** B7 (the relative-import rule) does not misfire on Python tests. It misfires on a TypeScript test whose `import {…} from "./game"` spans several lines (`frontend/src/game.test.ts`). The Python problem is a different one: the `spec:` tag must start with `//`, so a Python test cannot carry one at all, and the scenarios it covers can never count as covered. **Going with the suggested split.** - Here, as three OpenSpec changes on the branch `claude/issue-121` (not pushed yet): - `retry-malformed-reports`: finding 5. It also fixes #122, which is the same run 37 failure. - `agent-shell-environment`: findings 8 (`OSF_PYTHON`), 9 and 10. - `sharper-briefs`: the brief half of finding 2, and findings 8 and 11. - Split off: #124 (thinking budget, finding 1), #125 (verification overlap, finding 3), #126 (review rounds, finding 4), #127 (browser check of a multi-player app, finding 7) and #128 (parallelism and speculative decoding, finding 12).