jared/cc-os

Watch

Fork 0

dispatches token columns are zero for some implementations (#583, #565, #566, #572-#574) #590

New issue

Closed

opened 2026-09-15 13:37:56 +00:00 by jared · 2 comments

jared commented

2026-09-15 13:37:56 +00:00

Owner

Context

Reviewing pipeline.db dispatches/token accounting during responsibility-refactor batch 5, 2026-09-15.

Observed

dispatches.input_tokens/output_tokens/cache_read_tokens/cache_creation_tokens are all 0 for implementations tied to #583, #565, #566, and #572-#574. Rows for #584 and #585 carry populated token values. No orchestrator-role dispatch row exists, so main-loop token usage is never recorded at all.

Reproduce

sqlite3 .sdlc/pipeline.db "select implementation_id, role, input_tokens, output_tokens from dispatches where implementation_id in (select id from implementations where ticket in (583,565,566,572,573,574))"

Expected

Every dispatch row carries usage figures. Consider adding an orchestrator-role dispatch row so main-loop token usage is captured alongside subagent dispatches.

Origin

Trigger: pipeline.db query this session
Improvised this session: none
Chain: zero token columns on some dispatch rows ← missing orchestrator row / partial instrumentation ← IMPROVISATION (instrumentation added incrementally across tickets)
Root candidate: this ticket
Where: os-sdlc pipeline dispatch/usage recording
Session: b1c83b81-7be1-4f17-9e8e-cae36a934f25
Transcript: n/a

## Context Reviewing `pipeline.db` dispatches/token accounting during responsibility-refactor batch 5, 2026-09-15. ## Observed `dispatches.input_tokens`/`output_tokens`/`cache_read_tokens`/`cache_creation_tokens` are all 0 for implementations tied to #583, #565, #566, and #572-#574. Rows for #584 and #585 carry populated token values. No orchestrator-role dispatch row exists, so main-loop token usage is never recorded at all. ## Reproduce ``` sqlite3 .sdlc/pipeline.db "select implementation_id, role, input_tokens, output_tokens from dispatches where implementation_id in (select id from implementations where ticket in (583,565,566,572,573,574))" ``` ## Expected Every dispatch row carries usage figures. Consider adding an orchestrator-role dispatch row so main-loop token usage is captured alongside subagent dispatches. ## Origin - Trigger: pipeline.db query this session - Improvised this session: none - Chain: zero token columns on some dispatch rows ← missing orchestrator row / partial instrumentation ← IMPROVISATION (instrumentation added incrementally across tickets) - Root candidate: this ticket - Where: os-sdlc pipeline dispatch/usage recording - Session: b1c83b81-7be1-4f17-9e8e-cae36a934f25 - Transcript: n/a

jared added the

plugin/os-sdlc

filed-by/agent

labels

2026-09-15 13:37:57 +00:00

jared commented

2026-09-15 15:46:09 +00:00

Author

Owner

Investigation 2026-09-15: NULL, not 0, and the cause is timing

The token columns on the affected rows are NULL. The report renders NULL as 0.

Ticket	Rows with usage	Rows NULL	Last populated	First NULL
565, 566, 583	0	11, 20, 12	none	all
572, 573, 574	10, 16, 7	0	all	none
584	14	6	17:06	17:08
585	14	4	17:47	18:11

Usage is read lazily from agents.transcript_path by Dispatch#record_usage! (runner/dispatch.rb:43), and only when os-sdlc-runner implementation-report runs. A missing transcript file returns nil and leaves the row NULL. The transcript directories for every affected worktree are gone. Rows written before a by-hand report call have usage; rows after it do not. No format problem exists.

Lazy reading is correct and must stay (ADR-0175). Measured on 12 dispatches from #594 and #595: the final assistant turn, the one carrying message.usage, lands 9 to 39 seconds after dispatches.completed_at, because an agent settles its own dispatch and then keeps writing.

Slice

Sweep NULL usage at the next subagent start, so every dispatch except the last is stamped while its transcript still exists. Add a catch-all for the last dispatch at worktree finish.

Owner sketch

Change 1, sweep at subagent start. DispatchCommands.subagent_start (runner/dispatch_commands.rb:28) runs in the SubagentStart hook of the next agent. Every earlier agent on the implementation has returned, so their transcripts are complete.

# runner/implementation.rb
def record_missing_usage!
  dispatches.select { |d| d.input_tokens.nil? }.each(&:record_usage!)
end

# runner/start_subagent.rb, after the implementation is resolved and before the brief is composed
implementation.record_missing_usage!

record_usage! already returns nil on a missing file, so a row that cannot be read stays NULL and is retried on the next start. Inline, not a side process: one JSON Lines scan per row, milliseconds, and a failure is visible in the hook output instead of lost in a fork.

Change 2, catch-all at worktree finish. plugins/os/lib/worktree_cli_finish.rb:163 removes the worktree. The os plugin cannot require os-sdlc (ADR-0157, ADR-0174). Guarded shell-out before removal:

def sweep_usage
  return unless File.exist?(File.join(worktree_path, ".sdlc", "pipeline.db"))
  system("os-sdlc-runner", "implementation-report", "--sweep-only", chdir: worktree_path)
end

--sweep-only stamps usage and prints nothing. Record the coupling in an ADR that amends ADR-0157.

The existing report call on a terminal payload stays as written in the implement skill.

Cases

Second dispatch starts, first dispatch has NULL usage and an existing transcript: first row is stamped with model and four token columns.
Second dispatch starts, first dispatch has usage already: row unchanged, byte-identical.
Second dispatch starts, transcript file missing: row stays NULL, no error, brief composed as before.
Worktree finish with .sdlc/pipeline.db present: NULL rows with existing transcripts are stamped before git worktree remove.
Worktree finish without .sdlc/pipeline.db: no shell-out, finish unchanged.
implementation-report --sweep-only: stamps, prints nothing, exit 0.

Acceptance criteria

After a full pipeline run through the implement skill, every dispatch row on the implementation has non-NULL token columns.
After a run stopped by hand (unexpected_pass, bound_exhausted) and finished with the worktree CLI, every dispatch row except at most zero has non-NULL token columns.
Tests cover the six cases above.

Non-goals

An orchestrator-role dispatch row for main-loop usage. Split to its own ticket.
Changing when completed_at is written.
Finding what deletes ~/.claude/projects/<worktree-slug>. Unknown, out of scope.
Backfilling the affected rows. The transcripts are gone.

## Investigation 2026-09-15: NULL, not 0, and the cause is timing The token columns on the affected rows are NULL. The report renders NULL as 0. | Ticket | Rows with usage | Rows NULL | Last populated | First NULL | | --- | --- | --- | --- | --- | | 565, 566, 583 | 0 | 11, 20, 12 | none | all | | 572, 573, 574 | 10, 16, 7 | 0 | all | none | | 584 | 14 | 6 | 17:06 | 17:08 | | 585 | 14 | 4 | 17:47 | 18:11 | Usage is read lazily from `agents.transcript_path` by `Dispatch#record_usage!` (`runner/dispatch.rb:43`), and only when `os-sdlc-runner implementation-report` runs. A missing transcript file returns nil and leaves the row NULL. The transcript directories for every affected worktree are gone. Rows written before a by-hand report call have usage; rows after it do not. No format problem exists. Lazy reading is correct and must stay (ADR-0175). Measured on 12 dispatches from #594 and #595: the final assistant turn, the one carrying `message.usage`, lands 9 to 39 seconds after `dispatches.completed_at`, because an agent settles its own dispatch and then keeps writing. ## Slice Sweep NULL usage at the next subagent start, so every dispatch except the last is stamped while its transcript still exists. Add a catch-all for the last dispatch at worktree finish. ## Owner sketch Change 1, sweep at subagent start. `DispatchCommands.subagent_start` (`runner/dispatch_commands.rb:28`) runs in the SubagentStart hook of the next agent. Every earlier agent on the implementation has returned, so their transcripts are complete. ```ruby # runner/implementation.rb def record_missing_usage! dispatches.select { |d| d.input_tokens.nil? }.each(&:record_usage!) end # runner/start_subagent.rb, after the implementation is resolved and before the brief is composed implementation.record_missing_usage! ``` `record_usage!` already returns nil on a missing file, so a row that cannot be read stays NULL and is retried on the next start. Inline, not a side process: one JSON Lines scan per row, milliseconds, and a failure is visible in the hook output instead of lost in a fork. Change 2, catch-all at worktree finish. `plugins/os/lib/worktree_cli_finish.rb:163` removes the worktree. The os plugin cannot require os-sdlc (ADR-0157, ADR-0174). Guarded shell-out before removal: ```ruby def sweep_usage return unless File.exist?(File.join(worktree_path, ".sdlc", "pipeline.db")) system("os-sdlc-runner", "implementation-report", "--sweep-only", chdir: worktree_path) end ``` `--sweep-only` stamps usage and prints nothing. Record the coupling in an ADR that amends ADR-0157. The existing report call on a terminal payload stays as written in the implement skill. ## Cases - Second dispatch starts, first dispatch has NULL usage and an existing transcript: first row is stamped with model and four token columns. - Second dispatch starts, first dispatch has usage already: row unchanged, byte-identical. - Second dispatch starts, transcript file missing: row stays NULL, no error, brief composed as before. - Worktree finish with `.sdlc/pipeline.db` present: NULL rows with existing transcripts are stamped before `git worktree remove`. - Worktree finish without `.sdlc/pipeline.db`: no shell-out, finish unchanged. - `implementation-report --sweep-only`: stamps, prints nothing, exit 0. ## Acceptance criteria - After a full pipeline run through the implement skill, every dispatch row on the implementation has non-NULL token columns. - After a run stopped by hand (unexpected_pass, bound_exhausted) and finished with the worktree CLI, every dispatch row except at most zero has non-NULL token columns. - Tests cover the six cases above. ## Non-goals - An orchestrator-role dispatch row for main-loop usage. Split to its own ticket. - Changing when `completed_at` is written. - Finding what deletes `~/.claude/projects/<worktree-slug>`. Unknown, out of scope. - Backfilling the affected rows. The transcripts are gone.

jared referenced this issue

2026-09-15 15:58:58 +00:00

Record main-loop token usage per implementation #598

jared commented

2026-09-15 16:35:05 +00:00

Author

Owner

Resolution

Done: NULL (not 0) token columns fixed: StartSubagent sweeps earlier dispatches' missing usage before inserting the new row; implementation-report --sweep-only IMPLEMENTATION_ID stamps one implementation silently; worktree finish --implementation ID runs the sweep before git worktree remove. Lazy read kept per ADR-0175 (usage-bearing turn lands 9-39 s after completed_at).

Evidence: commit 88cd513 merged 98a4f40 on main 2026-09-15; os-sdlc suite 1220 runs 0 failures; os suite 22 runs 0 failures; plan and investigation in the 2026-09-15 comment on this ticket

Follow-ups: #598 main-loop token usage (split, filed); affected rows are unrecoverable, transcripts gone; cause of ~/.claude/projects/ deletion unknown, no ticket by user decision

## Resolution **Done:** NULL (not 0) token columns fixed: StartSubagent sweeps earlier dispatches' missing usage before inserting the new row; implementation-report --sweep-only IMPLEMENTATION_ID stamps one implementation silently; worktree finish --implementation ID runs the sweep before git worktree remove. Lazy read kept per ADR-0175 (usage-bearing turn lands 9-39 s after completed_at). **Evidence:** commit 88cd513 merged 98a4f40 on main 2026-09-15; os-sdlc suite 1220 runs 0 failures; os suite 22 runs 0 failures; plan and investigation in the 2026-09-15 comment on this ticket **Follow-ups:** #598 main-loop token usage (split, filed); affected rows are unrecoverable, transcripts gone; cause of ~/.claude/projects/<worktree-slug> deletion unknown, no ticket by user decision

jared closed this issue

2026-09-15 16:35:05 +00:00

jared referenced this issue from a commit

2026-09-15 18:48:16 +00:00

feat(os-sdlc,os): sweep unstamped dispatch usage at subagent start and worktree finish (#590)

jared referenced this issue from a commit

2026-09-15 18:48:16 +00:00

docs: ADR-0193 usage sweep at SubagentStart and finish; history rows for #590