cmoriarty/braid

Fork 0

A running command reads as silence: show what is running, and don't redo a step waiting on its own tool call #69

New issue

Closed

opened 2026-09-26 23:59:21 -04:00 by cmoriarty · 2 comments

cmoriarty commented

2026-09-26 23:59:21 -04:00

Owner

Problem

On run_01M3GB3KN38YT9TZJ7KA7RQ5M0 (soundcheck#32), an openspec.apply agent ran npx vitest run src/lib/server/ops/maintenance.test.ts src/lib/server/artists/resolve.test.ts 2>&1 | tail -12 for several minutes. While it ran:

the spine row counted "silent for …", the warning meant for a stalled step;
nothing said a command was running, which one, or for how long. The transcript row shows the command, but it looks the same as a finished call.

Cause

Silence is measured from the step's last event (StepActivity in src/osf/format.py; the watchdog's _examine also counts streamed tokens). A shell command produces no events while it runs, so a step waiting on its own bash reads exactly like a step that has stopped. Yet opencode already records the tool part as state.status: running, with its input (the command, which tool_target extracts) and time.start. The digest and the watchdog just don't use it.

The same cause can kill a long command

The stall watchdog (src/osf/engine/watchdog.py, the loop over report.checked) redoes an agent step whose session is busy and which has been silent for more than STALL_REDO_S = 480 s. A redo rolls the worktree back to the entry checkpoint. It already skips a step waiting on a subagent (child_busy) and a step waiting on the operator (status not running), but not a step waiting on its own tool call. opencode's bash tool allows up to 10 minutes per call (the agent can raise the 2-minute default), and a test suite or build that prints only at the end produces nothing until it exits. So any command running quietly past 8 minutes gets its step redone mid-command, and the work is thrown away. The dogfood evidence behind 480 s ("longest legitimate silence 215 s") predates agents running whole suites themselves.

Proposal

A running tool call is not silence. The step's activity tracks the newest tool part. While it is pending or running, the step is not silent, and its phrase names what is running, e.g. Running npx vitest run … · 3m 12s, timed from the tool's own time.start.
The digest carries it: running_tool: {tool, target, started_at}. The spine row shows Running a command · 3m 12s and puts the full command in its tooltip. The stage header says the same.
The transcript row of a running tool call shows it's running: a spinner or pulse, and an elapsed counter that stops at completion. The row already shows the tool's duration once it completes.
The watchdog doesn't redo a step waiting on its own tool call, up to the tool's own limit (opencode's 10-minute ceiling plus a margin). Past that, a tool opencode still calls running is itself a wedge, and the stall redo applies as today.

Done when

A step whose bash call has been running for 5 minutes reads Running … · 5m, not silent for 5m, in the spine and the stage header.
A step whose bash call runs 9 minutes is not redone by the watchdog. One whose tool call is still running after the ceiling plus the margin is.
The transcript row of a running tool call shows an elapsed counter.

## Problem On `run_01M3GB3KN38YT9TZJ7KA7RQ5M0` (soundcheck#32), an `openspec.apply` agent ran `npx vitest run src/lib/server/ops/maintenance.test.ts src/lib/server/artists/resolve.test.ts 2>&1 | tail -12` for several minutes. While it ran: - **the spine row counted "silent for …"**, the warning meant for a stalled step; - **nothing said a command was running, which one, or for how long.** The transcript row shows the command, but it looks the same as a finished call. ## Cause Silence is measured from the step's **last event** (`StepActivity` in `src/osf/format.py`; the watchdog's `_examine` also counts streamed tokens). A shell command produces no events while it runs, so a step waiting on its own `bash` reads exactly like a step that has stopped. Yet opencode already records the tool part as `state.status: running`, with its `input` (the command, which `tool_target` extracts) and `time.start`. The digest and the watchdog just don't use it. ## The same cause can kill a long command The stall watchdog (`src/osf/engine/watchdog.py`, the loop over `report.checked`) **redoes** an agent step whose session is busy and which has been silent for more than `STALL_REDO_S` = 480 s. A redo rolls the worktree back to the entry checkpoint. It already skips a step waiting on a subagent (`child_busy`) and a step waiting on the operator (status not `running`), but **not a step waiting on its own tool call**. opencode's `bash` tool allows up to 10 minutes per call (the agent can raise the 2-minute default), and a test suite or build that prints only at the end produces nothing until it exits. So any command running quietly past 8 minutes gets its step redone mid-command, and the work is thrown away. The dogfood evidence behind 480 s ("longest legitimate silence 215 s") predates agents running whole suites themselves. ## Proposal 1. **A running tool call is not silence.** The step's activity tracks the newest tool part. While it is `pending` or `running`, the step is not silent, and its phrase names what is running, e.g. `Running npx vitest run … · 3m 12s`, timed from the tool's own `time.start`. 2. **The digest carries it:** `running_tool: {tool, target, started_at}`. The spine row shows `Running a command · 3m 12s` and puts the full command in its tooltip. The stage header says the same. 3. **The transcript row of a running tool call shows it's running:** a spinner or pulse, and an elapsed counter that stops at completion. The row already shows the tool's duration once it completes. 4. **The watchdog doesn't redo a step waiting on its own tool call**, up to the tool's own limit (opencode's 10-minute ceiling plus a margin). Past that, a tool opencode still calls `running` is itself a wedge, and the stall redo applies as today. ## Done when - A step whose `bash` call has been running for 5 minutes reads `Running … · 5m`, not `silent for 5m`, in the spine and the stage header. - A step whose `bash` call runs 9 minutes is not redone by the watchdog. One whose tool call is still `running` after the ceiling plus the margin is. - The transcript row of a running tool call shows an elapsed counter.

cmoriarty referenced this issue from a commit

2026-09-27 00:16:17 -04:00

fix(activity): a step waiting on its own command says what is running, and is not redone as stalled (#69)

cmoriarty referenced this issue from a pull request that will close it,

2026-09-27 00:16:27 -04:00

fix(activity): a step waiting on its own command says what is running, and is not redone as stalled (#69) #71

cmoriarty closed this issue

2026-09-27 00:16:36 -04:00

cmoriarty commented

2026-09-27 01:07:41 -04:00

Author

Owner

Shipped in #71 (558560e, archived as 2026-09-27-running-tool-is-not-silence), deployed as bd3902f at 01:07 EDT.

A tool call opencode has started and not finished is what the step is doing, not silence. The digest carries running_tool, running_target and running_for_s, timed from the call's own start.
The spine line names and times it, e.g. Running npx vitest run src/lib/… · 3m 12s. The tooltip has the whole command line, how long it has run, and the step's time.
A running call's transcript row counts up.
The stall watchdog no longer redoes (and rolls back) a step waiting on its own tool call younger than TOOL_CALL_CEILING_S (20 minutes). A call still running past that is a wedge, and the redo applies.

Restart recovery still rolls running steps back: #70.

Shipped in #71 (`558560e`, archived as `2026-09-27-running-tool-is-not-silence`), deployed as `bd3902f` at 01:07 EDT. - A tool call opencode has started and not finished is what the step is doing, not silence. The digest carries `running_tool`, `running_target` and `running_for_s`, timed from the call's own start. - The spine line names and times it, e.g. `Running npx vitest run src/lib/… · 3m 12s`. The tooltip has the whole command line, how long it has run, and the step's time. - A running call's transcript row counts up. - The stall watchdog no longer redoes (and rolls back) a step waiting on its own tool call younger than `TOOL_CALL_CEILING_S` (20 minutes). A call still running past that is a wedge, and the redo applies. Restart recovery still rolls running steps back: #70.

cmoriarty commented

2026-09-27 01:11:05 -04:00

Author

Owner

Shipped in PR #71 (558560e), deployed to production at bd3902f on 2026-09-27 at 01:07.

What shipped:

A step waiting on its own tool call isn't silence. The spine names and times the call, and the digest frames carry running_tool, running_target and running_for_s.
The watchdog doesn't redo a step that is waiting on its own call, up to a 20-minute ceiling.

Checked live: I captured /api/stream?run=run_01M3GB3KN38YT9TZJ7KA7RQ5M0 for 90 s after the deploy. Digest frames for openspec.apply[4] carried running_tool for read and grep calls with their targets (.../scripts/extract.ts, .../server/ops), and running_for_s counted up.

One defect found in that check: a call that was in flight when the restart killed attempt 1 kept showing as bash running, with no target, while attempt 2 worked. The digest's fold spans attempts. Only the display is affected: the watchdog's read is attempt-scoped. Filed as #73.

Shipped in PR #71 (`558560e`), deployed to production at `bd3902f` on 2026-09-27 at 01:07. **What shipped:** - A step waiting on its own tool call isn't silence. The spine names and times the call, and the digest frames carry `running_tool`, `running_target` and `running_for_s`. - The watchdog doesn't redo a step that is waiting on its own call, up to a 20-minute ceiling. **Checked live:** I captured `/api/stream?run=run_01M3GB3KN38YT9TZJ7KA7RQ5M0` for 90 s after the deploy. Digest frames for `openspec.apply[4]` carried `running_tool` for `read` and `grep` calls with their targets (`.../scripts/extract.ts`, `.../server/ops`), and `running_for_s` counted up. **One defect found in that check:** a call that was in flight when the restart killed attempt 1 kept showing as `bash` running, with no target, while attempt 2 worked. The digest's fold spans attempts. Only the display is affected: the watchdog's read is attempt-scoped. Filed as #73.

cmoriarty referenced this issue

2026-10-04 21:48:25 -04:00

The watchdog orphans a working step when its subagent finishes first: it checks the subagent's session, not the step's #141

No labels

No milestone

No project

No assignees

1 participant

Notifications

Due date

The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference

cmoriarty/braid#69

No description provided.

Rows
Columns