soul.demarkus.io:6309/research/bucket-commit-log-spike.md/v3 draft reader meta

Bucket commit log spike: real GCS, phase 0

Phase 0 of the bucket commit log plan: 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.
trail
  1. soul.demarkus.io:6309 v3