Skip to content

fix: stop losing a failed mutation's entire token accounting - #73

Open
KE7 wants to merge 3 commits into
mainfrom
fix/charge-usage-before-parse
Open

fix: stop losing a failed mutation's entire token accounting#73
KE7 wants to merge 3 commits into
mainfrom
fix/charge-usage-before-parse

Conversation

@KE7

@KE7 KE7 commented Sep 9, 2026

Copy link
Copy Markdown
Owner

Two fixes, one story: a Unicode line-splitting bug that fragments backend JSONL, and the accounting hole it exposed — HELIX silently loses a failed attempt's entire token usage.

How it surfaced

In a codex run, one mutation failed with:

HELIX ERROR — Failed to parse Codex CLI JSONL output line
Operation: mutate | Phase: JSON parsing | Exit code: 0
Mutation failed -- skipping.

That agent had run for most of an hour and was the most expensive step of its run. None of its tokens reached state.json's budget, and nothing in the run output said so. The loss was confirmed three independent ways: the orphaned turn.completed record preserved in the failed invocation's stdout in .helix/helix.log, the Codex rollout file for that thread in the agent auth volume, and the residual between the whole-run total and state.json's own reported total. All three agreed exactly.

Mechanism

Root cause (commit 1). _parse_jsonl_output split stdout with str.splitlines(). That breaks on eight boundaries a newline-delimited format does not define, including U+0085 (NEL), U+2028 and U+2029. JSON leaves those three unescaped inside a string literal — RFC 8259 only requires escaping C0 controls — and neither serde_json (Codex) nor JSON.stringify (the Node CLIs) escapes them.

The failed invocation's stdout carried a few raw U+0085 bytes inside the aggregated_output of one command_execution record that had captured binary data from a curl. Replaying that exact stdout: splitlines() produced fragments that failed json.loads; split("\n") parsed every record. With exit code 0 the parse is strict, so the first bad fragment raised MutationError and the mutation was lost.

The accounting hole (commit 2). budget.charge_llm_usage was reachable only from the success paths. invoke_claude_code raises, mutate catches, removes the worktree and returns None, and MutationFailedProposal had no field for usage to travel in — so the apply phase had nothing to charge. Every token the attempt spent went out with the candidate. The under-report is proportional: several such failures in a run lose several generations of accounting.

The parse bug is fixed, but it is not the only way a strict parse can fail, so the accounting is made independent of it too.

The fix

Commit 1 — fix(mutator): split backend JSONL on LF only

Adds helix.lines.split_lf_lines so the invariant has one name, one docstring and one test, and applies it at the twelve sites where the line boundary is defined by the format:

  • mutator.py: _parse_jsonl_output, the five per-backend transcript tool-event counters, and the HELIX_RESULT= stripper that builds mutation prompts
  • executor.py + parsers/helix_result.py: the paired HELIX_RESULT= reverse scans — a payload with U+2028 in evaluator side info was truncated mid-JSON
  • sandbox.py: the JSONL fallback in _extract_session_id_from_json_output
  • config.py + evolution.py: the JSONL dataset readers — a fragmented line raised JSONDecodeError in one and inflated the example-id count in the other, desynchronising HELIX's ids from the evaluator's own dataset indexing

Not a blanket replace. Five splitlines() calls are deliberately left alone, since breaking on any Unicode line boundary is either correct or harmless there: the dotenv reader (human-authored, wants CRLF tolerance), the two git-output readers, the .gitignore membership check, and asi.py's ASI log reader — whose writer uses ensure_ascii=True, so that file is ASCII by construction. A comment now records that reason at the asi.py site.

Commit 2 — fix(budget): charge backend token usage even when the output fails to parse

Token usage is a fact about work the backend already did. It must not be conditional on whether that work produced something usable.

  • _salvage_backend_usage recovers usage from raw stdout with a parse that cannot raise — JSONL backends reuse _parse_jsonl_output in its existing strict=False mode, Claude's object mode falls back to the same line scan. invoke_claude_code calls it immediately after the subprocess returns, before anything that can fail.
  • HelixError.usage carries that record out on every error raised from invoke_claude_code; format_full and print_helix_error now print it. None (no invocation) stays distinct from a zero-token UsageStats (an invocation that reported nothing).
  • mutate and merge take a record_usage sink, called once with the usage whether or not a candidate comes back. Return contracts are unchanged — mutate still returns None on MutationError.
  • MutationFailedProposal gains child_usage; the worker fills it from a worker-local list and the sequential apply phase charges it with source="mutation_failed". Merge failures charge with source="merge_failed". Charging stays in the apply phase, so the serialization invariant documented at the top of budget.py holds and workers stay state-free.

Rate-limited invocations get the same handoff — a run can burn tokens before the limit trips. .helix_backend_result.json also now records the recovered usage instead of zeros when the strict parse failed.

Tests

18 new tests. Every one of them fails against the pre-fix source (verified by reverting the source and re-running).

  • tests/unit/test_lines.py (7 behavioural): every non-LF boundary; strict JSONL parse over a Codex-shaped stream carrying U+0085 / U+2028 / U+2029; the tool-event counter reading one record rather than two fragments; a HELIX_RESULT= payload not truncated at U+2028; and the machine-protocol fragment no longer leaking into the mutation prompt.
  • tests/unit/test_budget.py (6): the headline regression — feed a malformed JSONL line to each JSONL backend and assert the budget still records the usage. Plus: recovered usage pinned against a strict parse of the same stream minus the junk line; the artifact; the None-vs-zero distinction.
  • tests/unit/test_mutator.py (7): the sink on the success, failure, rate-limit and no-invocation paths, plus _salvage_backend_usage directly.
  • tests/unit/test_evolution.py (2): end to end through run_evolution — a failed mutation produces exactly one mutation_failed charge, and a failure with no usage produces none.

Results

uv run pytest tests/unit/ -q     1008 passed          (985 on main, +23)
uv run mypy --strict src/helix/  Success: no issues found in 28 source files
uv run ruff check src/ tests/    All checks passed

No pre-existing failures on main to report: the baseline was green on both.

ruff format --check is not clean on this repo and never has been — 20 files under src/ would reformat both before and after this branch, and CI does not run it. This branch adds no new formatting drift.

Scope note

The trigger was one failure in one codex run. The mechanism is verified directly in the source and by replaying the captured stdout, so the fix does not rest on that sample; the size of the under-report in any given run depends on how many mutations fail this way.

🤖 Generated with Claude Code

https://claude.ai/code/session_01NLHEwgZV983irkXWSXz2Vd

KE7 and others added 3 commits September 9, 2026 12:46
`str.splitlines()` breaks on eight boundaries a newline-delimited format
does not define: U+000B, U+000C, U+001C-U+001E, U+0085 (NEL), U+2028 and
U+2029. JSON leaves the last three unescaped inside a string literal --
RFC 8259 only requires escaping C0 controls -- and neither `serde_json`
(Codex) nor `JSON.stringify` (the Node CLIs) escapes them. So a single
NEL byte inside one agent message, or inside one blob of captured command
output, turns a valid JSONL record into two invalid fragments.

`_parse_jsonl_output` raises `MutationError` on the first fragment when
the backend exited 0 (`strict=True`), which loses the whole mutation.

Observed in a real run: one generation's stdout contained a few raw
U+0085 bytes inside the `aggregated_output` of a `command_execution`
record that had captured binary data from a `curl`. `splitlines()`
produced fragments that failed `json.loads`; on LF-only splitting every
record parsed. The run log showed the resulting failure:

    HELIX ERROR - Failed to parse Codex CLI JSONL output line
    Operation: mutate | Phase: JSON parsing | Exit code: 0
    Mutation failed -- skipping.

The agent had run for most of an hour; its work and its accounting were
both discarded. (The accounting half is fixed separately in the next
commit.)

Adds `helix.lines.split_lf_lines` so the invariant has one name, one
docstring and one test, and applies it at the twelve sites where the
line boundary is defined by the format rather than by human authorship:

  mutator.py  `_parse_jsonl_output` (the site above), the five per-backend
              transcript tool-event counters, and the `HELIX_RESULT=`
              stripper that builds mutation prompts
  executor.py, parsers/helix_result.py
              the paired `HELIX_RESULT=` reverse scans -- a payload with
              U+2028 in evaluator side info was truncated mid-JSON
  sandbox.py  the JSONL fallback in `_extract_session_id_from_json_output`
  config.py, evolution.py
              JSONL dataset readers; a fragmented line raised
              `JSONDecodeError` in one and inflated the example-id count
              in the other, desynchronising HELIX's ids from the
              evaluator's own dataset indexing

Deliberately left on `splitlines()`, since breaking on any Unicode line
boundary is either correct or harmless there: `config.py`'s dotenv reader
(human-authored, wants CRLF tolerance), the two git-output readers in
`worktree.py` / `cli.py`, `cli.py`'s `.gitignore` membership check, and
`asi.py`'s ASI log reader -- whose writer uses `ensure_ascii=True`, so
that file is ASCII by construction. A comment now records that reason at
the `asi.py` site.

Tests: `tests/unit/test_lines.py`. All seven behavioural assertions fail
against `splitlines()` and pass against `split("\n")`, verified by
temporarily reverting the helper body.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01NLHEwgZV983irkXWSXz2Vd
… parse

`budget.charge_llm_usage` was reachable only from the success paths of the
mutate and merge operators. `invoke_claude_code` raises `MutationError`
when the strict parse of backend output fails, `mutate`/`merge` catch it,
remove the worktree and return `None`, and `MutationFailedProposal` had no
field for usage to travel in -- so the apply phase had nothing to charge.
Every token an attempt spent before failing was discarded along with the
candidate.

Token usage is a fact about work the backend already did. It cannot be
conditional on whether that work produced something usable.

Observed in a real run: one generation's entire usage -- the most
expensive generation of that run -- was missing from `state.json`'s
budget because its JSONL output failed to parse (root cause fixed in
the previous commit), with nothing in the run output saying so. The
loss was confirmed three ways, all agreeing: the orphaned
`turn.completed` record preserved in `.helix/helix.log`, the Codex
rollout for that thread in the agent auth volume, and the residual
against `state.json`'s reported total.

The fix, in four parts:

* `_salvage_backend_usage` recovers usage from raw stdout with a parse
  that cannot raise -- JSONL backends reuse `_parse_jsonl_output` in its
  existing `strict=False` mode, Claude's object mode falls back to the
  same line scan. `invoke_claude_code` calls it immediately after the
  subprocess returns, before anything that can fail.
* `HelixError.usage` carries that record out on every error raised from
  `invoke_claude_code`, and `format_full` / `print_helix_error` now print
  it. `None` (no invocation) stays distinct from a zero-token
  `UsageStats` (an invocation that reported nothing).
* `mutate` and `merge` take a `record_usage` sink, called once with the
  usage whether or not a candidate comes back. Their return contracts are
  unchanged -- `mutate` still returns `None` on `MutationError`.
* `MutationFailedProposal` gains `child_usage`; the worker fills it from a
  worker-local list, and the sequential apply phase charges it with
  `source="mutation_failed"`. Merge failures charge with
  `source="merge_failed"`. Charging stays in the apply phase, so the
  serialization invariant documented at the top of `budget.py` holds.

Rate-limited invocations get the same handoff -- a run can burn tokens
before the limit trips.

`.helix_backend_result.json` also now records the recovered usage instead
of zeros when the strict parse failed, so the on-disk artifact stays a
faithful account of the invocation.

Tests: 11 new. `tests/unit/test_budget.py` feeds a malformed JSONL line to
each JSONL backend and asserts the budget still records the usage, pins
the recovered usage against a strict parse of the same stream minus the
junk line, and covers the artifact and the None-vs-zero distinction.
`tests/unit/test_mutator.py` covers the sink on the success, failure,
rate-limit and no-invocation paths plus `_salvage_backend_usage` directly.
`tests/unit/test_evolution.py` asserts end to end through `run_evolution`
that a failed mutation produces exactly one `mutation_failed` charge and
that a failure with no usage produces none. All 11 fail against the
pre-fix source.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01NLHEwgZV983irkXWSXz2Vd
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01NLHEwgZV983irkXWSXz2Vd
@KE7
KE7 force-pushed the fix/charge-usage-before-parse branch from c58e9bb to d2e9e9c Compare September 10, 2026 00:36
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant