Decouple PASSIVE/TRUNCATE WAL checkpoint cadences

coordinator/cmd/drsyncd/main.go

@@ -250,9 +250,10 @@ func run(agentAddr, httpAddr, dataDir, apiTokenFile, tlsCert, tlsKey, tlsCA, smt
 	// s.mu (and therefore every agent's grant/renew/complete call) for
 	// however long that copy takes.
 	//
-	// 20s ticks, TRUNCATE only every walCheckpointTruncateEvery of them (see
-	// RunWALCheckpoint/WALCheckpoint in store.go for the full history): the
-	// original 5-minute, TRUNCATE-only interval measured a live 10-agent
+	// PASSIVE every 60s, TRUNCATE every 200s — independent cadences (see
+	// RunWALCheckpoint in store.go for why they're no longer one ticker with
+	// TRUNCATE riding every Nth PASSIVE tick, and the full history below).
+	// The original 5-minute, TRUNCATE-only interval measured a live 10-agent
 	// median WALCheckpoint hold of 33s (max 144s) — TRUNCATE needs an
 	// exclusive lock over the whole WAL to shrink the file, held under s.mu
 	// for the full copy-back duration, so every other coordinator write
@@ -266,12 +267,22 @@ func run(agentAddr, httpAddr, dataDir, apiTokenFile, tlsCert, tlsKey, tlsCA, smt
 	// content, no exclusive lock needed) with TRUNCATE only periodically
 	// (reclaims file size, but by then PASSIVE has already drained most of
 	// what it would otherwise have to copy) addresses that floor instead of
-	// just calling TRUNCATE more often. Moving checkpointing off s.mu
-	// entirely was considered and rejected: TRUNCATE's exclusive WAL lock is
-	// a SQLite-level constraint, not an app-level overcaution, so that would
-	// only trade a blocked goroutine for a SQLITE_BUSY retry loop of similar
-	// wall-clock cost. Re-measure after changing either number here.
-	go st.RunWALCheckpoint(ctx, 20*time.Second)
+	// just calling TRUNCATE more often — this got TRUNCATE's own median down
+	// to 2.95s (max 8.7s). But a 6-hour, 10-agent test at PASSIVE=20s (one
+	// ticker, TRUNCATE riding every 10th tick) found PASSIVE's own median
+	// hold (3.4s) running *higher* than TRUNCATE's — at 20s there is so
+	// little real WAL content per call that PASSIVE's hold is dominated by
+	// the same fixed per-call overhead that limited TRUNCATE before the
+	// split, just paid 9x as often. Decoupling the two cadences (this call)
+	// lets PASSIVE widen to accumulate more real backlog per call — 60s,
+	// still far more frequent than the original 5-minute baseline — without
+	// having to also widen TRUNCATE's already-working interval to do it.
+	// Moving checkpointing off s.mu entirely was considered and rejected:
+	// TRUNCATE's exclusive WAL lock is a SQLite-level constraint, not an
+	// app-level overcaution, so that would only trade a blocked goroutine for
+	// a SQLITE_BUSY retry loop of similar wall-clock cost. Re-measure after
+	// changing either number here.
+	go st.RunWALCheckpoint(ctx, 60*time.Second, 200*time.Second)
 	go pc.Run(ctx, 2*time.Second)
 	go poller.Run(ctx, time.Second)
 	// Journal durability: fsync persisted batches, then ack each agent up to its

coordinator/internal/store/store.go

@@ -1957,18 +1957,19 @@ func (s *Store) RunIncrementalVacuum(ctx context.Context, every time.Duration) {
 // hold 33s -> 4.6s) but scaled sublinearly — a 15x shorter interval only
 // bought a 7x shorter hold, which means TRUNCATE has real fixed overhead
 // (the file-truncate step plus its fsync) that does not shrink just because
-// less WAL content has accumulated. checkpointRunPassive (called every tick)
-// is the fix for that floor: PASSIVE copies WAL content back to the main db
-// file the same as TRUNCATE does, without needing TRUNCATE's exclusive
-// file-shrinking lock, so it holds s.mu only as long as the copy itself
-// takes — cheap and frequent. TRUNCATE (this method, still what
-// WALCheckpoint calls directly) then runs far less often
-// (walCheckpointTruncateEvery ticks), and by the time it does, the
-// intervening PASSIVE calls have already drained most of the WAL content, so
-// there is less left for TRUNCATE to redo and its own hold should be
-// shorter still — not just called less often, but each call doing less work.
-// See its call site in main.go for the current interval/ratio and the
-// reasoning behind them. Called on a fixed schedule (RunWALCheckpoint) now
+// less WAL content has accumulated. checkpointRunPassive (called on its own,
+// independent cadence, see RunWALCheckpoint) is the fix for that floor:
+// PASSIVE copies WAL content back to the main db file the same as TRUNCATE
+// does, without needing TRUNCATE's exclusive file-shrinking lock, so it
+// holds s.mu only as long as the copy itself takes — cheap and frequent.
+// TRUNCATE (this method, still what WALCheckpoint calls directly) then runs
+// far less often, and by the time it does, the intervening PASSIVE calls
+// have already drained most of the WAL content, so there is less left for
+// TRUNCATE to redo and its own hold should be shorter still — not just
+// called less often, but each call doing less work. See RunWALCheckpoint's
+// doc comment and its call site in main.go for the current cadences and the
+// reasoning behind them (including why the two run on independent tickers
+// rather than one coupled ratio). Called on a fixed schedule now
 // that wal_autocheckpoint is disabled at Open (see its comment there) — this
 // is what actually keeps the WAL from growing unbounded, just on a schedule
 // this process controls instead of one SQLite's internal page-count trigger
@@ -2001,37 +2002,45 @@ func (s *Store) walCheckpoint(mode, label string) error {
 	return nil
 }
 
-// walCheckpointTruncateEvery: RunWALCheckpoint runs PASSIVE on every tick and
-// promotes to TRUNCATE (which actually shrinks the WAL file on disk, see
-// WALCheckpoint's doc comment) once every this-many ticks.
-const walCheckpointTruncateEvery = 10
-
 // RunWALCheckpoint periodically checkpoints the WAL until ctx is done: a
-// cheap PASSIVE checkpoint every tick to keep WAL content continuously
-// drained, escalating to the more expensive TRUNCATE only every
-// walCheckpointTruncateEvery ticks to reclaim the file's size on disk. See
-// WALCheckpoint's doc comment for the full reasoning (this split is what
-// brought the s.mu hold time down further than shortening the interval alone
-// could) and the wal_autocheckpoint(0) comment in Open for why this exists:
-// with SQLite's own auto-checkpoint trigger disabled, nothing else keeps the
-// WAL bounded.
-func (s *Store) RunWALCheckpoint(ctx context.Context, every time.Duration) {
-	t := time.NewTicker(every)
-	defer t.Stop()
-	tick := 0
+// cheap PASSIVE checkpoint every passiveEvery to keep WAL content
+// continuously drained, escalating to the more expensive TRUNCATE every
+// truncateEvery to reclaim the file's size on disk. See WALCheckpoint's doc
+// comment for the full reasoning (this split is what brought the s.mu hold
+// time down further than shortening one shared interval alone could) and the
+// wal_autocheckpoint(0) comment in Open for why this exists: with SQLite's
+// own auto-checkpoint trigger disabled, nothing else keeps the WAL bounded.
+//
+// The two cadences are independent, not one ticker with TRUNCATE riding
+// every Nth PASSIVE tick (an earlier version did that): coupling them meant
+// widening either cadence to fix one moved the other too. That mattered live
+// — a 6-hour, 10-agent test at passiveEvery=20s/truncateEvery=200s (the
+// coupled 1-tick/10-tick version) found PASSIVE's own median hold (3.4s)
+// running *higher* than TRUNCATE's (2.95s), the opposite of what the split
+// was for. At a 20s interval PASSIVE has very little WAL content to copy
+// each call, so its hold time is dominated by fixed per-call overhead (lock
+// dispatch, the PRAGMA itself) rather than actual copy work — running it 9x
+// more often than truncateEvery was paying that fixed cost 9x without
+// letting it amortize over more real work per call, the same floor
+// TRUNCATE's own interval hit before this split existed. Decoupling lets
+// passiveEvery widen (accumulate more real backlog per call, so the fixed
+// cost matters less) independently of whatever truncateEvery is already
+// tuned to.
+func (s *Store) RunWALCheckpoint(ctx context.Context, passiveEvery, truncateEvery time.Duration) {
+	passiveT := time.NewTicker(passiveEvery)
+	defer passiveT.Stop()
+	truncateT := time.NewTicker(truncateEvery)
+	defer truncateT.Stop()
 	for {
 		select {
 		case <-ctx.Done():
 			return
-		case <-t.C:
-			tick++
-			var err error
-			if tick%walCheckpointTruncateEvery == 0 {
-				err = s.WALCheckpoint()
-			} else {
-				err = s.checkpointRunPassive()
+		case <-passiveT.C:
+			if err := s.checkpointRunPassive(); err != nil {
+				slog.Error("wal checkpoint failed", "err", err)
 			}
-			if err != nil {
+		case <-truncateT.C:
+			if err := s.WALCheckpoint(); err != nil {
 				slog.Error("wal checkpoint failed", "err", err)
 			}
 		}

coordinator/internal/store/store_test.go

@@ -2479,14 +2479,15 @@ func TestCheckpointRunPassiveDoesNotShrinkWALFile(t *testing.T) {
 	}
 }
 
-// TestRunWALCheckpointTruncatesOnlyPeriodically: RunWALCheckpoint must not
-// shrink the WAL file on every tick — only every walCheckpointTruncateEvery
-// of them (see its doc comment for why: TRUNCATE's fixed per-call overhead
-// means calling it as often as the cheap PASSIVE checkpoints would give back
-// most of what shortening the interval bought). Drives exactly
-// walCheckpointTruncateEvery-1 ticks (file must not have shrunk yet) then one
-// more (file must have shrunk by then).
-func TestRunWALCheckpointTruncatesOnlyPeriodically(t *testing.T) {
+// TestRunWALCheckpointTruncatesOnItsOwnCadence: RunWALCheckpoint's
+// PASSIVE and TRUNCATE cadences are independent tickers (not one ticker with
+// TRUNCATE riding every Nth PASSIVE tick — see its doc comment for why that
+// coupling was dropped: widening PASSIVE's interval to fix its fixed-cost
+// problem would have forced widening TRUNCATE's too). This drives
+// RunWALCheckpoint with a short PASSIVE interval and a longer TRUNCATE
+// interval, and asserts the WAL file has NOT shrunk while only PASSIVE ticks
+// have fired, then HAS shrunk once TRUNCATE's own interval has also elapsed.
+func TestRunWALCheckpointTruncatesOnItsOwnCadence(t *testing.T) {
 	path := filepath.Join(t.TempDir(), "state.db")
 	s, err := Open(path)
 	if err != nil {
@@ -2513,39 +2514,39 @@ func TestRunWALCheckpointTruncatesOnlyPeriodically(t *testing.T) {
 		t.Fatalf("WAL only %d bytes before checkpoint, too small to exercise this", before.Size())
 	}
 
-	// Drive one continuous RunWALCheckpoint (its own tick counter must not be
-	// restarted mid-test, or the Nth-tick assertion below is meaningless).
-	// The interval is generous relative to how long one checkpoint call
-	// actually takes (a few ms for 586 pages, more so for TRUNCATE) so ticks
-	// don't run behind schedule under load — this test previously flaked
-	// under -count=5 and under the full package's -race load at a tighter
-	// interval/margin.
-	const tickInterval = 150 * time.Millisecond
+	// PASSIVE fast enough to fire several times before TRUNCATE's own
+	// interval elapses; both generous relative to how long one checkpoint
+	// call actually takes (a few ms for 586 pages) so ticks don't run behind
+	// schedule under load — an earlier, tighter-margin version of this test
+	// flaked under -count=N and under the full package's -race load.
+	const passiveEvery = 50 * time.Millisecond
+	const truncateEvery = 400 * time.Millisecond
 	ctx, cancel := context.WithCancel(context.Background())
 	defer cancel()
-	go s.RunWALCheckpoint(ctx, tickInterval)
+	go s.RunWALCheckpoint(ctx, passiveEvery, truncateEvery)
 
-	// Sample just before the Nth tick would fire: must still be PASSIVE-only.
-	time.Sleep(time.Duration(walCheckpointTruncateEvery-1) * tickInterval)
+	// Sample partway to truncateEvery: several PASSIVE ticks have fired, but
+	// TRUNCATE's own interval has not elapsed yet.
+	time.Sleep(truncateEvery - passiveEvery)
 	mid, err := os.Stat(walPath)
 	if err != nil {
 		t.Fatal(err)
 	}
 	if mid.Size() < before.Size() {
-		t.Fatalf("WAL file already shrunk before tick %d (%d -> %d bytes): "+
-			"TRUNCATE fired too early", walCheckpointTruncateEvery, before.Size(), mid.Size())
+		t.Fatalf("WAL file already shrunk before TRUNCATE's own interval elapsed "+
+			"(%d -> %d bytes)", before.Size(), mid.Size())
 	}
 
-	// Generous margin past the Nth tick, not a tight window right after it.
-	time.Sleep(3 * tickInterval)
+	// Generous margin past truncateEvery, not a tight window right after it.
+	time.Sleep(3 * truncateEvery)
 	cancel()
 	after, err := os.Stat(walPath)
 	if err != nil {
 		t.Fatal(err)
 	}
 	if after.Size() >= mid.Size() {
-		t.Fatalf("WAL file did not shrink by tick %d (%d bytes): "+
-			"TRUNCATE should have fired by now", walCheckpointTruncateEvery, after.Size())
+		t.Fatalf("WAL file did not shrink once TRUNCATE's interval elapsed (%d bytes): "+
+			"TRUNCATE should have fired by now", after.Size())
 	}
 }
 
@@ -2559,7 +2560,7 @@ func TestRunWALCheckpointStopsOnContextCancel(t *testing.T) {
 	ctx, cancel := context.WithCancel(context.Background())
 	done := make(chan struct{})
 	go func() {
-		s.RunWALCheckpoint(ctx, time.Millisecond)
+		s.RunWALCheckpoint(ctx, time.Millisecond, time.Millisecond)
 		close(done)
 	}()
 	cancel()

docs/DESIGN-coordinator.md

@@ -319,13 +319,32 @@ journal_cursors (pass_id, agent_id, acked_seq)      -- JournalBatch flow control
   WAL content back to the main db file, same as TRUNCATE, but needs no exclusive
   file-shrinking lock, so its `s.mu` hold is only as long as the copy itself) and a
   `TRUNCATE` checkpoint (still what `Store.WALCheckpoint` calls directly — existing
-  callers and tests are unaffected) only every `walCheckpointTruncateEvery` (10)
-  ticks, to reclaim the file's size on disk. By the time TRUNCATE runs, the
-  intervening PASSIVE calls have already drained most of what it would otherwise
-  have to copy, so its own hold should be shorter too, not just less frequent —
-  this is the fix for the fixed-cost floor the interval alone couldn't reach.
+  callers and tests are unaffected), to reclaim the file's size on disk. By the time
+  TRUNCATE runs, the intervening PASSIVE calls have already drained most of what it
+  would otherwise have to copy, so its own hold should be shorter too, not just less
+  frequent — this is the fix for the fixed-cost floor the interval alone couldn't
+  reach. And it worked on that axis: TRUNCATE's own median hold dropped further, to
+  2.95s (max 8.7s), in a 6-hour, 10-agent re-test.
+  That same re-test surfaced a second-order effect the first version of the split
+  (one ticker, TRUNCATE riding every 10th PASSIVE tick) hadn't accounted for:
+  PASSIVE's own median hold (3.4s, 377 calls) came back *higher* than TRUNCATE's
+  (2.95s, 41 calls) — backwards from what the split was for, since PASSIVE needs no
+  exclusive lock at all. At a 20s PASSIVE interval there is very little real WAL
+  content to copy each call, so PASSIVE's hold is dominated by the same *fixed*
+  per-call overhead (lock dispatch, the `PRAGMA` itself) that limited TRUNCATE
+  before this split existed — just paid 9x as often as necessary, since the coupled
+  ticker forced PASSIVE's cadence to be exactly `truncateEvery`'s cadence divided by
+  the ratio. `RunWALCheckpoint` now runs PASSIVE and TRUNCATE on two independent
+  tickers (`passiveEvery`, `truncateEvery`) instead of one ticker with a tick-count
+  ratio, specifically so each cadence can be tuned without moving the other: PASSIVE
+  widened to 60s (accumulates more real backlog per call, amortizing its fixed cost
+  better) while TRUNCATE's already-working ~200s cadence is left alone.
   `TestCheckpointRunPassiveDoesNotShrinkWALFile` and
-  `TestRunWALCheckpointTruncatesOnlyPeriodically` pin the split.
+  `TestRunWALCheckpointTruncatesOnItsOwnCadence` pin the split and its independence.
+  The general lesson, consistent with every other `s.mu` finding in this file: two
+  competing costs (call frequency vs. per-call fixed overhead) rarely share one
+  optimal knob, and coupling them to save a line of code cost a real regression that
+  only a live re-measurement caught — re-measure again if either number here moves.
 - **Indexing discipline for high-write tables:** every predicate a hot-path query
   filters or joins on needs an index that actually serves it — not just "an index
   exists on the table." A single-writer store makes this load-bearing in a way a