The 5-second checkpoint, holding the database lock, waited up to the 5-second busy timeout for every open read, and logged a busy result as completed.
What changed
Checkpoint runs a PASSIVE checkpoint, which never waits: it copies what no open read still needs.
When the WAL file is over 64 MiB, Checkpoint runs one TRUNCATE checkpoint instead, with the busy timeout lowered to 500 ms, so batch writes wait at most that long for reads. It is logged with its duration and whether it emptied the file.
A checkpoint that leaves part of the WAL uncopied returns ErrCheckpointIncomplete; the maintainer logs it as "WAL checkpoint incomplete" and does not count it as completed.
The writing connection's journal_size_limit is 64 MiB.
When the WAL file shrinks
A file over 64 MiB is emptied by the first checkpoint that finds no read open, at its start or during its 500 ms wait. While reads follow one another with no pause between them, every such checkpoint can give up after its full wait, and the file can keep growing for as long as they do: SQLite cannot empty the WAL under such reads.
What the diff does not show
The startup checkpoint in Initialize stays TRUNCATE: no read is open then.
Disclosures
Judgement calls: 64 MiB and 500 ms, not measured against the live feed; "WAL checkpoint incomplete" is a debug message, like "completed", as most checkpoints are incomplete while reads overlap.
TODO.md is unchanged: the brief named the files to change.
Model: opus-5-5
Fixes https://git.eeqj.de/sneak/routewatch/issues/102.
The 5-second checkpoint, holding the database lock, waited up to the 5-second busy timeout for every open read, and logged a busy result as completed.
**What changed**
- `Checkpoint` runs a PASSIVE checkpoint, which never waits: it copies what no open read still needs.
- When the WAL file is over 64 MiB, `Checkpoint` runs one TRUNCATE checkpoint instead, with the busy timeout lowered to 500 ms, so batch writes wait at most that long for reads. It is logged with its duration and whether it emptied the file.
- A checkpoint that leaves part of the WAL uncopied returns `ErrCheckpointIncomplete`; the maintainer logs it as "WAL checkpoint incomplete" and does not count it as completed.
- The writing connection's `journal_size_limit` is 64 MiB.
**When the WAL file shrinks**
A file over 64 MiB is emptied by the first checkpoint that finds no read open, at its start or during its 500 ms wait. While reads follow one another with no pause between them, every such checkpoint can give up after its full wait, and the file can keep growing for as long as they do: SQLite cannot empty the WAL under such reads.
**What the diff does not show**
- The startup checkpoint in `Initialize` stays TRUNCATE: no read is open then.
**Disclosures**
- Judgement calls: 64 MiB and 500 ms, not measured against the live feed; "WAL checkpoint incomplete" is a debug message, like "completed", as most checkpoints are incomplete while reads overlap.
- `TODO.md` is unchanged: the brief named the files to change.
Model: opus-5-5
internal/database/database.go, Checkpoint, with the journal_size_limit set in New: while reads overlap, the WAL file grows without limit. The 64 MiB limit cuts the file only when SQLite starts the WAL again from the beginning. SQLite does that only at a write that comes after a checkpoint has copied everything and while no read that began before that checkpoint is still open. A PASSIVE checkpoint never waits for that moment, so while some read is always open (the crawl of AS pages the issue describes), the WAL never starts again. With two overlapping 300 ms reads and batch writes running, it passed 500 MiB within 4 seconds and fell back to 64 MiB only after the reads stopped. Meanwhile each of those checkpoints returns nil and is logged and counted as completed, because Checkpoint reads the WAL page count and the copied page count and throws them away. The comments on Checkpoint and sqliteWALSizeLimitBytes say the WAL shrinks, which holds only once reads stop. Acceptable looks like this: the WAL file stays under a stated bound while reads overlap. For example, once the file passes the limit or a checkpoint leaves pages uncopied, a checkpoint runs that does start the WAL again, and how long it may keep batch writes waiting is bounded and logged. A checkpoint that leaves pages uncopied is not logged as completed, and a test keeps reads overlapping and checks the WAL file size.
internal/database/database_internal_test.go, TestCheckpointDoesNotWaitForReader: fails at random, which would turn next red. It waits with waitForLockMessage, which fails the test when Checkpoint returns before its "Database lock acquired" message has been read. With the fix, the checkpoint returns almost at once, while the earlier batch writes' lock messages are still queued ahead of that message. So whenever the test goroutine runs a little late, the select takes the return and the test fails with "Checkpoint returned (error: <nil>) without logging "Database lock acquired"". It failed this way in a full test run of this branch rebased onto current next. Acceptable: a quick return from Checkpoint is the passing case and does not fail the test, and the test passes however the goroutines are scheduled, under -race with the whole suite.
Judgement call: finding 1 stands although the definition of done in #102 suggests PASSIVE with journal_size_limit; that design alone does not keep the WAL bounded.
Model: opus-5-5
1. `internal/database/database.go`, `Checkpoint`, with the `journal_size_limit` set in `New`: while reads overlap, the WAL file grows without limit. The 64 MiB limit cuts the file only when SQLite starts the WAL again from the beginning. SQLite does that only at a write that comes after a checkpoint has copied everything and while no read that began before that checkpoint is still open. A PASSIVE checkpoint never waits for that moment, so while some read is always open (the crawl of AS pages the issue describes), the WAL never starts again. With two overlapping 300 ms reads and batch writes running, it passed 500 MiB within 4 seconds and fell back to 64 MiB only after the reads stopped. Meanwhile each of those checkpoints returns nil and is logged and counted as completed, because `Checkpoint` reads the WAL page count and the copied page count and throws them away. The comments on `Checkpoint` and `sqliteWALSizeLimitBytes` say the WAL shrinks, which holds only once reads stop. Acceptable looks like this: the WAL file stays under a stated bound while reads overlap. For example, once the file passes the limit or a checkpoint leaves pages uncopied, a checkpoint runs that does start the WAL again, and how long it may keep batch writes waiting is bounded and logged. A checkpoint that leaves pages uncopied is not logged as completed, and a test keeps reads overlapping and checks the WAL file size.
2. `internal/database/database_internal_test.go`, `TestCheckpointDoesNotWaitForReader`: fails at random, which would turn `next` red. It waits with `waitForLockMessage`, which fails the test when `Checkpoint` returns before its "Database lock acquired" message has been read. With the fix, the checkpoint returns almost at once, while the earlier batch writes' lock messages are still queued ahead of that message. So whenever the test goroutine runs a little late, the `select` takes the return and the test fails with "Checkpoint returned (error: <nil>) without logging "Database lock acquired"". It failed this way in a full test run of this branch rebased onto current `next`. Acceptable: a quick return from `Checkpoint` is the passing case and does not fail the test, and the test passes however the goroutines are scheduled, under -race with the whole suite.
Judgement call: finding 1 stands although the definition of done in https://git.eeqj.de/sneak/routewatch/issues/102 suggests PASSIVE with `journal_size_limit`; that design alone does not keep the WAL bounded.
Model: opus-5-5
When the WAL file is over 64 MiB, Checkpoint now runs a TRUNCATE checkpoint with the writing connection's busy timeout lowered to 500 ms for it and restored after, so it keeps batch writes waiting at most that long for reads; it is logged with its duration, at warning level when it could not empty the file. The bound is stated on Checkpoint: under 64 MiB plus what writes add between two checkpoints, while reads end within 500 ms. A checkpoint that leaves pages uncopied returns ErrCheckpointIncomplete and is logged as "WAL checkpoint incomplete", not counted as completed. TestCheckpointKeepsWALSmallWhileReadsOverlap keeps two reads overlapping while it writes 80 MiB, checkpointing every 4 MiB, and checks the WAL file stays under 72 MiB; with the TRUNCATE step removed it fails.
TestCheckpointDoesNotWaitForReader no longer waits for a lock message: it starts Checkpoint and the batch write together and checks that both end within 1 s whichever takes the lock first, so a quick return is the passing case. It now also expects ErrCheckpointIncomplete, since the open read keeps part of the WAL uncopied.
Model: opus-5-5
1. When the WAL file is over 64 MiB, `Checkpoint` now runs a TRUNCATE checkpoint with the writing connection's busy timeout lowered to 500 ms for it and restored after, so it keeps batch writes waiting at most that long for reads; it is logged with its duration, at warning level when it could not empty the file. The bound is stated on `Checkpoint`: under 64 MiB plus what writes add between two checkpoints, while reads end within 500 ms. A checkpoint that leaves pages uncopied returns `ErrCheckpointIncomplete` and is logged as "WAL checkpoint incomplete", not counted as completed. `TestCheckpointKeepsWALSmallWhileReadsOverlap` keeps two reads overlapping while it writes 80 MiB, checkpointing every 4 MiB, and checks the WAL file stays under 72 MiB; with the TRUNCATE step removed it fails.
2. `TestCheckpointDoesNotWaitForReader` no longer waits for a lock message: it starts `Checkpoint` and the batch write together and checks that both end within 1 s whichever takes the lock first, so a quick return is the passing case. It now also expects `ErrCheckpointIncomplete`, since the open read keeps part of the WAL uncopied.
Model: opus-5-5
internal/database/database_internal_test.go, TestCheckpointKeepsWALSmallWhileReadsOverlap: fails at random under -race, both alone and with the rest of the package, which would turn next red. In the failing runs the TRUNCATE checkpoint gives up twice in a row after its full 500 ms and the WAL file passes walFillBound. The overlap the test depends on is also left to timing: the readers are staggered with time.Sleep, and nothing checks that a read is open at each write. Acceptable: the test passes on every run under -race with the whole suite, and the overlap is arranged by the test rather than by sleeps.
internal/database/database.go, Checkpoint and truncateWAL: the condition stated for the bound, on Checkpoint and in the PR body, is wrong. It says the WAL file stays under 64 MiB plus one interval's writes as long as no read stays open longer than 500 ms. But the TRUNCATE checkpoint also waits its full 500 ms and gives up when every read lasts 50 ms, whenever a connection begins its next read as soon as its last one ends, as keepReading does; that is the cause of finding 1. Under a steady read load, every 5-second checkpoint can then hold batch writes for 500 ms while the WAL file keeps growing. Acceptable: the condition stated on Checkpoint and in the PR body is one under which the TRUNCATE checkpoint does succeed, a test covers that condition on every run, and if no checkpoint can keep the file bounded under reads that follow one another with no pause, the comment says so.
Judgement call: the TRUNCATE checkpoint's wait of up to 500 ms under the database lock is not counted against the first point of the definition of done in #102, as the earlier review asked for a bounded, logged wait.
Model: opus-5-5
1. `internal/database/database_internal_test.go`, `TestCheckpointKeepsWALSmallWhileReadsOverlap`: fails at random under -race, both alone and with the rest of the package, which would turn `next` red. In the failing runs the TRUNCATE checkpoint gives up twice in a row after its full 500 ms and the WAL file passes `walFillBound`. The overlap the test depends on is also left to timing: the readers are staggered with `time.Sleep`, and nothing checks that a read is open at each write. Acceptable: the test passes on every run under -race with the whole suite, and the overlap is arranged by the test rather than by sleeps.
2. `internal/database/database.go`, `Checkpoint` and `truncateWAL`: the condition stated for the bound, on `Checkpoint` and in the PR body, is wrong. It says the WAL file stays under 64 MiB plus one interval's writes as long as no read stays open longer than 500 ms. But the TRUNCATE checkpoint also waits its full 500 ms and gives up when every read lasts 50 ms, whenever a connection begins its next read as soon as its last one ends, as `keepReading` does; that is the cause of finding 1. Under a steady read load, every 5-second checkpoint can then hold batch writes for 500 ms while the WAL file keeps growing. Acceptable: the condition stated on `Checkpoint` and in the PR body is one under which the TRUNCATE checkpoint does succeed, a test covers that condition on every run, and if no checkpoint can keep the file bounded under reads that follow one another with no pause, the comment says so.
Judgement call: the TRUNCATE checkpoint's wait of up to 500 ms under the database lock is not counted against the first point of the definition of done in https://git.eeqj.de/sneak/routewatch/issues/102, as the earlier review asked for a bounded, logged wait.
Model: opus-5-5
The 5-second checkpoint ran in TRUNCATE mode, which waits up to the
5-second busy timeout for every open read while holding the database
lock every batch write needs. It now runs in PASSIVE mode, which never
waits. A WAL file over 64 MiB instead gets one TRUNCATE checkpoint whose
wait for reads is capped at 500 ms and logged; it empties the file once
no read is open, and while reads follow one another with no pause it
can give up every time. A checkpoint that leaves part of the WAL
uncopied returns ErrCheckpointIncomplete, which the maintainer logs as
incomplete instead of completed. The writing connection's
journal_size_limit is 64 MiB.
Model: opus-5-5
TestCheckpointKeepsWALSmallWhileReadsOverlap is replaced by TestCheckpointEmptiesWALOnceNoReadIsOpen, which has no sleeps: the test itself holds one read open while it fills the WAL file past 64 MiB, then checks that Checkpoint gives up within its 500 ms wait plus a second, returns ErrCheckpointIncomplete, and that a batch write still succeeds; after it closes the read, it checks that the next Checkpoint brings the WAL file under 64 MiB.
The comment on Checkpoint and the PR body now state when the file shrinks: a file over the limit is emptied by the first checkpoint that finds no read open, at its start or during its wait; while reads follow one another with no pause, every TRUNCATE checkpoint can give up after its full wait and the file can keep growing, which they say. The second half of the test above covers the condition under which the TRUNCATE checkpoint succeeds. The code and the 500 ms wait are unchanged.
Model: opus-5-5
1. `TestCheckpointKeepsWALSmallWhileReadsOverlap` is replaced by `TestCheckpointEmptiesWALOnceNoReadIsOpen`, which has no sleeps: the test itself holds one read open while it fills the WAL file past 64 MiB, then checks that `Checkpoint` gives up within its 500 ms wait plus a second, returns `ErrCheckpointIncomplete`, and that a batch write still succeeds; after it closes the read, it checks that the next `Checkpoint` brings the WAL file under 64 MiB.
2. The comment on `Checkpoint` and the PR body now state when the file shrinks: a file over the limit is emptied by the first checkpoint that finds no read open, at its start or during its wait; while reads follow one another with no pause, every TRUNCATE checkpoint can give up after its full wait and the file can keep growing, which they say. The second half of the test above covers the condition under which the TRUNCATE checkpoint succeeds. The code and the 500 ms wait are unchanged.
Model: opus-5-5
Blocking a user prevents them from interacting with repositories, such as opening or commenting on pull requests or issues. Learn more about blocking a user.
Fixes #102.
The 5-second checkpoint, holding the database lock, waited up to the 5-second busy timeout for every open read, and logged a busy result as completed.
What changed
Checkpointruns a PASSIVE checkpoint, which never waits: it copies what no open read still needs.Checkpointruns one TRUNCATE checkpoint instead, with the busy timeout lowered to 500 ms, so batch writes wait at most that long for reads. It is logged with its duration and whether it emptied the file.ErrCheckpointIncomplete; the maintainer logs it as "WAL checkpoint incomplete" and does not count it as completed.journal_size_limitis 64 MiB.When the WAL file shrinks
A file over 64 MiB is emptied by the first checkpoint that finds no read open, at its start or during its 500 ms wait. While reads follow one another with no pause between them, every such checkpoint can give up after its full wait, and the file can keep growing for as long as they do: SQLite cannot empty the WAL under such reads.
What the diff does not show
Initializestays TRUNCATE: no read is open then.Disclosures
TODO.mdis unchanged: the brief named the files to change.Model: opus-5-5
internal/database/database.go,Checkpoint, with thejournal_size_limitset inNew: while reads overlap, the WAL file grows without limit. The 64 MiB limit cuts the file only when SQLite starts the WAL again from the beginning. SQLite does that only at a write that comes after a checkpoint has copied everything and while no read that began before that checkpoint is still open. A PASSIVE checkpoint never waits for that moment, so while some read is always open (the crawl of AS pages the issue describes), the WAL never starts again. With two overlapping 300 ms reads and batch writes running, it passed 500 MiB within 4 seconds and fell back to 64 MiB only after the reads stopped. Meanwhile each of those checkpoints returns nil and is logged and counted as completed, becauseCheckpointreads the WAL page count and the copied page count and throws them away. The comments onCheckpointandsqliteWALSizeLimitBytessay the WAL shrinks, which holds only once reads stop. Acceptable looks like this: the WAL file stays under a stated bound while reads overlap. For example, once the file passes the limit or a checkpoint leaves pages uncopied, a checkpoint runs that does start the WAL again, and how long it may keep batch writes waiting is bounded and logged. A checkpoint that leaves pages uncopied is not logged as completed, and a test keeps reads overlapping and checks the WAL file size.internal/database/database_internal_test.go,TestCheckpointDoesNotWaitForReader: fails at random, which would turnnextred. It waits withwaitForLockMessage, which fails the test whenCheckpointreturns before its "Database lock acquired" message has been read. With the fix, the checkpoint returns almost at once, while the earlier batch writes' lock messages are still queued ahead of that message. So whenever the test goroutine runs a little late, theselecttakes the return and the test fails with "Checkpoint returned (error: <nil>) without logging "Database lock acquired"". It failed this way in a full test run of this branch rebased onto currentnext. Acceptable: a quick return fromCheckpointis the passing case and does not fail the test, and the test passes however the goroutines are scheduled, under -race with the whole suite.Judgement call: finding 1 stands although the definition of done in #102 suggests PASSIVE with
journal_size_limit; that design alone does not keep the WAL bounded.Model: opus-5-5
d78b4226b0to4b2d3a9ff2Checkpointnow runs a TRUNCATE checkpoint with the writing connection's busy timeout lowered to 500 ms for it and restored after, so it keeps batch writes waiting at most that long for reads; it is logged with its duration, at warning level when it could not empty the file. The bound is stated onCheckpoint: under 64 MiB plus what writes add between two checkpoints, while reads end within 500 ms. A checkpoint that leaves pages uncopied returnsErrCheckpointIncompleteand is logged as "WAL checkpoint incomplete", not counted as completed.TestCheckpointKeepsWALSmallWhileReadsOverlapkeeps two reads overlapping while it writes 80 MiB, checkpointing every 4 MiB, and checks the WAL file stays under 72 MiB; with the TRUNCATE step removed it fails.TestCheckpointDoesNotWaitForReaderno longer waits for a lock message: it startsCheckpointand the batch write together and checks that both end within 1 s whichever takes the lock first, so a quick return is the passing case. It now also expectsErrCheckpointIncomplete, since the open read keeps part of the WAL uncopied.Model: opus-5-5
internal/database/database_internal_test.go,TestCheckpointKeepsWALSmallWhileReadsOverlap: fails at random under -race, both alone and with the rest of the package, which would turnnextred. In the failing runs the TRUNCATE checkpoint gives up twice in a row after its full 500 ms and the WAL file passeswalFillBound. The overlap the test depends on is also left to timing: the readers are staggered withtime.Sleep, and nothing checks that a read is open at each write. Acceptable: the test passes on every run under -race with the whole suite, and the overlap is arranged by the test rather than by sleeps.internal/database/database.go,CheckpointandtruncateWAL: the condition stated for the bound, onCheckpointand in the PR body, is wrong. It says the WAL file stays under 64 MiB plus one interval's writes as long as no read stays open longer than 500 ms. But the TRUNCATE checkpoint also waits its full 500 ms and gives up when every read lasts 50 ms, whenever a connection begins its next read as soon as its last one ends, askeepReadingdoes; that is the cause of finding 1. Under a steady read load, every 5-second checkpoint can then hold batch writes for 500 ms while the WAL file keeps growing. Acceptable: the condition stated onCheckpointand in the PR body is one under which the TRUNCATE checkpoint does succeed, a test covers that condition on every run, and if no checkpoint can keep the file bounded under reads that follow one another with no pause, the comment says so.Judgement call: the TRUNCATE checkpoint's wait of up to 500 ms under the database lock is not counted against the first point of the definition of done in #102, as the earlier review asked for a bounded, logged wait.
Model: opus-5-5
4b2d3a9ff2to847a930df8TestCheckpointKeepsWALSmallWhileReadsOverlapis replaced byTestCheckpointEmptiesWALOnceNoReadIsOpen, which has no sleeps: the test itself holds one read open while it fills the WAL file past 64 MiB, then checks thatCheckpointgives up within its 500 ms wait plus a second, returnsErrCheckpointIncomplete, and that a batch write still succeeds; after it closes the read, it checks that the nextCheckpointbrings the WAL file under 64 MiB.Checkpointand the PR body now state when the file shrinks: a file over the limit is emptied by the first checkpoint that finds no read open, at its start or during its wait; while reads follow one another with no pause, every TRUNCATE checkpoint can give up after its full wait and the file can keep growing, which they say. The second half of the test above covers the condition under which the TRUNCATE checkpoint succeeds. The code and the 500 ms wait are unchanged.Model: opus-5-5
Review passed.
Model: opus-5-5