From 9b0b7c19f40efb290f5c62b4680a6626f458a01b Mon Sep 17 00:00:00 2001 From: m5r Date: Fri, 21 Aug 2026 18:43:45 +0200 Subject: [PATCH] querylog: checkpoint every 8192 wal pages instead of 1000 --- CHANGELOG.md | 8 +++++ specs/querylog-autocheckpoint.md | 43 ++++++++++++++++++++++++ specs/querylog-batching.md | 4 +++ src/cli.zig | 4 ++- src/storage/db.zig | 25 ++++++++++++++ src/storage/querylog_schema.zig | 29 ++++++++++++++-- src/storage/storage_integration_test.zig | 30 +++++++++++++++++ 7 files changed, 140 insertions(+), 3 deletions(-) create mode 100644 specs/querylog-autocheckpoint.md diff --git a/CHANGELOG.md b/CHANGELOG.md index 323c902..fa78c95 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,14 @@ All notable changes to nxdns are recorded here. The format follows [Keep a Chang Sections are written by hand. Nothing here is generated from commit messages: the point of the file is to say what changed for an operator, which a commit subject rarely does. +## [0.0.8] - 2026-08-21 + +One constant, chosen from the 0.0.7 field numbers: the checkpoint cadence was the last first-order write cost on the Pi's SD card. + +### Changed + +- **The query log checkpoints its write-ahead log every 32 MiB instead of every 4 MiB.** Batching the writer in 0.0.7 took the deployed Pi from about 0.5 to 0.281 GiB of writes a day, and about 130 MiB of what is left is checkpoint writeback: SQLite's 1000-page default trips roughly every 40 minutes and rewrites the same hot index and interior pages into `querylog.db` each time. Every read-write connection to `querylog.db` now sets `wal_autocheckpoint` to 8192 pages, which stretches that to roughly five hours and cuts those in-place rewrites about eightfold, for an expected total near 190 MiB a day. The price is durability under power loss or a kernel panic. At `synchronous = NORMAL` a commit does not fsync, so the checkpoint is the only guaranteed durability boundary, and it now sits about five hours of query rows and upstream-history minutes back rather than 40 minutes. Kernel writeback normally makes the real loss far smaller than that, but nothing guarantees it. A process crash or a clean stop still loses nothing that was committed, and the database is never left inconsistent: recovery replays the longest valid prefix of the log. The `querylog.db-wal` file is expected to sit near 32 MiB rather than capped there, since a long-running reader can hold a checkpoint off and let it overshoot, and the daily retention pass still truncates it. `config.db` is unchanged. + ## [0.0.7] - 2026-08-20 Operational failures get a page of their own, and the query log stops wearing out the disk it lives on: the deployed Pi was writing half a gigabyte a day to store two megabytes of query rows, one transaction per query. Both came out of running 0.0.6 on real hardware. diff --git a/specs/querylog-autocheckpoint.md b/specs/querylog-autocheckpoint.md new file mode 100644 index 0000000..ee365f2 --- /dev/null +++ b/specs/querylog-autocheckpoint.md @@ -0,0 +1,43 @@ +# querylog.db: wal_autocheckpoint = 8192 + +One constant. The v0.0.7 batching cut process writes from ~0.5 to 0.281 GiB/day (measured over a 10 h process lifetime on the Pi); ~130 MiB/day of the remainder is autocheckpoint writeback — SQLite's 1000-page default trips every ~40 min and rewrites the same hot index/interior pages into the main db each time. At 8192 pages (32 MiB at the 4096-byte page size) the cadence drops to ~5 h, cutting those in-place rewrites ~8x, expected total ≈190 MiB/day. The previous SD card died of write wear; the current card's endurance is unknown, which argues for cutting known writes, not against it. Codex approved the decision and this shape (thread 01a0205d). + +## Decision + +`PRAGMA wal_autocheckpoint = 8192` on every read-write querylog.db connection. Hardcoded constant, no config knob, no checkpoint task. `synchronous=NORMAL` and the daily retention `wal_checkpoint(TRUNCATE)` (queries_repo.zig:169, called from the retention pass) stay as they are. config.db — including the diagnostics store's connection, which `app.zig:416` opens via `openConfigDb` despite the variable name `events_db` — keeps the SQLite default. There are exactly two database files; nothing named events.db exists. + +## Durability contract (goes in the constant's comment, stated precisely) + +- Commit never fsyncs at `synchronous=NORMAL`; the checkpoint's fsync is the only guaranteed durability boundary. This change moves that boundary from ~40 min to ~5 h of querylog data (query rows + upstream-history minutes) under power loss or kernel panic. Typical loss stays far smaller (kernel writeback), but that is not a guarantee. +- Process crash or clean stop loses nothing committed, at any threshold. Consistency is never at risk: recovery replays the longest valid WAL prefix atomically. +- 32 MiB is an expectation, not a cap: a pinned reader snapshot stops a passive checkpoint partway and the WAL overshoots until the reader finishes; the daily TRUNCATE is the backstop that shrinks the file. + +## Implementation + +1. **src/storage/db.zig** — `Pragmas` (:753) gains `wal_autocheckpoint_pages: ?i32 = null`. `applyPragmas` (:762), when non-null: `PRAGMA wal_autocheckpoint = N;` then read back via the pragma's own return and fail loudly on mismatch — mirror the `foreign_keys` set-and-verify at :781-783. Default null leaves every existing `.{}` caller (config.db sites, tests) untouched with zero diffs. db.zig stays generic; it must not know the word querylog. +2. **src/storage/querylog_schema.zig** — owns the constant (the module already owns querylog policy: fingerprint, DDL, recreate classification): `pub const wal_autocheckpoint_pages: i32 = 8192;` carrying the durability contract above as its comment. Passed at both production `applyPragmas` sites: the probe path (:129) and `createFresh` (:253). The third `applyPragmas` in that file (:273) is inside an in-memory test and stays `.{}` deliberately. +3. **src/cli.zig** — `reopenQuerylogDb` (:354) passes the constant. These three sites are the only read-write querylog connections by construction — every open flows through `querylog_schema.open` or `DataDir.reopenQuerylogDb`. + +## Tests + +- Unit, db.zig, in-memory (the pragma reads back per-connection regardless of journal mode): default `Pragmas` leaves `PRAGMA wal_autocheckpoint` at 1000; a set value reads back. +- File-backed storage integration test through the real helpers: `openQuerylogDb` and `reopenQuerylogDb` connections both read back 8192; an `openConfigDb` connection reads 1000. +- The read-back inside `applyPragmas` makes misapplication loud at startup, complementing both. + +## Docs + +- CHANGELOG Unreleased, Changed: the checkpoint cadence change, the measured why, and the widened power-loss window stated per the durability contract (not as an unconditional bound). +- One short paragraph appended to specs/querylog-batching.md linking here. + +## Rejected (do not relitigate without new facts) + +- Config knob: nobody tunes this twice; scope is small on purpose. +- Periodic checkpoint task: reproduces autocheckpoint with more moving parts (cadence state, busy handling, shutdown, diagnostics). +- `wal_autocheckpoint=0` + daily TRUNCATE only: unbounded intraday WAL growth under reader pinning; strictly worse. +- `journal_size_limit`: redundant with the daily TRUNCATE, and rejecting it needs no claim about passive checkpoints never truncating (after a completed checkpoint resets the WAL, the limit does truncate on the next write — the knob is merely surplus here). +- Touching config.db policy or differentiating reader vs writer querylog connections: readers cannot trip checkpoints, the pragma is inert on them; uniformity is simpler. + +## Gates + +1. `zig build test` and `-Dintegration` 0 failed; fmt clean. +2. Field verification on the released build (the Pi deploys releases, not branches, so this necessarily follows the cut — owner-ordered 2026-08-21): one 24-hour run spanning several autocheckpoints and a retention pass — WAL resets normally, writeback falls materially, no dropped batches; measured as process write_bytes AND device sectors (/sys/block/mmcblk0/stat). The rpi-nixos-iac session runs it; a bad result reverts the constant in a follow-up patch release. diff --git a/specs/querylog-batching.md b/specs/querylog-batching.md index dbd4731..330c822 100644 --- a/specs/querylog-batching.md +++ b/specs/querylog-batching.md @@ -19,6 +19,10 @@ Model key + round-trip drift guards, validation + validation reference, settings - Crash-loss window: up to `interval` seconds of query history on process failure; power loss can additionally lose recent committed transactions (WAL + synchronous=NORMAL). Query history is the least valuable data on the box. - Staleness: every query-log-backed read (query-log page, totals, timeseries) lags up to `interval` seconds. The live view is unaffected — it is fed from the hub before the queue. +## Follow-up + +The "unchanged on purpose" line above no longer holds for `wal_autocheckpoint`. Batching landed and the Pi measured 0.281 GiB/day, of which ~130 MiB is autocheckpoint writeback — second-order next to one transaction per query, first-order next to one per minute. specs/querylog-autocheckpoint.md raises the threshold to 8192 pages on every read-write `querylog.db` connection and states the durability contract that comes with it. Nothing else in this spec changes. + ## Acceptance - [ ] Deterministic tests: interval batching (entries within the window land in one transaction), flush_batch early flush, 0-sentinel immediate flush, shutdown drains a held batch and the queue (the race sequence: producers stopped → queue closed → writer awaited), disk-gated final drain counts drops. diff --git a/src/cli.zig b/src/cli.zig index ba8bdbc..ceb7ccf 100644 --- a/src/cli.zig +++ b/src/cli.zig @@ -351,7 +351,9 @@ pub const DataDir = struct { _ = io; var database = try db.Db.open(self.querylog_db_path, .{ .mode = .read_write_existing }); errdefer database.close(); - try db.applyPragmas(&database, .{}); + try db.applyPragmas(&database, .{ + .wal_autocheckpoint_pages = querylog_schema.wal_autocheckpoint_pages, + }); return database; } diff --git a/src/storage/db.zig b/src/storage/db.zig index db628b7..57b0d38 100644 --- a/src/storage/db.zig +++ b/src/storage/db.zig @@ -754,6 +754,9 @@ pub const Pragmas = struct { journal_wal: bool = true, synchronous_normal: bool = true, foreign_keys: bool = true, + /// Null leaves SQLite's 1000-page default. A caller that sets it owns the + /// durability consequences, which depend on what the database holds. + wal_autocheckpoint_pages: ?i32 = null, }; /// MUST be called before any transaction is opened: `PRAGMA foreign_keys` is a @@ -785,6 +788,16 @@ pub fn applyPragmas(self: *Db, p: Pragmas) Error!void { return error.SqliteError; } } + if (p.wal_autocheckpoint_pages) |pages| { + var buf: [64]u8 = undefined; + const sql = std.fmt.bufPrintZ(&buf, "PRAGMA wal_autocheckpoint = {d};", .{pages}) catch unreachable; + try self.exec(sql); + const applied = try self.queryInt("PRAGMA wal_autocheckpoint"); + if (applied != pages) { + log.warn("PRAGMA wal_autocheckpoint = {d} reported {d}", .{ pages, applied }); + return error.SqliteError; + } + } } /// A write transaction. @@ -907,6 +920,18 @@ test "applyPragmas succeeds and foreign_keys reads back as 1" { try testing.expectEqual(@as(i64, 1), try db.queryInt("PRAGMA foreign_keys")); } +test "applyPragmas leaves wal_autocheckpoint at the default unless a page count is given" { + var db = try openMemory(); + defer db.close(); + try applyPragmas(&db, .{}); + try testing.expectEqual(@as(i64, 1000), try db.queryInt("PRAGMA wal_autocheckpoint")); + + var configured = try openMemory(); + defer configured.close(); + try applyPragmas(&configured, .{ .wal_autocheckpoint_pages = 8192 }); + try testing.expectEqual(@as(i64, 8192), try configured.queryInt("PRAGMA wal_autocheckpoint")); +} + test "open on a directory path returns error.CantOpen and leaks no handle" { var i: usize = 0; while (i < 1000) : (i += 1) { diff --git a/src/storage/querylog_schema.zig b/src/storage/querylog_schema.zig index 5d5a429..e1e9c75 100644 --- a/src/storage/querylog_schema.zig +++ b/src/storage/querylog_schema.zig @@ -77,6 +77,31 @@ pub const fingerprint: i32 = blk: { const set_user_version = std.fmt.comptimePrint("PRAGMA user_version = {d};", .{fingerprint}); +/// The WAL checkpoint threshold for every read-write `querylog.db` connection, +/// in pages (32 MiB at the 4096-byte page size). SQLite's 1000-page default +/// trips every ~40 min under this workload and rewrites the same hot index and +/// interior pages into the main database each time; 8192 stretches that to ~5 h +/// and cuts those in-place rewrites ~8x, which is SD-card write wear this +/// household appliance does not need to spend. +/// +/// The durability consequence, stated precisely: +/// +/// - Commit never fsyncs at `synchronous = NORMAL`; the checkpoint's fsync is +/// the only guaranteed durability boundary. This moves that boundary from +/// ~40 min to ~5 h of querylog data (query rows plus upstream-history +/// minutes) under power loss or kernel panic. Typical loss stays far smaller +/// because of kernel writeback, but that is not a guarantee. +/// - Process crash or clean stop loses nothing committed, at any threshold. +/// Consistency is never at risk: recovery replays the longest valid WAL +/// prefix atomically. +/// - 32 MiB is an expectation, not a cap: a pinned reader snapshot stops a +/// passive checkpoint partway and the WAL overshoots until that reader +/// finishes. The daily retention `wal_checkpoint(TRUNCATE)` is the backstop +/// that shrinks the file. +/// +/// `config.db` keeps the SQLite default: it holds configuration, not a log. +pub const wal_autocheckpoint_pages: i32 = 8192; + /// Long enough for any path this program will be handed, plus the aside suffix. /// A longer path is `error.NameTooLong`, which is what the filesystem calls /// would have returned anyway. @@ -126,7 +151,7 @@ pub fn open(io: std.Io, dir: std.Io.Dir, path: [:0]const u8) Error!OpenResult { break :probe recreatable(e) orelse return e; const opened = &handle.?; - db.applyPragmas(opened, .{}) catch |e| + db.applyPragmas(opened, .{ .wal_autocheckpoint_pages = wal_autocheckpoint_pages }) catch |e| break :probe recreatable(e) orelse return e; const healthy = quickCheck(opened) catch |e| @@ -250,7 +275,7 @@ fn deleteSidecars(io: std.Io, dir: std.Io.Dir, path: []const u8) Error!void { fn createFresh(path: [:0]const u8) db.Error!db.Db { var database = try db.Db.open(path, .{ .mode = .read_write_create }); errdefer database.close(); - try db.applyPragmas(&database, .{}); + try db.applyPragmas(&database, .{ .wal_autocheckpoint_pages = wal_autocheckpoint_pages }); var tx = try db.Tx.begin(&database); errdefer tx.rollback(); diff --git a/src/storage/storage_integration_test.zig b/src/storage/storage_integration_test.zig index e0e4e62..621bd1f 100644 --- a/src/storage/storage_integration_test.zig +++ b/src/storage/storage_integration_test.zig @@ -600,6 +600,36 @@ test "S7 case 23: a locked querylog propagates Busy and is never destroyed" { try testing.expectEqual(@as(usize, 0), asides_after.items.items.len); } +// --------------------------------------------------------------------------- +// the querylog checkpoint threshold (specs/querylog-autocheckpoint.md) +// --------------------------------------------------------------------------- + +test "every querylog connection carries the raised wal_autocheckpoint; config.db keeps the default" { + if (!build_options.integration) return error.SkipZigTest; + + var f: Fixture = .init(); + defer f.deinit(); + + var data = try openMigrated(&f, "data"); + defer data.deinit(); + + var opened = try data.dir.openQuerylogDb(io); + defer opened.database.close(); + try testing.expectEqual( + @as(i64, querylog_schema.wal_autocheckpoint_pages), + try opened.database.queryInt("PRAGMA wal_autocheckpoint"), + ); + + var reopened = try data.dir.reopenQuerylogDb(io); + defer reopened.close(); + try testing.expectEqual( + @as(i64, querylog_schema.wal_autocheckpoint_pages), + try reopened.queryInt("PRAGMA wal_autocheckpoint"), + ); + + try testing.expectEqual(@as(i64, 1000), try data.database.queryInt("PRAGMA wal_autocheckpoint")); +} + // --------------------------------------------------------------------------- // case 8-10: config.db, permissions and the schema stamp // ---------------------------------------------------------------------------