Skip to content

Pre-deploy P0.2, P0.3, P0.4: admission control and a meter - #4

Open
31803smith wants to merge 3 commits into
mainfrom
feat/pre-deploy-logging
Open

Pre-deploy P0.2, P0.3, P0.4: admission control and a meter#4
31803smith wants to merge 3 commits into
mainfrom
feat/pre-deploy-logging

Conversation

@31803smith

@31803smith 31803smith commented Aug 18, 2026

Copy link
Copy Markdown
Collaborator

Three P0 items from docs/pre-deploy.md, in the two server files they all
touch. Each is small; together they are the difference between deploying blind
and deploying.


P0.4 · Metering

The server had five console.* statements, four of them lifecycle noise.
Nothing recorded who asked for what, how long it took, what it cost, or why it
failed, and a successful POST /api/<command> was invisible — http.mjs
logged only on throw.

Everything needed was already on the wire and being thrown away.

Measured first, and it corrects the doc

pre-deploy.md says review is "plausibly the majority" of spend. Split by
phase across three real boards, using each session's own per-message usage:

board main turn review rounds
weather-badge-10 76.3% 23.2%
weather-badge-11 65.5% 26.6%
weather-badge-13 60.6% 39.1%

Less than the majority, and far too much to omit. runReviewRound did
child.stdout.resume() — a pure drain — so a meter reading only the main turn
undercounts every board by a quarter to two fifths.

Four counters, not a total

weather-badge-13, one board end to end:

input_tokens                      420
cache_creation_input_tokens 2,248,535
cache_read_input_tokens    30,555,177
output_tokens                 241,443

Raw input is a rounding error and cache reads are 99% of the volume. The four
are priced roughly 1× / 1.25× / 0.1× / 5× against base input — a 50× spread
inside one turn
— so a total_tokens column cannot be multiplied back into
money by anyone. Logging the obvious two would have captured 0.7% of what
moved; a test asserts exactly that against these numbers.

total_cost_usd is kept as well and is not a duplicate: it is a price
snapshot
, and recomputing an old turn at next quarter's rates gives a figure
nobody was ever charged. A missing cost reads null, never 0 — "not
reported" and "free" are different claims and only one is safe to sum.

What changed

usage.mjs (new, pure, 13 tests) — reads a result line, folds records,
formats one line.

Main turnfromResult read obj.result, the text, and dropped usage,
total_cost_usd, duration_ms, is_error, stop_reason, api_error_status.

Review children — stdout is still drained continuously (the deadlock
resume() prevented is real on a ninety-minute craft round) but only the last
non-empty line is kept: this repo's own "one JSON line, last line wins", at the
cost of one string rather than a transcript. stderr is now buffered at the same
8192 cap as the main turn. spawnClaude throwing reports spawn_failed — a
review round that never started returned a bare false, exactly what a round
that ran and changed nothing returns.

Command boundary — every command logs, with the project and elapsed time.
Bodies are deliberately not logged; they carry chat text and pasted images. An
expected refusal (error.code) is refused, not error: reading those as one
event is how a broken deploy looks healthy.

turn=t1 project=p1 phase=build model=claude-opus-5 effort=5x elapsed_ms=3360123 \
  in=420 out=241k cache_w=2.2M cache_r=30.6M claude_turns=8 cost_usd=12.3456 exit=ok

Deliberately not included: the durable event log and the SSE backlog. The
doc argues they are the same work and architecturally they may be, but that is
a new subsystem and this is a meter.


P0.2 · Two turns can run on the same project

Two claude --resume <sessionId> children on one session collide, and the
footgun CLAUDE.md inherits — "Session ID already in use" — is that collision.

turnInProgress(projectId, sessionId) already existed and was already wired
into refuseIfBuilding(), which protects board-source writes while a build
owns the file. That is a real guard; it is just not this one. The turn that
creates the collision was gated on nothing: http.mjs calls
chat.startTurn() from three commands with no check, and startTurn() did not
self-guard.

Guarded inside startTurn rather than at the three call sites, so a fourth
entry point cannot be added without it. TURN_RUNNING / 409, the same shape
refuseIfBuilding already returns.

The lock is per project, not a global mutex — a test pins that a second
project still starts, because turning a collision guard into a
one-user-at-a-time server would be a worse bug than the one being fixed.


P0.3 · No concurrency cap

turns was an unbounded in-memory Map in one process. Ten people pressing
build is ten CLI children and ten routers on one box, and the multiplier is
worse than it reads: autopilot chains a build turn after every plan turn, and a
build turn spawns up to seven review children of its own, each rebuilding the
board.

DEFAULT_MAX_TURNS = 4, overridable with CIRCUIT_MAX_TURNS. Four is not a
tuned number and the comment says so. The measured input is that one board is
43–147 minutes of near-constant CPU on this hardware, so concurrency here is
not a throughput knob, it is a blast radius. TOO_MANY_TURNS / 503 — the
request is fine and the server is full, which is what 503 means.

Checked at admission only. Work already admitted runs to completion: an
autopilot build chains through runTurn directly, and a review round is inside
a turn already counted. Killing either halfway leaves a half-built board, which
is worse than a slow one.

Both errors are plain Errors carrying code and statusCode rather than
importing the HTTP layer into the driver — sendIpcError reads those off any
thrown value, and the command-boundary log above already classifies a coded
refusal as refused.


Still open in P0

P0.1 · auth is untouched and is the one that gates a deploy. Note the
ordering the doc calls out: auth and metering have to land together, because
authenticating users without attributing their spend gives every logged-in user
every other user's boards. The user= column exists now and is empty, waiting
for exactly that.

Checks

  • usage.test.mjs 13/13, built from a real board's counters
  • driver.test.mjs 49 → 53
  • viewer: 13 failing files, the same set as clean upstream/main @ 6040efb,
    captured fresh from a worktree and compared with comm — empty both ways
  • npm run build passes

No new ChatEvent kind, so docs/circuit-interfaces.md §3 is untouched.

🤖 Generated with Claude Code

31803smith and others added 2 commits August 18, 2026 15:08
The server had five `console.*` statements, four of them lifecycle noise.
Nothing recorded who asked for what, how long it took, what it cost, or why it
failed, and a successful `POST /api/<command>` was completely invisible —
`http.mjs` logged only on throw.

Everything needed was already on the wire and being discarded.

**The main turn.** `claude -p --output-format stream-json` ends each turn with a
`result` line carrying `usage`, `total_cost_usd`, `duration_ms`, `is_error`,
`stop_reason` and `api_error_status`. `fromResult` read `obj.result` — the text
— and dropped the rest.

**The review children, which is the part that mattered.** `runReviewRound` did
`child.stdout.resume()`, a pure drain, and `child.stderr.resume()`, so unlike
the main turn it did not even buffer the place a dying child prints why. Split
by phase across three real boards (weather-badge-10, -11 and -13), review
rounds are **23%, 27% and 39%** of a board's weighted spend. `pre-deploy.md`
guessed "plausibly the majority"; measured, it is less than that and far too
much to omit. A meter reading only the main turn undercounts every board by a
quarter to two fifths.

Stdout is still drained continuously — the deadlock the `resume()` prevented is
real on a ninety-minute craft round — but only the last non-empty line is kept,
which is this repo's own "one JSON line, last line wins" convention and costs
one string instead of a transcript. Stderr is buffered at the same 8192 cap and
for the same reason as the main turn. `spawnClaude` throwing now reports
`spawn_failed`: a review round that never started returned a bare `false`,
which is exactly what a round that ran and changed nothing returns.

**Four counters, not a total.** weather-badge-13, one board end to end:

    input_tokens                      420
    cache_creation_input_tokens 2,248,535
    cache_read_input_tokens    30,555,177
    output_tokens                 241,443

Raw input is a rounding error, cache reads are 99% of the volume, and the four
are priced roughly 1x / 1.25x / 0.1x / 5x — a 50x spread inside one turn, so a
`total_tokens` column cannot be turned back into money by anyone. Logging the
obvious two would have recorded 0.7% of what moved; there is a test that
asserts exactly that against these numbers. `total_cost_usd` is kept as well
and is not a duplicate: it is a price snapshot, and recomputing an old turn at
next quarter's rates gives a number nobody was ever charged.

A missing cost reads `null`, never `0` — "not reported" and "free" are
different claims and only one of them is safe to sum.

**Format.** Space-separated `key=value` on stdout, one line per turn, absent
fields omitted rather than printed as `null` so a short line means little
happened rather than something broke. Errors are collapsed to a single line and
capped; a stack trace here would break every consumer that splits on newlines.

**Command boundary.** Every command logs now, not only the ones that throw,
with the project it was about and how long it ran. Bodies are deliberately not
logged — they carry chat text and pasted images. An expected refusal
(`error.code`) is recorded as `refused` rather than `error`: reading those as
one event is how a broken deploy looks healthy.

Deliberately out of scope: the durable event log and the SSE backlog. The doc
argues they are the same work and architecturally they may be, but that is a
new subsystem and this is a meter.

`spawnTurn` gains `projectId` for the log line. `runReviewRound` and
`runReviewFixLoop` gain an optional `onMeter` callback rather than a changed
return type, so the boolean every caller reads is untouched.

13 new tests, built from a real board's counters. driver.test.mjs 49/49. viewer
13 failing files — the same set as clean upstream/main @ 6040efb, compared with
`comm`. Build passes.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
**P0.2.** Two `claude --resume <sessionId>` children on one session collide, and
the footgun CLAUDE.md inherits — "Session ID already in use" — is exactly that
collision. `turnInProgress(projectId, sessionId)` already existed and was
already wired into `refuseIfBuilding()`, which protects *board-source writes*
while a build owns the file. That is a real guard; it is just not this one. The
turn that creates the collision was never gated on anything: `http.mjs` calls
`chat.startTurn()` from three commands with no check, and `startTurn()` did not
self-guard.

Guarded inside `startTurn` rather than at the three call sites, so a fourth
entry point cannot be added without it. Refused with `TURN_RUNNING` / 409, the
same shape `refuseIfBuilding` already returns for the write path.

The lock is per project, not a global mutex — a test pins that a second project
still starts, because turning a collision guard into a one-user-at-a-time
server would be a worse bug than the one being fixed.

**P0.3.** `turns` was an unbounded in-memory Map in one process. Ten people
pressing build is ten CLI children and ten routers on one box, and the
multiplier is worse than it reads: autopilot chains a build turn after every
plan turn, and a build turn spawns up to seven review children of its own, each
rebuilding the board.

`DEFAULT_MAX_TURNS = 4`, overridable with `CIRCUIT_MAX_TURNS`. Four is not a
tuned number and the comment says so. The measured input is that one board is
43-147 minutes of near-constant CPU on this hardware, so concurrency here is
not a throughput knob, it is a blast radius. Refused with `TOO_MANY_TURNS` /
503 — the request is fine and the server is full, which is what 503 means.

The cap is checked at **admission only**. Work already admitted runs to
completion: an autopilot build chains through `runTurn` directly and a review
round is inside a turn that was already counted. Killing either halfway leaves
a half-built board, which is worse than a slow one.

Both errors are thrown as plain `Error`s carrying `code` and `statusCode`
rather than importing the HTTP layer into the driver — `sendIpcError` reads
those off any thrown value, and the command-boundary log added in this branch
already classifies a coded refusal as `refused` rather than `error`.

driver.test.mjs 49 -> 53. viewer 13 failing files, the same set as clean
upstream/main @ 6040efb. Build passes.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@31803smith 31803smith changed the title P0.4: meter a turn, including the review children that were drained away Pre-deploy P0.2, P0.3, P0.4: admission control and a meter Aug 18, 2026
The turn log printed a `user=` field that nothing ever set, and a column that
is introduced at the same moment as the thing that populates it is a column
nobody has ever read. `CIRCUIT_USER_ID` is one hardcoded identity, `"local"` by
default, on both the turn line and the command-boundary line.

Deliberately NOT the rest of P0.1. `pre-deploy.md` asks for per-user project
directories so one account cannot read another's boards; that is a migration,
not a constant. Changing the projects root also changes the encoded Claude
session directory — `encodeCwd` maps every non-alphanumeric character to `-`,
so `…-projects-<uuid>` becomes `…-users-local-projects-<uuid>` — and every
existing board would keep its artifacts, lose its chat history, and hand
`--resume` a session id it can no longer find, which is the "Session ID already
in use" path CLAUDE.md warns about. Verified by resolving `sessionJsonlPath`
for both layouts before writing any of it. This repo is R&D for now, so the
partition waits for the migration that has to come with it.

Sanitised anyway. Nothing can set this to anything odd today, but the day it
becomes request-derived is the day a `..` in it reads someone else's boards.
The first attempt was too weak — `../../etc` came out as `-..-etc`, still
carrying a dot-segment — so `..` is now collapsed anywhere it appears rather
than only at the front, and the test asserts the property (no `..`, no
separator, never empty) over a list of hostile inputs instead of pinning one
output string.

usage.test.mjs 13 -> 16. driver.test.mjs 53/53. viewer 13 failing files, the
same set as clean upstream/main @ 6040efb. Build passes.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
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