# Bucket commit log spike: real GCS, phase 0 Phase 0 of the [bucket commit log plan](/plans/bucket-commit-log.md): the log protocol simulated against real GCS from GKE pods, measured against the plan's gate. Audience: demarkus maintainers. Run 2026-10-02. Verdict: **the gate passes**, with two design changes (stage two batches ahead; size the shard count to the world) and a latency gate restated in milliseconds. ## Setup - Harness: a throwaway Go binary (`demarkus-logspike`) with setup, run and teardown scripts, built on the `benchmarks` worktree and deleted after the run; it was never committed. It simulated slots, blobs, checkpoints and replicas with synthetic objects using the same GCS settings as `server/blob/gcs` (JSON API client, SDK retries off, single-request uploads with CRC32C, `DoesNotExist` creates). It never ran `bucketstore`, so member builds and index work cost nothing here. - Raw evidence: 49 JSON reports under `tools/benchmarks/artifacts/logspike-2026-10-02/` (ignored). - Cluster `demarkus` (zonal, northamerica-northeast2-a), a tainted scratch pool of 2 n2-standard-8 nodes, pods limited to 4 vCPU and 10 GiB. Scratch buckets in northamerica-northeast2, Standard, soft delete off. All removed afterwards. - Shapes: 2 KB bodies, 1.2 KB slot entries, 850 byte shard entries, 3 KB of section text per document, 4096 shards. Batches form from whatever is queued, with no timer. - To fit the time, the last third of the runs went in three lanes on three separate buckets at once; lanes shared nodes, so cold start and gate timings may carry some CPU contention. ## Gate 10 minutes open-loop at 250 writes/s on a 1,000,000-document world, batch limit 16, two batches staged ahead, with a replica following and reading every changed body, and a compactor writing a full 1M checkpoint every minute. | Criterion | Result | Pass | |---|---|---| | At least 200 writes/s sustained for 10 min | 250/s; slowest 10 s window 245/s; 150,012 writes | yes | | No lost writes | verify walked 14,597 slots: 0 lost, 0 gaps, 0 chain breaks, 0 duplicates | yes | | 429s absorbed by bounded retry | no 429 or 5xx on any slot or blob create | yes | | Write latency | p50 143 ms, p99 196 ms, p999 319 ms; median 10 s window p99 178 ms, worst 429 ms | yes, at the restated bound below | | Cold start within the bound set before the run (15 s at 1M, 3 s at 100k, heap under 1.5 GiB) | 1M: 7.6 s after the gate (10.3 s on a contended node), heap 1.04 GiB. 100k: 4.2 s | 1M yes; 100k no, see shard count | ## c and read costs | Operation (low concurrency) | p50 | p99 | |---|---|---| | Create, 1.2 KB or 4 KB | 39.5 ms | 50 ms | | Get, 1.2 KB | 18 ms | 37 ms | | HEAD or GET of a missing name (tip check) | 11 to 14 ms | 18 to 24 ms | Under load (16 parallel blob creates plus a slot create) creates run 45 to 52 ms at p50, about 60 ms at p90. A path read pays one tip check, about 14 ms. ## Slot chain Closed loop, one store, 2 minute runs; every run verified with 0 lost writes. | Batch | Staging | Writers | Writes/s | p50 | p99 | |---|---|---|---|---|---| | 16 | sequential | 64 | 179 | 350 ms | 573 ms | | 16 | sequential | 256 | 177 | 1446 ms | 1616 ms | | 16 | 1 ahead | 64 | 256 | 247 ms | 313 ms | | 16 | 1 ahead | 256 | 291 | 874 ms | 1117 ms | | 16 | 2 ahead | 64 | 352 | 179 ms | 220 ms | | 16 | 2 ahead | 256 | 355 | 716 ms | 984 ms | | 16 | 3 ahead | 64 | 330 | 188 ms | 256 ms | | 32 | sequential | 64 | 289 | 220 ms | 288 ms | | 32 | sequential | 256 | 309 | 824 ms | 897 ms | | 32 | 1 ahead | 64 | 470 | 134 ms | 192 ms | | 32 | 1 ahead | 256 | 512 | 497 ms | 597 ms | - With one batch staged ahead, the critical path is staging, not the slot: the next batch is ready only when the slowest of its 16 parallel blob creates finishes, about the p94 create latency (~60 ms) against a slot create of ~45 ms. A local dry run with injected latency reproduced this exactly. - Two batches ahead takes staging off the critical path: batch 16 reaches about 355/s, close to the batch limit divided by c. Three ahead adds nothing. - Closed-loop latency is mostly queueing (writers divided by throughput). ## Latency without a queue Open loop, one store, batch 16, two ahead, 1 minute runs, 0 lost. | Writes/s | Mean batch | p50 | p99 | p999 | |---|---|---|---|---| | 100 | 3.9 | 134 ms | 173 ms | 214 ms | | 200 | 8.4 | 147 ms | 200 ms | 249 ms | | 250 (gate) | 10.3 | 143 ms | 196 ms | 319 ms | | 300 | 13.3 | 155 ms | 306 ms | 354 ms | A write waits for batch formation, its blob create, the slot already in flight, and its own slot create: about 3.5c at p50 and 5c at p99, not the 1c to 3c the plan projected. ## Several stores racing Closed loop, 64 writers per store, batch 16, one ahead, 1 minute runs; the third store of the 3-store runs shared a pod with the second. Every run verified against every store's acks: 0 lost, 0 gaps, 0 chain breaks. | Stores | Yield | Total writes/s | Per store | Per store p99 | |---|---|---|---|---| | 2 | off | 290 | 100, 190 | 5.5 s, 2.9 s | | 2 | 30 ms | 255 | 136, 119 | 1.6 s, 1.6 s | | 3 | off | 294 | 51, 92, 151 | 6.5 s, 3.4 s, 2.4 s | | 3 | 30 ms | 272 | 95, 99, 78 | 3.0 s, 2.2 s, 2.5 s | - Total throughput holds at the single-store level; stores trade slots, they do not add contention cost. - Without yield, one store starves the others. A 30 ms yield after a win, while another store's ID was seen in the last 3 s, evens throughput and cuts the worst p99 from 6.5 s to 3 s, for about 10% of throughput. - About half of all slot attempts lose with 2 or 3 stores; each loss costs one create and one read. ## Bucket rate and the head baseline - Ramp of open-loop creates in 30 s steps to 1200/s, on a bucket warmed by a checkpoint write: no 429 and no 5xx at any step. Latency is the signal instead: p50 stays at 38 to 41 ms through 800/s and doubles to about 91 ms at 1000/s and above. A cold bucket may throttle sooner; it was not tested. - Checkpoint writes reached 1123 creates/s on a fresh bucket without a 429. - Today's head CAS, paced at 1.5 s: exactly 0.67 commits/s. Three unpaced writers on one head: 1.2 commits/s, with 552 of 692 attempts throttled (429) and 68 conflicts. ## Checkpoints and cold start | | 100,000 docs | 1,000,000 docs | |---|---|---| | Checkpoint, shards and root | 86 MB | 863 MB; 6 to 13 s per write, 10 writes during the gate, 0 failures | | Checkpoint with section segments | 395 MB in 7.3 s | 3.9 GB in 18.4 s | | Cold start: list, root, 4096 shards, 1024 slots | 4.2 s | 7.6 s (10.3 s contended) | | Index heap after load | 106 MiB | 1.04 GiB | | Replay of 1024 slots (10,504 entries) | | 0.9 s | | Section segments load | 308 MB in 5.7 s | 3.08 GB in 20.7 s | - At 100,000 documents the 4096 shards are about 21 KB each, so cold start is bound by object count (4096 gets, 64 at a time) rather than bytes, and misses the 3 s bound. - During the gate, 11 of 60 ten-second windows had a writer p99 above 230 ms; only one of them overlapped a compactor run, so the 60 s compactor shows no clear effect on write latency. ## Replica apply and body catch-up During the gate the follower applied every slot (14,591 slots, 250 entries/s) by reading the next name until not found: slot get p50 20 ms, apply lag p99 166 ms. With 16 workers reading every changed body, body lag p99 was 191 ms with no backlog, well inside the 1 s search bound. ## What this changes in the plan - **c:** 40 ms p50 and 50 ms p99 at low concurrency, 45 to 52 ms under load. The plan's 40 ms case holds. - **Stage two batches ahead.** Pipelining with one speculative batch caps batch 16 near 260 to 290/s; two ahead reaches about 355/s. - **Batch limit:** batch 32 with one ahead reaches 470 to 510/s. Letting the limit grow to 32 when the queue is deep is worth it. - **Latency gate in milliseconds:** single store at 200 writes/s, p99 at most 250 ms (measured 200 ms). Under contention between stores at saturation, p99 is in seconds and is set by queueing and fairness, not c. - **Yield:** keep the rule; 30 ms of jitter with a 3 s recency window. - **Checkpoint interval:** 60 s is cheap at 1M (full rewrite in about 10 s). - **Shard count:** scale it with the world (target about 200 KB per shard), or load shards with far more parallelism; a fixed 4096 makes small worlds slow to start. - **Section index at 1M:** a first body search answers from the catalog for about 20 s while 3 GB of segments load, and those sections would stay resident at about 3 GB per world per replica. Section segments need to stay off-heap or be queried in the bucket; this belongs with the catalog memory wall. - **`blob.Store.List` needs a start offset** for cold start to list the log from a checkpoint; the spike used the SDK directly. ## Caveats - Synthetic objects: no member builds, topology checks or catalog updates, so real per-batch CPU is not included. - Only the gate ran 10 minutes; the matrix ran 2 minutes, lanes 1 minute, the ramp 30 s per step. - Contention runs were closed loop only; an open-loop race at a fixed rate was not run. - Batch 16 with three ahead at 256 writers was not run. - Buckets were warm from earlier runs; a cold bucket's ramp is untested.