fix: Persist per-node workflow token usage - #2347
Conversation
Workflow node token usage was only written to local JSONL logs, leaving remote event consumers without provider-neutral per-node usage data. Changes: - Persist direct AI-node token usage in node_completed events - Persist aggregated loop and loop-group token usage - Add regression coverage for all successful AI-derived completion paths Fixes #2333
|
Important Review skippedDraft detected. Please check the settings in the CodeRabbit UI or the ⚙️ Run configurationConfiguration used: defaults Review profile: CHILL Plan: Pro Plus Run ID: You can disable this status message by setting the Use the checkbox below for a quick retry:
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
Consolidated Review: PR #2347Date: 2026-07-30T17:24:44+03:00 Executive SummaryThis is a small, well-scoped change that persists already-captured token usage on successful direct AI, Overall Verdict: NEEDS_DISCUSSION Auto-fix Candidates: 0 CRITICAL + HIGH issues can be auto-fixed Statistics
CRITICAL Issues (Must Fix)No critical issues were reported by the available artifacts. HIGH Issues (Should Fix)No high-severity issues were reported by the available artifacts. MEDIUM Issues (Options for User)Issue 1: Optional token-key omission is not regression-testedSource Agent: test-coverage-agent Problem: The new tests verify token values when usage is present, but do not assert that Options:
Recommendation: Fix now. Three small executor-level assertions match the PR's three-path scope and protect the persisted event contract without adding production complexity. LOW Issues (For Consideration)No low-severity issues were reported by the available artifacts. Positive Observations
Suggested Follow-up Issues
Next Steps
Agent Artifacts
Metadata
|
Fixed:\n- cover omission of unreported token usage in completion events\n\nTests added:\n- direct AI and loop_group no-usage completion coverage\n- loop no-usage assertion\n\nSkipped:\n- none
Fix Report: PR #2347Date: 2026-07-30T14:27:59Z SummaryReview artifacts reported one medium-severity coverage gap: successful completion events without provider usage were not asserted to omit Fixes Applied
Tests Added
Docs Updated(none) Skipped Findings(none) Blocked (Could Not Fix)(none) Suggested Follow-up Issues(none) Validation
|
pr: 2347
|
| Test | Reverted | With fix |
|---|---|---|
stores node_output in node_completed event data for AI nodes |
FAIL | PASS |
records requested model/tier on node_started and the resolved model on node_completed (#2314) |
FAIL | PASS |
COST: accumulates token usage across loop_group iterations |
FAIL | PASS |
omits tokens from a direct AI node_completed event when the provider reports no usage |
pass | pass |
omits tokens from a loop_group node_completed event when providers report no usage |
pass | pass |
Each of the three production sites has a test that genuinely fails without it. The two omits tokens… tests pass either way — correctly so (they are absence-contract guards), but they prove nothing about the fix itself and should not be counted as coverage of it.
Full file restored: 436 pass / 0 fail.
Validation
| Check | Result |
|---|---|
bun run type-check |
PASS (all 13 packages) |
bun run lint |
PASS (clean) |
bun --filter @archon/workflows test |
PASS (exit 0) |
bun test packages/workflows/src/dag-executor.test.ts |
436/436 |
Empirical
~/.archon/archon.db (read-only): 548 node_completed events, 0 carrying tokens. The gap is real.
Item 1 — aggregation semantics. SETTLED: the sum is correct, no double-count.
executeLoopNode already carries the #2083 fix for tokens:
dag-executor.ts:4199-4210— within an iteration,iterationTokensuses overwrite semantics (iterationTokens = {…}), with an explicit comment that a later result chunk from a background-task wait carries session-cumulative values.dag-executor.ts:4070-4085—foldIterationUsage()folds the last-seen per-iteration value intoloopTotalTokensexactly once, latched byiterationUsageFolded.
So a second result chunk in one iteration overwrites rather than adds. The hazard you flagged was already handled, and it carries a Number.isFinite guard the direct path does not (see S2).
executeLoopGroupNode (dag-executor.ts:3327-3331) sums iterCtx.totalTokensIn/Out with a fresh iterCtx per iteration — a genuine per-iteration sum.
Summing tokens while resolvedModel stays last-seen-wins is deliberate and right.
Item 2 — loop_group bodies route through executeNodeInternal, and 300/30 is a real sum.
The fixture yields distinct values per iteration ({100,10} then {200,20}) and pins expect(calls).toBe(2), so 300 is provably 100+200, not a fixture coincidence. Body nodes reach iterCtx.totalTokensIn via NodeOutput.tokens at dag-executor.ts:6220-6221.
Issues Found
Important
I1 — loop_group double-counts in the persisted event stream.
packages/workflows/src/dag-executor.ts:3509
I instrumented the loop_group test and dumped every node_completed the run persists:
paid.work → {"input":100,"output":10} ← iteration 1 body node
paid.work → {"input":200,"output":20} ← iteration 2 body node
paid → {"input":300,"output":30} ← group aggregate (new)
Why: a consumer summing node_completed.tokens over a run gets {600,60} for {300,30} of real usage — exactly 2×. Leaf rows and the aggregate row use the same field name with no discriminator; the only signal is that step_name contains a ., which is undocumented and fragile. This is precisely the consumer #2333 exists to serve ("benchmark query", "per-run cost/efficiency reporting"). Note loop does not have this problem — its per-iteration events are loop_iteration_completed (:4618) and carry no tokens; only loop_group emits both levels. Run-level totals stay correct (aggregated once at :6215); this is an event-stream-only defect.
Fix: either drop tokens from the group-level event (bodies already report it, so the sum is recoverable), or mark the aggregate — e.g. tokens_rollup: true or type: 'loop_group' — so consumers can filter. Whichever you pick, say it in the event-shape docs.
I2 — the workflow: sub-run node is a 4th AI-derived path, and it was missed.
packages/workflows/src/dag-executor.ts:5147
data: {
node_output: output,
type: 'workflow',
child_run_id: outcome.childRunId,
...(outcome.costUsd !== undefined ? { cost_usd: outcome.costUsd } : {}),
// ← outcome.tokens dropped here
},…while the same function, 29 lines later at :5176, already does:
...(outcome.tokens !== undefined ? { tokens: outcome.tokens } : {}),ChildWorkflowOutcome.tokens is declared at :325 and populated by childOutcomeFromRun (:364-388) from the child's total_tokens_in/total_tokens_out metadata. The value is live and in scope.
Why: this is the identical defect #2333 describes — captured, threaded to the return value, dropped from the persisted event. It is also backwards relative to the issue's own thesis: the sub-run node propagates cost (which Codex cannot report, so it is not comparable) and drops tokens (the one axis that is). A workflow using workflow: nodes gets a queryable event stream with cost but no tokens on exactly the nodes that did the work.
Fix: one-line spread, mirroring cost_usd, plus a test.
I3 — finalizeLoopFromSignal emits a token-less node_completed.
packages/workflows/src/dag-executor.ts:3049
data: { duration_ms: 0, node_output: finalizeOutput },This is the #2074 path: on an interactive loop gate whose iteration already emitted the completion signal, approving with no text finalizes the node from the already-computed output without a new iteration. The function signature (:3021-3030) takes no usage parameters at all, so tokens are unreachable from inside it — but both call sites (:3153, :3894) have loopTotalTokens in scope.
Why: an interactive loop that finalizes at the gate persists duration_ms: 0 and no tokens, despite having consumed them across its iterations. Silent — the operator sees a node that apparently cost nothing. Pre-existing (cost_usd is missing too, so this is not a regression), but it sits squarely inside this PR's stated scope of "loop completion events", and the run reports a number that will be believed.
Fix: thread the loop totals into the finalize helper and spread them like the other sites; or, if deliberate, comment why this path reports no usage.
Suggestions
S1 — the persisted tokens shape is not uniform across the three patched sites.
dag-executor.ts:2253 vs :3509 / :4655
The direct-node path persists the raw provider object. TokenUsage (packages/providers/src/types.ts:167-172) is {input, output, total?, cost?}, and real logs confirm the 4-field form is common:
{"input":2592,"output":170,"total":2762,"cost":0.0009816}The loop paths instead construct {input, output} only, dropping total/cost. That matters because total is not input + output: Pi's usageToTokens (community/pi/event-bridge.ts:105-112) sets total from usage.totalTokens, which includes cache tokens, and OpenCode does the same (its own test maps {input:11, output:7, reasoning:3, cache:1} → total: 21). I found a real log line where total is 2759 against input+output of 172.
So one field name now carries two different accounting bases depending on node type, and tokens.cost duplicates the sibling cost_usd. On payload size (your item 6) the PR is fine — TokenUsage is capped at 4 numeric fields and the richer cache/reasoning breakdown is already discarded at the provider boundary, so nothing unbounded rides along. The problem is consistency, not size.
Fix: normalise at all three sites — either persist {input, output} everywhere, or carry total/cost everywhere.
S2 — the new direct-node site bypasses the repo's NaN guard.
dag-executor.ts:1644 → :2253
Capture is if (msg.tokens) nodeTokens = msg.tokens; — no finiteness check. The repo guards this value twice elsewhere, deliberately:
:6215— "Token values come from providers (incl. community ones) — guard so a NaN can't silently poison the totals":4202-4210— the loop node's per-iteration capture, which references that rationale
Before this PR, nodeTokens only reached the JSONL log and the guarded run-level aggregator. It now goes straight to the store, unguarded. JSON.stringify(NaN) is null, so a misbehaving provider yields a persisted tokens: {input: null, output: null}. The loop paths are protected; the direct path is not.
Fix: reuse the same Number.isFinite check at capture, with the existing usage_tokens_non_finite_ignored warn.
S3 — zero-usage asymmetry (your item 4).
Absence is preserved when the provider omits msg.tokens — I verified both new tests and confirmed no path emits tokens: undefined. But a provider that reports an explicit {input: 0, output: 0} is truthy at :1644, so the direct node persists {input:0,output:0}, while loop_group's > 0 guard (:3327) skips it and omits the field. The same zero report is therefore recorded as "zero" by one node type and "unreported" by another. Not the fabricated-number bug you were worried about, but the same family.
Strengths
- Finding and fixing the
loop_grouppath unprompted — the exact gap fix(providers): record resolved model metadata #2337 was sent back for. - Reuses the established conditional-spread convention; zero new production complexity.
- Tests assert against
deps.store.createWorkflowEvent(the persisted row), not the in-process emitter — which is what actually matters, and confirms your item 5. - The loop_group fixture uses distinct per-iteration values, so it tests summation rather than a repeated constant. That is better than the average test in this file.
- Absence-contract tests were added on review feedback rather than argued away.
Notes on the issue spec
Beyond the loop-path omission already identified, #2333 was incomplete in three ways:
- It missed the
workflow:sub-run node (I2) — an AI-derived completion event withtokensalready in scope and its siblingcost_usdalready handled. - It missed
finalizeLoopFromSignal(I3). - It proposed the one-line spread without noticing that adding
tokensto both body and aggregate rows makes theloop_groupevent stream non-summable (I1) — which undercuts the benchmarking motivation the issue is built on.
One factual correction: the issue lists "Roll-up on the run" as still to be decided. It already exists — total_tokens_in / total_tokens_out are written to run metadata at dag-executor.ts:7300-7301, and childOutcomeFromRun reads them back. That part of the spec is asking for something already built.
Recommendation
NEEDS FIXES. I2 is a one-line fix with the value in scope and should land with this PR — leaving it means shipping the fix for #2333 while an equivalent instance survives in the same file. I1 needs a decision (drop the aggregate, or mark it) before consumers start summing. I3 and S2 are small and worth folding in. S1/S3 are consistency cleanups that can be deferred if you prefer to keep the diff tight, but they should be a follow-up issue rather than nothing.
Reviewed by Claude
Review findings on the initial persistence change. B1 — loop_group double-counted the persisted event stream. A loop_group's body nodes write their own namespaced node_completed rows, so persisting the group total under the same `tokens` field name meant a consumer summing node_completed rows got 600/60 for 300/30 of real usage, with nothing in the row marking it as an aggregate. Chose omission over a discriminator: the leaves are authoritative (per-provider, so usable for the cross-provider comparison the issue exists to enable) and already summable by step-name prefix, and omission means a naive consumer gets the right total without having to know about a discriminator field. The return value still carries the total — that is the run-level roll-up, which counts each group once. `cost_usd` has the same double-count shape and predates this; left as-is and noted rather than silently changed under a token fix. B2 — the `workflow:` sub-run node persisted the child's rolled-up cost but not its tokens, dropping the one axis every provider reports. Added. B3 — finalizeLoopFromSignal (bare approve at a signalled gate) wrote a node_completed with no usage for iterations that really ran. The gate now carries the pausing invocation's usage across the pause in the approval context, matching what the normal re-run completion path reports. Cost and resolved model are lost across the same gate; those belong to the single "preserve terminal provider stats across a gate" change tracked by #2345. Also normalizes the direct-node capture to `{input, output}` with a finite-value guard, mirroring the loop-node capture: `total` is provider-defined and is not input + output (Pi folds cache tokens into it), `cost` duplicates cost_usd, and a NaN would persist as a null a consumer would believe.
|
This would be extremely useful and is a blocker from my team using this tool right now. We want to track token usage per node. |
Second-pass review — scoped to the fix commits (
|
| Check | Result |
|---|---|
bun run type-check |
PASS |
bun run lint |
PASS (0 warnings) |
bun run format:check |
PASS |
bun --filter @archon/workflows test |
PASS, 0 failures |
packages/core/src/db/workflows.test.ts |
82 pass (in isolation) |
packages/core/src/workflows/store-adapter.test.ts |
13 pass (in isolation) |
finalizeLoopFromSignal is shared by executeLoopNode and executeLoopGroupNode. Passing it the gate's signaledTokens is right for a plain loop -- its per-iteration rows carry no tokens, so the finalize row is the only record of the usage -- but wrong for a loop_group, whose body nodes persisted their own `<groupId>.<nodeId>` rows (with tokens) BEFORE the pause. Those rows survive the pause, so the finalize row repeated usage already in the same event stream: a consumer summing `data.tokens` read 200/20 for 100/10 of real usage. This is the same double-count the natural-completion group row already avoids by omitting `tokens`; the gate path had simply not been covered. - loop_group finalize call site no longer passes finalizeTokens - loop_group gate pause no longer writes signaledTokens (it had no consumer left) - the schema field and the pauseWorkflowRun explicit-null reset stay: the plain loop still writes the field, and the reset still clears a stale value from a prior gate in the same run Tests: a loop_group gate -> bare approve -> resume across ONE shared event store, asserting the naive sum over persisted node_completed rows equals the true usage. Per-test isolation is what hid this: the pre-pause body rows have to survive into the resume for the double-count to appear at all. Plus a guard that the loop_group gate context carries no signaledTokens. Also corrects a measurably false claim in the signaledTokens doc comment: earlier invocations' usage is NOT visible in the run-level totals. A pausing invocation never reaches completeWorkflowRun (status is `paused`, so the pre-complete check bails) and `total_tokens_*` are written only there -- measured on a twice-gated loop, 40/4 then 60/6, the node row and the run row both report only 60/6. That under-report is pre-existing and belongs to #2345; only the comment changed.
2 participants
Summary
UX Journey
Before
After
Architecture Diagram
Before
After
Connection inventory (list every module-to-module edge, mark changes):
Label Snapshot
risk: lowsize: Sworkflowsworkflows:executorChange Metadata
bugworkflowsLinked Issue
Validation Evidence (required)
Commands and result summary:
bun run type-check bun run lint bun run format:check bun run test bun run validate.archon/edits that make bundled defaults stale; the same full gate passed in the clean snapshot with this fix applied.Security Impact (required)
Yes, describe risk and mitigation: Not applicable.Compatibility / Migration
Human Verification (required)
What was personally validated beyond CI:
undefinedevent field.Side Effects / Blast Radius (required)
node_completedevent data.Rollback Plan (required)
aa11bf1afromdevif event payload expansion causes an integration issue.tokensproperty or display unexpected node usage values.Risks and Mitigations