The 5-second TRUNCATE checkpoint holds the database lock for up to the busy timeout while any read is in progress, and logs the busy result as a success #102

Closed
opened 2026-10-19 22:35:08 +02:00 by clawbot · 1 comment
Collaborator

Where: Database.Checkpoint in internal/database/database.go; DBMaintainer.runCheckpoint in internal/routewatch/dbmaintainer.go.

Every 5 seconds Checkpoint takes the database lock every batch write needs and runs PRAGMA wal_checkpoint(TRUNCATE). In TRUNCATE mode SQLite cannot finish while any connection is reading: walCheckpoint (bundled source) calls the busy handler, the 5000 ms _busy_timeout from the DSN, until every reader has left its snapshot, and a read holds its snapshot for the whole statement. So while an HTTP read is in progress (an AS page for a large AS runs for seconds, up to the 30-second limit) each checkpoint holds the lock for up to 5 s, then returns a row with busy = 1, which the code discards: Checkpoint returns nil and the maintainer logs "WAL checkpoint completed" and counts a success.

Effect: during a long read the writer gets the lock about half the time. PR 98 measured route writes at about 12,000 updates/s against a feed peak of 10,000/s, so halving write time makes the prefix handler fall behind: batch at the ceiling, queue full, updates dropped, and a dropped withdrawal leaves a route in the table for good (the #96 failure). Anyone crawling AS pages causes it.

Severity: medium.

Definition of done

  • The periodic checkpoint never waits on readers while holding the database lock: PASSIVE mode on the timer (it never invokes the busy handler) with journal_size_limit on the writing connection so the WAL file shrinks when it restarts, or an equivalent that bounds the hold to the copy itself.
  • A busy result is read and logged as such, not as a success.
  • Test, failing before the fix: with a reader holding an open read transaction on live_routes_v4 and one route committed since, Checkpoint returns well under 1 s (today it waits the 5 s busy timeout) and a batch write issued meanwhile completes within the same bound.
  • make check passes.

Model: fable-5-1

Where: `Database.Checkpoint` in `internal/database/database.go`; `DBMaintainer.runCheckpoint` in `internal/routewatch/dbmaintainer.go`. Every 5 seconds `Checkpoint` takes the database lock every batch write needs and runs `PRAGMA wal_checkpoint(TRUNCATE)`. In TRUNCATE mode SQLite cannot finish while any connection is reading: `walCheckpoint` (bundled source) calls the busy handler, the 5000 ms `_busy_timeout` from the DSN, until every reader has left its snapshot, and a read holds its snapshot for the whole statement. So while an HTTP read is in progress (an AS page for a large AS runs for seconds, up to the 30-second limit) each checkpoint holds the lock for up to 5 s, then returns a row with busy = 1, which the code discards: `Checkpoint` returns nil and the maintainer logs "WAL checkpoint completed" and counts a success. Effect: during a long read the writer gets the lock about half the time. PR 98 measured route writes at about 12,000 updates/s against a feed peak of 10,000/s, so halving write time makes the prefix handler fall behind: batch at the ceiling, queue full, updates dropped, and a dropped withdrawal leaves a route in the table for good (the https://git.eeqj.de/sneak/routewatch/issues/96 failure). Anyone crawling AS pages causes it. Severity: medium. ## Definition of done - The periodic checkpoint never waits on readers while holding the database lock: PASSIVE mode on the timer (it never invokes the busy handler) with `journal_size_limit` on the writing connection so the WAL file shrinks when it restarts, or an equivalent that bounds the hold to the copy itself. - A busy result is read and logged as such, not as a success. - Test, failing before the fix: with a reader holding an open read transaction on `live_routes_v4` and one route committed since, `Checkpoint` returns well under 1 s (today it waits the 5 s busy timeout) and a batch write issued meanwhile completes within the same bound. - `make check` passes. Model: fable-5-1
clawbot self-assigned this 2026-10-19 22:35:08 +02:00
Author
Collaborator

#126 makes the 5-second checkpoint PASSIVE, so it never waits on a read while holding the database lock; the writing connection's journal_size_limit (64 MiB) shrinks the WAL file instead, and a busy checkpoint is logged as busy at warning level, not as completed.

Model: opus-5-5

https://git.eeqj.de/sneak/routewatch/pulls/126 makes the 5-second checkpoint PASSIVE, so it never waits on a read while holding the database lock; the writing connection's `journal_size_limit` (64 MiB) shrinks the WAL file instead, and a busy checkpoint is logged as busy at warning level, not as completed. Model: opus-5-5
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: sneak/routewatch#102