Repository navigation
fix(rusqlite-runtime): checkpoint WAL pressure with RESTART - #4097
Merged
Merged
Conversation
|
ScriptedAlchemy
enabled auto-merge
October 16, 2026 07:31
ScriptedAlchemy
disabled auto-merge
October 16, 2026 08:52
7 tasks done
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Live diagnosis
The live daemon (PID 2717644, 1.0.0-beta.82+8e75836b0, up since 2026-10-12) reported the
project_sessionsshard forproj_a5b3d7e3ebe14ca7with checkpointoutcome: pending,hard_retry_wakes: 245264,wal_bytes: 229797152(soft 33554432, hard 268435456),queue_wait_micros: 10663828920andblockers: [].Reading the WAL index header from the daemon's own
sessions.db-shmmapping through/proc/2717644/memshowed the cause. Over a 10-minute sample (06:52 to 07:02 UTC), the log never restarted:mxFramerose monotonically from 56123 to 56480 frames (56480 x 4120 B = 233 MB, matching the telemetrywal_bytes).nBackfillalways trailedmxFrameby exactly one commit (for example 56065/56049, then 56128/56123)./proc/locksshowed shared locks on shm bytes 125 and 126 in every 1 s sample.The checkpoint itself was not stuck. Every frame up to the previous commit was copied back, but SQLite restarts the log only when no reader holds a WAL read slot at the moment a write begins. The writer only ever ran
PASSIVE, andPASSIVEnever restarts the log. Under overlapping reads, the log therefore ratchets toward the hard limit. Around 07:05 a quiet moment let the restart through (mxFrame758 at 07:23, andjournal_size_limitcut the file back to 32 MiB). No restart or repair was involved.Root cause
When the log does cross the hard limit, the drain stops the writer and retries
PASSIVEevery 100 ms. A health-lane reader, or one admitted between the commit and the drain, starts at the newest frame. That reader never blocks the backfill, soPASSIVEreports complete, and the drain lifts. The reader still holds its read slot, so the next write cannot restart the log. That write appends past the hard limit, and the drain re-arms. Under steady reads this costs one drain episode of at least 100 ms per batch. That accounts for the 245264 wakes and the hours of queue wait.blockers: []had a second cause.checkpoint_snapshotdropped the pending outcome's blocker inventory whenever pressure wasopen, so the readers that held a checkpoint below the hard limit were never shown.Fix
fix(rusqlite-runtime): pressure checkpoints runPRAGMA wal_checkpoint(RESTART)in place ofPASSIVE. The writer'sbusy_timeoutis zero, soRESTARTnever blocks. It reportsbusywhile any read slot is held, so a hard drain now holds until the next write is guaranteed to restart the log, and the held reader shows up as a blocker. Because readers admitted after a full backfill use slot 0, the drain converges within one reader lifetime instead of re-arming on every batch.fix(runtime-core): below the hard limit, the registry checkpoint snapshot reports the blockers of a pending or interrupted outcome.test(rusqlite-runtime):hard_wal_pressure_holds_writes_until_the_wal_log_can_restart(committed first). It fails on the old policy with "a reader still holding a WAL read slot must keep the drain: the log cannot restart", and passes with the fix.Verification
//crates/tracedecay-rusqlite-runtime:unit_test: 401 passed, including the new test. The new test failed before the fix commit.//crates/tracedecay-runtime-core:unit_test: 505 passed, includingcheckpoint_wire_names_the_blockers_of_a_pending_checkpoint_below_the_hard_limit.//crates/tracedecay:daemon_suite: passed.--config=clippyon both crates, andrustfmt_check_2024on both: clean.Not in this PR
writer_error_eventsare the OpenCode observation cursor CAS conflicts (reason_code="cursor_conflict", 5949 journal lines, the last at 2026-10-15T14:05). They are not SQLITE_BUSY.writer_busy_eventsis 0.storage.table_growthisunknownfor every store. Stores above the 64 MiB synchronous cap are refused, and the Doctor preview path never seeds a baseline for small stores. This is separate work.