acpmux: the event log through one append-only journal, behind store.journal (R-DURABILITY S2)
Summary
Stage 2 of the R-DURABILITY rewrite (design: handoff/rewrites/R-DURABILITY/DESIGN.md 3.3, 3.3a, 3.3b and 3.3c). It needs #33919 (the cmux-journal crate), merged into feat-cmux-next as da881c3b3c1.
Today no acpmux event-log append is synced. A line a client was told about (a queue edit, a permission decision, prompt_accepted, a status) reaches the disk only at the next flush, which runs at shutdown. So an OS crash or a power loss takes back every line since the daemon started its last flush (DESIGN E12). With store.journal on, each line goes to the chat's events/*.ndjson as before and then one record with the same line goes to <home>/journal/ (group commit, one sync per batch; a power loss takes back at most the last second, always a suffix). Readers, segment files and every file format stay as they are.
The switch store.journal is off by default. With it off, nothing changes, except that a journal left by a run with it on is first written into the logs (below).
What changes
cmux-journal:Journal::retire_through(lsn), the crate's one delete: it removes the journal segments that hold no record after the caller's compaction point (tests: a crash, process, OS or power loss, at every storage operation of a retirement).Journal::check_append(len): whether an append would be refused now (closed, behind), asked before the caller writes anything else.acpmux/src/store/journal_store.rs(new),JournalStoreoverLocalStore:- append: under one lock,
check_append, the line to the chat's log, then the record. So every record's line went to the log, and a refused line is never journaled. A log line may lack its record (a crash between the two, a record still in memory at a kill). Agent stream lines (insession/update,claude.*,codex.*) areStreamrecords, every other line isAck. - checkpoint (
<home>/journal-projected.json): every 30 s while the journal grew, past 64 MiB of it, atflush(shutdown) and before a retention commit. It syncs every log written since and the sessions folder, writes an LSN at or before the journal's durable end (temporary file, sync, rename, folder sync, every error checked), then retires the journal before it. A failed fsync (in it, at a log's close, or inflush_session) freezes it: it then returns an error (a retention commit does not go ahead), and the store asks the daemon to stop with a restart (Store::stop_reason, a select branch indaemon.rs), whose replay writes the logs again. Ten failed checkpoints in a row ask the same. So the journal past the checkpoint stays bounded. - recovery at open repairs each chat's log with its records after the checkpoint and never deletes a whole line or a folder: the log's lines and the journal's merge by
seq(a line in both must be equal; a line only the log has stays; a line only the journal has goes in its place); only bytes that do not parse as a whole JSON line (a torn tail, a hole of zeros, a line a hole ran into a later one) are dropped. Every merged line is written again from the repair start, so the first checkpoint after a restart syncs bytes this process wrote (a killed daemon's writes may be in the page cache only; a failed sync's dropped pages still read back). The lines only the log holds from there are journaled and made durable before the cut, so a crash inside the repair loses no line. A chat whose folder is gone is not written again. A log that moved on without the journal (a line in both that differs, lines out of order: a run with the switch off or an older build after a crash) is left as it is, and the journal's lines go to<home>/journal-unapplied/, as do the lines of a chat whose log cannot be read or written; the open goes on. - delete: a
forgetrecord under the lock (the replay then drops the chat's earlier journaled lines), then the folder's removal off the lock, with no wait. - seal: the logs refuse writes and the journal syncs fully; the shutdown's
flushthen checkpoints. - The journal's files go through
FencedStorage, which refuses writes under a lost home (config::refuse_lost_home). An unreadable checkpoint fails the open. The open waits up to 5 s for the journal lock (a restart overlaps the old daemon's exit). Crashed checkpoint temporaries are removed.
- append: under one lock,
store::openwith the switch off: a journal a run with it on left is replayed, checkpointed and retired first (journal_store::catch_up), so a crash with the switch on and a start with it off keep every acknowledged line.LocalStore:appendis serialize +append_line;sync_log; a failed fsync is aSyncFailederror; a failed sync at a log's close is noted.MemoryStoreand the store settings move tostore/memory.rsandconfig/store_config.rs(a pure move, so the over-limitstore.rsandconfig.rsdo not grow). README listsstore.journal.
Review fixes (independent review FIX at ab0e9535d9da, comment 6624439824)
| finding | fix | regression test (red on the code before the fix) |
|---|---|---|
| 1a the replay's cut deleted lines written with the switch off after a crash | recovery merges and repairs, never rebuilds; the switch-off start replays a left journal first | lines_written_with_the_switch_off_survive_turning_it_on_again, switching_off_after_a_crash_keeps_every_acknowledged_line |
| 1b a kill while the writer syncs: lines in the log, records in memory, cut by the replay | same | a_kill_while_the_journal_syncs_keeps_the_lines_the_log_got |
1c lines flush_session synced whose records an OS crash took back | same | a_line_flush_session_made_durable_survives_losing_its_record |
| 1, a hole: lines only the log holds after a hole of zeros, also through a crash in the repair | they are journaled and durable before the cut | an_os_crash_hole_is_repaired_and_the_lines_after_it_kept, a_crash_inside_a_repair_loses_no_line |
| 2 the replay deleted a folder a rename put back | the replay never deletes a folder | a_folder_put_back_after_a_delete_is_not_deleted_by_the_replay |
| 3 a kill in a delete wrote the chat's last lines back into a new folder | the replay never makes a missing folder again | a_kill_in_a_delete_leaves_the_chat_whole_or_gone |
| 4 delete removed the folder under the appends' lock and waited up to 5 s on a Tokio worker | removal off the lock, no wait | a_delete_does_not_wait_for_the_journal_sync |
| 5 a failed sync in a checkpoint did not freeze it; no bound when it keeps failing | freeze on a failed fsync, stop for a restart; ten failures in a row stop too | a_failed_log_sync_freezes_the_checkpoint, a_checkpoint_that_keeps_failing_asks_the_daemon_to_stop |
| 6 one chat's folder error failed the open (every restart) | that chat's lines go to journal-unapplied/, the open goes on | one_chat_that_cannot_be_repaired_does_not_stop_the_open |
| 7 the journal wrote past the lost-home fence | FencedStorage | the_journal_storage_refuses_a_lost_home |
nit: Ahead after a normal crash | the checkpoint is never past the durable end | a_crash_right_after_a_checkpoint_reports_no_damage |
| nit: an unreadable checkpoint read as LSN 0 | the open fails | an_unreadable_checkpoint_fails_the_open |
| nit: the lock race at restart | the open waits up to 5 s | the_open_waits_for_the_previous_daemon_to_let_go_of_the_journal |
| nit: crashed checkpoint temporaries stayed | removed at open | a_crashed_checkpoint_temporary_is_removed_at_open |
nit: a lost cancel record wrote a refused line again | log first, then the record: no cancel | a_line_the_log_refused_is_never_written_later (kept) |
nits: kind-index copy order, damage never cleared, frozen checkpoint returned Ok, on_written unused, README | copy removed before the cut; damage cleared after the next checkpoint; frozen returns an error; on_written removed; README entry | (by reading; the frozen error is in the freeze test) |
check_append has its own test in the crate: check_append_says_what_append_would_do.
Review 2 fixes (independent review FIX at dcfecade4df, comment 6629184957)
The logs' OS crash model in the tests now follows the syncs that ran (store/sync_model.rs, tests only): a segment keeps its length at its last sync that counts; a failed sync loses what was written since the one before, and a later sync does not bring it back; a cut ends a loss it removes. Every log segment sync goes through log_sync::sync_segment.
| finding | fix | regression test (red on the code before the fix) |
|---|---|---|
| 1a after a kill, the restart's first checkpoint retired records whose log lines were in the page cache only | the repair writes every merged line again from the repair start; the checkpoint then syncs bytes this process wrote | an_os_crash_after_a_restart_from_a_kill_keeps_every_acked_line |
| 1b after a failed sync, the restart read the dropped pages back, wrote nothing, and its checkpoint retired the records | same | an_os_crash_after_a_restart_from_a_failed_sync_keeps_every_acked_line |
| 2 a hole that starts inside a line made the repair leave the whole log as it was | a piece is a line only when it parses as one JSON value (piece_seq) | a_hole_that_starts_inside_a_line_is_repaired (the reviewer's test) |
3 a failed sync in flush_session did not freeze the checkpoint | its file sync is a SyncFailed; the journal store freezes on it | a_failed_sync_in_flush_session_freezes_the_checkpoint |
nit: no sync of events/ between a cut's removals and the lines written again | cut_at syncs events/ after its removals, and the kind-index folder after its copies go | (by reading) |
| nit: DESIGN.md said 256 MiB, the code stops after ten failures | DESIGN.md 3.3c says ten failures in a row | (text) |
| nit: with the switch on, a line over 64 MiB is refused | the README says it | (text) |
Found by the S2c A/B, fixed here: the hub's tap logs an ACP session/update under its sessionUpdate kind, so agent chunks were Ack records (a sync each). The record's method now says Stream (an_agent_chunk_is_a_stream_record; red a43e979ae39, fleet 2b6becd0; green ce8dcba5458, fleet 409c5cfa).
Risk: high
- It adds deletes of user data, behind the default-off switch: the journal's
retire_through(journal segments that a synced checkpoint covers), and the repair's cut of a chat's log, which removes only bytes that do not read and lines it writes back, after every line only the log held is durable in the journal. - Rollback: turn
store.journaloff. The next start writes the journal's lines into the logs first, then runs as today. An older build that does not know the journal reads the logs as they are; if it ran after a crash with the switch on, it misses at most the lines since the last checkpoint (30 s), and turning the switch on again later keeps every line that build wrote (a log that moved on is left as it is; the journal's lines go tojournal-unapplied/).
Known gaps
- Replies and events do not wait for their records to be durable yet: a client can be told about a line that a crash then takes back. S2c (the next PR, stacked on this one) holds each reply and acknowledged event until its record is durable.
- A change the hub makes in memory before its record is appended can be seen before the record exists: a rename sets the chat's name, then appends
renamed, so another connection's reply (a session list) can show the new name in that window, and a crash in it loses the rename that the reply showed. S2c's wait does not close it, because the reply can be built before the record is appended. S3 (chat metadata through the journal, due 2026-11-05 18:00Z) appends the metadata image under the chat's meta lock with the change, which closes it. - The daemon does not stop when the journal's writer ends (a panic on its thread); appends then fail and are logged. S2c makes the daemon stop for a restart.
- The journal writer thread keeps the process's utility I/O policy. S2c measures acknowledged-reply latency under disk stress with and without it first (lead rule: a reply the person waits for never waits on a throttled sync).
Testing
acpmux store::journal_store_tests (the journal on the simulated file system cmux_journal::SimStorage; the chat logs are real files, and an OS crash of them follows the syncs that ran, store/sync_model.rs), 28 tests: the 6 below, the 17 regressions of review 1, the 4 of review 2 and the Stream class test.
a_line_the_store_says_is_durable_survives_an_os_crash,a_kill_keeps_every_line_once,a_deleted_chat_stays_deleted_after_a_crash,a_line_the_log_refused_is_never_written_later,a_line_after_the_seal_is_refused_and_never_written_later,a_chat_made_again_after_its_delete_keeps_its_files_through_a_replay.
cmux-journal: the retirement tests and check_append_says_what_append_would_do.
Red on the code before each fix:
-
First round, red on
LocalStore(53e933431e0): fleet a736b8cd (hq run 41773493313):a_line_the_store_says_is_durable_survives_an_os_crashfailed (lines 2..20 lost), in the full run and alone. At00512a295dea: fleet dc9dde1c (hq run 41780243300):a_chat_made_again_after_its_delete_keeps_its_files_through_a_replayfailed (None, wantedSome("again")). -
Review regressions at
e030f4fe402e: 17 of 17 new tests fail, each also alone, the 6 earlier ones pass: owned Mac aws-m4pro-4 fleet d8e7037d, Linux fleet 1c22175e (hq run 41791487676); the crate'scheck_appendtest: fleet 63604b26 (hq run 41791488139). The failures name the findings: the switch-off lines gone ([1..5], wanted[1..9]), a kill lost line 4,flush_session's line 3 gone, the put-back chat deleted ([]), a deleted chat back in part ([2]), the delete waited 5.0 s, the hole's last line gone ([1..9]), the open failed on chat-b's link,Ahead { journal_end: 1, from: 3 }, the lock not waited for, and so on. -
The freeze test as it is now (it fails the log sync itself,
8b71b4f7a690): fleet 4addcf1e (hq run 41794281768):a_failed_log_sync_freezes_the_checkpointfailed ("a checkpoint after a failed sync went ahead"), also alone. -
Review 2 regressions at
d2c63860ece(red): owned Mac aws-m4pro-7, fleet bec8251c, and Linux, fleet 17755e95 (hq run 41825080459): the 4 new tests fail, each also alone, the other 24 pass. 1a and 1b give[1](wanted[1..5]), 2 gives[1, 2, 3, 4, 5, 9](wanted[1..9]), 3 "a checkpoint after a failed sync in flush_session went ahead". -
The Stream class test at
a43e979ae39(red): fleet 2b6becd0, the agent chunk read back asAck.
Green at the head 3273b2ade1f81deb90a9367229ffb85040af4d6a (feat-cmux-next merged twice with scripts/merge-main.sh: 3b245c15615 merges b43ce2b4ae2, with one conflict in daemon.rs's module list, feat's term_sender from #35147 and S2's stop_causes, both kept; 3273b2ade1f merges d3d5a6246ab cleanly):
- fleet 22f1a1fe (Linux, hq run 41832790237):
all store::: fmt, clippy and 317 of 317 tests pass. - fleet b65e73b6 (Linux) and 8cdb6cd0 (owned Mac aws-m4pro-7):
journal_store_tests28 of 28. - fleet 8196015c (owned Mac aws-m4pro-6):
daemon821 of 822; the one failure is the base redacpmux_daemon_idle_has_no_periodic_wakeups(below).
Green at the previous head 84f9c266975af5eec7216f751ea055e279ba7467 (the head the review 3 SHIP names):
- fleet a380f52d (owned Mac):
journal_store_tests28 of 28. fleet 490a1dae (Linux, hq run 41826018179): 28 of 28. - fleet 9b3ba15b (Linux, hq run 41826017850):
all store::: fmt pass, tests 316 of 316 (filterstore::); clippy red only atcmux-tui/crates/cmux-tui/tests/link_push_bench.rs:59(type_complexity), the base red from #34538. - fleet 9b985930 (owned Mac):
daemontests 810 of 812.acpmux_daemon_idle_has_no_periodic_wakeupsfails the same way on the merge based422b94b60dalone (fleet 6c027917: an idle daemon woke 8, 3 and 4 times per 10 s window): a base red.router_exits_when_its_daemon_is_killedfailed once in the full run (set_read_timeoutEINVAL attests/router_lifetime.rs:248, the router had already closed the socket) and passed on its rerun; it passes alone on the base too (fleet bfb4e48d): a timing flake, not this PR.
Green at the previous head dcfecade4df4421713ec773e0255ccde78d28cf3 (the review fix merged with feat-cmux-next d422b94b60d, which holds #33919 as da881c3b3c1; the cmux-journal files conflicted only as add/add, and feat's copy equals the S1 head 51cfdee876b):
- fleet 89e53e31 (hq run 41800044755):
all store: fmt green, tests 616 of 616 passed. Its only red step is clippy atcmux-tui/crates/cmux-tui/tests/link_push_bench.rs:59(type_complexity): a base red from #34538 (586595362c2), a file this PR does not touch; S2c's server step (335b7dac) has the same single red. - fleet 64fc71c9 (owned Mac aws-m4pro-7):
journal_store_tests23 of 23,cmux-tui-rust-check: green. - fleet 74864ef6: panic ratchet green; no hit names a file of this PR, and
cmux-journalhas no line. - fleet 104f7e6b:
daemontests 815 of 816. The one failure,a_daemon_whose_home_is_removed_stops(ENOTEMPTY when the test removes the daemon's home), fails the same way on featd422b94b60dalone (fleet e0522147, hq run 41803060724): a base red, owned by BASE RED ACPMUX (a bisect of3a436460eaa1..d422b94b60d); this PR does not touch it. It passed at this branch before the feat merge (fleet 5f5c5b49, hq run 41796145764). - Before the merge, at
7a8bbdce62c: fleet 6798b9c1 (hq run 41798793202)all storegreen (fmt, clippy, 592 of 592); at92b52bfe6f0: fleet 92e85362cmux_journal_testsand ed455835 crash sim green (the crate did not change since).
Observed / Not run
- Observed: the fleet steps above (Linux: Blacksmith 8-vCPU Ubuntu 24.04; macOS: owned Macs aws-m4pro-*).
- Not run: the whole acpmux test suite (the
storeanddaemonfilters run the store's, the hub's store and the daemon's tests; the PR's CI runs the rest), and a daemon withstore.journalon (no dogfood yet: the switch is off by default). The daemon's stop branch (store_asks_to_stop) has no daemon-level test; the store's side (stop_reasonset on a freeze and after ten failures) has. - Panic ratchet: green at the merged head (the base red
acpmux: clippy::indexing_slicing 703 > 686was fixed on feat by #34735 and #34941, which this branch now has).
Changelog
none
Proof
No capture: a daemon storage change behind a default-off setting, with no UI.
Review receipt
Review (r-durability-s2-merge-reviewer): SHIP at 3273b2ade1f81deb90a9367229ffb85040af4d6a (comment 6632437161): the merge resolution at this head. Review 3 (r-durability-s2-reviewer): SHIP at 84f9c266975af5eec7216f751ea055e279ba7467 (comment 6630992897): the code before the merges. Non-green checks at this head are base findings (comment 6632519884). Its non-blocking follow-ups go in their own PRs: a repair that fails after it changed a log keeps its chat's records past the checkpoint; a hole that ends at a line start; the open's sync cost per replayed chat, measured against the start budget; the idle checkpointer's 30 s wake.