PR #35562 - manaflow-ai/cmux

Summary

Follow-ups from the third independent review of #34901 (S2, landed as 6ad43f5d1bb; comment 6630992897), for the acpmux event journal behind store.journal (default off). Stacked on #35483 (S3a).

A chat whose repair fails is repaired at a later start. When a chat's log cannot be read or written at the open (a link, a permission error, EIO), its lines go to its repair file journal-unapplied/<id>.<lsn>.repair.ndjson (a header line with the chat's id, then the lines; owner-only, synced). The next open journals them again, waits until they are durable, removes the file, and repairs the chat with them as with any journaled line. The checkpoint of every chat goes on. A delete removes its chat's repair file, so a chat made again under the same id gets none of the old lines. Before S2's follow-ups the open's checkpoint retired those records and no later start put the lines back; this PR's first head held the global checkpoint instead, which the review of this PR rejected (below).
A hole that ends at a line start keeps that line. A piece of a log is split at its last zero byte (a whole JSON line holds none), so after a torn line and zeros, the whole line that follows is read. Before, it was read as part of the torn piece and dropped; it mattered for a line only the log holds.
An idle checkpointer sleeps (cmux-ad m9, idle wakeups). With nothing to checkpoint, the checkpointer waits until a change wakes it (Inner::touched: one atomic read per append), then checkpoints one period later. Before, it woke every 30 s. Each of its two waits ends only on the state its waker sets (the period wait: the period, wanted or stop), never on a bare notify (5279af4bbf7; section below).

The review's fourth follow-up (the open's syncs per replayed chat against the 8 s start budget) is in the recovery-syncs PR stacked on #35565.

Review of 49d7e5cef83 (comment 6638710718): what changed

F1 (a checkpoint below the hold wrote non-durable metadata images), F2 (the hold kept every chat's replay window: a start with the switch off replayed it again; a retention rewrite came undone) and F3 (the journal grew with each restart): the hold is gone (Order::held, HOLD_MAX_BYTES, target()); the repair file above keeps only the broken chat's lines. The checkpoint takes order.applied again, so F1 also goes.
F4 (process-global test seams): closed by edca3b4823d (the seams by the store's home), in the section below.
Merge 75550bae7ad: the S3a fix 0d246364d90 (with S2c's head and feat). Its two conflicts (journal_store.rs, journal_store_tests.rs) were code both sides added at the same place; both kept.

Testing

acpmux store::journal_store_tests and store::journal_meta_tests:

a_chat_whose_repair_failed_is_repaired_at_the_next_start
a_hole_that_ends_at_a_line_start_keeps_that_line
an_idle_store_does_not_wake_its_checkpointer
a_change_seen_by_the_idle_checkpointers_second_look_waits_one_period (section below)
the review of 49d7e5cef83: a_failed_repair_does_not_hold_the_checkpoint_of_other_chats, a_retention_rewrite_after_a_failed_repair_stays_after_a_restart, a_checkpoint_after_a_failed_repair_writes_only_durable_images (the reviewer's test, renamed); guards a_start_with_the_switch_off_after_a_failed_repair_keeps_a_rename_made_with_it_off, a_start_with_the_switch_off_after_a_failed_repair_keeps_a_chat_deleted_with_it_off (the reviewer's two; green since the S3a fix: its stamp rule and no folder remake), a_chat_deleted_after_its_failed_repair_does_not_get_its_old_lines

Test seams only: the checkpointer's period, wake count and two holds, by the store's home (checkpointer_seams).

Red at d147057bf85 (the first tests on S3a), owned Mac aws-m4pro-7, fleet 835dac86: the 3 fail for their reasons ("the open's checkpoint retired the records of a chat it could not repair": [1], wanted [1, 2, 3]; "a line after a hole that ends at its start was dropped": [1..7], wanted [1..8]; "an idle checkpointer woke 23 times in 500 ms (period 20 ms)"); the other 28 pass.

Red at 23870301064 (the review's tests on the merge 75550bae7ad): the 3 fail for their reasons, in the full run and alone; the 3 guards pass; 339 of 342:

macOS: fleet a8be0684 (owned Mac). Linux: fleet 97d6cbc1 (hq run 41896101617).
"the checkpoint stayed at 1 below chat-a's records (the journal ends at 5)"; "the checkpoint wrote an image to session.json before its record was durable"; "the open kept a copy of a rewritten log aside: [chat-b.2.ndjson, chat-a.3.ndjson]".

Green at the head dbd1e79737adfb5be0745c464498c789bb42d294 (the fix 3b7007c175d plus merges: the S3a head fc83b326fba with its N1 fix, and feat 7427100d5d0; the one conflict, journal_meta_tests.rs, was tests both sides added at the end, both kept):

macOS: fleet 3ca759ef (owned Mac aws-m4pro-4), journal_ 350 of 350.
Linux: fleet 384cca10 (hq run 41907480494), all store::: fmt, clippy and 351 of 351 tests (acpmux 153, cmux-tui 41, cmux-tui-core 154, cmux-worktree-care 3).

Green at 3b7007c175d (the fix alone):

macOS: fleet 7c640389 (owned Mac), journal_ 342 of 342; fleet df5f16f3 (owned Mac), durable_gate 4 of 4.
Linux: fleet 8731e052 (hq run 41897058021), all store::: clippy pass, tests 347 of 347 (acpmux 150, cmux-tui 40, cmux-tui-core 154, cmux-worktree-care 3). fmt red only on 5 files this PR does not change (cmux-app-manifest/tests/customize_example.rs, cmux-tui/src/link/sync_cli.rs, cmux-tui/src/link/sync_cli/store.rs, cmux-tui-core/src/apps/grants.rs, cmux-tui-core/src/lib.rs), each the same as on feat a0d32a7b4e8: a base finding, fixed by #35845 (merged as 7dd3f2e99015) and by cf49e02fcfc for the first file. Feat 7427100d5d0 is merged in since; fmt at f2694125d59: fleet b023b875, green.

Earlier green at 49d7e5cef83: fleet 1bc4a394 (owned Mac aws-m4pro-6), journal_ 325 of 325; fleet 8d153f12 (Linux, hq run 41844883811), all store:: 329 of 329.

Observed / Not run

Observed: the fleet steps above, each log read.
Not run: the daemon-level idle test (acpmux_daemon_idle_has_no_periodic_wakeups) with the switch on; it is a base red with the switch off (an idle daemon wakes 3-8 times per 10 s window on feat, STATUS 11873), owned by cmux-ad m9. A repair file left by a chat that is never repaired stays in journal-unapplied/ and is journaled again at each open (its own lines only, bounded by that chat); no test runs many opens of it.

The idle checkpointer's period (after fleet 0577ac62)

Found: a_failed_log_sync_freezes_the_checkpoint failed once in the full store:: run of fleet 0577ac62 (Linux, at b80145ec8a6, which holds this PR) and passed alone. The cause is in this PR's idle checkpointer. The checkpointer marks itself idle under the timer lock, then looks for work a second time. A change in that window takes the idle flag in touched and notifies when it gets the timer lock. The change shows in the second look, so the checkpointer is in its period wait by then, and the notify ended that wait at once: a checkpoint ran right away on the checkpointer's thread (a burst no longer shared one, and a spurious wakeup could do the same). In that test, such a checkpoint took line 2 and synced its log on the checkpointer's thread, where the thread-local FAIL_NEXT_LOG_SYNC is not set. The test's own flush then had nothing to do and returned Ok. The review's P3 note ("a change between the flag and the second look ends the following period wait at once") is the same defect.
Fix, 5279af4bbf7: the period wait ends only on the period, wanted or stop (wait_timeout_while). Each of the two waits ends only on the state its waker sets before it notifies under the timer lock. No sleep, no retry; the idle wait is unchanged.
Test, edca3b4823d: a_change_seen_by_the_idle_checkpointers_second_look_waits_one_period holds the checkpointer right after it marked itself idle, and the change's touched right after it took the flag, so the order is exact. It then asserts no checkpoint within 300 ms (the period is 30 s). The checkpointer's test seams are now by the store's home, which also closes review F4 (the process-global CHECKPOINTER_WAKES and TEST_CHECKPOINT_EVERY_MS, and the 20 ms period that was never reset).
Red at edca3b4823d: fleet 2a4e1be8 (Linux, hq run 41883989267) and 931a2cea (owned Mac aws-m4pro-6). Both fail in the full run and alone, at the test's own assertion: "the change's notify ended the checkpointer's period: a checkpoint ran at once" (left 1, right 0).
Green at 5279af4bbf7, the new test seen passing in each log:
- fleet 6ec6941e (Linux, hq run 41884555723): store:: 330 of 330;
- fleet 19cb9d1e (owned Mac aws-m4pro-9): journal_ 326 of 326;
- fleet 17ed5bf8 (owned Mac aws-m4pro-7): a_failed_log_sync_stops_the_daemon_for_a_restart 1 of 1, the daemon-level test with a 200 ms period.
50 runs alone, on Linux: a scratch test runs the body of a_failed_log_sync_freezes_the_checkpoint 50 times in one process and counts the failures (branches fix/r-durability-race-x50-*-nomerge, not for merge).

Commit	What it is	Failed of 50	Fleet
`b80145ec8a6`	the open-time head (on #35565)	0	4d3b3582 (hq run 41884984537)
`71d7e096cba`	its base, the head of #35565 (S3b)	1 (run 18: "the checkpoint went on past a failed log sync", as in 0577ac62)	93116d38 (hq run 41884984448)
`5279af4bbf7`	this fix	0	5629e7ef (hq run 41884984816)

#35565 changes only hub/ over 49d7e5cef83, so its 1 of 50 is this race. The fix reaches #35565 and the open-time branch when this branch is merged down.

Observed / Not run (this section)

Observed: the fleet steps above, read in their logs.
Not run: the 50 runs on macOS, and the journal tests under plain cargo test (one process for many tests; the fleet runs nextest, one process per test).

Delta review of dbd1e79737a: what changed (D1 to D4)

Red tests first in c0a20e09f1f; the fix in 1703e2f754e.

D1 (P2): the open took a repair file even when the chat's folder was not there. For example, a transfer held the folder aside at a kill, and the hub put it back after the store's open. The lines then went nowhere. Now the file's header names the folder's identity (the FolderId that S3a binds metadata images to), and take_repairs journals a file only when the folder at the chat's path has that identity. Otherwise the file stays: a later open applies it when that folder is back, and if the folder never comes back, the file is kept for a person to handle.
D2 (P3): kept files are written whole: a temporary copy, synced, renamed, then the folder synced. The open removes a temporary that a crash left. Bytes in a repair file that do not make a whole JSON line are passed over.
D3 (P3): delete keeps the chat's repair-file entry until the file is removed. So a delete that is tried again after a failed folder removal still removes the file (test seam FAIL_NEXT_FOLDER_REMOVAL).
D4 (P3): when the journal's queue is full, the open's repair appends wait for the writer (append_waiting). So a repair file larger than max_pending_bytes is applied. journal_lines uses the same path.
Red at c0a20e09f1f: macOS fleet 54945ca4. 5 of the 41 journal_store_tests fail, each for its own reason.
1a72d28729b: a clippy fix (unused_doc_comments). The delete test seam goes before the doc comment of PAUSE_AFTER_LOG_WRITE, not between that comment and its item.
7b8806c2d2d merges feat de5a69e786a, which contains S3a #35483 as 00655a40430. The merge resolved conflicts in 4 files by keeping this branch's copies, because feat's copies are the S3a head fc83b326fba, which this branch has with its own changes on top. fc6580356a9 merges feat ef400020f122 with no conflict.
Green at fc6580356a9: macOS journal_ (fleet a09a1ce6), and Linux store:: with fmt and clippy (fleet b8b715d8).

Changelog

none

Proof

No capture: a daemon storage change behind a default-off setting, with no UI.

^{Open in [code]smith · Need help on this PR? Tag @codesmith-bot with what you need.}

Summary by cubic

Addresses three follow-ups from the review of the acpmux event journal behind store.journal (default off).

A chat whose repair fails at the open keeps its journaled records until a later start repairs it again: the checkpoint stays below the chat's first journaled LSN. The hold drops past 256 MiB of journal after it, with an error logged.
A log piece now splits at its last zero byte, so a hole that ends exactly at a line start no longer drops the whole line that follows it.
The checkpointer now sleeps while idle and wakes on the next change (one atomic read per append), checkpointing one period later rather than every 30 seconds.

Adds three tests covering these behaviors to acpmux's store::journal_store_tests.