Skip to content

fix(rusqlite-runtime): checkpoint WAL pressure with RESTART - #4097

Merged
ScriptedAlchemy merged 3 commits into
masterfrom
fix/sweep-sessions-checkpoint
Oct 16, 2026
Merged

ScriptedAlchemy merged 3 commits into
masterfrom
fix/sweep-sessions-checkpoint

Conversation

@ScriptedAlchemy

@ScriptedAlchemy ScriptedAlchemy commented Oct 16, 2026 •

Copy link
Copy Markdown
Owner

Live diagnosis

The live daemon (PID 2717644, 1.0.0-beta.82+8e75836b0, up since 2026-10-12) reported the project_sessions shard for proj_a5b3d7e3ebe14ca7 with checkpoint outcome: pending, hard_retry_wakes: 245264, wal_bytes: 229797152 (soft 33554432, hard 268435456), queue_wait_micros: 10663828920 and blockers: [].

Reading the WAL index header from the daemon's own sessions.db-shm mapping through /proc/2717644/mem showed the cause. Over a 10-minute sample (06:52 to 07:02 UTC), the log never restarted:

  • mxFrame rose monotonically from 56123 to 56480 frames (56480 x 4120 B = 233 MB, matching the telemetry wal_bytes).
  • nBackfill always trailed mxFrame by exactly one commit (for example 56065/56049, then 56128/56123).
  • Read slots 1 and 2 were held almost continuously. /proc/locks showed 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, and PASSIVE never restarts the log. Under overlapping reads, the log therefore ratchets toward the hard limit. Around 07:05 a quiet moment let the restart through (mxFrame 758 at 07:23, and journal_size_limit cut 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 PASSIVE every 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, so PASSIVE reports 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_snapshot dropped the pending outcome's blocker inventory whenever pressure was open, so the readers that held a checkpoint below the hard limit were never shown.

Fix

  • fix(rusqlite-runtime): pressure checkpoints run PRAGMA wal_checkpoint(RESTART) in place of PASSIVE. The writer's busy_timeout is zero, so RESTART never blocks. It reports busy while 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, including checkpoint_wire_names_the_blockers_of_a_pending_checkpoint_below_the_hard_limit.
  • //crates/tracedecay:daemon_suite: passed.
  • --config=clippy on both crates, and rustfmt_check_2024 on both: clean.

Not in this PR

  • The 5949 writer_error_events are 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_events is 0.
  • storage.table_growth is unknown for 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.

Devin Review

@changeset-bot

changeset-bot Bot commented Oct 16, 2026

Copy link
Copy Markdown

⚠️ No Changeset found

Latest commit: c17e10d

Merging this PR will not cause a version bump for any packages. If these changes should not result in a new version, you're good to go. If these changes should result in a version bump, you need to add a changeset.

Click here to learn what changesets are, and how to add one.

Click here if you're a maintainer who wants to add a changeset to this PR

@devin-ai-integration devin-ai-integration Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

✅ Devin Review: No Issues Found

Devin Review analyzed this PR and found no bugs or issues to report.

Devin Review

@ScriptedAlchemy
ScriptedAlchemy merged commit 4b9ad9d into master Oct 16, 2026
16 of 21 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant