Performance - joeylking/agent-runtime GitHub Wiki

Performance

The runtime's own cost per step is small next to a model call, but it used to grow with the length of the run: every step reread and decoded every step before it. v0.3.0 fixed that, then deliberately made every step slower on disk by syncing each commit. This page is docs/performance.md for wiki readers: what a run costs, what changed and why each change is safe, what was measured and left alone, and how to run the benchmarks yourself. The repository document is authoritative and has every table.

All numbers come from bench_test.go, render/bench_test.go, and view/bench_test.go, run with -benchmem on an Apple M5 Max against a file-backed WAL store in a temporary directory, compared with benchstat.

The headline

A run of n steps is n−1 allowed tool calls with distinct arguments, then complete. The tool answers either with its arguments ("small") or with about 8 KiB of JSON.

Run time per step, before after
10 steps, small 329 µs 214 µs
100 steps, 8 KiB 919 µs 285 µs
400 steps, small 667 µs 229 µs
400 steps, 8 KiB 2,445 µs 290 µs

A 400-step run with 8 KiB observations took 978 ms and allocated 2.2 GiB; it then took 116 ms and 135 MiB. The cost of a step no longer grows with the number of steps before it. These are the numbers before durable commits were turned on, which added about a third per step; see the cost of full synchronous commits.

The step cache

The loop reread every prior step and approval from the store at every step, so a step cost O(n) rows unmarshalled, and Store.ListSteps was 44% of CPU and 98% of the bytes allocated.

Now a loop loads its steps and approvals once, when Start or Resume enters it, and keeps them (cache.go). It still reads the run row at every step, because model calls and an operator change it. Nothing is kept between loops.

Why the kept copy is exact. It is never built from the driver's own structs. A write records the columns it bound (stepRow, approvalRow in store.go), and once the transaction commits, those columns are decoded by the same code ListSteps and ListApprovals use. JSON the store compacts or escapes, and times it truncates to UTC text, therefore come back exactly as a fresh load would return them. A write that fails, at any statement or at commit, applies nothing. A row that cannot be applied marks the copy stale, and the next step loads afresh.

Why another process cannot fool it. The loop's writes are still compare-and-set inside their transactions, so an operator's Cancel makes the next write fail and the loop returns the cancelled run (TestCancel_LiveLoopStopsAtItsNextWrite).

How it was proved equal. TestDriver_CachedViewEqualsReloadedView runs one scenario twice with a deterministic clock and ids: once with the kept steps, once rereading the store and re-encoding every field at every step, the old path, reachable only from tests. The scenario covers an allowed step, a denial, an invalid decision, a tool error, an approval pause, a resume, a step interrupted while deciding, and a second resume. It compares every StepInput, every policy ToolRequest and RunView, every event, the number of clock readings, and every stored column. TestDriver_CacheEqualsStoreAfterEveryWrite checks the kept copy against a fresh load after each of that scenario's writes.

What is copied and why

Before, the agent's StepInput and the policy's RunView shared one slice and its pointers, so an agent could change what the policy was about to see. With a kept copy, it could also have changed what every later step saw, and what loop and failure detection read.

So the agent and the policy each get a mirror of the kept steps and approvals, with bytes of their own. A mirror copies a step only when that step changed since its last handout, so the bytes cost O(1) per step. Every handout is a fresh slice of fresh Decision, PolicyDecision, and Observation structs over the mirror. What a consumer does to a field, a struct behind a pointer, or a slice element never persists. The one thing that does is a write into the bytes of a RawMessage it was handed, and only into that consumer's own later views: never the driver's copy, the other consumer's view, or the store (TestDriver_ConsumersCannotCorruptEachOther).

Three handouts were measured on the final code:

Run time per step: shared mirror deep copy bytes per run: shared mirror deep copy
100 steps, small 204 µs 225 µs 220 µs 3.9 MiB 8.1 MiB 8.0 MiB
100 steps, 8 KiB 278 µs 292 µs 381 µs 15.2 MiB 20.9 MiB 96.1 MiB
400 steps, small 201 µs 234 µs 251 µs 15.4 MiB 83.1 MiB 84.4 MiB
400 steps, 8 KiB 275 µs 292 µs 647 µs 61.0 MiB 134.6 MiB 1,375 MiB

Sharing is not sound. A deep copy is sound but O(total bytes) per step. The mirror was chosen: its struct copies are O(n) per step, about 400 bytes per prior step per consumer, which is the price of isolation at the level of Go values. Resume gives the policy and the reconciliation copies too, and StepInput.Tools is a copy of the slice. A loop therefore keeps three copies of its run's step content: its own and one per consumer.

The other changes

  • Unchanged fields are not encoded again. A step is written up to four times (started, decided, executing, done). A write now reuses the previous write's text for any field whose pointer the driver has not replaced; the driver never writes through those pointers, it assigns new ones.
  • Guards read only the status. The guard at the start of each step transaction parsed the whole run row; it now reads status and whether the writer holds the lease (requireStatus).
  • Prepared statements. The loop's seven hot statements are prepared when a writer opens the store, worth about 12% per step. Stores from OpenExisting prepare nothing.
  • render. DefaultObservation converts content to a string only when it renders it in full, and Messages sizes and carves its allocations once. Output is byte-identical to the previous implementation, kept in render/oracle_test.go and checked over 3,000 random runs (TestMessages_MatchesOracle).
  • view and the operator command. GetApproval is one indexed row instead of every approval of the run; view.Runs finds pending approvals in one query (Store.PendingApprovalIDs) instead of one per waiting run; show reads the run, its steps, and its approvals once each.

render.Messages for the last decision of a 400-step 8 KiB run went from 376 µs to 36.4 µs; view.Runs over 1,000 runs with 500 waiting went from 7.72 ms to 1.95 ms.

The run lease

The lease was measured against the same benchmarks run just before it, medians of three: time per step moved by less than run-to-run noise, in both directions (215 to 223 µs for 10 small steps, 300 to 294 µs for 400 at 8 KiB). The heartbeat writes every third of the TTL, so a benchmark shorter than ten seconds renews nothing. What a step pays is in the guards, which compare the lease owner in SQL: about ten allocations and a few hundred bytes per step, 1.3% of allocations, plus one wall-clock read per tool call.

The cost of full synchronous commits

A store opened for writing syncs every commit (synchronous=FULL instead of NORMAL). In WAL mode NORMAL can lose the last commits on power loss, and the last commit may be the step.tool_started of a tool that ran; the next owner would then treat a tool that ran as one that never started. That costs one fsync of the WAL per transaction, four per step. Measured with BenchmarkDriver, medians of three:

Run before after after, with NORMAL put back
10 steps, small 219 µs 305 µs (+40%) 220 µs
10 steps, 8 KiB 310 µs 377 µs (+22%) 300 µs
100 steps, small 224 µs 294 µs (+31%) 219 µs
100 steps, 8 KiB 293 µs 377 µs (+29%) 301 µs
400 steps, small 234 µs 316 µs (+35%) 241 µs
400 steps, 8 KiB 295 µs 385 µs (+30%) 303 µs

All of the added time is the sync: with NORMAL the fixed code runs as fast as before. It is about 20 µs per commit on that Apple SSD, where fsync does not force the drive's own cache (SQLite's fullfsync is off). On a disk where fsync waits for the medium it is milliseconds per commit, and a step's cost is dominated by it. The cost was taken on purpose.

Bytes per run also grew about 60 bytes per prior step per step, 2% at 100 steps and 11% at 400, from the new Step.DecodeError and the three Decision.Invalid* fields the mirrors copy.

Measured and left alone

  • Commit. Tx.Commit is about 85% of the loop's CPU after these changes. A step is four transactions (started, decided, policy and tool start, done), one per state transition with its events. Merging them would change what a crash leaves behind and when the observer sees each event, so they stay.
  • Content checks and hashes. checkJSON and contentHash are about 22% of the bytes the loop still allocates. Their cost is proportional to the content, not the run's length, and the canonical encoder is pinned byte for byte to the stored hashes, so it was not touched.
  • The handout copy. Now the largest allocation, O(n) small structs per step; see the table above.
  • Indexes. Every statement the loop runs uses a primary key or an existing index. An index on approvals(status) was measured at 0.39 ms against 0.36 ms without it for 1,000 runs and 500 pending approvals. No index is warranted, and no schema change was made.
  • Resume. Resume loads the steps once to find the step it acts on, and the loop it enters loads them again: once per resume, not per step.
  • ListRuns parses every run's limits JSON; it is most of what remains of view.Runs and linear in the runs listed.

Running the benchmarks

From a clone, with the workspace out of the way so the core builds against only its own dependencies:

GOWORK=off go test -run '^$' -bench . -benchmem -count=5 ./ ./render ./view

Just the driver, as the durable-commit table was measured:

GOWORK=off go test -run '^$' -bench BenchmarkDriver -benchmem -count=3 .

Compare two runs with benchstat. Expect the absolute numbers to differ on your machine, and the sync cost most of all.

Next

Internals is where the cache sits in the loop. Persistence and Inspection covers the store the benchmarks write to.