acpmux: a host adoption after a restart parses only the log records it folds (163,616 -> 508 lines)

Merged
TE
11d ago
+684-8

After a restart, the acpmux daemon adopts each running agent host and reads that chat's whole log four times (remote_host_env_current, last_host_seq, open_work, then the process table), parsing every line into JSON. On big-red, 84 hosted chats hold 30 GB of logs (3.8 M records), so each restart held the daemon at 85-130% CPU for minutes: 4m30s of CPU in its first 5m20s, RSS 1.1-1.7 GB. Its 81 adoptions finished 218 s after the restart. The slowest were the largest logs: 2.4 GB took 44 s, 6.0 GB took 41 s, 4.0 GB took 24 s. Once adoption finished, the daemon dropped to about 4% CPU, all of it from the chat watcher thread, so start-up adoption is where the CPU went.

Leo: "A performance PR gives a before and after number from the same harness."

Change

  • Store::scan_heads hands each reader the record's head without parsing the line. The head is seq, at, dir, kind and the trailing hostSeq, read from the bytes the daemon wrote. The line is parsed only when the reader asks (RecordHead::record). A line in any other shape (an escaped kind, another field order, a hostSeq that isn't the last field) is parsed as before.

  • last_host_seq and remote_host_env_current parse only host_started.

  • The process table parses only the kinds it folds.

  • open_work parses only:

    • the mux kinds it folds,
    • agent requests and the answers to them,
    • records that can start a subagent,
    • every record of the log's last turn while that turn is open (scan_back finds that turn from the end).

    An earlier turn's output is passed on its head, and on these logs that output is 97% of the bytes. turn_result now clears heard_at and the open tools as well, so no state from an ended turn survives it. That changes nothing a caller reads, because those fields are only read while a turn is open.

  • Interrupted turns still resume after a daemon update. A test checks that open_work read from heads returns the same result as a parse of every record. It covers the adopted incarnation, an older incarnation and an unknown one, with the last turn open and with it closed: turn, steers, unanswered agent requests, permissions, the "allow always" grant, open tools, and a subagent's tool kept out of the turn's activity.

Before and after (same harness)

hub::hosts::hosts_tests::adoption_reads_parse_only_the_records_they_fold: 4 hosted chats Ɨ 10,226 records (72.5 MB), 50 closed turns of tool output and one open turn each. It runs the four adoption reads per chat. Run through cmux-ci test with --config profile.dev.package.acpmux.opt-level=3, 3 runs each:

lines parsedtime
before (test commit 0133a7d on base)163,616358 / 368 / 367 ms
after (this PR)50893 / 106 / 97 ms

The test fails before the fix (parsed 163616 of 40904 log lines) and passes after it. What is left of the time is reading the bytes, with no JSON parse. On big-red's logs, a script that applies the same rules to the 84 hosted chats finds that the rules leave 2.6% of the bytes (840 MB of 31.8 GB) to parse, where every byte was parsed before, four times.

Tests (cmux-ci test, Linux)

  • before: cargo test -p acpmux --lib hosts_tests → FAILED, parsed 163616 of 40904 log lines
  • after: cargo test -p acpmux --lib -- hosts_tests head_tests store:: processes → 18 passed

Risk: medium. If the read rules miss a record kind, open_work recovers less after a restart. The equivalence test covers each kind the fold reads, and any line whose head doesn't read falls back to a full parse.
Agent session: agent session

šŸ¤– Generated with Claude Code


View with [code]smith Autofix with [code]smith
Need help on this PR? Tag @codesmith-bot with what you need.