From 5b1a8c96a1fe59a36c5b26ecf31a86fbd2341212 Mon Sep 17 00:00:00 2001 From: "shoney.arickathil" Date: Thu, 27 Aug 2026 21:25:24 +0200 Subject: [PATCH] =?UTF-8?q?feat(db-bench):=20replay=20baseline=20=E2=80=94?= =?UTF-8?q?=20boot=20cost=20tracks=20history,=20not=20data?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Closes the last gap in databasev2 1; gives databasev2 3 its "before". - `boot` mode: does NOTHING. WO_DATA replay runs before main, so a mode with no work measures replay plus a fixed startup - `replayseed N M`: N inserts + M updates — same live rows, longer log - `replay` leg: empty-store startup floor measured and SUBTRACTED, then two shapes timed, median of 3 boots each - premise check: updates must actually append WAL records, else the two shapes are one measurement and the penalty means nothing - WAL bytes = non-zero prefix, never file size (fallocate'd to 1 MiB) - per-record cost stored in NANOseconds: as us it rounded 5.5 and 5.3 to 6 and 5, too coarse for the number a checkpoint exists to improve - 148 checks, 0 failures; gate bites on a doctored ns_per_record Measured — same 20 000 live rows, different history: - 20 000 records: 980 035 B WAL, 110 ms replay, 5.5 us/record - 40 000 records: 1 960 035 B WAL, 211 ms replay, 5.3 us/record - 1.9x boot cost for an IDENTICAL dataset; per-record cost flat, so replay is linear in records not rows - extrapolated: 10M records ~55 s of boot, 100M ~9 min - databasev2 3 correction: it planned to use "22's aged-store replay numbers", which never existed — 22 proved restart correctness, never timed it - databasev2 3 hazard recorded: compaction rewrites the log and moves every record, so it invalidates every `resident: keys` offset — an arbitrary byte in a rewritten file, not stale-but-readable - databasev2 1 -> status: done Co-Authored-By: Claude Opus 5 (1M context) --- bench/baseline.json | 276 +++++++++++------- docs/examples/db-bench/main.wo | 51 +++- docs/plan/perf-targets.md | 27 ++ docs/stories/00-status.md | 22 +- docs/stories/databasev2/00-story.md | 2 +- .../databasev2/01-ram-ceiling-measurement.md | 34 ++- docs/stories/databasev2/03-wal-checkpoint.md | 33 ++- scripts/db-bench.py | 111 +++++++ 8 files changed, 432 insertions(+), 124 deletions(-) diff --git a/bench/baseline.json b/bench/baseline.json index 106f427..65d90c1 100644 --- a/bench/baseline.json +++ b/bench/baseline.json @@ -8,15 +8,15 @@ }, "ceiling.rows_recovered": { "dir": "lower", - "floor": 159828, + "floor": 159744, "tolerance_pct": 100, - "value": 39957 + "value": 39936 }, "durable.s1.mixread.ops_sec": { "dir": "higher", - "floor": 2239, + "floor": 2237, "tolerance_pct": 50, - "value": 8957 + "value": 8949 }, "durable.s1.mixread.p50us": { "dir": "lower", @@ -34,25 +34,25 @@ "dir": "higher", "floor": 248, "tolerance_pct": 50, - "value": 995 + "value": 994 }, "durable.s1.mixwrite.p50us": { "dir": "lower", - "floor": 828, + "floor": 820, "tolerance_pct": 50, - "value": 207 + "value": 205 }, "durable.s1.mixwrite.p99us": { "dir": "lower", - "floor": 868, + "floor": 872, "tolerance_pct": 50, - "value": 217 + "value": 218 }, "durable.s1.query.ops_sec": { "dir": "higher", - "floor": 215517, + "floor": 335570, "tolerance_pct": 50, - "value": 862068 + "value": 1342281 }, "durable.s1.query.p50us": { "dir": "lower", @@ -68,9 +68,9 @@ }, "durable.s1.read.ops_sec": { "dir": "higher", - "floor": 221827, + "floor": 347705, "tolerance_pct": 50, - "value": 887311 + "value": 1390820 }, "durable.s1.read.p50us": { "dir": "lower", @@ -86,27 +86,27 @@ }, "durable.s1.seed.ops_sec": { "dir": "higher", - "floor": 1128, + "floor": 1103, "tolerance_pct": 15, - "value": 4515 + "value": 4415 }, "durable.s1.seed.p50us": { "dir": "lower", - "floor": 832, + "floor": 828, "tolerance_pct": 15, - "value": 208 + "value": 207 }, "durable.s1.seed.p99us": { "dir": "lower", - "floor": 2180, + "floor": 2092, "tolerance_pct": 15, - "value": 545 + "value": 523 }, "durable.s1.write.ops_sec": { "dir": "higher", - "floor": 1141, + "floor": 1155, "tolerance_pct": 15, - "value": 4565 + "value": 4620 }, "durable.s1.write.p50us": { "dir": "lower", @@ -116,51 +116,51 @@ }, "durable.s1.write.p99us": { "dir": "lower", - "floor": 2256, + "floor": 1948, "tolerance_pct": 15, - "value": 564 + "value": 487 }, "durable.sN.mixread.ops_sec": { "dir": "higher", - "floor": 1117, + "floor": 1112, "tolerance_pct": 50, - "value": 4468 + "value": 4450 }, "durable.sN.mixread.p50us": { "dir": "lower", - "floor": 240, + "floor": 236, "tolerance_pct": 50, - "value": 60 + "value": 59 }, "durable.sN.mixread.p99us": { "dir": "lower", - "floor": 19900, + "floor": 13100, "tolerance_pct": 50, - "value": 4975 + "value": 3275 }, "durable.sN.mixwrite.ops_sec": { "dir": "higher", - "floor": 124, + "floor": 123, "tolerance_pct": 50, - "value": 496 + "value": 494 }, "durable.sN.mixwrite.p50us": { "dir": "lower", - "floor": 1104, + "floor": 1160, "tolerance_pct": 50, - "value": 276 + "value": 290 }, "durable.sN.mixwrite.p99us": { "dir": "lower", - "floor": 1928, + "floor": 2944, "tolerance_pct": 50, - "value": 482 + "value": 736 }, "durable.sN.query.ops_sec": { "dir": "higher", - "floor": 331125, + "floor": 287356, "tolerance_pct": 50, - "value": 1324503 + "value": 1149425 }, "durable.sN.query.p50us": { "dir": "lower", @@ -176,9 +176,9 @@ }, "durable.sN.read.ops_sec": { "dir": "higher", - "floor": 341064, + "floor": 192752, "tolerance_pct": 50, - "value": 1364256 + "value": 771010 }, "durable.sN.read.p50us": { "dir": "lower", @@ -190,31 +190,31 @@ "dir": "lower", "floor": 100, "tolerance_pct": 50, - "value": 1 + "value": 2 }, "durable.sN.seed.ops_sec": { "dir": "higher", - "floor": 1125, + "floor": 1142, "tolerance_pct": 50, - "value": 4502 + "value": 4571 }, "durable.sN.seed.p50us": { "dir": "lower", - "floor": 828, + "floor": 836, "tolerance_pct": 50, - "value": 207 + "value": 209 }, "durable.sN.seed.p99us": { "dir": "lower", - "floor": 2624, + "floor": 1916, "tolerance_pct": 50, - "value": 656 + "value": 479 }, "durable.sN.write.ops_sec": { "dir": "higher", - "floor": 1150, + "floor": 1010, "tolerance_pct": 50, - "value": 4600 + "value": 4040 }, "durable.sN.write.p50us": { "dir": "lower", @@ -224,9 +224,9 @@ }, "durable.sN.write.p99us": { "dir": "lower", - "floor": 2348, + "floor": 1996, "tolerance_pct": 50, - "value": 587 + "value": 499 }, "growth.available": { "dir": "lower", @@ -272,9 +272,9 @@ }, "growth.int.noswap.rss_kb": { "dir": "lower", - "floor": 23920, + "floor": 23968, "tolerance_pct": 100, - "value": 5980 + "value": 5992 }, "growth.int.swap.bytes_per_row": { "dir": "lower", @@ -314,9 +314,9 @@ }, "growth.int.swap.rss_kb": { "dir": "lower", - "floor": 23920, + "floor": 23984, "tolerance_pct": 100, - "value": 5980 + "value": 5996 }, "growth.text.noswap.bytes_per_row": { "dir": "lower", @@ -356,9 +356,9 @@ }, "growth.text.noswap.rss_kb": { "dir": "lower", - "floor": 41184, + "floor": 41216, "tolerance_pct": 100, - "value": 10296 + "value": 10304 }, "growth.text.swap.bytes_per_row": { "dir": "lower", @@ -398,15 +398,15 @@ }, "growth.text.swap.rss_kb": { "dir": "lower", - "floor": 41200, + "floor": 41216, "tolerance_pct": 100, - "value": 10300 + "value": 10304 }, "ram.s1.mixread.ops_sec": { "dir": "higher", "floor": 2236, "tolerance_pct": 50, - "value": 8945 + "value": 8947 }, "ram.s1.mixread.p50us": { "dir": "lower", @@ -424,7 +424,7 @@ "dir": "higher", "floor": 248, "tolerance_pct": 50, - "value": 993 + "value": 994 }, "ram.s1.mixwrite.p50us": { "dir": "lower", @@ -440,15 +440,15 @@ }, "ram.s1.msgrate.msgs_sec": { "dir": "higher", - "floor": 392834, + "floor": 419322, "tolerance_pct": 15, - "value": 3142677 + "value": 3354579 }, "ram.s1.query.ops_sec": { "dir": "higher", - "floor": 214592, + "floor": 324675, "tolerance_pct": 50, - "value": 858369 + "value": 1298701 }, "ram.s1.query.p50us": { "dir": "lower", @@ -460,13 +460,13 @@ "dir": "lower", "floor": 100, "tolerance_pct": 50, - "value": 2 + "value": 1 }, "ram.s1.read.ops_sec": { "dir": "higher", - "floor": 226860, + "floor": 332889, "tolerance_pct": 50, - "value": 907441 + "value": 1331557 }, "ram.s1.read.p50us": { "dir": "lower", @@ -478,19 +478,19 @@ "dir": "lower", "floor": 100, "tolerance_pct": 50, - "value": 2 + "value": 1 }, "ram.s1.seed.ops_sec": { "dir": "higher", - "floor": 273373, + "floor": 375939, "tolerance_pct": 15, - "value": 1093493 + "value": 1503759 }, "ram.s1.seed.p50us": { "dir": "lower", "floor": 100, "tolerance_pct": 15, - "value": 1 + "value": 0 }, "ram.s1.seed.p99us": { "dir": "lower", @@ -500,9 +500,9 @@ }, "ram.s1.write.ops_sec": { "dir": "higher", - "floor": 159134, + "floor": 272628, "tolerance_pct": 15, - "value": 636537 + "value": 1090512 }, "ram.s1.write.p50us": { "dir": "lower", @@ -514,55 +514,55 @@ "dir": "lower", "floor": 100, "tolerance_pct": 15, - "value": 3 + "value": 2 }, "ram.sN.mixread.ops_sec": { "dir": "higher", - "floor": 2239, + "floor": 2241, "tolerance_pct": 50, - "value": 8958 + "value": 8964 }, "ram.sN.mixread.p50us": { "dir": "lower", - "floor": 232, + "floor": 228, "tolerance_pct": 50, - "value": 58 + "value": 57 }, "ram.sN.mixread.p99us": { "dir": "lower", - "floor": 1032, + "floor": 1412, "tolerance_pct": 50, - "value": 258 + "value": 353 }, "ram.sN.mixwrite.ops_sec": { "dir": "higher", - "floor": 248, + "floor": 249, "tolerance_pct": 50, - "value": 995 + "value": 996 }, "ram.sN.mixwrite.p50us": { "dir": "lower", - "floor": 256, + "floor": 252, "tolerance_pct": 50, - "value": 64 + "value": 63 }, "ram.sN.mixwrite.p99us": { "dir": "lower", - "floor": 328, + "floor": 280, "tolerance_pct": 50, - "value": 82 + "value": 70 }, "ram.sN.msgrate.msgs_sec": { "dir": "higher", - "floor": 229885, + "floor": 214795, "tolerance_pct": 50, - "value": 1839080 + "value": 1718360 }, "ram.sN.query.ops_sec": { "dir": "higher", - "floor": 337837, + "floor": 331125, "tolerance_pct": 50, - "value": 1351351 + "value": 1324503 }, "ram.sN.query.p50us": { "dir": "lower", @@ -578,9 +578,9 @@ }, "ram.sN.read.ops_sec": { "dir": "higher", - "floor": 342935, + "floor": 340599, "tolerance_pct": 50, - "value": 1371742 + "value": 1362397 }, "ram.sN.read.p50us": { "dir": "lower", @@ -596,9 +596,9 @@ }, "ram.sN.seed.ops_sec": { "dir": "higher", - "floor": 295159, + "floor": 353606, "tolerance_pct": 50, - "value": 1180637 + "value": 1414427 }, "ram.sN.seed.p50us": { "dir": "lower", @@ -614,9 +614,9 @@ }, "ram.sN.write.ops_sec": { "dir": "higher", - "floor": 289017, + "floor": 290697, "tolerance_pct": 50, - "value": 1156069 + "value": 1162790 }, "ram.sN.write.p50us": { "dir": "lower", @@ -632,27 +632,27 @@ }, "randread.collapse_x": { "dir": "lower", - "floor": 1136, + "floor": 1172, "tolerance_pct": 100, - "value": 284 + "value": 293 }, "randread.overcap.filled_rss_kb": { "dir": "lower", - "floor": 25024, + "floor": 25680, "tolerance_pct": 100, - "value": 6256 + "value": 6420 }, "randread.overcap.ops_sec": { "dir": "higher", - "floor": 1669, + "floor": 1665, "tolerance_pct": 100, - "value": 6676 + "value": 6661 }, "randread.overcap.read_p50us": { "dir": "lower", - "floor": 548, + "floor": 556, "tolerance_pct": 100, - "value": 137 + "value": 139 }, "randread.overcap.read_p99us": { "dir": "lower", @@ -662,15 +662,15 @@ }, "randread.resident.filled_rss_kb": { "dir": "lower", - "floor": 54000, + "floor": 54080, "tolerance_pct": 100, - "value": 13500 + "value": 13520 }, "randread.resident.ops_sec": { "dir": "higher", - "floor": 475556, + "floor": 488424, "tolerance_pct": 100, - "value": 1902225 + "value": 1953697 }, "randread.resident.read_p50us": { "dir": "lower", @@ -683,5 +683,65 @@ "floor": 100, "tolerance_pct": 100, "value": 1 + }, + "replay.history.ms": { + "dir": "lower", + "floor": 844, + "tolerance_pct": 100, + "value": 211 + }, + "replay.history.ns_per_record": { + "dir": "lower", + "floor": 21068, + "tolerance_pct": 100, + "value": 5267 + }, + "replay.history.records": { + "dir": "lower", + "floor": 160000, + "tolerance_pct": 100, + "value": 40000 + }, + "replay.history.wal_bytes": { + "dir": "lower", + "floor": 7840140, + "tolerance_pct": 100, + "value": 1960035 + }, + "replay.history_penalty_x": { + "dir": "lower", + "floor": 100, + "tolerance_pct": 100, + "value": 1.9 + }, + "replay.inserts.ms": { + "dir": "lower", + "floor": 444, + "tolerance_pct": 100, + "value": 111 + }, + "replay.inserts.ns_per_record": { + "dir": "lower", + "floor": 22120, + "tolerance_pct": 100, + "value": 5530 + }, + "replay.inserts.records": { + "dir": "lower", + "floor": 80000, + "tolerance_pct": 100, + "value": 20000 + }, + "replay.inserts.wal_bytes": { + "dir": "lower", + "floor": 3920140, + "tolerance_pct": 100, + "value": 980035 + }, + "replay.startup_ms": { + "dir": "lower", + "floor": 100, + "tolerance_pct": 100, + "value": 3 } } \ No newline at end of file diff --git a/docs/examples/db-bench/main.wo b/docs/examples/db-bench/main.wo index fa08f87..9b946b0 100644 --- a/docs/examples/db-bench/main.wo +++ b/docs/examples/db-bench/main.wo @@ -467,7 +467,7 @@ fn usage() -> Int { print_err("usage: db-bench "); print_err(" all N | seed N | read N | query N | write N | wal N"); print_err(" mix N C | msgrate N | growth N int|text | growth-verify"); - print_err(" randread N R"); + print_err(" randread N R | replayseed N M | boot"); print_err(" verify | verify-acked M"); return 2; } @@ -531,6 +531,41 @@ fn self_rss_kb() -> Int { -- larger than RAM. No RNG in the language and none needed: i*2654435761 mod n -- is a Weyl sequence, deterministic and spread, so the two legs read the SAME -- key order and only residency differs. +-- databasev2 1, for iteration 3: the replay "before". +-- +-- `boot` does NOTHING. That is the point: with WO_DATA set the runtime replays +-- the whole WAL before main runs, so the process's wall time IS the replay cost +-- plus a fixed startup. Any mode that touches rows would mix its own work into +-- the number. +fn boot_mode() -> Int { + print("booted"); + return 0; +} + +-- Build a store with N live rows and N+M total WAL records: M updates on top of +-- N inserts. The live dataset is IDENTICAL for any M -- only the history grows. +-- That is iteration 3's whole case: with no checkpoint, boot replays HISTORY, +-- not data, so a long-lived row that has been updated a thousand times costs a +-- thousand records at every boot forever. +fn replayseed_mode(n: Int, m: Int) -> Int { + let bref = insert Bucket { tag: "replay" }; + let i = 1; + while i <= n { + insert Item { k: i, v: item_v(i), bucket: bref }; + i = i + 1; + } + let j = 0; + while j < m { + let key = 1 + (j * 2654435761) % n; + for r in from x in Item where x.k == key take 1 select x { + r.v = r.v + 1; + } + j = j + 1; + } + print("replayseeded ${n} ${m}"); + return 0; +} + fn randread_mode(n: Int, r: Int) -> Int { let bref = insert Bucket { tag: "randread" }; let i = 1; @@ -648,6 +683,9 @@ fn main(args: multi Text) -> Int { if args[0] == "growth-verify" { return growth_verify(); } + if args[0] == "boot" { + return boot_mode(); + } if len(args) < 2 { return usage(); } @@ -686,6 +724,17 @@ fn main(args: multi Text) -> Int { } return growth_mode(n, args[2]); } + if args[0] == "replayseed" { + if len(args) < 3 { + return usage(); + } + let mm = parse_int(args[2]); + if mm == nil or mm < 0 { + print_err("db-bench: must be zero or more"); + return 2; + } + return replayseed_mode(n, mm); + } if args[0] == "randread" { if len(args) < 3 { return usage(); diff --git a/docs/plan/perf-targets.md b/docs/plan/perf-targets.md index dfb5bec..a21870a 100644 --- a/docs/plan/perf-targets.md +++ b/docs/plan/perf-targets.md @@ -189,3 +189,30 @@ read path rather than inherit this figure. Gated as `db-bench`'s `randread` leg, which gates the **ratio** — the absolute reads/sec of the over-cap half is the box's swap device, while the factor between two runs differing only in their cap is the engine's. + +### Replay: boot cost tracks history, not data + +Two stores with the **same 20 000 live rows** and different history lengths. +Process startup (3.5 ms, empty store) is subtracted, so these are replay: + +| Shape | Records | WAL used | Replay | Per record | +| --- | --- | --- | --- | --- | +| N inserts | 20 000 | 980 035 B | **110 ms** | 5.5 µs | +| N inserts + N updates | 40 000 | 1 960 035 B | **211 ms** | 5.3 µs | + +**1.9× the boot cost for an identical dataset.** Per-record cost is flat, so +replay is linear in **records**, not rows. An update appends a record and nothing +ever collapses it, so a row updated a thousand times costs a thousand records at +every boot, forever. + +Extrapolated at 5.5 µs/record: **10M records ≈ 55 s of boot, 100M ≈ 9 minutes.** + +This is the "before" databasev2 3 lacked — `bench/baseline.json` carried no +replay, restart, boot or recovery metric at all, because iteration 22 proved +restart *correctness* and never timed it. Gated as `db-bench`'s `replay` leg: +`replay.inserts.*`, `replay.history.*`, `replay.history_penalty_x`. Per-record +cost is stored in **nanoseconds** — as µs it rounded 5.5 and 5.3 to 6 and 5, +which is too coarse for the one number a checkpoint is meant to improve. + +WAL bytes are measured as the file's **non-zero prefix**, never its size: shard +WALs are `fallocate`'d to 1 MiB, so an empty store reports 1048576. diff --git a/docs/stories/00-status.md b/docs/stories/00-status.md index a47501b..cddef50 100644 --- a/docs/stories/00-status.md +++ b/docs/stories/00-status.md @@ -76,8 +76,8 @@ Int-only `Item`; `growth N int|text` in the db-bench sample, reading its OWN the value *at* a boundary; `growth-verify`, which asserts the survivor of a crash is a contiguous intact prefix; and two harness legs — four footprint legs under a rootless cgroup v2 cap, a `ceiling` leg that deliberately dies at the cap -and then replays, and a `randread` leg that reads an oversized table randomly. -133 checks, 0 failures. +and then replays, a `randread` leg that reads an oversized table randomly, and a +`replay` leg that times boot against history length. 148 checks, 0 failures. **Key findings (measured, not asserted):** per-row footprint is **96.5–100 B** Int-only and **320.6–324 B** text-heavy — **3.3×**, not the "order of magnitude" @@ -92,7 +92,10 @@ collapse": 900 000 rows inside a 64 MiB cap with swap finished in **148 s against 150 s uncapped** — ~1%, on a real disk swap file with no zram. Also measured: **ack-after-fsync holds through an OOM kill** — ~40 000 rows came back as an intact prefix, no holes, not read as corruption. And the pattern the swap -leg was missing: **random reads over an oversized table collapse 273×.** +leg was missing: **random reads over an oversized table collapse 273×.** Plus +replay: **≈5.5 µs per WAL record**, and **1.9× the boot cost for an identical +live dataset** once each row has been updated once (110 → 211 ms for the same +20 000 rows) — boot replays **history, not data**. **Learned:** an append-mostly workload never re-touches its cold pages, so swap costs it nothing — and the opposite pattern was then measured on the same day. @@ -118,8 +121,15 @@ still NOT delivered — `bench/baseline.json` times no replay. number bounds demand-paged anonymous memory through swap (4 KiB per fault, no readahead); `pread` through the page cache should beat it, and **the entire value of `resident: keys` rests on how much** — if it is not materially better than -swapping, the design buys nothing the kernel was not already doing. Still absent: -a replay baseline for iteration 3. +swapping, the design buys nothing the kernel was not already doing. + +Iteration 3 now HAS its before, and a correction: it planned to use "22's +aged-store replay numbers", which never existed — 22 proved restart correctness +and never timed it. Also recorded there, before it could be rediscovered late: +**compaction invalidates every `resident: keys` offset**, since it rewrites the +log and moves every record. Not stale-but-readable — an arbitrary byte in a +rewritten file. So compaction cannot be a pure file operation that ignores +in-memory table state. **`.dev/reference` used:** none. Sources were the kernel's own interfaces — cgroup v2 `memory.max`/`memory.swap.max`, `/proc/self/status`, `/proc/swaps` and @@ -693,7 +703,7 @@ the language arc as v1 history. | # | Iteration | State | | --- | --- | --- | -| 1 | [RAM ceiling: measure the breaking point](databasev2/01-ram-ceiling-measurement.md) | 🔄 **MEASURED 2026-08-27** — `readiness: ready`, `status: in-progress` (iteration 3 replay baseline still undelivered), forks settled, harness landed (**133 checks**). Footprint **96.5–100 B/row** Int vs **320.6–324 B/row** text = **3.3×** (not the "order of magnitude" three docs claimed), read as median-of-marginals because doublings swing a two-point slope 2×. **Both predicted exits were wrong:** table storage has no checked ceiling and is **SIGKILLed** (overcommit lets `malloc` succeed, kernel kills on page touch), and swap is not latency collapse — 900k rows finished **148 s capped-with-swap vs 150 s uncapped**, ~1%, returning 0 while serving from disk. **Ack-after-fsync survives an OOM kill:** ~40 000 rows recovered as an intact prefix, gated as the `ceiling` leg. Also measured: **random reads over an oversized table collapse 273×** (1.85M vs 6 771 reads/s, p99 1 µs vs 487 µs) — so the two access patterns sit ~270× apart under the same pressure, and departure is a **step, not a curve**. Outstanding: iteration 3's replay baseline. Iteration 2's budget dependency is **removed, not satisfied** — there is no "swap onset" to derive it from | +| 1 | [RAM ceiling: measure the breaking point](databasev2/01-ram-ceiling-measurement.md) | ✅ **MEASURED 2026-08-27** — `readiness: ready`, `status: done`; forks settled, harness landed (**148 checks**). Footprint **96.5–100 B/row** Int vs **320.6–324 B/row** text = **3.3×** (not the "order of magnitude" three docs claimed), read as median-of-marginals because doublings swing a two-point slope 2×. **Both predicted exits were wrong:** table storage has no checked ceiling and is **SIGKILLed** (overcommit lets `malloc` succeed, kernel kills on page touch), and swap is not latency collapse — 900k rows finished **148 s capped-with-swap vs 150 s uncapped**, ~1%, returning 0 while serving from disk. **Ack-after-fsync survives an OOM kill:** ~40 000 rows recovered as an intact prefix, gated as the `ceiling` leg. Also measured: **random reads over an oversized table collapse 273×** (1.85M vs 6 771 reads/s, p99 1 µs vs 487 µs) — so the two access patterns sit ~270× apart under the same pressure, and departure is a **step, not a curve**. Replay measured too: **≈5.5 µs/record, 1.9× history penalty** (10M records ≈ 55 s of boot) — iteration 3's missing "before", now gated. Iteration 2's budget dependency is **removed, not satisfied** — there is no "swap onset" to derive it from | | 2 | [per-table storage: `durable` and `resident`](databasev2/02-table-storage-modes.md) | 🔄 **the language enrichment — the `durable` half is DONE and usable.** Two optional `@table` keys, `durable: true\|false` and `resident: all\|keys`, both defaulting to today's behaviour (all 28 existing declarations compile unchanged, no golden moved). Landed: the grammar, WO-E224 (a durable `ref` into a volatile table is refused), `.wob` v7 carrying both properties in spare `flags` bits, `durable: false` actually skipping the WAL (measured: 50 inserts → 1500 bytes durable, **0** volatile) with a mode-mismatch startup refusal, plus offset capture and read-a-row-from-an-offset. Outstanding: 5c/5d (the id→offset map and rewiring `wo_row_ptr`'s 11 call sites, slab scans and `@unique`/FK across the boundary — not yet written up), the two runtime refusals, and closeout. [spec](../superpowers/specs/2026-08-26-table-residency-design.md) · [plan](../superpowers/plans/2026-08-26-table-residency.md) | | 3 | [WAL checkpoint](databasev2/03-wal-checkpoint.md) *(was 32)* | ⬜ snapshot + truncate: disk reclaimed, replay bounded | | 4 | [io_uring group commit](databasev2/04-io-uring-commit.md) *(was 23)* | ⬜ **`readiness: ready` — the one startable iteration in the repo** (four forks confirmed settled 2026-08-20). Close the 66× gap iteration 22 measured (durable 4.5k vs ram 297k inserts/s) | diff --git a/docs/stories/databasev2/00-story.md b/docs/stories/databasev2/00-story.md index 405f69e..278eb17 100644 --- a/docs/stories/databasev2/00-story.md +++ b/docs/stories/databasev2/00-story.md @@ -140,7 +140,7 @@ before its mechanism existed; the history is in | # | Iteration | Delivers | Needs | | --- | --- | --- | --- | -| 1 | [RAM ceiling: measure the breaking point](01-ram-ceiling-measurement.md) | 🔄 **measured 2026-08-27**: footprint per shape (3.3× apart), the two silent exits (SIGKILL vs swap-serving-from-disk at ~uncapped speed), and ack-after-fsync surviving an OOM kill. Also measured: the **273× random-read collapse** over an oversized table. Outstanding: a replay baseline | nothing; extends iteration 22's harness | +| 1 | [RAM ceiling: measure the breaking point](01-ram-ceiling-measurement.md) | 🔄 **measured 2026-08-27**: footprint per shape (3.3× apart), the two silent exits (SIGKILL vs swap-serving-from-disk at ~uncapped speed), and ack-after-fsync surviving an OOM kill. Also measured: the **273× random-read collapse** over an oversized table, and replay at **≈5.5 µs/record with a 1.9× history penalty** — iteration 3's "before" | nothing; extends iteration 22's harness | | 2 | [per-table storage](02-table-storage-modes.md) | the grammar: `durable: true\|false` and `resident: all\|keys`, per table, replacing the global `WO_DATA` all-or-nothing. **In progress — the `durable` half is done** | 1 for the budget default | | 3 | [WAL checkpoint](03-wal-checkpoint.md) *(was language 32)* | snapshot + truncate: disk reclaimed, replay bounded | 4 composes | | 4 | [io_uring group commit](04-io-uring-commit.md) *(was language 23)* | close the 66× durable/RAM write gap (4.5k vs 297k inserts/s) | the arc (landed) | diff --git a/docs/stories/databasev2/01-ram-ceiling-measurement.md b/docs/stories/databasev2/01-ram-ceiling-measurement.md index 5018cfc..3abfc9a 100644 --- a/docs/stories/databasev2/01-ram-ceiling-measurement.md +++ b/docs/stories/databasev2/01-ram-ceiling-measurement.md @@ -1,7 +1,7 @@ --- track: databasev2 iteration: "1" -status: in-progress +status: done readiness: ready --- @@ -114,10 +114,10 @@ workload. Reading *randomly* across a table larger than the cap collapses | footprint metric = **median of marginals**, doublings counted separately | ✅ | | `ceiling` leg: dies at the cap, then replay must be intact | ✅ gated | | `randread` leg: control vs over-cap, same key order | ✅ gated | -| baseline + tolerance policy | ✅ 133 checks; footprint at ±10%, kill-timing metrics at ±100% | +| baseline + tolerance policy | ✅ 148 checks; footprint at ±10%, kill-timing metrics at ±100% | | `perf-targets.md` §5 | ✅ | | **resident-footprint fraction for [iteration 2](02-table-storage-modes.md)** | ⬜ **not delivered — the premise it rested on is false**, see Outstanding | -| **replay/restart baseline for [iteration 3](03-wal-checkpoint.md)** | ⬜ not delivered | +| `boot` + `replayseed N M` + the `replay` leg — [iteration 3](03-wal-checkpoint.md)'s "before" | ✅ **≈5.5 µs/record, 1.9× history penalty** | | `randread N R` + the `randread` leg — random reads over an oversized table | ✅ **273x collapse measured** | ## Measured @@ -174,6 +174,24 @@ while swap-in does not. **That is a hypothesis, not a result.** The honest reading is that 273× bounds what *swapping* costs, and iteration 2 must measure its own read path rather than inherit this number. +Replay, and it is iteration 3's whole case — same live dataset, different +history length: + +| Shape | Records | WAL | Replay | Per record | +| --- | --- | --- | --- | --- | +| N inserts | 20 000 | 980 035 B | **110 ms** | 5.5 µs | +| N inserts + N updates | 40 000 | 1 960 035 B | **211 ms** | 5.3 µs | + +**20 000 live rows either way. 1.9× the boot cost.** Per-record cost is flat +(5.5 vs 5.3 µs), so replay is linear in **records, not rows** — boot replays +*history*. A row updated a thousand times costs a thousand records at every boot, +forever, because nothing ever collapses them. Process startup (3.5 ms on an +empty store) is subtracted, so these are replay, not spawn. + +Extrapolated at 5.5 µs/record: **10M records ≈ 55 s of boot, 100M ≈ 9 minutes.** +That is the number [iteration 3](03-wal-checkpoint.md) exists to bound, and it +had no "before" until now. + **The finding that matters most is the swap leg succeeding.** It did not fail, did not warn, and returned 0. A deployment in that state looks healthy while serving from disk. That is the exit with no error signal, and it is why @@ -211,11 +229,15 @@ Met: the degradation is quantified. ✅ **273× throughput, ~480× p99**, both legs reading the same key order with all reads resolving. This closes the gap the swap leg left, and it is the pattern `resident: keys` creates. +- **Given** a store with history, **when** it boots, **then** replay cost is + recorded so iteration 3 has a before. ✅ **≈5.5 µs/record**, flat across + shapes, and **1.9× boot cost for an identical dataset** once each row has been + updated once. Startup subtracted via an empty store. Outstanding: - **The resident-footprint fraction for iteration 2's budget default. NOT - delivered, and the premise is false.** It was to be derived from the + delivered, and the premise is false** — a finding, not a gap. It was to be derived from the swap-onset point — but there is no onset: swap-off jumps straight from working to SIGKILL, and swap-on shows no degradation to detect an onset in. **Iteration 2 must pick its budget on other grounds** (host RAM fraction, or @@ -228,9 +250,7 @@ Outstanding: approach their 512 MiB cap, but the departure itself is measured by the `randread` leg as a **step, not a curve** — 1 µs resident, 487 µs over-cap. There is no gentle departure to find; residency is close to binary. -- **A replay/restart baseline for iteration 3.** Not delivered; `growth` exercises - `WO_DATA` but nothing times replay. Cheap to add, still absent from - `bench/baseline.json`. +- Nothing else. Both remaining gaps closed 2026-08-27. ## Out Of Scope diff --git a/docs/stories/databasev2/03-wal-checkpoint.md b/docs/stories/databasev2/03-wal-checkpoint.md index c93b0bc..74226ee 100644 --- a/docs/stories/databasev2/03-wal-checkpoint.md +++ b/docs/stories/databasev2/03-wal-checkpoint.md @@ -56,6 +56,14 @@ chain: 6 - **Given** the iteration-22 restart benchmark re-run after checkpoint lands, **when** replay time is measured on an aged store, **then** the bounded-replay improvement is recorded as a before/after delta. + **The "before" now EXISTS** (databasev2 1, 2026-08-27): `db-bench`'s + `replay` leg measures **≈5.5 µs per WAL record**, and — the number + this iteration is actually about — **1.9× the boot cost for an + identical live dataset** once the same rows have been updated once + each (20 000 rows: 110 ms at 20 000 records, 211 ms at 40 000). Boot + cost tracks **history, not data**, which is exactly what a checkpoint + collapses. Metrics: `replay.inserts.*`, `replay.history.*`, + `replay.history_penalty_x`. - **Given** writes arriving while a checkpoint runs (the DB actor serializes statements; the checkpoint must not stall them beyond the stated budget), **when** the mixed load completes, **then** every ack @@ -101,6 +109,29 @@ Forks the spec must settle: ## Proposed Solution Brainstorm → spec → plan after 23 lands (the write path it composes -with) using 22's aged-store replay numbers as the policy input; extend +with). **Correction (2026-08-27):** this said "using 22's aged-store +replay numbers as the policy input", but iteration 22 produced no such +numbers — it proved restart *correctness* and never timed it, and +`bench/baseline.json` carried zero replay metrics until databasev2 1 +added them. The policy input is the `replay` leg's ≈5.5 µs/record and +its 1.9× history penalty. Extend `04-db-binding.md`'s WAL section with the snapshot format the way the record grammar is documented today. +## Hazard: compaction invalidates every `resident: keys` offset + +Surfaced while refining this iteration and recorded here so it is not +rediscovered late. [Iteration 2](02-table-storage-modes.md)'s +`resident: keys` stores a **WAL byte offset per row** and reads the row +back with `pread` at that offset. Compaction — whichever of the two +shapes below wins — **rewrites the log and moves every record**, so +every stored offset becomes wrong. Not stale-but-readable: pointing at +an arbitrary byte in a rewritten file, which is a correctness fault, +not a performance one. + +So the two iterations are coupled and the coupling has to be designed, +not discovered: either compaction rebuilds the offset map as it +rewrites (it knows both addresses, so this is the cheap direction), or +the snapshot persists the map and compaction is forbidden while any +`resident: keys` table is live. **The first is almost certainly right**, +but it means compaction cannot be written as a pure file operation that +ignores in-memory table state. diff --git a/scripts/db-bench.py b/scripts/db-bench.py index 83fb69a..6c50b83 100755 --- a/scripts/db-bench.py +++ b/scripts/db-bench.py @@ -234,6 +234,7 @@ def tolerance_for(key): if key.startswith("growth."): return 100 if key.startswith("ceiling."): return 100 if key.startswith("randread."): return 100 + if key.startswith("replay."): return 100 if ".mixread." in key or ".mixwrite." in key: return 50 if ".sN." in key: return 50 if ".read." in key or ".query." in key: return 50 @@ -379,6 +380,8 @@ RAND_N = 60000 if QUICK else 200000 RAND_R = 20000 if QUICK else 40000 RAND_CAP_MB = 6 if QUICK else 14 # over-cap: holds roughly a third of the rows RAND_FIT_MB = 256 # control: same mechanism, cap simply does not bind +REPLAY_N = 20000 if QUICK else 100000 +REPLAY_BOOTS = 3 # median of 3; boot is timed, so noise matters def ceiling(metrics): """The ceiling itself, and the durability claim across it. @@ -513,6 +516,113 @@ def randread(metrics): f"({res['resident']} -> {res['overcap']} reads/sec)") + +def wal_used(data_dir): + """Bytes actually written across the store's WAL files. + + The non-zero prefix, NOT the file size: shard WALs are fallocate'd to + 1 MiB up front, so getsize reports 1048576 for an empty store and proves + nothing. Same reason scripts/residency-accept.sh measures it this way.""" + total = 0 + for name in sorted(os.listdir(data_dir)): + with open(os.path.join(data_dir, name), "rb") as f: + total += len(f.read().rstrip(b"\x00")) + return total + + +def time_boot(data_dir): + """Median wall-clock ms of `boot`, which does nothing at all. + + With WO_DATA set the runtime replays the entire WAL BEFORE main runs, so a + mode that does no work measures replay plus a fixed process startup. Any + mode that touched rows would fold its own cost in. Median of REPLAY_BOOTS + because this is wall-clock on a shared box.""" + env = dict(os.environ); env["WO_DATA"] = data_dir + samples = [] + for _ in range(REPLAY_BOOTS): + t0 = time.monotonic() + pr = subprocess.run([BIN, "boot"], stdout=subprocess.DEVNULL, + stderr=subprocess.DEVNULL, env=env, timeout=900) + if pr.returncode != 0: + return None + samples.append((time.monotonic() - t0) * 1000.0) + return sorted(samples)[len(samples) // 2] + + +def replay(metrics): + """The replay baseline databasev2 3 has no "before" for. + + bench/baseline.json carried zero metrics for replay, restart, boot or + recovery. Iteration 22 proved restart CORRECTNESS; it never timed it, so + iteration 3's "bounded replay" claim had nothing to measure against. + + Two shapes with the SAME live dataset and different history lengths: + - inserts: N inserts, N records + - history: N inserts + N updates, 2N records, same N live rows + The live data is identical; only the log is longer. That is iteration 3's + entire case: with no checkpoint, boot replays HISTORY rather than DATA, so a + row updated a thousand times costs a thousand records at every boot, + forever. history_penalty_x is the headline -- the boot cost of history that + a checkpoint would collapse. + + Startup is subtracted using an empty store, so the reported ms is replay, + not process spawn.""" + empty = os.path.join(ROOT, "bench", f"tmp.{os.getpid()}.replay.empty") + shutil.rmtree(empty, ignore_errors=True); os.makedirs(empty, exist_ok=True) + base_ms = time_boot(empty) + shutil.rmtree(empty, ignore_errors=True) + if base_ms is None: + bad("replay: empty-store boot failed", "cannot establish the startup floor") + return + metrics["replay.startup_ms"] = int(round(base_ms)) + ok(f"replay: empty-store startup floor {base_ms:.1f} ms (subtracted below)") + + res = {} + for legname, updates in (("inserts", 0), ("history", REPLAY_N)): + data = os.path.join(ROOT, "bench", f"tmp.{os.getpid()}.replay.{legname}") + shutil.rmtree(data, ignore_errors=True); os.makedirs(data, exist_ok=True) + env = dict(os.environ); env["WO_DATA"] = data + sr = subprocess.run([BIN, "replayseed", str(REPLAY_N), str(updates)], + stdout=subprocess.DEVNULL, stderr=subprocess.STDOUT, + env=env, timeout=900) + key = f"replay.{legname}" + if sr.returncode != 0: + bad(f"{key}: seed failed", f"rc={sr.returncode}") + shutil.rmtree(data, ignore_errors=True); return + wal = wal_used(data) + boot_ms = time_boot(data) + shutil.rmtree(data, ignore_errors=True) + if boot_ms is None: + bad(f"{key}: boot failed", "replay did not complete") + return + records = REPLAY_N + updates + rep_ms = max(boot_ms - base_ms, 0.0) + metrics[f"{key}.ms"] = int(round(rep_ms)) + metrics[f"{key}.records"] = records + metrics[f"{key}.wal_bytes"] = wal + # NANOseconds, integer: us_per_record rounded 5.5 and 5.3 to 6 and 5, + # which is too coarse for the one number iteration 3 exists to improve + metrics[f"{key}.ns_per_record"] = int(round(rep_ms * 1e6 / records)) + res[legname] = (rep_ms, wal, records) + ok(f"{key}: {rep_ms:.0f} ms replaying {records} records " + f"({rep_ms*1000.0/records:.1f} us/record), WAL {wal} B") + + ins_ms, ins_wal, _ = res["inserts"] + his_ms, his_wal, _ = res["history"] + # premise check: an update MUST cost a WAL record, or the two shapes are + # the same measurement and history_penalty_x means nothing + if his_wal < ins_wal * 1.5: + bad("replay: updates are not appending WAL records", + f"history WAL {his_wal} B vs inserts {ins_wal} B -- expected ~2x") + return + ok(f"replay: {REPLAY_N} updates doubled the log ({ins_wal} -> {his_wal} B) " + f"with the live row count unchanged") + penalty = his_ms / max(ins_ms, 1.0) + metrics["replay.history_penalty_x"] = round(penalty, 2) + ok(f"replay: identical dataset, {penalty:.2f}x the boot cost from history alone " + f"({ins_ms:.0f} -> {his_ms:.0f} ms) -- what a checkpoint would collapse") + + def main(): # --check : gate-only evaluation of a recorded run — the # gate-bites smoke doctors a copy and this mode must FAIL on it @@ -528,6 +638,7 @@ def main(): growth(metrics) ceiling(metrics) randread(metrics) + replay(metrics) os.makedirs(RESULTS_DIR, exist_ok=True) stamp = time.strftime("%Y%m%d-%H%M%S") out = os.path.join(RESULTS_DIR, f"run-{stamp}{'-quick' if QUICK else ''}.json")