diff --git a/.changeset/wal-write-path-perf-and-recovery-fixes.md b/.changeset/wal-write-path-perf-and-recovery-fixes.md new file mode 100644 index 0000000000..1ce6b43c6c --- /dev/null +++ b/.changeset/wal-write-path-perf-and-recovery-fixes.md @@ -0,0 +1,9 @@ +--- +"@electric-ax/durable-streams-server-rust": patch +--- + +Write-path performance overhaul plus three crash-recovery correctness fixes. + +Performance: removed the WAL group-commit coordination ceiling (+55–60% saturated write throughput, p99 41→12 ms), fixed the 200k–1M stream-cardinality write cliff (1M streams now sustains 1.11M ops/s on 16 vCPU), and made `--durability memory` the buffered append path (4× faster, no longer Linux-only). New flags: `--wal-stats ` and `--worker-threads `. + +Fixes (found by the new seeded crash/fault simulation): multi-segment WAL recovery no longer drops acked records after the first segment; a torn, never-acked tail on a quiet stream is truncated instead of becoming reader-visible; an acked DELETE is now durable before the 204. diff --git a/packages/durable-streams-rust/ARCHITECTURE.md b/packages/durable-streams-rust/ARCHITECTURE.md index 409023dd9a..8c712c4218 100644 --- a/packages/durable-streams-rust/ARCHITECTURE.md +++ b/packages/durable-streams-rust/ARCHITECTURE.md @@ -35,10 +35,10 @@ flowchart LR W2 --> W3["encode_wire
(JSON flatten, append delimiter)"] W3 --> W4[["per-stream appender mutex"]] W4 --> W5["write_all → data file
(lands in page cache)"] - W5 --> W6["update tail + resident cache"] - W6 --> W8["publish tail
(watch channel)"] - W8 --> W7["group-commit fsync
(WAL shard committer)"] - W7 --> W9["204 / 200 — only after durable"] + W5 --> W6["advance writer tail
+ stage into WAL shard"] + W6 --> W7["group-commit fsync
(WAL shard committer)"] + W7 --> W8["publish durable tail + resident cache
(watch channel)"] + W8 --> W9["204 / 200 — only after durable"] end subgraph READ["READ · GET"] @@ -72,10 +72,10 @@ The dotted edges are the only coupling between writers and readers: publishing t 1. **Parse idempotency headers** — `Producer-Id` / `Producer-Epoch` / `Stream-Seq`. Duplicate `(producer, epoch, seq)` is acknowledged without re-appending (exactly-once producers). 2. **`encode_wire`** — turn the request body into the contiguous wire representation. In JSON mode this flattens arrays and appends the `,` delimiter so the on-disk bytes are already a valid stream fragment. 3. **Acquire the per-stream appender mutex** (`AsyncMutex`). This is the _only_ serialization point, and it's per-stream — different streams never contend. -4. **`write_wire`** — `write_all` the bytes to the data file (they land in the OS page cache immediately), advance the tail under a short `RwLock` write, update the **resident tail cache**, then **publish the new tail** on the `watch` channel. Note the order: the cache is populated _before_ the wake, so a woken subscriber reliably hits it. -5. **Durability** — in `wal` mode the append is staged into the stream's assigned WAL shard, and the response returns only after the shard's group-commit committer `fdatasync`s the segment covering this record. See [Durability](#durability) below. In `wal` mode everything above and the entire read path are identical regardless of workload. In `memory` mode binary appends take a separate socket→file splice path (zero-copy `splice(2)`, no WAL, no `fdatasync`) that bypasses `handle_append` / `encode_wire` via the engine zero-copy intercept and acks immediately after the page-cache write. +4. **`write_wire`** — `write_all` the bytes to the data file (they land in the OS page cache immediately) and advance the _writer_ tail (`Shared.tail`) under a short `RwLock` write. The reader-observable tail does **not** move yet. +5. **Durability, then visibility** — in `wal` mode the append is staged into the stream's assigned WAL shard (under the appender mutex, so per-stream LSN order matches byte order) and the handler awaits the shard's group-commit `fdatasync`. Only after the record is durable does `publish_durable_tail` advance the **reader-observable `durable_tail`** (monotonically), populate the **resident tail cache**, and **publish on the `watch` channel** — cache before wake, so a woken subscriber reliably hits it. Then the 2xx is returned. See [Durability](#durability) below. In `memory` mode the same buffered path runs with the WAL stage/wait skipped: the page-cache write is the ack. -Visibility vs durability are deliberately decoupled: the bytes are in the page cache (and the tail is published) before durability resolves, so a live reader sees data with minimal latency, while the _appender_ doesn't get its 2xx until the data is durable. +Visibility is gated on durability (PROTOCOL.md §4.1): a live reader never observes bytes (or an EOF) that a crash could roll back. The writer tail runs ahead in `Shared.tail`; readers see `durable_tail`, which follows it as group commits resolve. ## Durability @@ -85,7 +85,7 @@ The server supports two durability modes, chosen at startup via `--durability`. **`wal` (default)** — durable, single-node no-loss durability via a sharded write-ahead log. An append acks only after its record is durable in the WAL (group-commit `fdatasync`). This is the safe default for any deployment where local disk loss must not cause data loss. See the `wal` mode section below for the design. -**`memory` (Linux-only)** — no WAL, no `fsync`: binary appends move `socket→file` via `splice(2)` (zero-copy in the kernel); JSON appends are buffered writes; ack fires on the page-cache write. The per-stream files are the only durable-enough record, and recovery is the existing sidecar pass (rebuild stream state from the per-stream files + `.meta` sidecars). **NOT locally crash-durable** — a power loss or kernel panic can lose any un-fsynced page. Durability is delegated to (future) replication. Exits with status 2 on non-Linux. +**`memory`** — no WAL, no `fsync`: appends take the same buffered write path as `wal` mode with the WAL stage/wait skipped; ack fires on the page-cache write. The per-stream files are the only durable-enough record, and recovery is the existing sidecar pass (rebuild stream state from the per-stream files + `.meta` sidecars). **NOT locally crash-durable** — a power loss or kernel panic can lose any un-fsynced page. Durability is delegated to (future) replication. Refuses to start over a WAL left by a previous `wal` run (replay it with `--durability wal` first, or delete the `wal/` directory to discard it deliberately). | Mode | ack after | fsync | WAL | crash-safe? | | -------- | ---------------- | ---------------------- | --- | -------------------- | @@ -105,11 +105,11 @@ Every append is written to the per-stream data file (page cache, no hot fsync Per-stream files are `fdatasync`'d off the ack path at a periodic **checkpoint**, after which the bounded WAL is recycled. On boot, recovery replays the WAL from its oldest retained segment, reconciles each stream's durable tail (torn-tail repair via truncation + `fdatasync`), then resets the WAL for fresh appends. -The invariant: **visibility is never gated on durability**. Bytes land in the page cache and the tail is published before the WAL `fdatasync`, so live readers see an append at memory latency while the appender's acknowledgement waits for the WAL commit. +The invariant: **readers only ever observe durable bytes** (PROTOCOL.md §4.1). Bytes land in the page cache immediately, but the reader-observable `durable_tail` (and the `watch` wake) advances only after the WAL `fdatasync` covering the record — the same barrier that releases the appender's acknowledgement. A crash therefore never rolls back anything a reader has seen. ### `memory` mode -In `memory` mode no WAL is created or attached. Appends write directly to the per-stream file (buffered write for JSON; zero-copy `socket→file` splice for binary) and ack immediately after the page-cache write — no `fdatasync`, no WAL staging. The per-stream file is the data; the `.meta` sidecar records the stream configuration and tail. On restart, the server runs the same sidecar pass it runs in `wal` mode (rebuild each stream from its file + sidecar) — there is no WAL to replay. Durability is delegated to replication (not yet built). +In `memory` mode no WAL is created or attached. Appends write directly to the per-stream file (the same buffered write as `wal` mode) and ack immediately after the page-cache write — no `fdatasync`, no WAL staging. The per-stream file is the data; the `.meta` sidecar records the stream configuration and tail. On restart, the server runs the same sidecar pass it runs in `wal` mode (rebuild each stream from its file + sidecar) — there is no WAL to replay. Durability is delegated to replication (not yet built). ## Read path in detail @@ -140,8 +140,8 @@ flowchart TB end A3 ==> PC[("OS page cache
— the hot tier")] - A3 ==> RC["resident tail cache
(last chunk, configurable via --tail-cache-bytes,
in heap)"] - A3 -.-> TW[/"tail watch channel
(one notify per append — before fsync)"/] + A4 ==> RC["resident tail cache
(last chunk, configurable via --tail-cache-bytes,
in heap)"] + A4 -.-> TW[/"tail watch channel
(one notify per append — after the group commit)"/] subgraph FAN["② Fan-out"] direction TB @@ -159,7 +159,7 @@ The techniques, each with its mechanism and payoff: 1. **Contiguous wire-byte storage.** The file _is_ the response. Reads are byte ranges with no reframing and no per-message copy — and this is what makes `sendfile` zero-copy possible at all. 2. **Group-commit coalesced fsync.** The durability contract ("return after fsync") is the expensive part of an append. Concurrent appenders share a single in-flight barrier fsync, so throughput scales with the _batch size_ per fsync rather than one fsync per message. This is why unbatched appends hit ~30k/s where a per-append-fsync server (Node) does ~130/s. 3. **Per-stream single writer, lock-free reads.** One async mutex orders a stream's appends; there is no global lock (streams live in a `DashMap`). Reads take a brief tail snapshot and do positioned reads — they never block the writer and never wait on each other. -4. **Pre-fsync visibility.** Appended bytes are in the page cache and the tail is published before the fsync resolves, so live readers see data at memory latency; only the appender's acknowledgement waits for durability. +4. **Durable-gated visibility, group-commit-amortized.** The reader-observable tail is published only after the record's group-commit fsync (readers never see bytes a crash could roll back — PROTOCOL.md §4.1). Because N concurrent appends share one barrier fsync, the visibility latency cost is one amortized group commit, not one fsync per append. 5. **`watch`-channel wakeups.** Live readers park on a per-stream `watch`; an append is one `send_replace` that wakes all of them. No polling loop, no timer churn. 6. **Resident tail cache (fan-out de-duplication).** Without it, N caught-up SSE/long-poll subscribers each re-read (and re-encode) the _same_ just-appended bytes — N× duplicated work that grows with audience size. The cache keeps the last chunk in the heap so all N share one read (and SSE encodes once per subscriber off that shared buffer). For small hot reads it's also fewer syscalls than `sendfile` and skips the read-offload pool hop. 7. **Zero-copy egress.** `FileRange` reads are served with `sendfile` (page cache → socket, no userspace copy → ~5× less CPU per byte than a buffered copy). The **`--read-offload`** strategy keeps a cold backfill's disk fault off the async workers so one slow read can't stall unrelated requests. diff --git a/packages/durable-streams-rust/CARDINALITY_1M.md b/packages/durable-streams-rust/CARDINALITY_1M.md new file mode 100644 index 0000000000..3fd0a3a91a --- /dev/null +++ b/packages/durable-streams-rust/CARDINALITY_1M.md @@ -0,0 +1,54 @@ +# 1M-stream cardinality fixes — findings + results (2026-07-02) + +Follow-up to `WRITE_BOTTLENECKS_1M.md` (bottleneck #2: stream cardinality) and +`CONTENTION_INVESTIGATION.md`. Server commit: `662b0c845` on +`perf/combined-t1a-t1c-t2a`. **Outcome: 1M streams reaches 1,114,644 ops/s on a +16 vCPU `c4d-standard-16-lssd` (ladder unsaturated), and the 500k→1M degradation at +equal load is −17% (was a cliff).** + +## Root causes (evidence-first, local Linux repro at 20k→400k streams) + +The key mechanism: **at high cardinality, ops/stream/checkpoint-interval drops below +1, so every "amortized once-per-stream-per-interval" cost becomes a per-op cost.** + +| # | cost | evidence | fix | +| --- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | ------------------------------------------------------------------------------------------------------------------ | ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| 1 | Checkpoint drain did O(touched) capture (`shared.read()` + Arc clone per stream) **while holding the shard `dirty` mutex** — the same mutex every append's epoch-transition takes; at 400k streams every append is a transition | `WAL_CKPT drain_us` 25–140 ms/tick; `dirty_wait_load` 0.01→0.30 cores as streams 20k→400k; p99 ≈ max drain | O(1) critical section: take Vec + bump epoch under the lock, capture after release | +| 2 | Checkpoint capture / cumulative tails-file re-read+re-sort+rewrite / recycle ran **on async runtime threads**, serially across shards | `WAL_CKPT` capture 31 ms + tails 24 ms per tick per shard on runtime threads | whole checkpoint body in one `spawn_blocking`; tails map memory-resident; shards checkpoint concurrently (`JoinSet`) | +| 3 | **Per-append meta sidecar flush**: with inter-append gap > the 100 ms debounce (always, at high cardinality) every producer append did JSON + `File::create(.meta.tmp)` + `rename` → all workers spin on the **data-dir inode rwsem** | perf: `osq_lock`+`rwsem_spin_on_owner` under `write_meta_sync` = **38–46% of ALL server CPU at every cardinality** | WAL-staged appends only mark `meta_dirty`; checkpoint writes sidecars for drained streams after recycle (memory-mode keeps the debounced flush). Producer/access staleness bound: 100 ms debounce → checkpoint cadence (contract already allows lag) | +| 4 | Two registry lookups per append (`handle_append` metric label + `_inner`) — 2× SipHash + cold DashMap walk at 1M keys | code inspection | `_inner` returns `is_json` | + +## Local A/B (Linux harness, 6 srv cores, conn=256, shards=6) + +| streams | before | after | p99 | +| ------- | ------------- | ---------- | ------------ | +| 20k | ~43–46k ops/s | **80.4k** | 41 → 7.7 ms | +| 200k | 32.3k | **50.6k** | 53 → 17.9 ms | +| 400k | 16.0k | **36–44k** | 144 → ~28 ms | + +Correctness: 95 crate tests + 326 conformance tests pass. New telemetry: `WAL_CKPT` +per-shard checkpoint phase line (`--wal-stats`), and the repro script grew +`--tmpfs` / `--wal-stats` knobs + WAL_CKPT summarizing. + +## Remote validation (GKE, 16 vCPU, pool client, 256 B, batch 1) + +Suite `ds-bench/suites/run-durable-cpu16-1m-card.json`, image +`durable-streams:combined-card@sha256:d74840bd…`; full detail + caveats in +`ds-bench/results/run-durable-cpu16-1m-card/FINDINGS.md`. + +| streams | pods | ops/s | p50 / p99 / max | +| ------- | ---- | ------------- | ------------------------------------------------------------ | +| 1M | 32 | 898,582 | 3.5 / 30.5 / **149.6 ms** (baseline 862k, 3.3 / 32 / 405 ms) | +| 1M | 64 | **1,114,644** | 3.4 / 60.3 / 211 ms — still climbing (+21%/+16 pods) | +| 500k | 48 | 1,110,268 | 3.1 / 42.7 / 145 ms | + +## Open follow-ups + +1. True 16 vCPU ceiling at 1M (ladder past 64 pods) and a 32 vCPU 1M run. +2. **Per-shard producer-state journal**: sidecar writes/s ≈ ops/s at full cardinality + (off the hot path now, but it stretches checkpoint cadence — locally ~1.6 s/shard + meta phase at 400k — and bounds producer-state staleness). One cumulative + per-shard file per tick, recovery overlays producers by max(epoch, seq). +3. Read+write mix at 1M streams (everything here is write-only). +4. `--wal-stats` cell on NVMe (`run-durable-cpu16-1m-card-stats.json`, never ran) to + confirm checkpoint fsync/meta phase behavior at 1M on real disks. diff --git a/packages/durable-streams-rust/CONTENTION_INVESTIGATION.md b/packages/durable-streams-rust/CONTENTION_INVESTIGATION.md new file mode 100644 index 0000000000..217df32354 --- /dev/null +++ b/packages/durable-streams-rust/CONTENTION_INVESTIGATION.md @@ -0,0 +1,105 @@ +# WAL write-saturation contention investigation + +Tracking doc for the investigation into the write-throughput ceiling reported in +`ds-bench/results/run-durable-pool2/FINDINGS.md` (server plateaus at ~80% CPU and +then _declines_ under more load — a ceiling set by the commit path, not compute). + +## Hypothesis + +Sharding, group-commit, and the network reactor are **not isolated**: they are +multiplexed over one shared work-stealing Tokio runtime, and each WAL shard is +guarded by cross-thread blocking `std::sync::Mutex`es. So a "shard" is a _lock_, +not a _core_. At saturation the cost is lock contention + committer scheduling + +a durability-wakeup thundering herd, not CPU. + +Per-append contended state (all on the shard a stream hashes to): + +- `shard.dirty` Mutex + HashMap insert — **every append** (`register_dirty`). +- `shard.inner` Mutex — **twice** per append (reserve + mark_written). +- `durable_tx` watch — `publish_durable` wakes **every** parked waiter on the shard. + +## Phase 0 — telemetry (DONE) + +Added always-on, dependency-free contention telemetry (independent of the heavy +`telemetry`/OTLP feature): + +- `ShardStats` gained per-shard counters: `inner`/`dirty` lock-wait nanos + + acquire counts, records `staged`, and durability `waiters_woken` + (`src/wal/telemetry.rs`). +- Instrumented the hot path (`src/wal/shard.rs`): `register_dirty`, + `reserve_and_stage` (both `inner` acquisitions), `publish_durable`. +- Runtime gate `--wal-stats `: arms the hot-path timing (one relaxed + atomic load when off — no clock reads in a default run) and spawns a stderr + emitter printing per-interval `WAL_CONT` lines: + + ``` + WAL_CONT staged/s=… fsync/s=… batch_avg=… inner_wait_us=… inner_wait_load=… \ + dirty_wait_us=… dirty_wait_load=… waiters_woken_avg=… + ``` + + `*_wait_load` = fraction of a core-second spent purely _waiting_ on that lock + (>1.0 ⇒ more than a whole core lost to parking on it). + +## Phase 0 — local reproduction (DONE / caveated) + +Local reproduction drives the server with the `ds-bench multi-stream` pool +client and reads throughput + CPU + steady-state `WAL_CONT`. + +**macOS caveats (why a Linux harness is also needed):** + +- `F_FULLFSYNC` is a true drive barrier (~tens of ms) and dominates the commit + path, masking the lock. Added a **bench-only** `DS_UNSAFE_FAST_FSYNC` env + (`src/store.rs`, `src/wal/segment.rs`) that uses plain `fsync` on macOS so a + RAM-disk data dir gives cheap fsync (the Linux+NVMe regime). NOT durable; never + set in production. +- The 10-core dev box co-locates client + server, so the _absolute_ throughput + ceiling is confounded (a flat ~1600 ops/s independent of shards/connections). + The **contention telemetry signals are valid** on macOS (use them for relative + before/after of a change); the **throughput-ceiling** comparison must run on + Linux with a tmpfs data dir and CPU isolation. + +Use a RAM disk for cheap fsync on macOS (point the server's data dir at it): + +``` +DEV=$(hdiutil attach -nomount ram://6291456 | awk '{print $1}') +diskutil erasevolume HFS+ dsram "$DEV" # → /Volumes/dsram +``` + +## Baseline (Linux harness, 6 server cores / 4 client cores, tmpfs, conn=256) + +Reproduces the findings' signature — a hard throughput ceiling at **~80% CPU** +(480–500 of 600), barely helped by more shards, with CPU left on the table: + +| shards | ops/s | cpu% | fsync/s | batch | inner_wait_load | waiters_woken | +| ------ | ------ | ---- | ------- | ----- | --------------- | ------------- | +| 1 | 45,543 | 482 | 6,113 | 7.5 | 0.02 | 25.8 | +| 2 | 46,905 | 504 | 12,384 | 3.8 | 0.01 | 12.4 | +| 6 | 48,825 | 495 | 24,177 | 2.0 | 0.01 | 5.2 | + +Read: fsync is cheap (tmpfs), the inner lock is not yet the gate at 6 cores +(`inner_wait_load`≈0.02), so the ceiling here is the **commit + durability-wakeup +coordination machinery** burning CPU/scheduling (25.8 waiters woken per commit at +1 shard). The lock itself becomes the gate at the findings' 32-core scale; both +are targeted below. (Numbers are this dev box; use deltas, not absolutes.) + +## How to judge a candidate change + +A change is good if it **lifts the Linux throughput ceiling** AND drives the +contention metric it targets toward zero: + +- lock-free `register_dirty` → `dirty_wait_load` → ~0 +- atomic reserve → `inner_wait_load` drops +- coalesced wakeups → `waiters_woken_avg` → ~1 +- dedicated committer / io_uring → higher `fsync/s` without CPU saturation + +## Candidate architectures (Phase 1, parallel worktrees) + +- **T1a** lock-free `register_dirty` (atomic dirty bit + lock-free push on 0→1). +- **T1b** atomic reserve (packed `fetch_add` for lsn+write_pos; lock only on roll). +- **T1c** coalesced durability wakeups (wake only satisfied waiters, not broadcast). +- **T2a** dedicated committer thread(s) off the shared runtime / drop per-commit + `spawn_blocking`. +- **T2b** io_uring WAL writes + fsync (Linux). +- **T3** shared-nothing thread-per-core spike (shard→core, per-core epoll via + `SO_REUSEPORT`, no cross-core lock; SPSC handoff for the pool client's + all-shards-per-connection access pattern). diff --git a/packages/durable-streams-rust/CRASH_SIM_FINDINGS.md b/packages/durable-streams-rust/CRASH_SIM_FINDINGS.md new file mode 100644 index 0000000000..b48383cba4 --- /dev/null +++ b/packages/durable-streams-rust/CRASH_SIM_FINDINGS.md @@ -0,0 +1,142 @@ +# Crash/recovery simulation — findings (2026-07-02) + +A seeded randomized crash/fault simulation for the WAL recovery path now lives at +`src/wal/sim_tests.rs` (design: `docs/superpowers/specs/2026-07-02-wal-crash-simulation-design.md`). +Each seed drives the real handler path with a random workload (creates, appends, +client-disconnect cancellations, closes, forks, deletes, checkpoints), crashes by dropping +the generation's tokio runtime + stopping committers, injects power-loss disk faults +constrained to the documented fault model, reboots through the real recovery sequence, and +checks a no-loss/no-torn/consistency oracle across multiple generations per seed. + +Run it: + +```sh +# CI-fast deterministic smoke (4 seeds) +cargo test crash_recovery_randomized_simulation + +# long hunt +DS_SIM_SEEDS=1000 DS_SIM_SEED0=20000 DS_SIM_GENS=4 DS_SIM_STEPS=150 \ + cargo test crash_recovery_randomized_simulation -- --nocapture + +# reproduce a failure (the panic message prints the seed) +DS_SIM_SEEDS=1 DS_SIM_SEED0= cargo test crash_recovery_randomized_simulation +# forensics: DS_SIM_SNAPSHOT=1 snapshots each generation's pre-boot disk state; +# `DS_DUMP_DIR= cargo test wal_forensic_dump -- --ignored --nocapture` decodes it. +``` + +## Finding 1 (CRITICAL, fixed): boot clobbered sealed/recycled WAL segments → acked-data loss + +Found by the very first seed (89837), gen 1. `Shard::open` unconditionally ran +`FileSegment::create(1.wal, segment_size)`, which re-preallocates to full segment size. +Two on-disk states the segment roll/recycle feature (11a) introduced made that destructive: + +- **Sealed `1.wal`** — sealing truncates a rolled segment to its exactly-packed length, + and that exact length is what lets `replay_from_checkpoint` walk across the segment seam + (`off == raw.len()` → next segment). Re-preallocating grafted a `fallocate`/`set_len` + zero tail onto the sealed segment; replay decoded the zeros as `Incomplete` — the clean + end of the durable log — and **silently dropped every acked record in all later + segments**. Worse than a skip: `reconcile_tail` then **truncated the per-stream files** + back to the stale frontier, destroying acked bytes that were sitting intact in the page + cache. Pure process crash (no power loss) suffices to trigger it. +- **Recycled `1.wal`** — after a checkpoint recycles the first segment(s), boot re-created + a fresh all-zero `1.wal`. The walk visits segments in start-lsn order, decoded zero + records in the spurious `1.wal`, and stopped — **replaying nothing**: every acked append + since the last checkpoint was truncated away. + +The trigger threshold in production is one segment roll (128 MiB of WAL traffic, or any +`--wal-segment-bytes` override) between two boots — no fault injection required. + +**Fix:** boot now discovers existing `*.wal` files and opens the newest one as a +non-destructive placeholder handle (`FileSegment::open_existing`); only a genuinely fresh +shard dir creates + preallocates `1.wal`. The in-memory cursor stays a placeholder until +`reset_after_recovery` rebuilds it, per the documented boot order. +Regression tests: `e2e_multi_segment_acked_records_after_first_seal_survive_crash`, +`e2e_recycled_first_segment_acked_records_survive_crash` (both fail on the pre-fix code). + +## Finding 2 (fixed): recovery debug assert panicked on a healthy multi-boot recovery + +Seed 89840, gen 2+. `recovery.rs` asserted that a stream rebuilt purely from replayed +records (no checkpoint-persisted tail) must have its first record at `file_base`. That +premise is false across the boot cycle: after `recover` + `reset_after_recovery`, a +stream's post-boot appends produce WAL records starting at its _recovered tail_ — with no +persisted-tails entry until the next checkpoint. The durable prefix below the first +replayed record came from the previous boot's recovery reconcile (which `fdatasync`s the +repaired file), a third proof source the assert didn't model. Debug builds panicked the +recovery thread (release builds were unaffected). + +**Fix:** the assert now checks the actual invariant — no _hole_ between the file's +pre-replay logical end and the first replayed record. + +## Finding 3 (docs, fixed): ARCHITECTURE.md described pre-fsync visibility; the code gates visibility on durability + +`ARCHITECTURE.md` claimed "visibility is never gated on durability" (tail published before +the WAL fsync). The implementation deliberately does the opposite: `write_wire` advances +only the writer tail; `publish_durable_tail` advances the reader-observable `durable_tail`, +populates the tail cache, and fires the `watch` **after** `wait_durable_lsn` — readers +never observe bytes a crash could roll back (PROTOCOL.md §4.1). The doc's write-path +diagram, §Durability invariant, and fan-out technique list were updated to match the code. + +## Observation (by design, worth knowing): cancelled appends leave a lagging reader tail + +A client that disconnects mid-append can leave the handler task cancelled at +`wait_durable_lsn`: the bytes are in the data file (and staged in the WAL, becoming durable +via the group commit), `Shared.tail` is advanced, but `publish_durable_tail` never runs for +that record. The reader-observable tail lags the file until the next successful append +publishes a higher frontier (monotonic heal) or a crash-recovery exposes the frontier. +Contract-consistent (the append never acked), but operators reading `Stream-Next-Offset` +may see it hold still despite durable bytes existing past it on a quiet stream. + +## Finding 4 (fixed): WAL-quiet streams had no torn-tail proof after power loss + +Initially documented as a theoretical residual gap, then **confirmed by the 1000-seed +hunt** (seed 20230, gen 1): a stream created after the last checkpoint whose only append +was in-flight at the crash. Power loss tore the append's WAL record (never fdatasync'd — +nothing acked) while the data file kept a torn prefix of its bytes. Recovery had **no +truncation proof** — zero surviving WAL records, no checkpoint `tails` entry — so the +sidecar pass trusted `tail = file_base + file size` and exposed the torn fragment (615 +bytes of a partial record) to readers: exactly the C1 torn-tail shape the WAL exists to +prevent, on the one class of stream the existing proof chain missed. No acked data was at +risk, but torn/garbage bytes (including torn JSON) became reader-visible. + +**Fix:** the `.meta` sidecar now persists a `durable_tail` proof, captured from +`Shared.durable_tail` (which only ever advances post-fsync, so any captured value is +honest). It rides along on writes that already happen — fsynced at create/close, +refreshed by the checkpoint's meta flush and by recovery's reconcile — **zero new +hot-path fsyncs**. Recovery seeds every sidecar-recovered stream's frontier with +`max(meta proof, checkpoint tails, replayed ends)` and truncates anything past it; a +fast path skips streams whose file already sits exactly at their frontier, so 1M-stream +boots stay free of extra I/O. Recovery durably re-persists the proof before +`reset_after_recovery` wipes the WAL + tails file (else the next boot's seed would +regress below a durable frontier it can no longer re-replay). Old sidecars without the +field keep the previous trust-the-file-size behavior (`serde` default), converting to +proven on their next natural meta write. +Regression test: `e2e_wal_quiet_stream_torn_unacked_tail_truncated`. + +## Finding 5 (fixed): an acked DELETE was not durable — crash resurrected the stream + +Found by the second 1000-seed hunt (seed 20387, gen 2), with **no fault injection at +all** — a clean process crash right after an acked DELETE. `handle_delete` returned 204 +while the data-file + sidecar unlinks ran on a **detached** `spawn_blocking` task (and +with no parent-directory fsync even once they ran). A crash after the ack left both +files on disk, and the next boot's sidecar pass resurrected the stream **with all its +data** — after the client was told it was permanently gone (a correctness and +data-retention/compliance issue). The soft-delete meta flag had the same fire-and-forget +shape. + +**Fix:** DELETE now awaits `delete_or_soft_delete_durable` before the 204 — synchronous +unlinks + one parent-dir fsync (both artifacts live in the same directory), or the +durable soft-delete meta write; a failure acks 500, not 204. The expiry sweep on the hot +read path keeps the detached non-durable variant (an expired stream that resurrects +simply re-expires on next access — harmless, and documented on the method). +Regression test: `e2e_acked_delete_is_durable_no_resurrection_after_crash`. + +## Simulation results + +- Pre-fix: seed 89837 (the first default seed) hit Finding 1 in generation 1; seed 20230 + hit Finding 4 in generation 1 of the first 1000-seed hunt; seed 20387 hit Finding 5 in + generation 2 of the second hunt (clean crash, no faults). +- Post-fix: 4 default smoke seeds + 50-seed and 1000-seed hunts (4 generations × 150 steps + each, 1–3 shards, 32 KiB segments to force rolls/recycles) pass with faults enabled + (data-file truncate/scribble/zero within the un-fsynced region; WAL suffix zero/scribble + above the durable LSN; torn staged appends; client-disconnect cancellations; + in-flight-at-crash appends). diff --git a/packages/durable-streams-rust/MIXED_WORKLOAD_VALIDATION.md b/packages/durable-streams-rust/MIXED_WORKLOAD_VALIDATION.md new file mode 100644 index 0000000000..f96b9584fb --- /dev/null +++ b/packages/durable-streams-rust/MIXED_WORKLOAD_VALIDATION.md @@ -0,0 +1,69 @@ +# Mixed read/write workload validation (local, 2026-07-02) + +Interference validation of **this branch's server build** under ds-bench's new mixed +workload (concurrent writers + paced catch-up readers + SSE subscribers on shared +streams). Run on a local kind cluster — server pinned to **2 CPU / 2 Gi**, single-node +MinIO, fresh server per cell. Shapes are trustworthy; absolute numbers need the remote +(GKE, separated node pools) run before being quoted. + +**Provenance.** Server: `bench/mixed-interference-validation` @ `06a8a37c5` +(= `perf/combined-t1a-t1c-t2a` head), image `durable-streams:dev` +`sha256:5468aaa3ffd1…` (built via ds-bench's `dockerfiles/durable-streams.Dockerfile`). +Harness: `electric-sql/ds-bench` @ `3bcc0f2` (`suites/mixed-{cal,writes,delivery}-local.json`); +full grids + FINDINGS in `results/mixed-{writes,delivery}-local/` there. + +Baseline ceiling (50 unthrottled writers, 256 B, no readers/subscribers): +**29.7k appends/s, p50 1.5 ms / p99 6.4 ms** — vs 19.6k for the pre-perf-branch build +in the morning's v1 run, i.e. this branch is ~1.5× faster on this box at 50-stream +write saturation. + +## 1. Bounded catch-up read load does not cost write throughput + +Writers pinned at 17.75k ops/s (60% of ceiling); readers each replay their stream +from offset 0 at 1 replay/s: + +| readers | write ops/s | write p50/p99 ms | read MiB/s | read p50/p99 ms | +| ------- | ----------- | ---------------- | ---------- | --------------- | +| 0 | 17303 | 1.2 / 9.8 | — | — | +| 4 | 17755 | 1.0 / 5.7 | 3.8 | 1.7 / 10.5 | +| 16 | 17756 | 0.9 / 5.3 | 15.4 | 3.9 / 17.1 | +| 64 | 17756 | 1.0 / 6.5 | 61.5 | 5.5 / 65.5 | +| 128 | 17750 | 1.1 / 52.9 | 123.0 | 4.9 / 50.9 | + +The pinned rate is delivered to within noise at every level; interference is +tail-only (write p99 6.5 → 53 ms once replay bandwidth passes ~60 MiB/s on 2 CPUs). +With **unpaced** hot-loop readers (adversarial mode, v1 run) the same sweep +fair-shares writes down −39%/−65%/−82% at 16/64/128 readers, with **zero 429/503 in +either mode** — the server never sheds read load; overload is silent. Worth deciding +whether that's intended behaviour at some point, but nothing on this branch regresses. + +## 2. Live SSE delivery latency is flat under write load; the latency floor is fsync + +100 SSE subscribers (2/stream), write rate swept 5% → 100% of ceiling, run under both +`--durability wal` and `--durability memory`: + +| rate/writer | wal write ops/s | wal deliv p50/p99 | mem write ops/s | mem deliv p50/p99 | +| ----------- | --------------- | ----------------- | --------------- | ----------------- | +| 30 | 1502 | 3.2 / 12.4 | 1502 | 1.4 / 8.7 | +| 120 | 6002 | 0.9 / 10.1 | 6002 | 0.8 / 3.5 | +| 300 | 14741 | 2.1 / 17.2 | 15001 | 0.9 / 5.1 | +| 475 | 17380 | 2.8 / 20.9 | 23752 | 1.3 / 8.5 | +| max | 17144 | 2.8 / 22.6 | 29247 | 3.3 / 34.8 | + +- Delivery p99 ≈ **write p99 + 1–3 ms in both configs at every level** — the SSE + fan-out path (reactor) is a small constant on top of commit latency. The apparent + "~14 ms delivery floor" in the v1 run was WAL fsync cost on the local VM disk, not + an SSE cadence. **No SSE-side change needed.** +- Every subscriber saw every record (deliveries = exactly 2× writes) at all levels + except memory-`max`, where the single client pod (parsing ~44k events/s while + driving ~29k appends/s) is the prime suspect, not the server. +- Fan-out tax: 100 subscribers cost ~42% of the wal write ceiling on 2 CPUs + (29.7k → 17.1–17.4k). A number to re-measure remotely with more server cores. + +## Verdict + +The perf-branch server passes both interference premises: bounded read load leaves +write throughput intact (tails couple only at high read bandwidth), and live delivery +latency tracks commit latency with ~1–3 ms of fan-out overhead all the way to +saturation. No server changes came out of this validation; this doc is the evidence +record for the branch. diff --git a/packages/durable-streams-rust/README.md b/packages/durable-streams-rust/README.md index 1d20d08c09..45b5ee5683 100644 --- a/packages/durable-streams-rust/README.md +++ b/packages/durable-streams-rust/README.md @@ -72,11 +72,11 @@ durable, single-node server on `127.0.0.1:4437` with its data dir under `$TMPDIR **Durability** — controls how appends are made durable. See [ARCHITECTURE.md › Durability modes](ARCHITECTURE.md#durability-modes). -| Flag | Default | Description | -| --------------------- | --------- | -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -| `--durability` | `wal` | `wal` (default) — durable group-commit `fdatasync`; an append acks only after its record is in the sharded WAL. `memory` (Linux-only) — no WAL; binary appends use zero-copy `socket→file` splice, ack on the page-cache write; **NOT locally crash-durable** — durability is delegated to (future) replication. Exits 2 on non-Linux. | -| `--wal-shards` | CPU cores | (`wal` mode) shard / group-commit-committer count; persisted on first run, a later run must match it | -| `--wal-segment-bytes` | `128 MiB` | (`wal` mode) per-shard WAL segment size; lower it only to force segment rolls in tests/benches | +| Flag | Default | Description | +| --------------------- | --------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| `--durability` | `wal` | `wal` (default) — durable group-commit `fdatasync`; an append acks only after its record is in the sharded WAL. `memory` — no WAL, no fsync; the same buffered append path with the WAL stage/wait skipped, ack on the page-cache write; **NOT locally crash-durable** — durability is delegated to (future) replication. | +| `--wal-shards` | CPU cores | (`wal` mode) shard / group-commit-committer count; persisted on first run, a later run must match it | +| `--wal-segment-bytes` | `128 MiB` | (`wal` mode) per-shard WAL segment size; lower it only to force segment rolls in tests/benches | **Read path** — performance knobs; none change protocol behaviour. Leave at defaults unless a benchmark says otherwise. @@ -105,10 +105,33 @@ S3 credentials come from the **environment**, never flags: `DS_S3_ACCESS_KEY_ID` ### Choosing a configuration -| Your situation | Use | -| ------------------------------------------------- | ----------------------------------------------------------------------------------------------------------- | -| **Bounded local disk with long history** | `--tier s3` (or `local`) — seal cold segments to object storage; the recent tail stays local and zero-copy. | -| **High fan-out p99 across many streams on Linux** | try `--tail-cache-bytes 65536` (off by default there because `sendfile` already covers it). | +| Your situation | Use | +| --------------------------------------------------- | ----------------------------------------------------------------------------------------------------------- | +| **Bounded local disk with long history** | `--tier s3` (or `local`) — seal cold segments to object storage; the recent tail stays local and zero-copy. | +| **High fan-out p99 across many streams on Linux** | try `--tail-cache-bytes 65536` (off by default there because `sendfile` already covers it). | +| **Experimenting on macOS and writes take ~2–10 ms** | expected — see [macOS write latency](#macos-write-latency-f_fullfsync) below. | + +### macOS write latency (`F_FULLFSYNC`) + +In `wal` mode every acked append is durable, and on macOS that durability +barrier is `fcntl(F_FULLFSYNC)` — a true flush of the drive's write cache. A +plain macOS `fsync()` does **not** survive power loss, so the server pays the +real barrier, and it costs **~2–10 ms per group commit** depending on the disk +(measured ~3 ms on an M-series laptop SSD). On Linux this doesn't apply: +`fdatasync` already issues the device barrier and is cheap on NVMe. + +So if you're benchmarking or demoing on a Mac and every write (and therefore +every live read) shows a few milliseconds of latency: that's the disk barrier, +not the server. Options, in order of preference: + +1. **`--durability memory`** — the honest "I don't need power-loss durability" + mode; write acks drop to ~0.2–0.5 ms. +2. **`DS_UNSAFE_FAST_FSYNC=1`** (env var, bench-only) — keeps `wal` mode but + swaps `F_FULLFSYNC` for a plain `fsync`, approximating the Linux/NVMe + regime on a Mac (~0.3 ms acks). The WAL machinery still runs; only the + final barrier is weakened. A no-op on Linux. **Never set this in + production**: a power failure can lose acked writes, which silently breaks + the `wal`-mode contract (process/OS crashes are still fine). ### Run-configuration matrix @@ -124,7 +147,7 @@ configurations CI guards. | `wal-default` | _(none)_ | WAL durability, buffered append, resident cache off (Linux) | all | | `wal-resident-cache` | `--tail-cache-bytes 65536` | WAL + resident tail cache on | all | | `wal-read-offload-always` | `--read-offload always` | reads served on the blocking pool | Linux | -| `memory` | `--durability memory` | no WAL; zero-copy socket→file append; page-cache ack | Linux | +| `memory` | `--durability memory` | no WAL; buffered append; page-cache ack | all | Run one configuration's conformance suite locally: @@ -132,8 +155,7 @@ Run one configuration's conformance suite locally: RUST_SERVER_ARGS="--durability memory" pnpm vitest run --project server-rust ``` -(The Linux-only configs need a Linux host — e.g. Docker — because `memory` -exits 2 elsewhere.) +(The Linux-only config needs a Linux host — e.g. Docker.) ## What it implements @@ -149,7 +171,7 @@ In `memory` mode there is no WAL and no WAL replay. Recovery is a sidecar pass: - **Sharded WAL durability** — in `wal` mode (the default), appends are acked only after their record is durable in the sharded write-ahead log. One group-commit committer per shard batches many streams' appends into a single `fdatasync` (`F_FULLFSYNC` on macOS), minimizing fsync operations regardless of stream cardinality. Per-stream files are the read view; checkpoint periodically fsyncs them and recycles WAL segments. See [Durability](ARCHITECTURE.md#durability). - **Per-stream serialization, lock-free reads** — one async mutex per stream orders appends; reads take a brief snapshot and do positioned `pread`s, never blocking the writer. - **watch-channel wakeups** drive long-poll and SSE subscribers, so there's no polling loop. -- **A single, hand-rolled HTTP/1.1 engine** — no framework: it owns the socket, so on Linux it serves reads with `sendfile(2)` (zero-copy page cache → socket, ~10× less CPU per byte) and binary appends with `splice(2)`; elsewhere it falls back to positioned reads. +- **A single, hand-rolled HTTP/1.1 engine** — no framework: it owns the socket, so on Linux it serves reads with `sendfile(2)` (zero-copy page cache → socket, ~10× less CPU per byte); elsewhere it falls back to positioned reads. ## Tiered storage (cold offload) diff --git a/packages/durable-streams-rust/bench-latency/latency-probe.mjs b/packages/durable-streams-rust/bench-latency/latency-probe.mjs new file mode 100644 index 0000000000..4a2013ba09 --- /dev/null +++ b/packages/durable-streams-rust/bench-latency/latency-probe.mjs @@ -0,0 +1,144 @@ +// Write/read latency probe for the durable-streams Rust server. +// +// Uses the real electric client (@durable-streams/client). Flow per run: +// 1. create a fresh stream +// 2. open a LIVE session (long-poll by default) and subscribe +// 3. wait until the session reports up-to-date (live poll is parked) +// 4. for each payload size: warmup appends, then N measured appends +// +// Per sample: +// write ms = t(append() resolves) - t(append() starts) [server ack incl. durability] +// read ms = t(bytes arrive at subscriber) - t(append() starts) [end-to-end since write timestamp] +// +// CLI: node latency-probe.mjs --url http://127.0.0.1:4437/bench-1 \ +// [--live long-poll|sse] [--samples 12] [--warmup 3] [--sizes 1024,4096,16384,65536] + +import { DurableStream } from '../../agents-server-conformance-tests/node_modules/@durable-streams/client/dist/index.js' + +const RECEIPT_TIMEOUT_MS = 10_000 + +function makePayload(size, tag) { + const buf = new Uint8Array(size) + const header = new TextEncoder().encode(`#${tag}|`) + buf.set(header.subarray(0, Math.min(header.length, size))) + buf.fill(120 /* 'x' */, Math.min(header.length, size)) + return buf +} + +function stats(xs) { + const s = [...xs].sort((a, b) => a - b) + const mean = s.reduce((a, b) => a + b, 0) / s.length + const q = (p) => s[Math.min(s.length - 1, Math.floor(p * s.length))] + return { + n: s.length, + mean: +mean.toFixed(3), + p50: +q(0.5).toFixed(3), + min: +s[0].toFixed(3), + max: +s[s.length - 1].toFixed(3), + } +} + +export async function runProbe({ + url, + live = `long-poll`, + sizes = [1024, 4096, 16384, 65536], + samples = 12, + warmup = 3, +}) { + const handle = await DurableStream.create({ + url, + contentType: `application/octet-stream`, + }) + + const res = await handle.stream({ offset: `-1`, live }) + + let receivedBytes = 0 + const waiters = [] + res.subscribeBytes((chunk) => { + const t = performance.now() + receivedBytes += chunk.data.byteLength + for (const w of waiters) { + if (!w.done && receivedBytes >= w.target) { + w.done = true + w.resolve(t) + } + } + }) + + // Wait until the live session has caught up (empty stream => immediately), + // then give the client a beat to park the next live long-poll so every + // measured write is delivered via the live path, not session setup. + const deadline = Date.now() + 5000 + while (!res.upToDate) { + if (Date.now() > deadline) throw new Error(`session never reached upToDate`) + await new Promise((r) => setTimeout(r, 5)) + } + await new Promise((r) => setTimeout(r, 200)) + + async function oneAppend(size, tag) { + const payload = makePayload(size, tag) + const target = receivedBytes + size + let resolveReceipt + const receipt = new Promise((r) => { + resolveReceipt = r + }) + waiters.push({ target, resolve: resolveReceipt, done: false }) + + const t0 = performance.now() + await handle.append(payload) + const tAck = performance.now() + const tRecv = await Promise.race([ + receipt, + new Promise((_, rej) => + setTimeout( + () => rej(new Error(`receipt timeout (tag ${tag})`)), + RECEIPT_TIMEOUT_MS + ) + ), + ]) + return { writeMs: tAck - t0, readMs: tRecv - t0 } + } + + const bySize = {} + for (const size of sizes) { + for (let i = 0; i < warmup; i++) await oneAppend(size, `w${size}.${i}`) + const writes = [] + const reads = [] + for (let i = 0; i < samples; i++) { + const { writeMs, readMs } = await oneAppend(size, `s${size}.${i}`) + writes.push(writeMs) + reads.push(readMs) + } + bySize[size] = { write: stats(writes), read: stats(reads) } + } + + res.cancel() + await handle.delete().catch(() => {}) + return { url, live, samples, bySize } +} + +// ---- CLI ---- +if (import.meta.url === `file://${process.argv[1]}`) { + const args = Object.fromEntries( + process.argv + .slice(2) + .map((a, i, xs) => (a.startsWith(`--`) ? [a.slice(2), xs[i + 1]] : null)) + .filter(Boolean) + ) + if (!args.url) { + console.error( + `usage: node latency-probe.mjs --url [--live long-poll|sse] [--samples N] [--warmup N] [--sizes a,b,c]` + ) + process.exit(2) + } + const result = await runProbe({ + url: args.url, + live: args.live ?? `long-poll`, + samples: args.samples ? parseInt(args.samples, 10) : 12, + warmup: args.warmup ? parseInt(args.warmup, 10) : 3, + sizes: args.sizes + ? args.sizes.split(`,`).map((s) => parseInt(s, 10)) + : undefined, + }) + console.log(JSON.stringify(result, null, 2)) +} diff --git a/packages/durable-streams-rust/bench-latency/latency-results.json b/packages/durable-streams-rust/bench-latency/latency-results.json new file mode 100644 index 0000000000..0a0b95755c --- /dev/null +++ b/packages/durable-streams-rust/bench-latency/latency-results.json @@ -0,0 +1,1020 @@ +{ + "host": "darwin", + "samples": 12, + "results": [ + { + "combo": { + "durability": "wal", + "offload": "tail", + "tailCache": "default", + "fastFsync": false + }, + "name": "wal offload=tail tailcache=default", + "url": "http://127.0.0.1:4620/latency-bench-0", + "live": "long-poll", + "samples": 12, + "bySize": { + "1024": { + "write": { + "n": 12, + "mean": 2.937, + "p50": 2.808, + "min": 1.713, + "max": 3.749 + }, + "read": { + "n": 12, + "mean": 3.218, + "p50": 3.158, + "min": 1.963, + "max": 3.992 + } + }, + "4096": { + "write": { + "n": 12, + "mean": 3.472, + "p50": 3.013, + "min": 1.828, + "max": 6.157 + }, + "read": { + "n": 12, + "mean": 3.724, + "p50": 3.28, + "min": 2.037, + "max": 6.463 + } + }, + "16384": { + "write": { + "n": 12, + "mean": 4.997, + "p50": 5.441, + "min": 2.597, + "max": 6.831 + }, + "read": { + "n": 12, + "mean": 5.315, + "p50": 5.745, + "min": 2.844, + "max": 7.124 + } + }, + "65536": { + "write": { + "n": 12, + "mean": 4.067, + "p50": 4.373, + "min": 1.87, + "max": 5.86 + }, + "read": { + "n": 12, + "mean": 4.409, + "p50": 4.743, + "min": 2.157, + "max": 6.238 + } + } + } + }, + { + "combo": { + "durability": "wal", + "offload": "tail", + "tailCache": "0", + "fastFsync": false + }, + "name": "wal offload=tail tailcache=0", + "url": "http://127.0.0.1:4621/latency-bench-1", + "live": "long-poll", + "samples": 12, + "bySize": { + "1024": { + "write": { + "n": 12, + "mean": 3.176, + "p50": 3.657, + "min": 1.476, + "max": 4.443 + }, + "read": { + "n": 12, + "mean": 3.5, + "p50": 3.954, + "min": 1.666, + "max": 4.923 + } + }, + "4096": { + "write": { + "n": 12, + "mean": 3.191, + "p50": 3.505, + "min": 1.532, + "max": 3.887 + }, + "read": { + "n": 12, + "mean": 3.474, + "p50": 3.744, + "min": 1.804, + "max": 4.241 + } + }, + "16384": { + "write": { + "n": 12, + "mean": 3.243, + "p50": 3.732, + "min": 2.23, + "max": 4.116 + }, + "read": { + "n": 12, + "mean": 3.537, + "p50": 3.988, + "min": 2.528, + "max": 4.503 + } + }, + "65536": { + "write": { + "n": 12, + "mean": 3.309, + "p50": 3.674, + "min": 2.092, + "max": 4.046 + }, + "read": { + "n": 12, + "mean": 3.622, + "p50": 3.991, + "min": 2.358, + "max": 4.311 + } + } + } + }, + { + "combo": { + "durability": "wal", + "offload": "inline", + "tailCache": "default", + "fastFsync": false + }, + "name": "wal offload=inline tailcache=default", + "url": "http://127.0.0.1:4622/latency-bench-2", + "live": "long-poll", + "samples": 12, + "bySize": { + "1024": { + "write": { + "n": 12, + "mean": 2.42, + "p50": 2.066, + "min": 1.436, + "max": 3.704 + }, + "read": { + "n": 12, + "mean": 2.64, + "p50": 2.291, + "min": 1.667, + "max": 4.003 + } + }, + "4096": { + "write": { + "n": 12, + "mean": 2.64, + "p50": 2.807, + "min": 1.451, + "max": 3.73 + }, + "read": { + "n": 12, + "mean": 2.906, + "p50": 3.064, + "min": 1.653, + "max": 4.166 + } + }, + "16384": { + "write": { + "n": 12, + "mean": 3.639, + "p50": 3.752, + "min": 2.734, + "max": 3.879 + }, + "read": { + "n": 12, + "mean": 3.874, + "p50": 3.957, + "min": 2.903, + "max": 4.288 + } + }, + "65536": { + "write": { + "n": 12, + "mean": 2.702, + "p50": 2.712, + "min": 1.585, + "max": 3.773 + }, + "read": { + "n": 12, + "mean": 2.987, + "p50": 3.108, + "min": 1.815, + "max": 4.079 + } + } + } + }, + { + "combo": { + "durability": "wal", + "offload": "inline", + "tailCache": "0", + "fastFsync": false + }, + "name": "wal offload=inline tailcache=0", + "url": "http://127.0.0.1:4623/latency-bench-3", + "live": "long-poll", + "samples": 12, + "bySize": { + "1024": { + "write": { + "n": 12, + "mean": 2.811, + "p50": 2.829, + "min": 1.455, + "max": 3.654 + }, + "read": { + "n": 12, + "mean": 3.041, + "p50": 3.118, + "min": 1.634, + "max": 3.815 + } + }, + "4096": { + "write": { + "n": 12, + "mean": 2.494, + "p50": 2.834, + "min": 1.358, + "max": 3.624 + }, + "read": { + "n": 12, + "mean": 2.713, + "p50": 3.058, + "min": 1.532, + "max": 3.871 + } + }, + "16384": { + "write": { + "n": 12, + "mean": 2.554, + "p50": 2.753, + "min": 1.818, + "max": 2.888 + }, + "read": { + "n": 12, + "mean": 2.75, + "p50": 2.968, + "min": 2.02, + "max": 3.088 + } + }, + "65536": { + "write": { + "n": 12, + "mean": 3.015, + "p50": 3.192, + "min": 1.567, + "max": 3.794 + }, + "read": { + "n": 12, + "mean": 3.275, + "p50": 3.399, + "min": 1.826, + "max": 4.136 + } + } + } + }, + { + "combo": { + "durability": "wal", + "offload": "always", + "tailCache": "default", + "fastFsync": false + }, + "name": "wal offload=always tailcache=default", + "url": "http://127.0.0.1:4624/latency-bench-4", + "live": "long-poll", + "samples": 12, + "bySize": { + "1024": { + "write": { + "n": 12, + "mean": 2.699, + "p50": 2.417, + "min": 1.22, + "max": 4.534 + }, + "read": { + "n": 12, + "mean": 3.281, + "p50": 3.319, + "min": 1.419, + "max": 5.014 + } + }, + "4096": { + "write": { + "n": 12, + "mean": 1.988, + "p50": 1.83, + "min": 1.111, + "max": 3.113 + }, + "read": { + "n": 12, + "mean": 2.097, + "p50": 1.925, + "min": 1.223, + "max": 3.262 + } + }, + "16384": { + "write": { + "n": 12, + "mean": 3.226, + "p50": 2.92, + "min": 2.785, + "max": 3.793 + }, + "read": { + "n": 12, + "mean": 3.412, + "p50": 3.233, + "min": 2.933, + "max": 3.95 + } + }, + "65536": { + "write": { + "n": 12, + "mean": 2.971, + "p50": 3.32, + "min": 1.487, + "max": 3.823 + }, + "read": { + "n": 12, + "mean": 3.252, + "p50": 3.553, + "min": 1.69, + "max": 4.187 + } + } + } + }, + { + "combo": { + "durability": "wal", + "offload": "always", + "tailCache": "0", + "fastFsync": false + }, + "name": "wal offload=always tailcache=0", + "url": "http://127.0.0.1:4625/latency-bench-5", + "live": "long-poll", + "samples": 12, + "bySize": { + "1024": { + "write": { + "n": 12, + "mean": 2.574, + "p50": 2.863, + "min": 1.448, + "max": 3.75 + }, + "read": { + "n": 12, + "mean": 2.73, + "p50": 3.022, + "min": 1.634, + "max": 3.897 + } + }, + "4096": { + "write": { + "n": 12, + "mean": 2.817, + "p50": 3.031, + "min": 1.454, + "max": 3.946 + }, + "read": { + "n": 12, + "mean": 2.953, + "p50": 3.167, + "min": 1.634, + "max": 4.037 + } + }, + "16384": { + "write": { + "n": 12, + "mean": 3.027, + "p50": 2.892, + "min": 2.47, + "max": 3.896 + }, + "read": { + "n": 12, + "mean": 3.164, + "p50": 3.066, + "min": 2.588, + "max": 4.042 + } + }, + "65536": { + "write": { + "n": 12, + "mean": 3.076, + "p50": 3.243, + "min": 1.961, + "max": 4.125 + }, + "read": { + "n": 12, + "mean": 3.267, + "p50": 3.453, + "min": 2.217, + "max": 4.301 + } + } + } + }, + { + "combo": { + "durability": "memory", + "offload": "tail", + "tailCache": "default", + "fastFsync": false + }, + "name": "memory offload=tail tailcache=default", + "url": "http://127.0.0.1:4626/latency-bench-6", + "live": "long-poll", + "samples": 12, + "bySize": { + "1024": { + "write": { + "n": 12, + "mean": 0.269, + "p50": 0.271, + "min": 0.213, + "max": 0.373 + }, + "read": { + "n": 12, + "mean": 0.408, + "p50": 0.41, + "min": 0.336, + "max": 0.497 + } + }, + "4096": { + "write": { + "n": 12, + "mean": 0.257, + "p50": 0.217, + "min": 0.188, + "max": 0.563 + }, + "read": { + "n": 12, + "mean": 0.389, + "p50": 0.323, + "min": 0.288, + "max": 0.889 + } + }, + "16384": { + "write": { + "n": 12, + "mean": 0.26, + "p50": 0.244, + "min": 0.203, + "max": 0.408 + }, + "read": { + "n": 12, + "mean": 0.42, + "p50": 0.41, + "min": 0.31, + "max": 0.652 + } + }, + "65536": { + "write": { + "n": 12, + "mean": 0.47, + "p50": 0.332, + "min": 0.247, + "max": 1.679 + }, + "read": { + "n": 12, + "mean": 0.676, + "p50": 0.559, + "min": 0.38, + "max": 1.932 + } + } + } + }, + { + "combo": { + "durability": "memory", + "offload": "tail", + "tailCache": "0", + "fastFsync": false + }, + "name": "memory offload=tail tailcache=0", + "url": "http://127.0.0.1:4627/latency-bench-7", + "live": "long-poll", + "samples": 12, + "bySize": { + "1024": { + "write": { + "n": 12, + "mean": 0.291, + "p50": 0.266, + "min": 0.216, + "max": 0.464 + }, + "read": { + "n": 12, + "mean": 0.481, + "p50": 0.404, + "min": 0.318, + "max": 1.179 + } + }, + "4096": { + "write": { + "n": 12, + "mean": 0.192, + "p50": 0.195, + "min": 0.161, + "max": 0.226 + }, + "read": { + "n": 12, + "mean": 0.31, + "p50": 0.31, + "min": 0.253, + "max": 0.397 + } + }, + "16384": { + "write": { + "n": 12, + "mean": 0.225, + "p50": 0.233, + "min": 0.186, + "max": 0.278 + }, + "read": { + "n": 12, + "mean": 0.352, + "p50": 0.351, + "min": 0.288, + "max": 0.46 + } + }, + "65536": { + "write": { + "n": 12, + "mean": 0.413, + "p50": 0.264, + "min": 0.21, + "max": 1.587 + }, + "read": { + "n": 12, + "mean": 0.599, + "p50": 0.44, + "min": 0.354, + "max": 1.822 + } + } + } + }, + { + "combo": { + "durability": "memory", + "offload": "inline", + "tailCache": "default", + "fastFsync": false + }, + "name": "memory offload=inline tailcache=default", + "url": "http://127.0.0.1:4628/latency-bench-8", + "live": "long-poll", + "samples": 12, + "bySize": { + "1024": { + "write": { + "n": 12, + "mean": 0.375, + "p50": 0.387, + "min": 0.26, + "max": 0.471 + }, + "read": { + "n": 12, + "mean": 0.606, + "p50": 0.619, + "min": 0.488, + "max": 0.808 + } + }, + "4096": { + "write": { + "n": 12, + "mean": 0.251, + "p50": 0.244, + "min": 0.222, + "max": 0.291 + }, + "read": { + "n": 12, + "mean": 0.41, + "p50": 0.385, + "min": 0.334, + "max": 0.707 + } + }, + "16384": { + "write": { + "n": 12, + "mean": 0.284, + "p50": 0.271, + "min": 0.208, + "max": 0.421 + }, + "read": { + "n": 12, + "mean": 0.438, + "p50": 0.403, + "min": 0.326, + "max": 0.582 + } + }, + "65536": { + "write": { + "n": 12, + "mean": 0.467, + "p50": 0.376, + "min": 0.246, + "max": 1.692 + }, + "read": { + "n": 12, + "mean": 0.68, + "p50": 0.601, + "min": 0.406, + "max": 1.943 + } + } + } + }, + { + "combo": { + "durability": "memory", + "offload": "inline", + "tailCache": "0", + "fastFsync": false + }, + "name": "memory offload=inline tailcache=0", + "url": "http://127.0.0.1:4629/latency-bench-9", + "live": "long-poll", + "samples": 12, + "bySize": { + "1024": { + "write": { + "n": 12, + "mean": 0.348, + "p50": 0.311, + "min": 0.25, + "max": 0.523 + }, + "read": { + "n": 12, + "mean": 0.527, + "p50": 0.442, + "min": 0.363, + "max": 0.964 + } + }, + "4096": { + "write": { + "n": 12, + "mean": 0.237, + "p50": 0.239, + "min": 0.179, + "max": 0.287 + }, + "read": { + "n": 12, + "mean": 0.366, + "p50": 0.369, + "min": 0.29, + "max": 0.511 + } + }, + "16384": { + "write": { + "n": 12, + "mean": 0.205, + "p50": 0.198, + "min": 0.176, + "max": 0.257 + }, + "read": { + "n": 12, + "mean": 0.319, + "p50": 0.307, + "min": 0.269, + "max": 0.434 + } + }, + "65536": { + "write": { + "n": 12, + "mean": 0.27, + "p50": 0.264, + "min": 0.212, + "max": 0.328 + }, + "read": { + "n": 12, + "mean": 0.423, + "p50": 0.423, + "min": 0.354, + "max": 0.524 + } + } + } + }, + { + "combo": { + "durability": "memory", + "offload": "always", + "tailCache": "default", + "fastFsync": false + }, + "name": "memory offload=always tailcache=default", + "url": "http://127.0.0.1:4630/latency-bench-10", + "live": "long-poll", + "samples": 12, + "bySize": { + "1024": { + "write": { + "n": 12, + "mean": 0.305, + "p50": 0.264, + "min": 0.223, + "max": 0.517 + }, + "read": { + "n": 12, + "mean": 0.46, + "p50": 0.426, + "min": 0.336, + "max": 0.805 + } + }, + "4096": { + "write": { + "n": 12, + "mean": 0.231, + "p50": 0.224, + "min": 0.204, + "max": 0.297 + }, + "read": { + "n": 12, + "mean": 0.369, + "p50": 0.362, + "min": 0.31, + "max": 0.554 + } + }, + "16384": { + "write": { + "n": 12, + "mean": 0.236, + "p50": 0.24, + "min": 0.208, + "max": 0.271 + }, + "read": { + "n": 12, + "mean": 0.363, + "p50": 0.368, + "min": 0.327, + "max": 0.399 + } + }, + "65536": { + "write": { + "n": 12, + "mean": 0.295, + "p50": 0.292, + "min": 0.241, + "max": 0.36 + }, + "read": { + "n": 12, + "mean": 0.487, + "p50": 0.488, + "min": 0.413, + "max": 0.559 + } + } + } + }, + { + "combo": { + "durability": "memory", + "offload": "always", + "tailCache": "0", + "fastFsync": false + }, + "name": "memory offload=always tailcache=0", + "url": "http://127.0.0.1:4631/latency-bench-11", + "live": "long-poll", + "samples": 12, + "bySize": { + "1024": { + "write": { + "n": 12, + "mean": 0.186, + "p50": 0.165, + "min": 0.129, + "max": 0.456 + }, + "read": { + "n": 12, + "mean": 0.277, + "p50": 0.252, + "min": 0.213, + "max": 0.587 + } + }, + "4096": { + "write": { + "n": 12, + "mean": 0.181, + "p50": 0.168, + "min": 0.146, + "max": 0.3 + }, + "read": { + "n": 12, + "mean": 0.291, + "p50": 0.267, + "min": 0.219, + "max": 0.533 + } + }, + "16384": { + "write": { + "n": 12, + "mean": 0.197, + "p50": 0.188, + "min": 0.159, + "max": 0.274 + }, + "read": { + "n": 12, + "mean": 0.309, + "p50": 0.297, + "min": 0.249, + "max": 0.441 + } + }, + "65536": { + "write": { + "n": 12, + "mean": 0.215, + "p50": 0.206, + "min": 0.151, + "max": 0.381 + }, + "read": { + "n": 12, + "mean": 0.351, + "p50": 0.341, + "min": 0.243, + "max": 0.582 + } + } + } + }, + { + "combo": { + "durability": "wal", + "offload": "tail", + "tailCache": "default", + "fastFsync": true + }, + "name": "wal+fastfsync offload=tail tailcache=default", + "url": "http://127.0.0.1:4632/latency-bench-12", + "live": "long-poll", + "samples": 12, + "bySize": { + "1024": { + "write": { + "n": 12, + "mean": 0.318, + "p50": 0.31, + "min": 0.233, + "max": 0.46 + }, + "read": { + "n": 12, + "mean": 0.452, + "p50": 0.438, + "min": 0.321, + "max": 0.634 + } + }, + "4096": { + "write": { + "n": 12, + "mean": 0.274, + "p50": 0.234, + "min": 0.207, + "max": 0.417 + }, + "read": { + "n": 12, + "mean": 0.4, + "p50": 0.362, + "min": 0.304, + "max": 0.617 + } + }, + "16384": { + "write": { + "n": 12, + "mean": 0.311, + "p50": 0.288, + "min": 0.241, + "max": 0.454 + }, + "read": { + "n": 12, + "mean": 0.445, + "p50": 0.448, + "min": 0.344, + "max": 0.618 + } + }, + "65536": { + "write": { + "n": 12, + "mean": 0.357, + "p50": 0.349, + "min": 0.281, + "max": 0.569 + }, + "read": { + "n": 12, + "mean": 0.523, + "p50": 0.491, + "min": 0.422, + "max": 0.739 + } + } + } + } + ] +} diff --git a/packages/durable-streams-rust/bench-latency/run-latency-matrix.mjs b/packages/durable-streams-rust/bench-latency/run-latency-matrix.mjs new file mode 100644 index 0000000000..d692d96825 --- /dev/null +++ b/packages/durable-streams-rust/bench-latency/run-latency-matrix.mjs @@ -0,0 +1,189 @@ +// Orchestrates the write/read latency matrix on this host. +// +// For each valid server config combination it: starts the server on a fresh +// data dir, waits for /health, runs latency-probe.mjs (live long-poll reader +// parked BEFORE each write), stops the server, and aggregates results. +// +// Dimensions: +// durability: wal | memory (+ one wal variant with DS_UNSAFE_FAST_FSYNC=1, +// bench-only plain fsync instead of macOS F_FULLFSYNC) +// read-offload: inline | tail (default) | always +// tail-cache: default (64 KiB on macOS) | 0 (disabled) +// payload sizes: 1 KiB, 4 KiB, 16 KiB, 64 KiB (in the probe) +// +// Usage: node run-latency-matrix.mjs [--samples 12] [--out results.json] [--quick] +// --quick runs only the default-config combos (one per durability mode). + +import { spawn } from 'node:child_process' +import { mkdtempSync, rmSync, writeFileSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join, dirname } from 'node:path' +import { fileURLToPath } from 'node:url' +import { runProbe } from './latency-probe.mjs' + +const HERE = dirname(fileURLToPath(import.meta.url)) +const SERVER_BIN = join( + HERE, + `..`, + `target`, + `release`, + `durable-streams-server` +) + +const args = Object.fromEntries( + process.argv + .slice(2) + .map((a, i, xs) => + a.startsWith(`--`) ? [a.slice(2), xs[i + 1] ?? `true`] : null + ) + .filter(Boolean) +) +const SAMPLES = args.samples ? parseInt(args.samples, 10) : 12 +const OUT = args.out ?? join(HERE, `latency-results.json`) +const QUICK = `quick` in args + +const FULL_COMBOS = [] +for (const durability of [`wal`, `memory`]) { + for (const offload of [`tail`, `inline`, `always`]) { + for (const tailCache of [`default`, `0`]) { + FULL_COMBOS.push({ durability, offload, tailCache, fastFsync: false }) + } + } +} +// Diagnostic variant: WAL commit with plain fsync instead of F_FULLFSYNC — +// approximates the Linux/NVMe regime and isolates the macOS barrier cost. +FULL_COMBOS.push({ + durability: `wal`, + offload: `tail`, + tailCache: `default`, + fastFsync: true, +}) + +const QUICK_COMBOS = [ + { + durability: `wal`, + offload: `tail`, + tailCache: `default`, + fastFsync: false, + }, + { + durability: `memory`, + offload: `tail`, + tailCache: `default`, + fastFsync: false, + }, + { durability: `wal`, offload: `tail`, tailCache: `default`, fastFsync: true }, +] + +const COMBOS = QUICK ? QUICK_COMBOS : FULL_COMBOS + +function comboName(c) { + return [ + c.durability + (c.fastFsync ? `+fastfsync` : ``), + `offload=${c.offload}`, + `tailcache=${c.tailCache}`, + ].join(` `) +} + +async function waitHealthy(port, proc, timeoutMs = 15_000) { + const deadline = Date.now() + timeoutMs + while (Date.now() < deadline) { + if (proc.exitCode !== null) + throw new Error(`server exited early (code ${proc.exitCode})`) + try { + const r = await fetch(`http://127.0.0.1:${port}/health`) + if (r.ok) return + } catch { + /* not up yet */ + } + await new Promise((r) => setTimeout(r, 50)) + } + throw new Error(`server never became healthy`) +} + +async function runCombo(combo, index) { + const port = 4620 + index + const dataDir = mkdtempSync(join(tmpdir(), `ds-latency-${index}-`)) + const argv = [ + `--port`, + String(port), + `--data-dir`, + dataDir, + `--durability`, + combo.durability, + `--read-offload`, + combo.offload, + ] + if (combo.tailCache !== `default`) + argv.push(`--tail-cache-bytes`, combo.tailCache) + + const env = { ...process.env } + if (combo.fastFsync) env.DS_UNSAFE_FAST_FSYNC = `1` + + const proc = spawn(SERVER_BIN, argv, { + env, + stdio: [`ignore`, `ignore`, `pipe`], + }) + let stderr = `` + proc.stderr.on(`data`, (d) => (stderr += d)) + + try { + await waitHealthy(port, proc) + const result = await runProbe({ + url: `http://127.0.0.1:${port}/latency-bench-${index}`, + live: `long-poll`, + samples: SAMPLES, + }) + return { combo, name: comboName(combo), ...result } + } catch (err) { + return { + combo, + name: comboName(combo), + error: String(err), + stderr: stderr.slice(-2000), + } + } finally { + proc.kill(`SIGTERM`) + await new Promise((r) => { + proc.on(`exit`, r) + setTimeout(() => { + proc.kill(`SIGKILL`) + r() + }, 3000) + }) + rmSync(dataDir, { recursive: true, force: true }) + } +} + +const results = [] +for (let i = 0; i < COMBOS.length; i++) { + const name = comboName(COMBOS[i]) + process.stderr.write(`[${i + 1}/${COMBOS.length}] ${name} ... `) + const r = await runCombo(COMBOS[i], i) + results.push(r) + process.stderr.write(r.error ? `ERROR: ${r.error}\n` : `ok\n`) +} + +writeFileSync( + OUT, + JSON.stringify({ host: process.platform, samples: SAMPLES, results }, null, 2) +) +process.stderr.write(`results written to ${OUT}\n`) + +// Markdown summary: one row per combo × size. +const KB = (n) => `${n / 1024}k` +console.log( + `| config | size | write mean | write p50 | read mean | read p50 | read min | read max |` +) +console.log(`| --- | --- | --- | --- | --- | --- | --- | --- |`) +for (const r of results) { + if (r.error) { + console.log(`| ${r.name} | - | ERROR: ${r.error} | | | | | |`) + continue + } + for (const [size, s] of Object.entries(r.bySize)) { + console.log( + `| ${r.name} | ${KB(+size)} | ${s.write.mean} | ${s.write.p50} | ${s.read.mean} | ${s.read.p50} | ${s.read.min} | ${s.read.max} |` + ) + } +} diff --git a/packages/durable-streams-rust/src/engine_raw.rs b/packages/durable-streams-rust/src/engine_raw.rs index 1e7558ea05..4de4aad121 100644 --- a/packages/durable-streams-rust/src/engine_raw.rs +++ b/packages/durable-streams-rust/src/engine_raw.rs @@ -14,8 +14,6 @@ // zero-copy page-cache → socket transfer, but a fault parks a pool thread // instead. ReadOffload picks where each read runs; see set_read_offload. -#[cfg(target_os = "linux")] -use std::sync::atomic::AtomicBool; use std::sync::atomic::{AtomicU8, Ordering}; use std::sync::Arc; @@ -60,25 +58,6 @@ impl ReadOffload { static READ_OFFLOAD: AtomicU8 = AtomicU8::new(ReadOffload::Tail as u8); -/// Process-global zero-copy-append toggle, set by `--durability memory` (Linux -/// only). When on, eligible binary appends are served via the socket→file splice -/// intercept and the tail cache is off. -#[cfg(target_os = "linux")] -static ZERO_COPY: AtomicBool = AtomicBool::new(false); - -/// Enable/disable the zero-copy append path (process-global). -#[cfg(target_os = "linux")] -pub fn set_zero_copy(on: bool) { - ZERO_COPY.store(on, Ordering::Relaxed); -} - -/// Whether the zero-copy append path is active. -#[cfg(target_os = "linux")] -#[inline] -pub fn zero_copy() -> bool { - ZERO_COPY.load(Ordering::Relaxed) -} - /// Set the read-offload strategy (process-global). Called once at startup. pub fn set_read_offload(mode: ReadOffload) { READ_OFFLOAD.store(mode as u8, Ordering::Relaxed); @@ -222,85 +201,6 @@ async fn conn_loop( let keep_alive = head.keep_alive; let is_head = head.is_head; - // ---- zero-copy binary-append intercept (Linux only, --durability memory) ---- - // - // Eligible: zero-copy on (set by --durability memory), POST, a known - // content-length (not chunked), and the route is a binary append. We DON'T - // `read_sized` here; instead the body is relayed socket→file via splice(2). - // The handler returns `Fallback` for any edge case (producer dup/gap, - // closed, close request, JSON, content-type mismatch, …), in which case we - // read the body buffered below and run the normal handler — byte-for-byte - // unchanged. - #[cfg(target_os = "linux")] - if zero_copy() - && matches!(head.method, crate::api::Method::Post) - && !head.chunked - && head.content_length.is_some_and(|n| n > 0) - { - let content_len = head.content_length.unwrap(); - // The bytes the head parser over-read are the body prefix. Take up to - // `content_len` of them (a tiny pipelined next-request tail must not be - // counted as body); the rest of the body is still on the socket. - let take = buf.len().min(content_len); - let prefix = buf.split_to(take).freeze(); - let remaining = content_len - prefix.len(); - // splice_rest moves the remaining socket bytes into (file_fd, off), - // awaiting socket read-readiness — the tokio `TcpStream` is - // non-blocking, so a splice that returns EAGAIN (body not fully - // arrived) must park on readiness rather than error. It borrows - // `stream` immutably (read-readiness only); the borrow lives across - // the handler's await while the appender lock is held — fine, the - // lock is an AsyncMutex. - let stream_ref = &stream; - let splice_rest = move |file_fd: std::os::fd::RawFd, off: i64| async move { - if remaining == 0 { - return Ok(()); - } - let mut o = off; - zerocopy::splice_socket_to_file(stream_ref, file_fd, &mut o, remaining).await - }; - let req = Req { - method: head.method, - path: head.path.clone(), - query: head.query.clone(), - headers: head.headers.clone(), - body: Bytes::new(), - }; - let outcome = handlers::handle_binary_append_zero_copy( - store.clone(), - &req, - &prefix, - content_len, - splice_rest, - ) - .await; - match outcome { - handlers::ZeroCopyOutcome::Done(resp) => { - write_response(&mut stream, resp, is_head, keep_alive).await?; - if !keep_alive { - return Ok(()); - } - continue; - } - handlers::ZeroCopyOutcome::DoneClose(resp) => { - // A splice leg failed mid-append: body bytes may already be - // consumed from the socket, so the connection is desynced. - // Send the 500 with `connection: close` and drop the - // connection — never reuse it as keep-alive. - write_response(&mut stream, resp, is_head, false).await?; - return Ok(()); - } - handlers::ZeroCopyOutcome::Fallback => { - // Put the prefix back at the front of the buffer so the - // buffered read below sees the full body again. - let mut rebuilt = BytesMut::with_capacity(prefix.len() + buf.len()); - rebuilt.extend_from_slice(&prefix); - rebuilt.extend_from_slice(&buf); - buf = rebuilt; - } - } - } - // ---- read request body ---- let body = if head.chunked { match http1::decode_chunked(&mut stream, &mut buf).await? { @@ -638,128 +538,6 @@ async fn write_segment(stream: &mut TcpStream, seg: &Segment) -> std::io::Result Ok(()) } -/// Zero-copy file-to-file / file-to-socket relay via `splice(2)`. -#[cfg(target_os = "linux")] -pub(crate) mod zerocopy { - use std::io; - use std::os::fd::{AsRawFd, RawFd}; - - /// Move exactly `len` bytes from a tokio (non-blocking) `TcpStream` into the - /// regular file `file_fd` at `*file_off`, in-kernel via an anonymous pipe, - /// awaiting socket read-readiness between attempts. - /// - /// The socket→pipe leg uses `stream.async_io(READABLE, …)`: a `splice(2)` - /// that would block (`EAGAIN`/`EWOULDBLOCK` — the body has not fully arrived - /// in the socket receive buffer) is reported to tokio as - /// `ErrorKind::WouldBlock`, so `async_io` parks on readiness and retries - /// instead of erroring. The pipe→file leg drains synchronously: the - /// destination is a regular file (positioned write, never `EAGAIN`), so no - /// readiness wait is needed and `*file_off` is advanced as bytes land. - /// - /// A socket `splice` returning 0 (peer closed before `len` bytes arrived) is - /// a hard error (`UnexpectedEof`) — and, crucially, NOT `WouldBlock`, so - /// `async_io` propagates it rather than spinning. Holding the appender - /// `AsyncMutex` across this await is intentional (per-stream serialization). - pub async fn splice_socket_to_file( - stream: &tokio::net::TcpStream, - file_fd: RawFd, - file_off: &mut i64, - mut len: usize, - ) -> io::Result<()> { - if len == 0 { - return Ok(()); - } - let socket_fd = stream.as_raw_fd(); - // One pipe for the whole transfer (re-created per call, not per retry): - // bytes spliced socket→pipe are drained pipe→file before the next - // readiness wait, so the pipe is empty across awaits. - let mut fds = [0i32; 2]; - // SAFETY: fds is a 2-element array; pipe2 fills both on success. - if unsafe { libc::pipe2(fds.as_mut_ptr(), libc::O_CLOEXEC) } != 0 { - return Err(io::Error::last_os_error()); - } - let (pr, pw) = (fds[0], fds[1]); - let res = async { - while len > 0 { - // socket → pipe, awaiting readiness. async_io retries ONLY on - // WouldBlock; any other error (incl. our EOF below) propagates. - let moved = stream - .async_io(tokio::io::Interest::READABLE, || { - // SAFETY: pw is the write end of a valid pipe; socket_fd - // is the stream's fd. splice aliases no Rust references. - let n = unsafe { - libc::splice( - socket_fd, - std::ptr::null_mut(), - pw, - std::ptr::null_mut(), - len, - libc::SPLICE_F_MOVE | libc::SPLICE_F_MORE, - ) - }; - if n < 0 { - let err = io::Error::last_os_error(); - // EAGAIN == EWOULDBLOCK on Linux: body not fully in - // the socket buffer yet. Map to WouldBlock so async_io - // parks on readiness and retries. - return match err.raw_os_error() { - Some(libc::EAGAIN) => Err(io::ErrorKind::WouldBlock.into()), - _ => Err(err), - }; - } - if n == 0 { - // Peer closed before all `len` bytes arrived. NOT - // WouldBlock, so this propagates out of async_io. - return Err(io::Error::new( - io::ErrorKind::UnexpectedEof, - "socket EOF before full append body", - )); - } - Ok(n as usize) - }) - .await?; - // pipe → file (drain exactly `moved` bytes; regular file, no EAGAIN). - let mut drained = 0usize; - while drained < moved { - // SAFETY: pr is the read end of the same pipe; file_fd is the - // splice file; *file_off is a valid &mut i64 cast to *mut i64. - let m = unsafe { - libc::splice( - pr, - std::ptr::null_mut(), - file_fd, - file_off as *mut i64, - moved - drained, - libc::SPLICE_F_MOVE | libc::SPLICE_F_MORE, - ) - }; - if m < 0 { - return Err(io::Error::last_os_error()); - } - if m == 0 { - return Err(io::Error::new( - io::ErrorKind::UnexpectedEof, - "splice pipe drain returned 0", - )); - } - drained += m as usize; - } - len -= moved; - } - Ok(()) - } - .await; - // SAFETY: close both pipe ends regardless of outcome; valid (pipe2 - // succeeded) and unused after this point. - unsafe { - libc::close(pr); - libc::close(pw); - } - res - } - -} - /// Portable fallback: positioned reads through a reusable buffer. #[cfg(not(target_os = "linux"))] async fn write_segment(stream: &mut TcpStream, seg: &Segment) -> std::io::Result<()> { diff --git a/packages/durable-streams-rust/src/handlers.rs b/packages/durable-streams-rust/src/handlers.rs index 061e684f72..43d9775f52 100644 --- a/packages/durable-streams-rust/src/handlers.rs +++ b/packages/durable-streams-rust/src/handlers.rs @@ -272,7 +272,7 @@ async fn dispatch(store: Arc, req: Req) -> Resp { Method::Post => handle_append(store, req, path).await, Method::Get => handle_read(store, req, path).await, Method::Head => handle_head(store, path), - Method::Delete => handle_delete(store, path), + Method::Delete => handle_delete(store, path).await, Method::Options => ResponseBuilder::new(204).body(empty()), Method::Other => text_response(405, "method not allowed"), } @@ -886,25 +886,26 @@ impl AppendOutcome { async fn handle_append(store: Arc, req: Req, path: String) -> Resp { let t0 = crate::telemetry::Timer::start(); - // is_json is needed for the metric label even on the not-found path, where we - // don't have a stream; default to false there. - let is_json = store.get(&path).map(|s| s.is_json).unwrap_or(false); - let (resp, outcome) = handle_append_inner(store, req, path).await; + // is_json comes back from the inner handler (false on the not-found path) so + // the metric label doesn't cost a SECOND registry lookup per append — at high + // stream cardinality each lookup is a cold walk of a million-key map. + let (resp, outcome, is_json) = handle_append_inner(store, req, path).await; crate::telemetry::record_append(t0.elapsed_secs(), outcome.label(), is_json); resp } -async fn handle_append_inner(store: Arc, req: Req, path: String) -> (Resp, AppendOutcome) { +async fn handle_append_inner(store: Arc, req: Req, path: String) -> (Resp, AppendOutcome, bool) { use AppendOutcome::*; + let st = match store.get(&path) { + Some(s) => s, + None => return (text_response(404, "stream not found"), Conflict, false), + }; + let is_json = st.is_json; macro_rules! ret { ($resp:expr, $oc:expr) => { - return ($resp, $oc) + return ($resp, $oc, is_json) }; } - let st = match store.get(&path) { - Some(s) => s, - None => ret!(text_response(404, "stream not found"), Conflict), - }; if st.shared.read().unwrap().soft_deleted { ret!(gone(), Conflict); } @@ -1156,7 +1157,18 @@ async fn handle_append_inner(store: Arc, req: Req, path: String) -> (Resp st.tail_tx.send_replace(Tail { bytes: tail, closed: true }); #[cfg(target_os = "linux")] crate::sse_reactor::wake_stream(&st); + } else if staged_lsn.is_some() { + // WAL mode: the stream is in its shard's dirty set (register_dirty ran + // during staging), so the ~3 s checkpoint will write the sidecar for us — + // just mark it. This keeps the meta `File::create`+`rename` (and its + // parent-directory rwsem, measured at ~40% of server CPU under write + // saturation) plus a timer task OFF the per-append path. Producer/access + // updates are already documented as a non-durable, lagging flush; the lag + // bound moves from the 100 ms debounce to the checkpoint cadence. + st.meta_dirty.store(true, std::sync::atomic::Ordering::Release); } else { + // No WAL record staged (memory durability): no checkpoint will flush the + // sidecar — keep the debounced flush. st.schedule_meta_flush(); } if !wire.is_empty() { @@ -1178,7 +1190,7 @@ async fn handle_append_inner(store: Arc, req: Req, path: String) -> (Resp if tail.closed { b = b.hs(H_CLOSED, "true"); } - (b.body(empty()), Accept) + (b.body(empty()), Accept, is_json) } fn closed_conflict(tail: u64) -> Resp { @@ -1188,214 +1200,6 @@ fn closed_conflict(tail: u64) -> Resp { .body(full("stream is closed")) } -// ---------- POST (append) — zero-copy socket→file splice path (Linux, --durability memory) ---------- - -/// Result of the zero-copy append entry. `Fallback` means the engine must fall -/// back to the buffered append path (read the whole body, run `handle`): the -/// request is anything but the simple happy-path append (a producer dup/gap/ -/// stale-epoch, a `Stream-Seq` regression, a closed stream, a close request, a -/// missing/mismatched content-type, …). Every such edge case is handled -/// byte-for-byte by the existing buffered handler — the splice path deliberately -/// covers only the accept-and-write case so its critical section is a tight -/// mirror of `write_wire` (memory mode has no WAL stage). -#[cfg(target_os = "linux")] -pub enum ZeroCopyOutcome { - /// Append handled; send `resp` and continue keep-alive as normal. - Done(Resp), - /// A splice leg failed mid-append: some body bytes may have already been - /// consumed from the socket, so the HTTP framing is desynced. Send `resp` - /// (a 500) but then CLOSE the connection — it must NOT be reused as - /// keep-alive (a stale partial body would corrupt the next request). - DoneClose(Resp), - Fallback, -} - -/// Zero-copy binary append (`--durability memory`): relay the request body -/// socket→file via `splice(2)` while holding the appender lock, then ack — the -/// offset/producer semantics are identical to the buffered append, only the byte -/// movement differs (no userspace `Bytes`). There is no WAL in memory mode: the -/// per-stream file write is the ack (durability comes from replication). -/// -/// The caller (engine) has already confirmed: `--durability memory` (the engine -/// zero-copy intercept), `POST`, a known -/// `content_length` (not chunked), and a binary (non-JSON) target stream. -/// `prefix` is the leading body bytes the HTTP parser over-read; `splice_rest` -/// moves the remaining `content_len - prefix.len()` bytes from the socket to the -/// given `(file_fd, offset)` (the engine owns the socket fd + pipe machinery). -/// -/// Returns `Fallback` for anything that is not a plain accept (see -/// `ZeroCopyOutcome`); the engine then reads the body buffered and runs the -/// normal handler. No stream state is mutated before the accept decision, so the -/// fallback re-validates from scratch and is fully idempotent. -/// -/// `splice_rest` moves the remaining `content_len - prefix.len()` body bytes from -/// the socket to `(file_fd, offset)` and is `async`: the socket is non-blocking, -/// so the socket→file splice awaits read-readiness (it may park if the body has -/// not fully arrived). It is awaited here WHILE the appender `AsyncMutex` is held -/// — intended per-stream serialization; holding it across `.await` is supported. -#[cfg(target_os = "linux")] -pub async fn handle_binary_append_zero_copy( - store: Arc, - req: &Req, - prefix: &[u8], - content_len: usize, - splice_rest: F, -) -> ZeroCopyOutcome -where - F: FnOnce(std::os::fd::RawFd, i64) -> Fut, - Fut: std::future::Future>, -{ - use std::os::fd::AsRawFd; - - let path = req.path.clone(); - // Route. A missing/soft-deleted/JSON stream, or one whose content-type does - // not match, is an edge case → buffered fallback. - let st = match store.get(&path) { - Some(s) => s, - None => return ZeroCopyOutcome::Fallback, - }; - if st.is_json || st.shared.read().unwrap().soft_deleted { - return ZeroCopyOutcome::Fallback; - } - // A close request, an empty body, or producer headers that don't parse are - // all handled by the buffered path. Likewise any explicit close. - if header_is_true(req, H_CLOSED) || content_len == 0 { - return ZeroCopyOutcome::Fallback; - } - let producer = match parse_producer_headers(req) { - Ok(p) => p, - Err(_) => return ZeroCopyOutcome::Fallback, - }; - let seq_header = header_str(req, H_SEQ).map(|s| s.to_string()); - // Content-type must be present and match (binary stream): a missing or - // mismatched type is a 4xx the buffered path renders. - match header_str(req, "content-type") { - None => return ZeroCopyOutcome::Fallback, - Some(ct) => { - if media_type(ct) != media_type(&st.config.content_type) { - return ZeroCopyOutcome::Fallback; - } - } - } - - // Serialize per stream — same lock the buffered path holds across the byte - // write. Held across the socket→file splice (the appender's per-stream - // serialization). - let lock_t0 = crate::telemetry::Timer::start(); - let mut ap = st.appender.lock().await; - crate::telemetry::record_append_lock_wait(lock_t0.elapsed_secs()); - - // Re-check closed / producer / seq under the lock. ANY non-accept outcome → - // fall back (the lock is released on drop, no state mutated). - { - let s = st.shared.read().unwrap(); - if s.closed { - return ZeroCopyOutcome::Fallback; - } - } - if let Some(p) = &producer { - let outcome = { - let s = st.shared.read().unwrap(); - validate_producer(&s, p) - }; - if !matches!(outcome, ProducerOutcome::Accept) { - return ZeroCopyOutcome::Fallback; - } - } - if let Some(seq) = &seq_header { - let s = st.shared.read().unwrap(); - if let Some(last) = &s.last_seq_header { - if seq.as_str() <= last.as_str() { - return ZeroCopyOutcome::Fallback; - } - } - } - - // ---- accepted: drive the socket→file splice ---- - // File offset O where this append lands in the stream's own data file. - let file_off = ap.written; - - // Open a fresh non-O_APPEND fd for positioned writes (splice rejects O_APPEND). - let splice_file = match st.open_splice_fd() { - Ok(f) => f, - Err(_) => return ZeroCopyOutcome::Fallback, - }; - let file_fd = splice_file.as_raw_fd(); - - // Write the already-buffered prefix at O (positioned). On failure the - // remaining body is still unconsumed on the socket, so the HTTP framing is - // desynced → force-close (see DoneClose). - if !prefix.is_empty() { - use std::os::unix::fs::FileExt; - if splice_file.write_all_at(prefix, file_off).is_err() { - return ZeroCopyOutcome::DoneClose(text_response(500, "write failed")); - } - } - // Relay the rest socket→file at O+prefix.len() (awaits socket read-readiness - // — the socket is non-blocking). On failure some body bytes may already be - // consumed from the socket → desynced → force-close. - let rest_off = (file_off + prefix.len() as u64) as i64; - if splice_rest(file_fd, rest_off).await.is_err() { - return ZeroCopyOutcome::DoneClose(text_response(500, "write failed")); - } - - // Publish the new logical tail. `ap.written` and `s.tail` advance under the - // lock exactly as in `write_wire`. The tail cache is OFF under - // --durability memory, so we do NOT call set_last_chunk. - ap.written += content_len as u64; - let (tail, closed) = { - let mut s = st.shared.write().unwrap(); - let tail = s.file_base + ap.written; - s.tail = tail; - // memory mode: the page-cache write IS the ack, so the bytes are - // reader-visible immediately (no WAL fsync to wait for). - s.durable_tail = tail; - s.last_access = SystemTime::now(); - (tail, s.closed_durable) - }; - st.tail_tx.send_replace(Tail { bytes: tail, closed }); - #[cfg(target_os = "linux")] - crate::sse_reactor::wake_stream(&st); - - // Shared response builder: captures `st`, `producer` by ref. - let make_ok = || { - let t = st.tail(); - let status = if producer.is_some() { 200 } else { 204 }; - let mut b = ResponseBuilder::new(status).h(H_NEXT_OFFSET, format_offset(t.bytes)); - if let Some(p) = &producer { - b = b - .h(H_PRODUCER_EPOCH, p.epoch.to_string()) - .h(H_PRODUCER_SEQ, p.seq.to_string()); - } - if t.closed { - b = b.hs(H_CLOSED, "true"); - } - ZeroCopyOutcome::Done(b.body(empty())) - }; - - // This path is reached only in `--durability memory` (the engine zero-copy - // intercept is enabled solely by that mode). The per-stream file write IS the - // durable-enough ack (no WAL, no fsync — durability comes from replication). - debug_assert_eq!(durability(), DurabilityMode::Memory); - // Commit producer/seq dedup state under the appender lock so a concurrent - // same-producer request cannot double-accept. - { - let mut s = st.shared.write().unwrap(); - if let Some(p) = &producer { - s.producers.insert( - p.id.clone(), - ProducerState { epoch: p.epoch, last_seq: p.seq }, - ); - } - if let Some(seq) = &seq_header { - s.last_seq_header = Some(seq.clone()); - } - } - drop(ap); // critical section ends - st.schedule_meta_flush(); - maybe_seal_bg(&store, &st); - make_ok() -} // ---------- reading bodies from the data file ---------- @@ -2162,7 +1966,7 @@ fn handle_head(store: Arc, path: String) -> Resp { // ---------- DELETE ---------- -fn handle_delete(store: Arc, path: String) -> Resp { +async fn handle_delete(store: Arc, path: String) -> Resp { let st = match store.get(&path) { Some(s) => s, None => return text_response(404, "stream not found"), @@ -2170,8 +1974,16 @@ fn handle_delete(store: Arc, path: String) -> Resp { if st.shared.read().unwrap().soft_deleted { return gone(); } - store.delete_or_soft_delete(&st); - ResponseBuilder::new(204).body(empty()) + // The 204 is a durability promise: once acked, a crash must never + // resurrect the stream. Await the on-disk removal (unlinks + parent-dir + // fsync, or the soft-delete meta flag) before responding — a detached + // removal task can be lost to a crash after the ack. + let store2 = Arc::clone(&store); + let st2 = Arc::clone(&st); + match tokio::task::spawn_blocking(move || store2.delete_or_soft_delete_durable(&st2)).await { + Ok(Ok(())) => ResponseBuilder::new(204).body(empty()), + _ => text_response(500, "delete not durable"), + } } #[cfg(test)] diff --git a/packages/durable-streams-rust/src/main.rs b/packages/durable-streams-rust/src/main.rs index aa4bc7b748..5e838b1fe8 100644 --- a/packages/durable-streams-rust/src/main.rs +++ b/packages/durable-streams-rust/src/main.rs @@ -120,10 +120,23 @@ fn main() { // core count; on an existing one reuse the persisted N. A value ≠ the persisted // N is rejected with exit 2 (spec §5). let mut wal_shards: Option = None; + // `--worker-threads N` sizes the tokio runtime's worker-thread pool (and the + // default WAL shard count). `None` ⇒ `available_parallelism()`. This is + // load-bearing under a cgroup cpu limit: `available_parallelism()` reads + // `cpu.max`, so on a big node with a small limit it would under-size the pool; + // an explicit value (e.g. the ds-bench pool suites' `--worker-threads 32`) + // pins the pool to the intended core count regardless. + let mut worker_threads: Option = None; // `--wal-segment-bytes N` overrides the per-shard WAL segment size (the // `fallocate` size + segment-roll threshold). `None` ⇒ the 128 MiB default. // Useful for forcing rolls in tests and benches without writing a full 128 MiB segment. let mut wal_segment_bytes: Option = None; + // `--wal-stats N`: every N seconds print a `WAL_CONT` line of per-interval WAL + // contention rates (lock-wait, wakeup fan-out, coalescing) to stderr, and arm + // the hot-path timing that feeds it. OFF by default (no clock reads on the + // append path). Dependency-free — the measurement vehicle for the contention + // investigation, independent of the heavy `telemetry` OTLP feature. + let mut wal_stats_secs: Option = None; let mut args = std::env::args().skip(1); while let Some(a) = args.next() { match a.as_str() { @@ -191,6 +204,14 @@ fn main() { } wal_shards = Some(n); } + "--worker-threads" => { + let n: usize = parse_val(args.next(), "--worker-threads"); + if n == 0 { + eprintln!("--worker-threads must be ≥ 1"); + std::process::exit(2); + } + worker_threads = Some(n); + } "--wal-segment-bytes" => { let n: u64 = parse_val(args.next(), "--wal-segment-bytes"); if n == 0 { @@ -199,6 +220,14 @@ fn main() { } wal_segment_bytes = Some(n); } + "--wal-stats" => { + let n: u64 = parse_val(args.next(), "--wal-stats"); + if n == 0 { + eprintln!("--wal-stats must be ≥ 1 (seconds)"); + std::process::exit(2); + } + wal_stats_secs = Some(n); + } "--durability" => { let v = val(args.next(), "--durability"); match handlers::parse_durability(&v) { @@ -216,8 +245,10 @@ fn main() { } } - // Apply --durability memory AFTER the arg loop. On non-Linux, reject immediately. - // On Linux, force the tail cache off (binary appends use the zero-copy socket→file splice). + // Apply --durability memory AFTER the arg loop. Memory mode is the buffered + // append path with the WAL stage/wait skipped (no splice intercept, no forced + // tail-cache-off — those belonged to the removed zero-copy path); the only + // gate is refusing to silently ignore a WAL left by a previous wal run. if handlers::durability() == handlers::DurabilityMode::Memory { // Fail fast on a WAL left by a previous `--durability wal` run: memory mode // never opens/replays it, so starting here would silently ignore those @@ -235,19 +266,6 @@ fn main() { ); std::process::exit(2); } - #[cfg(not(target_os = "linux"))] - { - eprintln!("--durability memory is Linux-only (zero-copy socket→file)"); - std::process::exit(2); - } - #[cfg(target_os = "linux")] - { - if store::tail_cache_bytes() != 0 { - eprintln!("--durability memory disables the resident tail cache"); - } - store::set_tail_cache_bytes(0); - engine_raw::set_zero_copy(true); // binary appends take the splice intercept - } } // S3 credentials come from env (never CLI flags), matching the OTEL_*/AWS @@ -261,9 +279,9 @@ fn main() { .ok(); } - let workers = std::thread::available_parallelism() + let workers = worker_threads.unwrap_or_else(|| std::thread::available_parallelism() .map(|n| n.get()) - .unwrap_or(4); + .unwrap_or(4)); let rt = tokio::runtime::Builder::new_multi_thread() .worker_threads(workers) .enable_all() @@ -307,6 +325,10 @@ fn main() { // per-shard committers, and start the checkpoint ticker. No append can // run before this point (we have not begun serving yet), so no durable // record is lost and no new append collides with un-recovered WAL data. + // Held so the shutdown path can stop + join the dedicated committer + // threads (Tier-2a) after draining in-flight requests. `None` in + // `--durability memory` mode (no committers spawned). + let mut wal_for_shutdown: Option> = None; if handlers::durability() == handlers::DurabilityMode::Wal { let open_res = match wal_segment_bytes { Some(sz) => wal::walset::WalSet::open_with_segment_size( @@ -326,6 +348,17 @@ fn main() { .wal .set(Arc::clone(&walset)) .unwrap_or_else(|_| panic!("WAL already attached")); + // Arm the contention timing + spawn the dependency-free stderr + // emitter BEFORE committers/serving start, so every acquisition from + // the first append is timed. No-op (and no clock reads) when the flag + // is absent. + if let Some(secs) = wal_stats_secs { + wal::telemetry::set_stats_enabled(true); + wal::telemetry::spawn_stats_emitter( + Arc::clone(&walset), + std::time::Duration::from_secs(secs), + ); + } walset.spawn_committers(); // Per-shard checkpoint ticker (spec §7): periodically `fdatasync` each // shard's touched per-stream files and recycle its WAL below the @@ -336,6 +369,7 @@ fn main() { // distribution + durability gauges. No-op unless built with // `--features telemetry`; off the hot commit/append path. wal::telemetry::spawn_emitter(Arc::clone(&walset)); + wal_for_shutdown = Some(walset); } let addr: SocketAddr = (host, port).into(); @@ -355,6 +389,12 @@ fn main() { #[cfg(target_os = "linux")] sse_reactor::shutdown(); engine_raw::drain(std::time::Duration::from_secs(25)).await; + // Stop + join the dedicated committer threads (Tier-2a) AFTER the + // request drain, so any commit a just-drained request staged is + // covered by each committer's final drain before the thread exits. + if let Some(walset) = wal_for_shutdown.take() { + walset.stop_committers(); + } telemetry_guard.shutdown(); } } @@ -382,11 +422,22 @@ fn spawn_checkpoint_ticker(walset: Arc) { ticker.tick().await; loop { ticker.tick().await; + // All shards checkpoint CONCURRENTLY. Each checkpoint is one + // spawn_blocking task (capture + per-stream fdatasyncs + tails/ckpt + // persist + recycle), so a serial walk makes every per-stream fsync + // across the whole server queue behind a single shard's — at high + // stream cardinality that serialization is what stretches the + // checkpoint wave (and on real disks wastes the device's parallelism). + let mut wave = tokio::task::JoinSet::new(); for shard in walset.shards() { - if let Err(e) = shard.checkpoint().await { - eprintln!("WAL checkpoint failed for shard {:?}: {e}", shard.dir()); - } + let shard = Arc::clone(shard); + wave.spawn(async move { + if let Err(e) = shard.checkpoint().await { + eprintln!("WAL checkpoint failed for shard {:?}: {e}", shard.dir()); + } + }); } + while wave.join_next().await.is_some() {} } }); } diff --git a/packages/durable-streams-rust/src/sse_reactor.rs b/packages/durable-streams-rust/src/sse_reactor.rs index 549fe27b6c..50636a53d4 100644 --- a/packages/durable-streams-rust/src/sse_reactor.rs +++ b/packages/durable-streams-rust/src/sse_reactor.rs @@ -143,6 +143,12 @@ pub fn wake_stream(st: &StreamState) { // server) with no SSE subscribers never spawns a reactor thread. let guard = st.sse_subs.lock().unwrap(); let Some(list) = guard.as_ref() else { return }; + // Coalesce: if a wake for this stream is already queued and not yet + // flushed, this publish is covered by the flush's tail read — skip the + // queue pushes and the eventfd syscall entirely. + if list.wake_pending.swap(true, Ordering::AcqRel) { + return; + } // Subscribers exist only because `register` ran, so the pool is live. let pool = pool(); for h in &list.subs { @@ -278,6 +284,14 @@ impl Reactor { .get(key as usize) .is_some_and(|s| s.gen == gen && s.sub.is_some()) { + // Clear the stream's coalescing latch BEFORE producing: + // produce() reads the tail after the clear, so a publish + // racing this flush is either included or re-queues. + if let Some(sub) = self.slab[key as usize].sub.as_ref() { + if let Some(list) = sub.st.sse_subs.lock().unwrap().as_ref() { + list.wake_pending.store(false, Ordering::Release); + } + } self.produce(key); self.flush(key); } @@ -319,13 +333,21 @@ impl Reactor { // Link onto the stream so the append path can find and wake this sub. { let mut g = st.sse_subs.lock().unwrap(); - g.get_or_insert_with(|| Box::new(StreamSubs { subs: Vec::new() })) - .subs - .push(SubHandle { - shard: self.shard_idx, - key, - gen, - }); + let list = g.get_or_insert_with(|| { + Box::new(StreamSubs { + subs: Vec::new(), + wake_pending: std::sync::atomic::AtomicBool::new(false), + }) + }); + list.subs.push(SubHandle { + shard: self.shard_idx, + key, + gen, + }); + // A gen-stale wake (subscriber closed between queue and drain) is + // dropped without clearing the latch; reset it on every register so + // a fresh subscriber can never inherit a stale-set latch. + list.wake_pending.store(false, Ordering::Release); } // Watch for peer close/errors; EPOLLOUT is armed lazily by flush(). let mut ev = libc::epoll_event { diff --git a/packages/durable-streams-rust/src/store.rs b/packages/durable-streams-rust/src/store.rs index c3ba17f5b8..8a99261309 100644 --- a/packages/durable-streams-rust/src/store.rs +++ b/packages/durable-streams-rust/src/store.rs @@ -106,10 +106,35 @@ pub struct Appender { /// Returns the fsync result: a failure (e.g. EIO writeback error) MUST be /// surfaced to the caller so an append is never acked as durable when the data /// did not reach stable storage. +/// BENCH-ONLY: whether `DS_UNSAFE_FAST_FSYNC` requests plain `fsync` over +/// `F_FULLFSYNC` on macOS (see [`barrier_fsync`]). Read once and cached — the env +/// is fixed for the process lifetime. +#[cfg(target_os = "macos")] +fn fast_fsync_enabled() -> bool { + use std::sync::OnceLock; + static ON: OnceLock = OnceLock::new(); + *ON.get_or_init(|| std::env::var_os("DS_UNSAFE_FAST_FSYNC").is_some()) +} + pub(crate) fn barrier_fsync(file: &File) -> std::io::Result<()> { let fd = file.as_raw_fd(); #[cfg(target_os = "macos")] unsafe { + // BENCH-ONLY escape hatch (NOT for production durability): when + // `DS_UNSAFE_FAST_FSYNC` is set, use a plain `fsync` instead of + // `F_FULLFSYNC`. On macOS `F_FULLFSYNC` forces a true drive-cache barrier + // (~tens of ms even on a RAM disk), which dominates the commit path and + // masks the per-shard LOCK contention this build is meant to study. Plain + // `fsync` on a RAM disk is ~free, reproducing the cheap-fsync (Linux + + // NVMe) regime where the lock is the bottleneck. Never set this where data + // must survive power loss. + if fast_fsync_enabled() { + return if libc::fsync(fd) == 0 { + Ok(()) + } else { + Err(std::io::Error::last_os_error()) + }; + } // Force a true flush to platter; fall back to a plain fsync. Only error // if the final fallback also fails. if libc::fcntl(fd, libc::F_FULLFSYNC) == 0 { @@ -152,8 +177,22 @@ pub struct StreamState { pub appender: AsyncMutex, pub shared: RwLock, pub tail_tx: watch::Sender, + /// The sidecar's persisted `durable_tail` as read at BOOT (None for sidecars + /// written by older servers). Consumed once by WAL recovery as this stream's + /// truncation-proof seed; never updated afterwards (the live value lives in + /// `Shared.durable_tail` and is re-captured on every meta write). + pub boot_meta_durable_tail: Option, /// True while a debounced meta flush is pending. pub meta_dirty: AtomicBool, + /// **Lock-free WAL dirty-set marker** (Tier-1a). The shard's checkpoint epoch + /// at which this stream was last registered into its shard's dirty set. The + /// hot append path compares this against the shard's current epoch: equal ⇒ + /// already registered this interval (no lock, no push); not-equal ⇒ CAS it to + /// the current epoch and, on the winning transition only, push this stream's + /// `Arc` into the shard's dirty collection. Initialised to `0` + /// (the shard's epoch starts at `1`), so the first append after creation always + /// registers. See `Shard::register_dirty`. + pub dirty_epoch: AtomicU64, /// Serializes sidecar writes for this stream. Concurrent writers (append /// flush, close, tiering offload flip, delete) otherwise race on the shared /// `.meta.tmp` file and can reorder their renames, letting a stale non-durable @@ -192,6 +231,15 @@ pub struct StreamState { #[cfg(target_os = "linux")] pub struct StreamSubs { pub subs: Vec, + /// Wake-coalescing latch: set by `wake_stream` when it queues this stream's + /// subscribers, cleared by the reactor BEFORE it reads the tail to flush + /// (clear-then-read: a publish racing the flush either lands before the + /// clear — its bytes are covered by the post-clear tail read — or after, + /// and re-queues). Converts per-append wakes into one wake per stream per + /// reactor cycle under load — the fan-out batching that wal mode gets for + /// free from group commit, without which memory mode drowns the reactor in + /// per-append eventfd signals (measured: delivery collapse past ~16k w/s). + pub wake_pending: std::sync::atomic::AtomicBool, } /// Locates one reactor subscriber: which shard owns it, its slab key, and the @@ -243,25 +291,6 @@ pub fn tail_cache_bytes() -> usize { } impl StreamState { - /// Open a fresh `O_WRONLY` fd on the data file for positioned splice writes. - /// - /// The shared `Appender.file` is opened `O_APPEND`, which `splice(2)` rejects - /// as a target (it ignores the supplied offset). The zero-copy append path - /// therefore opens its own non-`O_APPEND` write fd and positions every write - /// explicitly (`pwrite` for the buffered prefix, `splice` with an offset for - /// the socket relay). Called under the appender lock, so no other writer can - /// move the logical tail underneath it. - #[cfg(target_os = "linux")] - pub fn open_splice_fd(&self) -> std::io::Result { - // O_RDWR (not O_WRONLY): this same fd is the positioned-WRITE target for the - // socket→file splice AND the READ source for the file→WAL relay splice, so it - // must be readable. (Not O_APPEND — splice rejects O_APPEND targets.) - std::fs::OpenOptions::new() - .read(true) - .write(true) - .open(&self.file_path) - } - /// Record the just-appended wire chunk as the resident tail. `start` is the /// logical offset where `bytes` begins. Chunks larger than the tail-cache cap /// (or any append when the cache is disabled) are not cached (the entry is @@ -570,6 +599,7 @@ impl Store { file_path: data_path.clone(), base_offset: meta.base_offset, parent, + boot_meta_durable_tail: meta.durable_tail, appender: AsyncMutex::new(Appender { file: file.clone(), written }), shared: RwLock::new(Shared { tail, @@ -588,6 +618,9 @@ impl Store { }), tail_tx, meta_dirty: AtomicBool::new(false), + // Epoch 0 < the shard's initial epoch (1), so the first append + // registers this stream into the dirty set. + dirty_epoch: AtomicU64::new(0), meta_lock: StdMutex::new(()), last_chunk: RwLock::new(None), tier: crate::tier::TierState::from_meta( @@ -638,7 +671,27 @@ impl Store { } /// Hard-delete when nothing references the stream; soft-delete otherwise. + /// + /// NON-durable, detached variant for the expiry sweep on the read path: the + /// on-disk removals / soft-meta write run on a fire-and-forget blocking + /// task, so a crash can undo them (an expired stream re-expires on the next + /// access — harmless). The DELETE handler must NOT use this: an acked + /// DELETE undone by a crash resurrects the stream with all its data — use + /// [`Store::delete_or_soft_delete_durable`] there. pub fn delete_or_soft_delete(&self, st: &Arc) { + let _ = self.delete_impl(st, false); + } + + /// [`Store::delete_or_soft_delete`] with the DELETE-ack durability contract: + /// the file + sidecar unlinks (and their parent-directory entry) — or the + /// soft-delete meta flag — are durable on disk before this returns, so a + /// post-ack crash can never resurrect the stream. Synchronous file I/O + + /// fsync: call from a blocking context. + pub fn delete_or_soft_delete_durable(&self, st: &Arc) -> std::io::Result<()> { + self.delete_impl(st, true) + } + + fn delete_impl(&self, st: &Arc, durable: bool) -> std::io::Result<()> { let soft = { let mut s = st.shared.write().unwrap(); if s.ref_count > 0 { @@ -649,10 +702,14 @@ impl Store { } }; if soft { - let st2 = st.clone(); - tokio::task::spawn_blocking(move || { - let _ = write_meta_sync(&st2, true); - }); + if durable { + write_meta_sync(st, true)?; + } else { + let st2 = st.clone(); + tokio::task::spawn_blocking(move || { + let _ = write_meta_sync(&st2, true); + }); + } } else { self.streams .remove_if(&st.path, |_, v| Arc::ptr_eq(v, st)); @@ -661,12 +718,21 @@ impl Store { // with no remaining fork references. self.gc_remote_segments(st); let fp = st.file_path.clone(); - tokio::task::spawn_blocking(move || { + if durable { + // Both unlinks live in the same directory; one dir fsync makes + // them crash-durable together. let _ = std::fs::remove_file(meta_path(&fp)); - let _ = std::fs::remove_file(fp); - }); + let _ = std::fs::remove_file(&fp); + fsync_parent_dir(&fp)?; + } else { + tokio::task::spawn_blocking(move || { + let _ = std::fs::remove_file(meta_path(&fp)); + let _ = std::fs::remove_file(fp); + }); + } self.release_parent(st); } + Ok(()) } /// Decrement the parent's fork refcount; cascade-collect soft-deleted parents @@ -741,6 +807,9 @@ impl Store { file_path, base_offset, parent: parent.clone(), + // Live-created stream: the durable frontier IS the initial tail (the + // create meta below persists it). Only consulted by boot recovery. + boot_meta_durable_tail: Some(base_offset), appender: AsyncMutex::new(Appender { file: file.clone(), written: 0 }), shared: RwLock::new(Shared { tail: base_offset, @@ -758,6 +827,9 @@ impl Store { }), tail_tx, meta_dirty: AtomicBool::new(false), + // Epoch 0 < the shard's initial epoch (1), so the first append + // registers this stream into the dirty set. + dirty_epoch: AtomicU64::new(0), meta_lock: StdMutex::new(()), last_chunk: RwLock::new(None), tier: crate::tier::TierState::default(), @@ -951,6 +1023,16 @@ pub struct Meta { /// once the rewrite + swap completes durably. #[serde(default)] pub pending_compaction: Option, + /// The stream's durable frontier (logical bytes) when this sidecar was + /// written — WAL recovery's per-stream truncation proof for streams with NO + /// retained WAL record and NO checkpoint `tails` entry (e.g. a stream + /// created after the last checkpoint whose only in-flight append was torn + /// by power loss). Only ever holds values that were durable at capture + /// time; a lagging (lazily-flushed) value is safe because recovery takes + /// the max of every proof. `None` in sidecars written by older servers → + /// recovery falls back to trusting the file size (the pre-field behavior). + #[serde(default)] + pub durable_tail: Option, } /// Serialized form of a sealed-segment manifest entry. @@ -1019,6 +1101,7 @@ impl Meta { sealed_offset: st.tier.manifest.lock().unwrap().sealed_offset, file_base: Some(s.file_base), pending_compaction: *st.compaction.lock().unwrap(), + durable_tail: Some(s.durable_tail), } } } diff --git a/packages/durable-streams-rust/src/wal/e2e_tests.rs b/packages/durable-streams-rust/src/wal/e2e_tests.rs index 7f8099122c..e2e3819f3e 100644 --- a/packages/durable-streams-rust/src/wal/e2e_tests.rs +++ b/packages/durable-streams-rust/src/wal/e2e_tests.rs @@ -18,13 +18,13 @@ use std::io; use std::sync::Arc; use bytes::Bytes; -use tokio::task::JoinHandle; use crate::api::{Method, Req}; use crate::handlers; use crate::handlers::test_support::DurabilityGuard; use crate::store::Store; use crate::tier::TierConfig; +use crate::wal::shard::CommitterHandle; use crate::wal::walset::WalSet; /// A unique temp data dir for one test. @@ -40,12 +40,15 @@ fn tmp(tag: &str) -> std::path::PathBuf { } /// A booted WAL-mode server harness: the store with its WAL attached and the -/// per-shard committers running. Committer `JoinHandle`s are held so a test can -/// `.abort()` them to simulate a crash (a graceful shutdown would drain them). +/// per-shard committers running on their dedicated OS threads. Committer +/// [`CommitterHandle`]s are held so a test can stop + join them to simulate a +/// crash. (Every record a crash test relies on is already acked — hence durable — +/// before the stop, so the final drain a graceful stop performs is a no-op for +/// those records; the on-disk state matches an abrupt crash.) struct Harness { store: Arc, walset: Arc, - committers: Vec>, + committers: Vec, } impl Harness { @@ -60,7 +63,18 @@ impl Harness { /// the durable WAL into the per-stream files + fsync) → `reset_after_recovery` /// (wipe the old WAL) → attach + `spawn_committers`. fn boot(dir: &std::path::Path, shards: Option, default_n: usize) -> io::Result { - let walset = WalSet::open(dir, shards, default_n)?; + Harness::boot_with_segment_size(dir, shards, default_n, crate::wal::segment::SEGMENT_BYTES) + } + + /// [`Harness::boot`] with an explicit WAL segment size, so a test can force + /// segment rolls/recycles cheaply (multi-segment recovery coverage). + fn boot_with_segment_size( + dir: &std::path::Path, + shards: Option, + default_n: usize, + segment_size: u64, + ) -> io::Result { + let walset = WalSet::open_with_segment_size(dir, shards, default_n, segment_size)?; let store = Arc::new(Store::new_with_tier(dir.to_path_buf(), TierConfig::default())?); crate::wal::recovery::recover(&store, &walset)?; walset.reset_after_recovery()?; @@ -69,23 +83,29 @@ impl Harness { .set(Arc::clone(&walset)) .unwrap_or_else(|_| panic!("WAL already attached")); // Spawn committers ourselves (not `walset.spawn_committers()`) so we keep - // the JoinHandles and can abort them to simulate a crash. + // the handles and can stop them to simulate a crash. let mut committers = Vec::new(); for shard in walset.shards() { - let shard = Arc::clone(shard); - committers.push(tokio::spawn(shard.run_committer())); + committers.push(shard.spawn_committer()); } Ok(Harness { store, walset, committers }) } - /// Simulate a crash: abort the committers (so no further `durable_lsn` + /// Stop + join every committer thread (so no further `durable_lsn` advance can + /// race the test's subsequent file surgery). All records the caller cares + /// about are already acked/durable, so each committer's final drain is a + /// no-op for them. + fn stop_committers(&mut self) { + for h in self.committers.drain(..) { + h.stop(); + } + } + + /// Simulate a crash: stop the committers (so no further `durable_lsn` /// advance) and drop the store + WalSet WITHOUT a graceful drain/shutdown. /// The data dir on disk is left exactly as the live process left it. - fn crash(self) { - for h in &self.committers { - h.abort(); - } - drop(self.committers); + fn crash(mut self) { + self.stop_committers(); drop(self.store); drop(self.walset); } @@ -253,7 +273,7 @@ async fn e2e_no_loss_unacked_tail_is_absent_after_crash() { let dir = tmp("noloss-unacked"); - let h = Harness::boot(&dir, Some(1), 1).unwrap(); + let mut h = Harness::boot(&dir, Some(1), 1).unwrap(); create_stream(&h.store, "s", OCTET).await; // Two genuinely-acked appends through the real path (durable in the WAL). @@ -267,9 +287,7 @@ async fn e2e_no_loss_unacked_tail_is_absent_after_crash() { // (a) append the un-acked bytes to the per-stream file (page-cache write). // (b) plant a TORN partial WAL record right after the two whole durable // records: only a few header bytes, never a full framed record. - for c in &h.committers { - c.abort(); - } + h.stop_committers(); let st = h.store.get("s").unwrap(); let unacked: &[u8] = b"UNACKED-NEVER-DURABLE|"; { @@ -480,7 +498,7 @@ async fn e2e_sharding_below_file_base_record_skipped() { let _guard = DurabilityGuard::wal(); let dir = tmp("below-base"); - let h = Harness::boot(&dir, Some(1), 1).unwrap(); + let mut h = Harness::boot(&dir, Some(1), 1).unwrap(); // Parent with content so a fork can diverge at offset > 0. create_stream(&h.store, "parent", OCTET).await; append_acked(&h.store, "parent", OCTET, b"0123456789").await; // tail = 10 @@ -507,10 +525,8 @@ async fn e2e_sharding_below_file_base_record_skipped() { // Stage a WAL record for the fork BELOW its file_base (stream_offset 2 < 5): // the frontier-skip case. It must be skipped on replay (re-applying would be // an out-of-range / double-apply; those bytes live in the parent/sealed - // prefix). Abort the committer first so we don't perturb the acked frontier. - for c in &h.committers { - c.abort(); - } + // prefix). Stop the committers first so we don't perturb the acked frontier. + h.stop_committers(); let shard = h.walset.shard_for(child.id); shard .reserve_and_stage( @@ -522,11 +538,10 @@ async fn e2e_sharding_below_file_base_record_skipped() { .unwrap(); // Re-run a committer briefly so this staged record DOES become durable in the // WAL (proving the skip is in recovery's replay, not just an un-acked drop). - let shard_arc = Arc::clone(shard); - let c = tokio::spawn(async move { shard_arc.run_committer().await }); + let c = shard.spawn_committer(); // Wait until durable so the record is genuinely in the WAL's durable range. shard.wait_durable(shard.tail_lsn()).await; - c.abort(); + c.stop(); drop(child); let store = h.store; @@ -784,6 +799,15 @@ async fn strict_created_dir_reopens_wal_only_without_data_loss() { .await .unwrap() .unwrap(); + // A strict-era server predates the `durable_tail` sidecar proof — strip + // the field the CURRENT writer emitted so the sidecar is byte-faithful + // to what an old deployment left behind (recovery must fall back to + // trusting the file size for such sidecars). + let meta_path = crate::store::meta_path(&st.file_path); + let mut v: serde_json::Value = + serde_json::from_slice(&std::fs::read(&meta_path).unwrap()).unwrap(); + v.as_object_mut().unwrap().remove("durable_tail"); + std::fs::write(&meta_path, serde_json::to_vec(&v).unwrap()).unwrap(); } // Remove any wal/ subtree — a strict-era dir has none. std::fs::remove_dir_all(dir.join("wal")).ok(); @@ -817,6 +841,261 @@ async fn strict_created_dir_reopens_wal_only_without_data_loss() { let _ = std::fs::remove_dir_all(&dir); } +// =========================================================================== +// (7b) MULTI-SEGMENT recovery: boot must not clobber sealed/recycled segments +// =========================================================================== + +/// Acked records that live in WAL segments AFTER the first survive a crash. +/// +/// With a small segment size, enough acked appends roll the WAL: `1.wal` is +/// SEALED (truncated to its exactly-packed length + fsync'd) and later records +/// land in `.wal`. A crash + reboot must replay ALL retained segments. +/// +/// Regression (sim seed 89837): `Shard::open` re-preallocated `1.wal` to full +/// segment size, so the sealed segment grew a zero tail; replay read that tail +/// as `Incomplete` (= end of the durable log) and silently dropped every +/// record in later segments — then `reconcile_tail` TRUNCATED the per-stream +/// files back to the stale frontier. Acked-data loss on the recovery path. +#[tokio::test] +async fn e2e_multi_segment_acked_records_after_first_seal_survive_crash() { + let _guard = DurabilityGuard::wal(); + const SEG: u64 = 4096; + let dir = tmp("multi-seg"); + + let h = Harness::boot_with_segment_size(&dir, Some(1), 1, SEG).unwrap(); + create_stream(&h.store, "s", OCTET).await; + + // Append acked records until the shard has rolled at least once (≥2 + // on-disk segments), then a few more so the post-roll segment holds data. + let mut expected = Vec::new(); + let mut i = 0usize; + while h.walset.shards()[0].wal_segments() < 2 || i < 40 { + let rec = format!("multi-seg-record-{i:04}|").into_bytes(); + append_acked(&h.store, "s", OCTET, &rec).await; + expected.extend_from_slice(&rec); + i += 1; + assert!(i < 10_000, "never rolled a segment; check SEG/record sizing"); + } + assert!( + h.walset.shards()[0].wal_segments() >= 2, + "test needs ≥2 retained segments" + ); + + h.crash(); + + let h2 = Harness::boot_with_segment_size(&dir, None, 1, SEG).unwrap(); + let got = stream_file_bytes(&h2.store, "s"); + assert_eq!( + got.len(), + expected.len(), + "every acked record recovers across ALL retained segments (lost {} bytes)", + expected.len().saturating_sub(got.len()) + ); + assert_eq!(got, expected, "recovered bytes byte-identical across segment seams"); + h2.crash(); + let _ = std::fs::remove_dir_all(&dir); +} + +/// Acked records recover when `1.wal` was RECYCLED (checkpoint deleted it and +/// the oldest retained segment starts at lsn > 1). +/// +/// Regression (same root cause, worse case): `Shard::open` unconditionally +/// created a fresh, all-zero `1.wal`. Replay walked segments in start-lsn +/// order, began with the spurious zero-filled `1.wal`, decoded `Incomplete` at +/// offset 0, and treated that as the end of the durable log — replaying +/// NOTHING. Every acked record after the last checkpoint was truncated away. +#[tokio::test] +async fn e2e_recycled_first_segment_acked_records_survive_crash() { + let _guard = DurabilityGuard::wal(); + const SEG: u64 = 4096; + let dir = tmp("recycled-first"); + + let h = Harness::boot_with_segment_size(&dir, Some(1), 1, SEG).unwrap(); + create_stream(&h.store, "s", OCTET).await; + + // Phase 1: roll past 1.wal, then checkpoint → sealed segments fully below + // the floor (including 1.wal) are recycled (deleted). + let mut expected = Vec::new(); + let mut i = 0usize; + while h.walset.shards()[0].wal_segments() < 3 { + let rec = format!("pre-ckpt-{i:04}|").into_bytes(); + append_acked(&h.store, "s", OCTET, &rec).await; + expected.extend_from_slice(&rec); + i += 1; + assert!(i < 10_000, "never rolled; check SEG/record sizing"); + } + h.walset.shards()[0].checkpoint().await.unwrap(); + assert!( + !dir.join("wal").join("0").join("1.wal").exists(), + "checkpoint recycled 1.wal (else this test is vacuous)" + ); + + // Phase 2: more ACKED records after the checkpoint (they live only in the + // WAL + page cache; the checkpoint that would fsync them never runs). + for j in 0..25usize { + let rec = format!("post-ckpt-{j:04}|").into_bytes(); + append_acked(&h.store, "s", OCTET, &rec).await; + expected.extend_from_slice(&rec); + } + + h.crash(); + + let h2 = Harness::boot_with_segment_size(&dir, None, 1, SEG).unwrap(); + let got = stream_file_bytes(&h2.store, "s"); + assert_eq!( + got.len(), + expected.len(), + "post-checkpoint acked records recover from the retained (recycle-survivor) segments" + ); + assert_eq!(got, expected, "recovered bytes byte-identical"); + h2.crash(); + let _ = std::fs::remove_dir_all(&dir); +} + +// =========================================================================== +// (7c) WAL-QUIET stream: torn unacked tail truncated via the sidecar proof +// =========================================================================== + +/// A stream with NO durable WAL record and NO checkpoint `tails` entry (created +/// after the last checkpoint; its only append was in-flight at the crash) must +/// still have its torn, never-acked page-cache tail truncated on recovery. +/// +/// Regression (sim seed 20230): with the WAL bytes for the in-flight append +/// torn by power loss and its data-file bytes partially persisted, recovery had +/// NO truncation proof for the stream — the sidecar pass trusted +/// `tail = file size` and exposed the torn fragment to readers (the exact C1 +/// shape the WAL exists to prevent). The sidecar now persists a `durable_tail` +/// proof (fsynced at create/close, refreshed at checkpoint + recovery), and +/// recovery seeds every stream's frontier from it. +#[tokio::test] +async fn e2e_wal_quiet_stream_torn_unacked_tail_truncated() { + let _guard = DurabilityGuard::wal(); + let dir = tmp("quiet-torn"); + + let mut h = Harness::boot(&dir, Some(1), 1).unwrap(); + + // An earlier checkpointed stream so the shard's tails file is non-empty + // (proves the fix is not just "empty tails == reconcile everything"). + create_stream(&h.store, "older", OCTET).await; + append_acked(&h.store, "older", OCTET, b"older-rec|").await; + h.walset.shards()[0].checkpoint().await.unwrap(); + + // The WAL-quiet stream: created AFTER the checkpoint, never acked an append. + create_stream(&h.store, "fresh", OCTET).await; + + // Its only append is in-flight at the crash: bytes reached the data file's + // page cache and the WAL staging buffer, but the committer never fsync'd + // (stop it first), so no ack was ever released. + h.stop_committers(); + let st = h.store.get("fresh").unwrap(); + let torn: &[u8] = b"TORN-IN-FLIGHT-NEVER-ACKED"; + { + use std::io::Write; + let mut f = std::fs::OpenOptions::new().append(true).open(&st.file_path).unwrap(); + f.write_all(torn).unwrap(); + f.sync_all().unwrap(); // even fully-persisted: still un-acked, must go + } + let shard = h.walset.shard_for(st.id).clone(); + shard + .reserve_and_stage(crate::wal::codec::RecordKind::Append, st.id, 0, torn) + .unwrap(); + // Power loss tears the staged (never-fdatasync'd) WAL record: zero it out. + // Everything at/above this record was never covered by an ack. + { + use std::io::{Seek, SeekFrom, Write}; + let seg = crate::wal::segment::seg_path(&dir.join("wal").join("0"), 1); + let len = std::fs::metadata(&seg).unwrap().len(); + let mut f = std::fs::OpenOptions::new().write(true).open(&seg).unwrap(); + // The quiet stream's record is the LAST staged record; zeroing the whole + // segment suffix past the durable prefix models its loss. Find the + // offset by decoding up to the first record for `st.id`. + let bytes = std::fs::read(&seg).unwrap(); + let mut off = 0usize; + while let crate::wal::codec::Decoded::Record { stream_id, total, .. } = + crate::wal::codec::decode_at(&bytes, off) + { + if stream_id == st.id { + break; + } + off += total; + } + f.seek(SeekFrom::Start(off as u64)).unwrap(); + f.write_all(&vec![0u8; (len as usize) - off]).unwrap(); + f.sync_all().unwrap(); + } + + drop(st); + let store = h.store; + let walset = h.walset; + drop(store); + drop(walset); + + // Reopen: recovery must truncate the torn tail even though the stream has + // zero surviving WAL records and no tails entry — the sidecar's durable_tail + // proof (0, persisted at create) is the seed. + let h2 = Harness::boot(&dir, None, 1).unwrap(); + let got = stream_file_bytes(&h2.store, "fresh"); + assert_eq!( + got, + b"", + "torn un-acked tail truncated on a WAL-quiet stream (sidecar durable_tail proof)" + ); + let st2 = h2.store.get("fresh").unwrap(); + assert_eq!(st2.tail().bytes, 0, "tail reconciled to the durable frontier (0)"); + // The checkpointed stream is untouched. + assert_eq!(stream_file_bytes(&h2.store, "older"), b"older-rec|"); + h2.crash(); + let _ = std::fs::remove_dir_all(&dir); +} + +// =========================================================================== +// (7d) DELETE ack durability: an acked DELETE survives a crash +// =========================================================================== + +/// The 204 for DELETE is a durability promise. Regression (sim seed 20387): +/// `handle_delete` acked while the file + sidecar unlinks ran on a DETACHED +/// blocking task — a crash right after the ack (before the task ran) left both +/// files on disk and the stream RESURRECTED with all its data on reboot. The +/// unlinks (+ parent-dir fsync) are now awaited before the 204. +#[tokio::test] +async fn e2e_acked_delete_is_durable_no_resurrection_after_crash() { + let _guard = DurabilityGuard::wal(); + let dir = tmp("delete-durable"); + + let h = Harness::boot(&dir, Some(1), 1).unwrap(); + create_stream(&h.store, "victim", OCTET).await; + append_acked(&h.store, "victim", OCTET, b"doomed-data|").await; + let file_path = h.store.get("victim").unwrap().file_path.clone(); + let meta = crate::store::meta_path(&file_path); + + let resp = handlers::handle( + Arc::clone(&h.store), + Req { + method: Method::Delete, + path: "victim".into(), + query: None, + headers: vec![], + body: Bytes::new(), + }, + ) + .await; + assert_eq!(resp.status, 204, "delete acked"); + // The ack IS the durability point: both on-disk artifacts are already gone + // when the response returns (not on some detached task's schedule). + assert!(!file_path.exists(), "data file removed before the DELETE ack"); + assert!(!meta.exists(), "meta sidecar removed before the DELETE ack"); + + // Crash + reboot: the stream must not resurrect. + h.crash(); + let h2 = Harness::boot(&dir, None, 1).unwrap(); + assert!( + h2.store.get("victim").is_none(), + "acked-deleted stream must not resurrect after a crash" + ); + h2.crash(); + let _ = std::fs::remove_dir_all(&dir); +} + // =========================================================================== // (8) MEMORY-MODE sidecar recovery (no WAL) // =========================================================================== diff --git a/packages/durable-streams-rust/src/wal/mod.rs b/packages/durable-streams-rust/src/wal/mod.rs index e8f0ef67f6..e0ff787b9b 100644 --- a/packages/durable-streams-rust/src/wal/mod.rs +++ b/packages/durable-streams-rust/src/wal/mod.rs @@ -17,3 +17,6 @@ pub mod walset; #[cfg(test)] mod e2e_tests; + +#[cfg(test)] +mod sim_tests; diff --git a/packages/durable-streams-rust/src/wal/recovery.rs b/packages/durable-streams-rust/src/wal/recovery.rs index 7f1942e6e8..ecf4a9d3d4 100644 --- a/packages/durable-streams-rust/src/wal/recovery.rs +++ b/packages/durable-streams-rust/src/wal/recovery.rs @@ -70,9 +70,34 @@ pub fn recover(store: &Arc, wal: &Arc) -> io::Result<()> { // Build the id → StreamState index once from the sidecar-recovered streams. // Streams are keyed by NAME in the store; recovery routes by `stream_id`, so // we re-key on the stable id. Shared across shards read-only. + // + // Alongside it, build each shard's per-stream durable-frontier SEED: the + // sidecar's persisted `durable_tail` proof (`None` in old sidecars → trust + // the file size, i.e. the boot tail — the pre-field behavior). Seeding EVERY + // stream (not just those the WAL touched) is what lets recovery truncate a + // torn, never-durable page-cache tail on a stream with NO retained WAL + // record and NO checkpoint `tails` entry — e.g. a stream created after the + // last checkpoint whose only in-flight append was torn by power loss. The + // reconcile loop below skips streams whose file already sits exactly at + // their frontier, so the seeding adds no boot I/O for untouched streams. let mut index: HashMap> = HashMap::new(); + let mut seeds: Vec> = vec![HashMap::new(); wal.shards().len()]; + let shard_pos: HashMap<*const crate::wal::shard::Shard, usize> = wal + .shards() + .iter() + .enumerate() + .map(|(i, s)| (Arc::as_ptr(s), i)) + .collect(); for entry in store.streams.iter() { let st = entry.value().clone(); + let proof = { + let s = st.shared.read().unwrap(); + // `s.tail` at boot is file_base + on-disk file size (the sidecar + // pass's trust-the-file seed). + st.boot_meta_durable_tail.unwrap_or(s.tail) + }; + let pos = shard_pos[&Arc::as_ptr(wal.shard_for(st.id))]; + seeds[pos].insert(st.id, proof); index.insert(st.id, st); } let index = Arc::new(index); @@ -80,10 +105,10 @@ pub fn recover(store: &Arc, wal: &Arc) -> io::Result<()> { // Per-shard passes are independent (disjoint stream sets). Spawn one blocking // task per shard and join — the replay is synchronous file I/O. let mut handles = Vec::with_capacity(wal.shards().len()); - for shard in wal.shards() { + for (shard, seed) in wal.shards().iter().zip(seeds) { let shard = Arc::clone(shard); let index = Arc::clone(&index); - handles.push(std::thread::spawn(move || recover_shard(&shard, &index))); + handles.push(std::thread::spawn(move || recover_shard(&shard, &index, seed))); } for h in handles { // A panicked recovery thread is a bug (poisoned state); surface it. @@ -93,9 +118,13 @@ pub fn recover(store: &Arc, wal: &Arc) -> io::Result<()> { } /// Replay one shard and reconcile the tails of the streams it touched. +/// `seed` carries every one of this shard's streams' sidecar durable-tail proof +/// (see `recover`); the durable frontier per stream is the max of that seed, +/// the checkpoint-persisted tails, and the replayed record ends. fn recover_shard( shard: &crate::wal::shard::Shard, index: &HashMap>, + seed: HashMap, ) -> io::Result<()> { // `checkpoint_lsn` is a WRITE-SKIP optimization ONLY — NOT the boundary for // which streams get reconciled. We replay from the OLDEST RETAINED record so @@ -136,13 +165,23 @@ fn recover_shard( // below. Only streams with EITHER a persisted tail OR an in-range Append are // inserted, so we reconcile exactly the streams the WAL touched. let mut frontier: HashMap = shard.read_durable_tails(); - // (debug) Snapshot the persisted-tail seed and track the lowest replayed - // offset per stream, to assert that a stream reconstructed purely from - // replayed Appends covers `[file_base, frontier)` with no interior gap. - #[cfg(debug_assertions)] - let persisted_tails = frontier.clone(); + // Fold in the per-stream sidecar proof (every stream of this shard gets an + // entry; max keeps the strongest proof). + for (id, proof) in seed { + let slot = frontier.entry(id).or_insert(0); + *slot = (*slot).max(proof); + } + // Streams whose per-stream FILE was actually written by the replay below — + // their reconcile must run unconditionally (fsync the repair). + let mut replay_wrote: std::collections::HashSet = std::collections::HashSet::new(); + // (debug) Track, per replayed stream, the lowest replayed offset AND the + // file's logical end BEFORE the first replay write touched it, to assert the + // replayed records tile onto the existing durable prefix with no interior + // hole (see the debug_assert below). #[cfg(debug_assertions)] let mut min_applied: HashMap = HashMap::new(); + #[cfg(debug_assertions)] + let mut pre_replay_end: HashMap = HashMap::new(); // Captured replay error from inside the closure (the closure cannot return // `io::Result`). The first error aborts further application for this shard. let mut replay_err: Option = None; @@ -167,10 +206,18 @@ fn recover_shard( return; } let file_pos = stream_offset - file_base; + #[cfg(debug_assertions)] + pre_replay_end.entry(stream_id).or_insert_with(|| { + // Logical end of the per-stream file before replay writes to it — + // the durable prefix the replayed records must tile onto. + let len = std::fs::metadata(&st.file_path).map(|m| m.len()).unwrap_or(0); + file_base + len + }); if let Err(e) = write_at(st, file_pos, payload) { replay_err = Some(e); return; } + replay_wrote.insert(stream_id); let end = stream_offset + payload.len() as u64; let slot = frontier.entry(stream_id).or_insert(0); *slot = (*slot).max(end); @@ -185,9 +232,9 @@ fn recover_shard( return Err(e); } - // Reconcile each touched stream's file tail to its durable frontier (the max - // of the persisted durable tail and the replayed WAL frontier, already folded - // into `frontier`). + // Reconcile each stream's file tail to its durable frontier (the max of the + // sidecar durable-tail seed, the checkpoint-persisted tails, and the + // replayed WAL frontier, already folded into `frontier`). for (stream_id, &logical_tail) in &frontier { let st = match index.get(stream_id) { Some(st) => st, @@ -199,19 +246,49 @@ fn recover_shard( // underflow `logical_tail - file_base`; skip — the live file already // starts at `file_base` and its tail is governed by the sealed watermark, // not this stale recorded tail. - if logical_tail < st.shared.read().unwrap().file_base { + let (file_base, boot_tail) = { + let s = st.shared.read().unwrap(); + (s.file_base, s.tail) + }; + if logical_tail < file_base { + continue; + } + // Fast path (keeps 1M-stream boots cheap): the replay never wrote this + // stream's file and the file already sits exactly at its frontier + // (`boot_tail` is file_base + on-disk size, seeded by the sidecar pass) + // — nothing to truncate, extend, or fsync. Persist the strengthened + // proof only when the sidecar's recorded one lags the frontier (e.g. a + // checkpoint `tails` entry outran the meta): the `tails` file is wiped + // by `reset_after_recovery`, so without the bump the NEXT boot's seed + // would regress below this durable frontier and truncate acked bytes. + // Old sidecars (no recorded proof) are left as-is — they keep + // file-size trust rather than paying a boot-time meta rewrite per + // stream (the proof materializes on their next natural meta write). + if !replay_wrote.contains(stream_id) && boot_tail == logical_tail { + if st.boot_meta_durable_tail.is_some_and(|d| d < logical_tail) { + write_meta_durable(st)?; + } continue; } - // (debug) A stream rebuilt PURELY from replay (no persisted durable tail) - // must start at `file_base`; otherwise `[file_base, lowest_record)` is a - // torn interior prefix kept silently. Fail loudly in tests if a future - // compaction/`file_base` interaction breaks the contiguous-tiling premise. + // (debug) No interior HOLE: a stream's first replayed record must start + // at or below the file's pre-replay logical end. The prefix below it is + // durable via one of THREE sources — a checkpoint-persisted tail, the + // previous boot's recovery reconcile (which fdatasync'd the repaired + // file before `reset_after_recovery` wiped the old WAL — so a stream + // recovered last boot legitimately has post-boot WAL records starting + // at its recovered tail with NO persisted-tail entry yet), or the + // records replayed earlier in this pass. A first record strictly ABOVE + // the pre-replay end means `[pre_end, lowest_record)` was never written + // by anything durable — a gap kept silently. Fail loudly in tests. #[cfg(debug_assertions)] debug_assert!( - persisted_tails.contains_key(stream_id) - || min_applied.get(stream_id).copied() - == Some(st.shared.read().unwrap().file_base), - "WAL replay gap: stream {stream_id} rebuilt from replay does not start at file_base" + min_applied.get(stream_id).map_or(true, |&lo| { + pre_replay_end.get(stream_id).is_some_and(|&pre| lo <= pre) + }), + "WAL replay hole: stream {stream_id}: first replayed record at {:?} is past \ + the pre-replay file end {:?}", + min_applied.get(stream_id), + pre_replay_end.get(stream_id) ); reconcile_tail(st, logical_tail)?; } @@ -303,9 +380,21 @@ fn reconcile_tail(st: &StreamState, logical_tail: u64) -> io::Result<()> { let mut ap = st.appender.blocking_lock(); ap.written = file_len; } + // Persist the reconciled durable frontier into the sidecar BEFORE + // `reset_after_recovery` wipes the WAL and the checkpoint `tails` file. If + // the proof stayed stale (below the frontier just made durable above), the + // NEXT boot's seed would truncate this stream back below acked, durable + // bytes it can no longer re-replay. + write_meta_durable(st)?; Ok(()) } +/// Durably rewrite a stream's sidecar (recovery-time only — captures the +/// just-reconciled `Shared.durable_tail` as the next boot's truncation proof). +fn write_meta_durable(st: &StreamState) -> io::Result<()> { + crate::store::write_meta_sync(st, true) +} + /// Open a fresh read-write (non-append) handle to a stream's per-stream data file /// for positioned writes / truncation during recovery. fn open_rw(st: &StreamState) -> io::Result { @@ -797,9 +886,10 @@ mod tests { /// Drive a real shard so the committer makes records durable. Used by the 11b /// tests to checkpoint (recording per-stream durable tails) and roll/recycle. - fn spawn_committer(shard: &std::sync::Arc) -> tokio::task::JoinHandle<()> { - let s = std::sync::Arc::clone(shard); - tokio::spawn(async move { s.run_committer().await }) + fn spawn_committer( + shard: &std::sync::Arc, + ) -> crate::wal::shard::CommitterHandle { + shard.spawn_committer() } /// CRITICAL (11b): a stream X whose durable WAL records are ALL recycled @@ -886,7 +976,7 @@ mod tests { // segment below it (incl. X's original `1.wal`) is recycled. let ckpt2 = shard.checkpoint().await.unwrap(); assert_eq!(ckpt2, last); - h.abort(); + h.stop(); // X must now have NO retained WAL record: replay sees nothing for X. let mut x_records_in_wal = 0usize; @@ -1020,7 +1110,7 @@ mod tests { } let l3 = shard.reserve_and_stage(RecordKind::Append, x_id, after_r2, r3).unwrap(); shard.wait_durable(l3).await; - h.abort(); + h.stop(); // Torn page-cache tail past r3 (un-acked). { diff --git a/packages/durable-streams-rust/src/wal/segment.rs b/packages/durable-streams-rust/src/wal/segment.rs index 5c46790ab2..bd74249960 100644 --- a/packages/durable-streams-rust/src/wal/segment.rs +++ b/packages/durable-streams-rust/src/wal/segment.rs @@ -84,6 +84,22 @@ impl FileSegment { Ok(FileSegment { file }) } + /// Open an EXISTING segment without changing its size or contents. + /// + /// Boot-time (`Shard::open`) must be non-destructive: a sealed segment is + /// exactly packed (its length IS the durable-log seam recovery walks across), + /// so re-preallocating it to full size would graft a zero tail onto it and + /// recovery would mis-read that tail as the end of the durable log — dropping + /// every later segment's acked records. This constructor only opens the fd. + pub fn open_existing(path: PathBuf) -> io::Result { + let file = std::fs::OpenOptions::new() + .read(true) + .write(true) + .truncate(false) + .open(&path)?; + Ok(FileSegment { file }) + } + /// **Seal** this segment at a roll: truncate it to exactly `len` bytes (drop /// the unused `fallocate`'d zero tail) and `fdatasync` so its new size + data /// are durable. After this the segment is **exactly packed** — its on-disk @@ -117,8 +133,33 @@ impl FileSegment { /// preserves the ORIGINAL F_FULLFSYNC errno in context — the fallback's errno /// alone would mislead durability diagnostics. (Shared by `seal_to` and /// `FileSegment::fdatasync`; mirrors `store::barrier_fsync`.) +/// BENCH-ONLY: whether `DS_BENCH_FAST_FSYNC` requests plain `fsync` over +/// `F_FULLFSYNC` on macOS. Read once and cached. Mirrors the gate in +/// `store::barrier_fsync`. +#[cfg(target_os = "macos")] +fn fast_fsync_enabled() -> bool { + use std::sync::OnceLock; + static ON: OnceLock = OnceLock::new(); + *ON.get_or_init(|| std::env::var_os("DS_BENCH_FAST_FSYNC").is_some()) +} + #[cfg(target_os = "macos")] fn macos_full_fsync(fd: libc::c_int) -> io::Result<()> { + // BENCH-ONLY (`DS_BENCH_FAST_FSYNC`): plain `fsync` instead of the + // `F_FULLFSYNC` drive barrier so the committer's hot fsync is cheap on a RAM + // disk and the per-shard LOCK becomes the bottleneck (the Linux+NVMe regime + // this build studies). NOT power-loss durable; never set in production. See + // `store::barrier_fsync` for the rationale. + if fast_fsync_enabled() { + // SAFETY: `fd` is a valid open fd for the lifetime of the call. + return unsafe { + if libc::fsync(fd) == 0 { + Ok(()) + } else { + Err(io::Error::last_os_error()) + } + }; + } // SAFETY: callers pass a valid open fd for the lifetime of the call. unsafe { if libc::fcntl(fd, libc::F_FULLFSYNC) == 0 { diff --git a/packages/durable-streams-rust/src/wal/shard.rs b/packages/durable-streams-rust/src/wal/shard.rs index fbad8b60c6..765d61dbf1 100644 --- a/packages/durable-streams-rust/src/wal/shard.rs +++ b/packages/durable-streams-rust/src/wal/shard.rs @@ -29,12 +29,14 @@ //! the invariant the committer relies on. `lsn`s start at 1; `written_high == 0` //! means "nothing contiguous yet". -use std::collections::{BTreeSet, HashMap}; +use std::cmp::Ordering as CmpOrdering; +use std::collections::{BTreeSet, BinaryHeap, HashMap}; use std::io; use std::path::{Path, PathBuf}; -use std::sync::{Arc, Mutex}; +use std::sync::atomic::{AtomicU64, Ordering}; +use std::sync::{Arc, Condvar, Mutex}; -use tokio::sync::{watch, Notify}; +use tokio::sync::oneshot; use super::codec::{encode_into, Record, RecordKind}; use super::segment::{seg_path, FileSegment, SegmentWriter, SEGMENT_BYTES}; @@ -104,13 +106,205 @@ impl ShardInner { } } +/// A single parked `wait_durable(lsn)` caller: its target `lsn`, a monotonic +/// `seq` (tie-break so equal-lsn waiters have a total order — `BinaryHeap` +/// requires `Ord`), and the `oneshot` whose fire un-parks it. +/// +/// Ordered as a **min-heap by `lsn`** (then `seq`): we reverse the natural +/// comparison so [`BinaryHeap`] (a max-heap) yields the *smallest* lsn at the +/// top. That lets [`Shard::publish_durable`] pop exactly the prefix of waiters +/// with `lsn <= watermark` and stop — the coalesced wakeup — instead of the old +/// `watch` broadcast that woke every parked subscriber. +struct DurableWaiter { + lsn: u64, + seq: u64, + tx: oneshot::Sender<()>, +} + +impl PartialEq for DurableWaiter { + fn eq(&self, other: &Self) -> bool { + self.lsn == other.lsn && self.seq == other.seq + } +} +impl Eq for DurableWaiter {} +impl PartialOrd for DurableWaiter { + fn partial_cmp(&self, other: &Self) -> Option { + Some(self.cmp(other)) + } +} +impl Ord for DurableWaiter { + fn cmp(&self, other: &Self) -> CmpOrdering { + // Reverse `(lsn, seq)` so the max-heap pops the LOWEST lsn first. + other + .lsn + .cmp(&self.lsn) + .then_with(|| other.seq.cmp(&self.seq)) + } +} + +/// Per-shard min-ordered registry of parked durability waiters (the coalesced +/// replacement for the `watch` broadcast). Guarded by a short `Mutex` held only +/// to push one waiter (`wait_durable`) or drain the satisfied prefix +/// (`publish_durable`). +struct WaiterReg { + heap: BinaryHeap, + /// Monotonic id handed to each waiter for the heap tie-break. + next_seq: u64, +} + +/// Stage→committer signalling for the **dedicated-OS-thread committer** (Tier-2a). +/// +/// The committer no longer lives on the shared async runtime, so the wakeup can +/// no longer be an async `tokio::sync::Notify`. This is a plain +/// `Mutex + Condvar` the sync appender (`reserve_and_stage`) signals and +/// the committer thread blocks on. +/// +/// **Lost-wakeup safety (the load-bearing invariant):** `work_pending` is set +/// **under the same mutex** the committer checks before parking, and the +/// committer always *re-snapshots the watermark off-lock after waking* — so a +/// stage that races the committer's park is never lost. Two cases: if the stage +/// takes the mutex *after* the committer parks, the condvar wakes the committer +/// (standard predicate-under-lock pattern), which then re-snapshots and commits; +/// if the stage takes the mutex *before* the committer parks, the committer sees +/// `work_pending == true` and does not park, looping to re-snapshot. +/// +/// Because the watermark is always read fresh after the park (never carried +/// across), cross-mutex ordering between `inner` (watermark) and this mutex +/// cannot drop a staged record. This is the same guarantee the old +/// `Notify`-registration-before-snapshot gave. +struct CommitSignal { + state: Mutex, + cv: Condvar, +} + +#[derive(Default)] +struct CommitState { + /// A stage happened since the committer last cleared this — there may be new + /// contiguous-written work to fsync. Set under `state`, cleared by the + /// committer under `state` before it re-snapshots the watermark. + work_pending: bool, + /// Shutdown requested: the committer must do a final drain and exit. + stop: bool, +} + +impl CommitSignal { + fn new() -> Self { + CommitSignal { + state: Mutex::new(CommitState::default()), + cv: Condvar::new(), + } + } + + /// Appender → committer (hot path): mark work pending and wake the committer. + /// The flag is set under `state` so it can never be lost against the + /// committer's park (see type docs). + fn signal_work(&self) { + { + let mut g = self.state.lock().unwrap(); + g.work_pending = true; + } + // Notify after releasing the lock so a woken committer doesn't immediately + // re-block on the mutex we still hold. + self.cv.notify_one(); + } + + /// Shutdown → committer: request a clean stop (committer drains then exits). + fn signal_stop(&self) { + { + let mut g = self.state.lock().unwrap(); + g.stop = true; + } + self.cv.notify_one(); + } + + /// Block until a stage signals work or stop is requested; clear the + /// `work_pending` flag and return whether `stop` was requested. Called by the + /// committer when it has caught up (nothing left to commit). + fn wait_for_work(&self) -> bool { + let mut g = self.state.lock().unwrap(); + while !g.work_pending && !g.stop { + g = self.cv.wait(g).unwrap(); + } + g.work_pending = false; + g.stop + } + + /// Error-backoff wait: park up to `timeout`, returning early if stop is + /// requested. Returns whether `stop` was requested. Does **not** clear + /// `work_pending` — we want to retry the same un-acked watermark, and a + /// pending stage should still drive the next wake. Using the condvar (rather + /// than `thread::sleep`) lets shutdown interrupt a long backoff. + fn backoff_wait(&self, timeout: std::time::Duration) -> bool { + let g = self.state.lock().unwrap(); + if g.stop { + return true; + } + let (g, _timed_out) = self.cv.wait_timeout(g, timeout).unwrap(); + g.stop + } +} + +/// Handle to a shard's dedicated committer OS thread. Signalling stop + joining +/// happens on `stop()` (or on `Drop`, so a handle dropped without an explicit +/// stop still shuts the thread down cleanly rather than detaching it). +pub struct CommitterHandle { + shard: Arc, + join: Option>, +} + +impl CommitterHandle { + /// Signal the committer to stop (non-blocking; does not join). Idempotent. + pub fn signal_stop(&self) { + self.shard.commit_signal.signal_stop(); + } + + /// Join the committer thread (call after `signal_stop`). Consumes the handle. + pub fn join(mut self) { + if let Some(j) = self.join.take() { + let _ = j.join(); + } + } + + /// Signal stop and join — the common single-handle path (the WalSet shutdown + /// path instead `signal_stop`s all shards then `join`s all, for a parallel + /// drain). Used by the test harnesses; allowed dead in the production binary. + #[cfg_attr(not(test), allow(dead_code))] + pub fn stop(self) { + self.signal_stop(); + self.join(); + } +} + +impl Drop for CommitterHandle { + fn drop(&mut self) { + // Ensure the thread is asked to stop and reaped even if the handle is + // dropped without an explicit `stop()` (e.g. a test guard going out of + // scope, or the WalSet being torn down). + self.shard.commit_signal.signal_stop(); + if let Some(j) = self.join.take() { + let _ = j.join(); + } + } +} + /// One WAL shard: a segmented append-only log with its own committer. pub struct Shard { inner: Mutex, - /// Publishes `durable_lsn` to `wait_durable` waiters. - durable_tx: watch::Sender, - /// Wakes the committer whenever a record is staged. - notify: Notify, + /// The highest lsn made durable + acked. Read cheaply (one relaxed-ish + /// atomic load) by `wait_durable`'s fast path, `checkpoint`, the committer, + /// and stats; advanced only by `publish_durable`. Replaces the `watch` + /// channel's value role — the WAKE role lives in `waiters` below. Storing an + /// atomic + firing oneshots both work from the dedicated committer thread + /// (Tier-2a), with no tokio runtime handle, so async `wait_durable` futures + /// are still woken across the thread boundary. + durable_lsn: AtomicU64, + /// Min-ordered (by lsn) registry of parked `wait_durable` waiters. A commit + /// drains only the waiters whose lsn the new watermark satisfies, instead of + /// broadcasting to every parked subscriber (the Tier-1c thundering-herd fix). + waiters: Mutex, + /// Wakes the dedicated committer thread whenever a record is staged (and + /// carries the shutdown signal). See [`CommitSignal`]. + commit_signal: CommitSignal, /// `/wal//` — where this shard's segments live. dir: PathBuf, /// The size each segment is `fallocate`'d to and the roll threshold. Defaults @@ -119,17 +313,45 @@ pub struct Shard { /// Immutable for the shard's lifetime, so a plain field (no lock) is enough. segment_size: u64, /// **Dirty set** (spec §7): the per-stream `StreamState`s this shard has - /// *touched* since its last checkpoint, deduped by `stream_id`. The append - /// path (`maybe_sync_on_ack`) registers the touched stream's `Arc` - /// here. `checkpoint()` drains this set, reads each stream's current logical - /// `Shared.tail` and live `Shared.file`, `fdatasync`s exactly these files — no - /// double-fsync of untouched streams — *before* recycling the WAL, and records - /// each stream's durable tail (the tail at the moment its file is fsync'd) into - /// the persisted per-shard tail map (spec §7, task 11b). Holding the - /// `StreamState` (rather than a bare `Arc`) lets checkpoint read the - /// logical tail it must record alongside the file it fsyncs. This stays - /// decoupled from `reserve_and_stage`, which never needs the `StreamState`. - dirty: Mutex>>, + /// *touched* since its last checkpoint. The append path (`maybe_sync_on_ack`) + /// registers the touched stream's `Arc` here via + /// `register_dirty`. `checkpoint()` drains this collection, reads each stream's + /// current logical `Shared.tail` and live `Shared.file`, `fdatasync`s exactly + /// these files — no double-fsync of untouched streams — *before* recycling the + /// WAL, and records each stream's durable tail (the tail at the moment its file + /// is fsync'd) into the persisted per-shard tail map (spec §7, task 11b). + /// Holding the `StreamState` (rather than a bare `Arc`) lets checkpoint + /// read the logical tail it must record alongside the file it fsyncs. This + /// stays decoupled from `reserve_and_stage`, which never needs the + /// `StreamState`. + /// + /// **Lock-free hot path (Tier-1a):** dedup is no longer done by a per-append + /// `HashMap` insert under this lock. Instead each stream carries a + /// `StreamState.dirty_epoch`; `register_dirty` only takes this lock to `push` + /// on the winning 0→current-epoch CAS transition (at most once per stream per + /// checkpoint interval, ~3 s). The already-dirty hot path never touches this + /// lock — it is a `Vec` (not a map) because the epoch CAS already guarantees + /// each stream is pushed at most once per interval, so no in-collection dedup + /// is needed (a stale-epoch race can at worst push a stream twice, costing one + /// redundant — harmless — fdatasync, never a lost stream). + dirty: Mutex>>, + /// **Current checkpoint epoch** (Tier-1a), starts at `1` (StreamStates start at + /// `dirty_epoch == 0`, so the first append always registers). `checkpoint()` + /// `fetch_add(1)`s this and drains `dirty` in the same step. A stream's + /// `register_dirty` compares the stream's `dirty_epoch` to this: equal ⇒ + /// already registered this interval (pure relaxed-load hot path, no lock); + /// otherwise CAS the stream to this epoch and, on the winning transition, push + /// it into `dirty`. Bumping BEFORE/with the drain is load-bearing: an append + /// racing the drain sees a stale stream epoch and re-registers into the next + /// interval's collection — no touched stream is ever dropped. + dirty_epoch: AtomicU64, + /// Resident copy of the CUMULATIVE per-stream durable-tail map persisted at + /// `/tails` (task 11b). `None` until the first checkpoint needs it + /// (then seeded from disk once); afterwards `persist_durable_tails` merges and + /// serializes from memory instead of re-reading + re-parsing the whole file + /// every ~3 s (O(total streams per shard) — ~20 ms/tick at 400k streams). + /// Only the (serialized, per-shard) checkpoint path locks it. + tails_cache: Mutex>>, /// Per-shard batch-size + durability counters (spec §11). Updated once per /// successful committer `fdatasync` (`record_batch`) — cheap relaxed atomics, /// no lock/alloc/syscall on the commit path. Read off-path by the 1 Hz @@ -202,9 +424,47 @@ impl Shard { /// [`WalSet::open_with_segment_size`]: super::walset::WalSet::open_with_segment_size pub fn open_with_segment_size(dir: PathBuf, segment_size: u64) -> io::Result> { std::fs::create_dir_all(&dir)?; - let seg_start_lsn = 1; - let active = Arc::new(FileSegment::create(seg_path(&dir, seg_start_lsn), segment_size)?); - let (durable_tx, _durable_rx) = watch::channel(0u64); + // Boot must be NON-DESTRUCTIVE (spec §9: recover-before-clobber): the + // on-disk segments are the durable log recovery is about to replay. + // + // - A SEALED segment was truncated to its exactly-packed length at the + // roll; that exact length is how replay walks across the segment seam. + // Re-`fallocate`ing it to full size grafts a zero tail onto it, which + // replay reads as `Incomplete` = end of the durable log — silently + // dropping every later segment's acked records (and recovery then + // truncates the per-stream files back to that stale frontier). + // - A RECYCLED `1.wal` no longer exists; creating a fresh zero-filled + // one makes replay (which walks in start-lsn order) decode zero + // records and stop before the real oldest retained segment. + // + // So: if any segment exists, open the highest-start one as a read-only + // placeholder handle and leave the disk untouched. The in-memory cursor + // (`write_pos`/`next_lsn`) is a placeholder too — `reset_after_recovery` + // MUST rebuild both (fresh `1.wal`, cursor to 0/1) before any append, + // which is the documented boot order (`open` → `recover` → `reset`). + // Only a genuinely fresh shard dir creates + preallocates `1.wal` here. + let mut existing: Vec<(u64, PathBuf)> = Vec::new(); + for entry in std::fs::read_dir(&dir)? { + let path = entry?.path(); + let Some(stem) = path + .file_name() + .and_then(|s| s.to_str()) + .and_then(|n| n.strip_suffix(".wal")) + else { + continue; + }; + if let Ok(start) = stem.parse::() { + existing.push((start, path)); + } + } + existing.sort_by_key(|(s, _)| *s); + let (seg_start_lsn, active) = match existing.pop() { + Some((start, path)) => (start, Arc::new(FileSegment::open_existing(path)?)), + None => ( + 1, + Arc::new(FileSegment::create(seg_path(&dir, 1), segment_size)?), + ), + }; Ok(std::sync::Arc::new(Shard { inner: Mutex::new(ShardInner { active, @@ -215,11 +475,19 @@ impl Shard { written_high: 0, written_ahead: BTreeSet::new(), }), - durable_tx, - notify: Notify::new(), + durable_lsn: AtomicU64::new(0), + waiters: Mutex::new(WaiterReg { + heap: BinaryHeap::new(), + next_seq: 0, + }), + commit_signal: CommitSignal::new(), dir, segment_size, - dirty: Mutex::new(HashMap::new()), + dirty: Mutex::new(Vec::new()), + // Epoch starts at 1; StreamStates start at dirty_epoch 0, so the first + // append on every stream registers it (0 != 1). + dirty_epoch: AtomicU64::new(1), + tails_cache: Mutex::new(None), stats: ShardStats::default(), #[cfg(test)] on_stage: Mutex::new(None), @@ -346,7 +614,13 @@ impl Shard { // --- Phase 1: (maybe roll, then) reserve under the short lock. --- let (lsn, off, seg) = { - let mut g = self.inner.lock().unwrap(); + // Time the contended `inner` acquisition (--wal-stats only). This is + // the headline per-shard write-serialization signal: every stream on + // this shard funnels through this one lock. + let mut g = super::telemetry::timed_lock( + |ns| self.stats.record_inner_lock_wait(ns), + || self.inner.lock().unwrap(), + ); // Segment roll (spec §4): if this record would overflow the active // segment's `fallocate`'d region, SEAL the current segment (truncate to @@ -407,25 +681,72 @@ impl Shard { seg.write_at(off, &buf)?; { - let mut g = self.inner.lock().unwrap(); + let mut g = super::telemetry::timed_lock( + |ns| self.stats.record_inner_lock_wait(ns), + || self.inner.lock().unwrap(), + ); g.mark_written(lsn); } - self.notify.notify_one(); + self.stats.record_staged(); + // Wake the dedicated committer thread. `work_pending` is set under the + // signal mutex (after `mark_written` above), so this can never be lost + // against the committer's park (see `CommitSignal` docs). + self.commit_signal.signal_work(); Ok(lsn) } /// Register a touched stream's `Arc` into this shard's dirty set /// (spec §7). Called from the append path (`maybe_sync_on_ack`) BEFORE staging /// the WAL record (register-before-stage, CQ-1), since that is where the - /// stream's `Arc` is in hand. Deduped by `stream_id`: re-touching - /// a stream just refreshes the handle, so `checkpoint()` reads each touched - /// stream's current tail + `fdatasync`s its file exactly once. + /// stream's `Arc` is in hand. + /// + /// **Lock-free hot path (Tier-1a).** Dedup is by epoch, not by a per-append + /// map insert under the shard's `dirty` lock: /// - /// `reserve_and_stage` itself stays ignorant of `StreamState` (it only ever - /// needs `stream_id`); the `StreamState` is needed solely by `checkpoint`, to - /// read the durable tail it records and the file it fsyncs. - pub fn register_dirty(&self, stream_id: u64, st: Arc) { - self.dirty.lock().unwrap().insert(stream_id, st); + /// - **Hot path (already dirty this interval):** one relaxed load of the shard + /// epoch + one relaxed load of the stream's `dirty_epoch`; if equal, return + /// immediately. No lock, no push, no clock read, no allocation — this is the + /// per-append common case (a stream is appended to many times between two + /// ~3 s checkpoints). + /// - **Transition (first touch this interval):** CAS the stream's `dirty_epoch` + /// to the current shard epoch. The unique winner of the 0/stale→epoch + /// transition pushes the `Arc` into the shard's `dirty` Vec. + /// Because that happens at most once per stream per checkpoint interval, the + /// Vec's `Mutex` is off the hot path — taken only on the transition. + /// + /// The contention stat (`record_dirty_lock_wait`) is still wired, but only + /// around the rare transition lock, so `dirty_wait_load` collapses toward ~0 + /// (the hot path records nothing). `reserve_and_stage` stays ignorant of + /// `StreamState`; the `StreamState` is needed solely by `checkpoint`. + pub fn register_dirty(&self, _stream_id: u64, st: Arc) { + let epoch = self.dirty_epoch.load(Ordering::Relaxed); + // Hot path: already registered for the current checkpoint interval. Pure + // relaxed loads + a branch — never touches the `dirty` lock. + if st.dirty_epoch.load(Ordering::Relaxed) == epoch { + return; + } + // Transition: claim this stream for the current epoch. Only the thread that + // wins the CAS (0/stale → epoch) pushes; a concurrent racer that lost (or + // already advanced the stream to `epoch`) does nothing. AcqRel so the push + // below is ordered after the claim is published. `compare_exchange` (not + // `_weak`) — we must not spuriously fail and double-push. + let cur = st.dirty_epoch.load(Ordering::Relaxed); + if cur == epoch { + return; + } + if st + .dirty_epoch + .compare_exchange(cur, epoch, Ordering::AcqRel, Ordering::Relaxed) + .is_ok() + { + // Off-hot-path: time the (now rare) dirty-set lock so `dirty_wait_load` + // still reports the residual transition-only contention (≈0). + let mut g = super::telemetry::timed_lock( + |ns| self.stats.record_dirty_lock_wait(ns), + || self.dirty.lock().unwrap(), + ); + g.push(st); + } } /// **Checkpoint** (spec §7), per shard, non-blocking w.r.t. acks: @@ -450,9 +771,9 @@ impl Shard { /// re-registering a stream is never lost (it lands in the *next* checkpoint). /// /// Returns the `checkpoint_lsn` persisted. - pub async fn checkpoint(&self) -> io::Result { + pub async fn checkpoint(self: &Arc) -> io::Result { // 1. Snapshot the recycle floor = the highest durably-acked lsn. - let checkpoint_lsn = *self.durable_tx.borrow(); + let checkpoint_lsn = self.durable_lsn.load(Ordering::Acquire); // 2. Drain the dirty set atomically, then fdatasync each touched file. // Draining first means a concurrent append re-registers into a fresh @@ -464,57 +785,124 @@ impl Shard { // file's cache, so the file is durable up to AT LEAST this tail // afterwards (a later concurrent append only extends past it and lands // in the next checkpoint). Recording this tail is conservative-safe. - let touched: Vec<(u64, u64, Arc)> = { + // LOAD-BEARING ORDERING (Tier-1a): bump the checkpoint epoch and drain + // the dirty Vec in the SAME `dirty`-lock critical section that + // `register_dirty`'s push also takes. This serialization is what makes + // the lock-free hot path safe: a stream registered for the OLD epoch is + // in the Vec we take (and keeps its old `dirty_epoch`, so its next append + // re-registers into the new interval); a stream whose `register_dirty` + // observes the bumped epoch necessarily pushes AFTER we release this + // lock, landing in the fresh post-take Vec for the next checkpoint. So no + // touched stream is ever both drained here AND silently skipped next time. + // The critical section is O(1) — take the Vec and bump the epoch, nothing + // else. The per-stream tail/file capture below runs AFTER the lock is + // released: at high stream cardinality nearly every append is its + // stream's first touch of the interval (the transition path), so any + // O(touched) work under this lock stalls every appender on the shard + // for the whole drain (measured 25–140 ms per tick at 400k streams). + let drained: Vec> = { let mut g = self.dirty.lock().unwrap(); + self.dirty_epoch.fetch_add(1, Ordering::AcqRel); std::mem::take(&mut *g) - .into_iter() - .map(|(id, st)| { + }; + + // Everything below is file IO + O(touched)/O(total-streams) CPU — run it + // in ONE blocking task so none of it ever stalls an async worker thread + // (at 400k streams the capture+fsync+tails phases are tens of ms per tick + // each; on a real disk the fsync fan-out can be far worse). Ordering + // inside the closure is exactly the required hard ordering: capture tails + // → fdatasync per-stream files → persist tails map → persist + // checkpoint_lsn → recycle. Acks never gate on any of this. + let this = Arc::clone(self); + tokio::task::spawn_blocking(move || -> io::Result { + // Phase timing for the `WAL_CKPT` line (`--wal-stats`). One clock + // read per phase, once per ~3 s per shard — nowhere near the hot path. + let t_start = std::time::Instant::now(); + // Capture each touched stream's current logical tail and live file. + // The tail is read BEFORE the fsync; the fdatasync flushes every page + // already in the file's cache, so the file is durable up to AT LEAST + // this tail afterwards (a later concurrent append only extends past + // it and lands in the next checkpoint). Conservative-safe. + let touched: Vec<(u64, u64, Arc)> = drained + .iter() + .map(|st| { let s = st.shared.read().unwrap(); - (id, s.tail, Arc::clone(&s.file)) + (st.id, s.tail, Arc::clone(&s.file)) }) - .collect() - }; - // Run the (potentially blocking) fdatasyncs off the async runtime so a - // slow disk can't stall this task's executor thread. Ordering preserved: - // we await all per-stream fsyncs before touching the WAL. We move only the - // files into the blocking task; the (stream_id, durable_tail) pairs stay - // here to merge into the persisted tail map after the fsyncs succeed. - let tails: Vec<(u64, u64)> = touched.iter().map(|(id, tail, _)| (*id, *tail)).collect(); - let to_sync: Vec> = - touched.into_iter().map(|(_, _, f)| f).collect(); - tokio::task::spawn_blocking(move || -> io::Result<()> { - for f in &to_sync { + .collect(); + let n_touched = touched.len(); + let t_capture = t_start.elapsed(); + + // 2. fdatasync each touched per-stream file. + for (_, _, f) in &touched { crate::store::barrier_fsync(f)?; } - Ok(()) + let t_fsync = t_start.elapsed(); + + // 3a. Persist the CUMULATIVE per-stream durable-tail map (task 11b) + // AFTER the per-stream files are fsync'd, and BEFORE recycle — + // same hard ordering as `checkpoint_lsn`. Merge this checkpoint's + // touched tails into the resident map so a stream touched in an + // earlier checkpoint (but not this one) keeps its last durable + // tail. `tmp` + rename + fsync makes the map itself crash-durable, + // so when recycle deletes the WAL records below the floor, + // recovery can still truncate a recycled stream's torn + // per-stream-file tail to its durable tail. + let tails: Vec<(u64, u64)> = + touched.iter().map(|(id, tail, _)| (*id, *tail)).collect(); + let n_tails = this.persist_durable_tails(&tails)?; + let t_tails = t_start.elapsed(); + + // 3b. Persist checkpoint_lsn (durably) AFTER the per-stream files are + // fsync'd, so the recorded floor only ever covers bytes already on + // disk in their own files. + let ckpt_path = this.dir.join(CHECKPOINT_FILE); + let tmp = this.dir.join(format!("{CHECKPOINT_FILE}.tmp")); + std::fs::write(&tmp, checkpoint_lsn.to_string())?; + std::fs::rename(&tmp, &ckpt_path)?; + + // 4. Recycle: unlink WAL segments fully below checkpoint_lsn. This is + // the LAST step — strictly after the per-stream fsyncs AND the + // durable-tail map persist above. + this.recycle_below(checkpoint_lsn)?; + let t_rest = t_start.elapsed(); + + // 5. Flush the meta sidecar of every touched stream whose append + // path marked it dirty (WAL mode defers the per-append debounced + // flush to here — see handle_append_inner). Strictly AFTER the + // WAL-critical sequence above: sidecar producer/access state is + // non-durable by contract and plays no part in WAL replay, so it + // must never delay the recycle floor. Errors are ignored exactly + // like the debounced flush ignored them. + let mut n_meta = 0u64; + for st in &drained { + if st.meta_dirty.swap(false, Ordering::AcqRel) { + let _ = crate::store::write_meta_sync(st, false); + n_meta += 1; + } + } + + if super::telemetry::stats_enabled() { + let t_total = t_start.elapsed(); + eprintln!( + "WAL_CKPT shard={} touched={} tails_entries={} meta={} capture_us={} fsync_us={} tails_us={} rest_us={} meta_us={} total_us={}", + this.dir.file_name().and_then(|s| s.to_str()).unwrap_or("?"), + n_touched, + n_tails, + n_meta, + t_capture.as_micros(), + (t_fsync - t_capture).as_micros(), + (t_tails - t_fsync).as_micros(), + (t_rest - t_tails).as_micros(), + (t_total - t_rest).as_micros(), + t_total.as_micros(), + ); + } + + Ok(checkpoint_lsn) }) .await - .expect("checkpoint fdatasync task panicked")?; - - // 3a. Persist the CUMULATIVE per-stream durable-tail map (task 11b) AFTER - // the per-stream files are fsync'd, and BEFORE recycle — same hard - // ordering as `checkpoint_lsn`. Merge this checkpoint's touched tails - // into the previously-persisted map so a stream touched in an earlier - // checkpoint (but not this one) keeps its last durable tail. `tmp` + - // rename + fsync makes the map itself crash-durable, so when recycle - // deletes the WAL records below the floor, recovery can still truncate - // a recycled stream's torn per-stream-file tail to its durable tail. - self.persist_durable_tails(&tails)?; - - // 3b. Persist checkpoint_lsn (durably) AFTER the per-stream files are - // fsync'd, so the recorded floor only ever covers bytes already on - // disk in their own files. - let ckpt_path = self.dir.join(CHECKPOINT_FILE); - let tmp = self.dir.join(format!("{CHECKPOINT_FILE}.tmp")); - std::fs::write(&tmp, checkpoint_lsn.to_string())?; - std::fs::rename(&tmp, &ckpt_path)?; - - // 4. Recycle: unlink WAL segments fully below checkpoint_lsn. This is the - // LAST step — strictly after the per-stream fsyncs AND the durable-tail - // map persist above. - self.recycle_below(checkpoint_lsn)?; - - Ok(checkpoint_lsn) + .expect("checkpoint task panicked") } /// Merge `touched` `(stream_id, durable_tail)` pairs into the persisted @@ -524,28 +912,40 @@ impl Shard { /// the WAL is recycled, so a torn per-stream-file tail can always be truncated /// to its durable tail even after its WAL records are gone (task 11b). /// - /// Cumulative-merge: read the existing map, overwrite each touched stream's - /// entry with its newest durable tail (`max`, so a re-checkpointed earlier tail - /// can never regress the recorded value), keep every untouched stream's last - /// recorded tail. - fn persist_durable_tails(&self, touched: &[(u64, u64)]) -> io::Result<()> { + /// Cumulative-merge: merge into the RESIDENT map (`tails_cache`, seeded from + /// disk once on first use), overwrite each touched stream's entry with its + /// newest durable tail (`max`, so a re-checkpointed earlier tail can never + /// regress the recorded value), keep every untouched stream's last recorded + /// tail. Serializing from memory avoids re-reading + re-parsing the whole + /// file every checkpoint (O(total streams per shard) each ~3 s). + /// Returns the number of entries in the persisted map (for `WAL_CKPT`). + fn persist_durable_tails(&self, touched: &[(u64, u64)]) -> io::Result { if touched.is_empty() && !self.dir.join(TAILS_FILE).exists() { // Nothing touched and no prior map: nothing to persist. - return Ok(()); + return Ok(0); } - let mut map = Self::read_durable_tails_at(&self.dir); + let mut cache = self.tails_cache.lock().unwrap(); + let map = cache.get_or_insert_with(|| Self::read_durable_tails_at(&self.dir)); for &(id, tail) in touched { let slot = map.entry(id).or_insert(0); *slot = (*slot).max(tail); } // Serialize as `stream_id durable_tail` lines (sorted for a deterministic, // diff-friendly file). Plain decimal text, matching the `checkpoint` file. - let mut entries: Vec<(u64, u64)> = map.into_iter().collect(); + let mut entries: Vec<(u64, u64)> = map.iter().map(|(&k, &v)| (k, v)).collect(); entries.sort_unstable(); + let n = entries.len(); let mut body = String::with_capacity(entries.len() * 16); - for (id, tail) in entries { - body.push_str(&format!("{id} {tail}\n")); + { + use std::fmt::Write as _; + for (id, tail) in entries { + let _ = writeln!(body, "{id} {tail}"); + } } + // The resident map is fully merged and serialized; release it before the + // file IO below (nothing else contends today, but don't hold a lock over + // a write+fsync+rename gratuitously). + drop(cache); let path = self.dir.join(TAILS_FILE); let tmp = self.dir.join(format!("{TAILS_FILE}.tmp")); std::fs::write(&tmp, &body)?; @@ -553,7 +953,7 @@ impl Shard { // crash-durable BEFORE recycle (the whole point of 11b). std::fs::File::open(&tmp)?.sync_all()?; std::fs::rename(&tmp, &path)?; - Ok(()) + Ok(n) } /// Read the persisted per-shard durable-tail map from `/tails`. Returns @@ -775,12 +1175,12 @@ impl Shard { self.stats.snapshot() } - /// Current `durable_lsn` — the highest lsn made durable + acked. Cheap - /// (`watch::borrow`), read by the emitter and by [`Shard::checkpoint`]. + /// Current `durable_lsn` — the highest lsn made durable + acked. Cheap (one + /// atomic load), read by the emitter and by [`Shard::checkpoint`]. /// Telemetry/test-only as a public accessor (see [`Shard::wal_size_bytes`]). #[cfg_attr(not(any(feature = "telemetry", test)), allow(dead_code))] pub fn durable_lsn_now(&self) -> u64 { - *self.durable_tx.borrow() + self.durable_lsn.load(Ordering::Acquire) } /// The shard's `tail_lsn` — the highest lsn **assigned** so far (`next_lsn - 1`, @@ -793,19 +1193,51 @@ impl Shard { } /// Await until this shard's `durable_lsn >= lsn`. + /// + /// Coalesced wakeup (Tier-1c): instead of subscribing to a broadcast that + /// every commit wakes, we register a single `oneshot` keyed by `lsn` in the + /// min-ordered [`WaiterReg`]. [`Shard::publish_durable`] fires only the + /// waiters whose lsn the new watermark satisfies — so a parked waiter is + /// woken at most once, exactly when its lsn becomes durable. + /// + /// **Cross-thread wakeup (Tier-2a):** `publish_durable` runs on the dedicated + /// committer OS thread; `oneshot::Sender::send` fires the receiver's waker + /// from any thread, so an async `wait_durable` future parked on the runtime is + /// woken across the thread→async boundary with no tokio handle required. + /// + /// **Lost-wakeup safety (the register/publish race):** `publish_durable` + /// stores `durable_lsn` (Release) *before* it locks the heap to drain; we + /// push our waiter *before* re-loading `durable_lsn` (Acquire). The heap + /// `Mutex` orders the two heap critical sections, so for any interleaving + /// either (a) our push precedes the commit's drain — it fires our oneshot — + /// or (b) the commit's drain precedes our push — but then its `durable_lsn` + /// store happens-before our re-check load, which sees it and returns. No + /// commit can land in the gap between the check and the registration and + /// leave us parked forever. pub async fn wait_durable(&self, lsn: u64) { - let mut rx = self.durable_tx.subscribe(); - if *rx.borrow_and_update() >= lsn { + // Fast path: already durable — return without touching the registry. + if self.durable_lsn.load(Ordering::Acquire) >= lsn { return; } - loop { - if rx.changed().await.is_err() { - return; - } - if *rx.borrow_and_update() >= lsn { - return; - } + let rx = { + let mut reg = self.waiters.lock().unwrap(); + let (tx, rx) = oneshot::channel(); + let seq = reg.next_seq; + reg.next_seq = reg.next_seq.wrapping_add(1); + reg.heap.push(DurableWaiter { lsn, seq, tx }); + rx + }; + // Re-check AFTER registering to close the race where a commit landed + // between the fast-path load and the push (see the doc comment). If it is + // now durable, return; our heap entry's receiver is dropped, so a later + // drain firing it is a silent no-op. + if self.durable_lsn.load(Ordering::Acquire) >= lsn { + return; } + // Park until our oneshot fires. A `RecvError` (sender dropped without + // firing) only happens at shard teardown — treat as "return", matching + // the old `watch::changed()`-errored behaviour. + let _ = rx.await; } /// Current contiguous-written watermark (`written_high`). Snapshot this @@ -829,37 +1261,102 @@ impl Shard { /// is the committer's Ok-branch; callers MUST pass a watermark snapshotted /// BEFORE the covering fsync (never re-snapshot afterwards). pub fn publish_durable(&self, watermark: u64) { - let durable = *self.durable_tx.borrow(); + let durable = self.durable_lsn.load(Ordering::Acquire); if watermark <= durable { return; } self.stats.record_batch(watermark - durable); - // Use send_replace (unconditional write) so the watermark is stored even - // when no receivers exist yet — `durable_tx` sits at 0 receivers between - // appends because the constructor drops `_durable_rx` and a waiter only - // subscribes inside `wait_durable` AFTER `reserve_and_stage` returns. - // `send()` silently no-ops when receiver_count == 0, which would drop the - // durable watermark; a waiter that subscribes afterwards reads a stale - // value and waits forever for an already-durable record. - self.durable_tx.send_replace(watermark); + // Publish the new watermark (Release) BEFORE draining the waiter heap. + // This ordering is load-bearing for lost-wakeup safety: a `wait_durable` + // that registers concurrently re-checks `durable_lsn` after pushing, and + // the heap `Mutex` guarantees it either observes this store or is drained + // below (see `wait_durable`'s doc comment). Storing the atomic + firing the + // oneshots below both work from the dedicated committer OS thread (Tier-2a) + // with no tokio runtime handle. + self.durable_lsn.store(watermark, Ordering::Release); + // Coalesced wakeup (Tier-1c): under the short lock, pop ONLY the prefix of + // waiters whose lsn <= the new watermark and fire their oneshots. The heap + // is min-ordered by lsn, so the first entry above the watermark stops the + // drain — every still-parked waiter has a strictly higher lsn. This + // replaces the `watch` broadcast that woke every parked subscriber (most + // of which re-checked and immediately re-parked — the thundering herd). + let mut fired = 0u64; + { + let mut reg = self.waiters.lock().unwrap(); + while let Some(top) = reg.heap.peek() { + if top.lsn > watermark { + break; + } + let w = reg.heap.pop().expect("peek just confirmed a top entry"); + // `send` fails silently if the receiver was dropped (a cancelled + // wait_durable — timeout/connection drop); count only live waiters + // actually woken, so `waiters_woken_avg` reflects real wakeups. + if w.tx.send(()).is_ok() { + fired += 1; + } + } + } + // Record how many waiters this commit ACTUALLY woke — now just the few + // satisfied by this watermark, not every parked subscriber. This is the + // proof of the coalescing: `waiters_woken_avg` collapses toward ~1. + self.stats.record_waiters_woken(fired); let mut g = self.inner.lock().unwrap(); g.sealed_pending.retain(|(end_lsn, _)| *end_lsn > watermark); } - /// The shard's group-commit committer: wait for staged work, `fdatasync` the - /// active segment, advance `durable_lsn` to the contiguous-written watermark, - /// and publish it to waiters. Runs forever (the caller `abort`s it). + /// One group-commit attempt: snapshot the contiguous-written watermark, + /// `fdatasync` the segments that cover it (sealed-pending first, then active), + /// then publish it as `durable_lsn`. Returns `Ok(Some(watermark))` when an + /// advance was published, `Ok(None)` when already caught up (nothing to do), + /// and `Err` when an fsync failed. + /// + /// **No-loss / watermark invariants (load-bearing):** the watermark is + /// snapshotted **before** the covering fsync and published **exactly** (never + /// re-snapshotted after the fsync — see [`Shard::publish_durable`]). On fsync + /// error we return `Err` and do **not** publish, so `durable_lsn` never + /// advances over un-fsync'd bytes (records stay un-acked). `sealed_pending` + /// segments are fsync'd before `publish_durable` retires them. + /// + /// Runs the `fdatasync` **synchronously on the committer's own OS thread** — + /// no `spawn_blocking` round-trip onto the shared runtime (the Tier-2a win). + fn commit_once(&self) -> io::Result> { + let watermark = self.snapshot_watermark(); + let durable = self.durable_lsn.load(Ordering::Acquire); + if watermark <= durable { + return Ok(None); + } + let (seg, sealed) = self.collect_fsync_targets(); + for s in &sealed { + s.fdatasync()?; + } + seg.fdatasync()?; + // Snapshotted-before-fsync watermark, published exactly. + self.publish_durable(watermark); + Ok(Some(watermark)) + } + + /// The shard's group-commit committer, run on a **dedicated OS thread** (one + /// per shard, spawned by [`Shard::spawn_committer`]) — off the shared async + /// runtime, so committers don't time-share the network/reactor worker threads + /// and pay no per-commit `spawn_blocking` hop (Tier-2a). It blocks on the + /// [`CommitSignal`] condvar for staged work, `fdatasync`s synchronously, and + /// advances/publishes `durable_lsn`. Firing the per-waiter `oneshot`s from + /// `publish_durable` (driven from this thread) still wakes async + /// `wait_durable` futures across the thread→async boundary. + /// + /// **Lost-wakeup safety:** when caught up we park in `wait_for_work`, which + /// checks `work_pending` **under the same mutex** a stage sets it under, and + /// we always re-snapshot the watermark off-lock after waking. A stage racing + /// the park is therefore never lost (see [`CommitSignal`]). /// - /// **Lost-wakeup safety:** we register the `Notified` future *before* - /// snapshotting the watermark. `Notify` stores one permit, so a `notify_one` - /// racing between our snapshot and the `await` is captured by the already- - /// registered future and returns immediately on the next iteration — no - /// staged record can sit un-committed waiting for a wakeup that already fired. + /// **fsync-error path:** on `fdatasync` failure we do **not** advance + /// `durable_lsn` (no ack) and back off with bounded exponential delay + /// (interruptible by shutdown), exactly as the no-loss invariant requires. /// - /// **fsync-error path:** if `fdatasync` fails we do **not** advance - /// `durable_lsn` and do **not** publish — the staged records stay un-acked, - /// exactly as the no-loss invariant requires (spec §6). - pub async fn run_committer(self: std::sync::Arc) { + /// **Shutdown:** on a stop signal the loop performs a **final drain** + /// (commits everything already contiguous-written, so in-flight commits are + /// not dropped) and then returns so the thread can be joined. + pub fn run_committer(&self) { // Backoff state for the fsync-error path: a persistently failing disk // (ENOSPC/EIO/read-only volume) must not busy-spin a core, hammer the disk, // and flood stderr. The no-loss invariant holds throughout — `durable_lsn` @@ -870,71 +1367,121 @@ impl Shard { let mut backoff = RETRY_BACKOFF_MIN; let mut consecutive_errors: u64 = 0; loop { - // Register interest BEFORE reading state (lost-wakeup safety). - let notified = self.notify.notified(); - - let watermark = self.snapshot_watermark(); - let durable = *self.durable_tx.borrow(); - - if watermark > durable { - let (seg, sealed) = self.collect_fsync_targets(); - let fsync_res: io::Result<()> = tokio::task::spawn_blocking(move || { - for s in &sealed { - s.fdatasync()?; + match self.commit_once() { + Ok(Some(_)) => { + // Advanced — re-snapshot immediately; more may have arrived + // while we were fsyncing (group commit naturally batches them). + consecutive_errors = 0; + backoff = RETRY_BACKOFF_MIN; + continue; + } + Ok(None) => { + // Caught up — reset the error backoff and park for the next + // stage (or a stop signal). + consecutive_errors = 0; + backoff = RETRY_BACKOFF_MIN; + if self.commit_signal.wait_for_work() { + // Stop requested: drain any records that became + // contiguous-written before/at the stop, then exit. We do + // NOT retry fsync errors forever here — on error we log and + // give up (no-loss holds: durable_lsn is not advanced, so + // the un-drained tail simply stays un-acked, exactly as a + // crash would leave it). + loop { + match self.commit_once() { + Ok(Some(_)) => continue, + Ok(None) => break, + Err(e) => { + eprintln!( + "WAL committer final-drain fdatasync failed: {e}" + ); + break; + } + } + } + return; } - seg.fdatasync()?; - Ok(()) - }) - .await - .unwrap_or_else(|e| Err(io::Error::other(format!("committer fsync task panicked: {e}")))); - match fsync_res { - Ok(()) => { - self.publish_durable(watermark); - consecutive_errors = 0; - backoff = RETRY_BACKOFF_MIN; - continue; + } + Err(e) => { + // Rate-limited log + bounded exponential backoff. The backoff + // parks on the condvar (not a raw sleep) so shutdown can + // interrupt it; a stream of concurrent stages cannot turn the + // retry into a hot loop (we do not clear `work_pending` here, + // so the same un-acked watermark is retried). + consecutive_errors += 1; + if consecutive_errors == 1 || consecutive_errors % LOG_EVERY == 0 { + eprintln!( + "WAL committer fdatasync failed (attempt {consecutive_errors}): {e}" + ); } - Err(e) => { - // Rate-limited log + bounded exponential backoff. We SLEEP - // (rather than await `notified`) so a stream of concurrent - // appends — each leaving a `Notify` permit — cannot turn the - // retry into a hot loop. A recovered disk costs at most one - // backoff interval of extra latency. Dropping the registered - // `notified` here is safe: an un-polled `Notified` does not - // consume the stored permit, so no stage wakeup is lost. - consecutive_errors += 1; - if consecutive_errors == 1 || consecutive_errors % LOG_EVERY == 0 { - eprintln!( - "WAL committer fdatasync failed (attempt {consecutive_errors}): {e}" - ); - } - tokio::time::sleep(backoff).await; - backoff = (backoff * 2).min(RETRY_BACKOFF_MAX); - continue; + if self.commit_signal.backoff_wait(backoff) { + // Stop requested during backoff: exit without acking the + // failing watermark (no-loss preserved). + return; } + backoff = (backoff * 2).min(RETRY_BACKOFF_MAX); } } + } + } - // Nothing new to commit — caught up, so reset the error backoff and - // wait for the next stage. - consecutive_errors = 0; - backoff = RETRY_BACKOFF_MIN; - notified.await; + /// Spawn this shard's committer on a dedicated OS thread and return a + /// [`CommitterHandle`] for clean shutdown. The thread holds an `Arc` + /// clone so it stays alive until stopped + joined. + pub fn spawn_committer(self: &Arc) -> CommitterHandle { + let me = Arc::clone(self); + let join = std::thread::Builder::new() + .name("wal-committer".to_string()) + .spawn(move || me.run_committer()) + .expect("spawn WAL committer thread"); + CommitterHandle { + shard: Arc::clone(self), + join: Some(join), } } /// Test-only: current `durable_lsn`. #[cfg(test)] pub fn durable_lsn(&self) -> u64 { - *self.durable_tx.borrow() + self.durable_lsn.load(Ordering::Acquire) + } + + /// Test-only: number of currently-parked durability waiters in the registry. + /// Lets the coalesced-wakeup tests assert that the fast path registers no + /// waiter and that a commit drains exactly the satisfied prefix. + #[cfg(test)] + pub fn waiter_count(&self) -> usize { + self.waiters.lock().unwrap().heap.len() } - /// Test-only: whether `stream_id` is currently in the dirty set. Used to - /// prove the append path registers a stream BEFORE its lsn can become + /// Test-only: whether `stream_id` is currently in the dirty set (i.e. its + /// `Arc` is present in the shard's pending dirty collection). Used + /// to prove the append path registers a stream BEFORE its lsn can become /// durable (the checkpoint recycle-before-fsync ordering invariant, spec §7). + /// Updated for the Tier-1a representation: a scan of the dirty `Vec` (a stream + /// is pushed at most once per checkpoint interval), not a `HashMap` lookup. #[cfg(test)] pub fn is_dirty(&self, stream_id: u64) -> bool { - self.dirty.lock().unwrap().contains_key(&stream_id) + self.dirty + .lock() + .unwrap() + .iter() + .any(|st| st.id == stream_id) + } + + /// Test-only: number of entries currently in the dirty collection. Because the + /// Tier-1a epoch CAS pushes each stream at most once per checkpoint interval, + /// this counts distinct touched streams (modulo a rare drain-race duplicate) — + /// used to prove the already-dirty hot path does NOT re-push. + #[cfg(test)] + pub fn dirty_len(&self) -> usize { + self.dirty.lock().unwrap().len() + } + + /// Test-only: the shard's current checkpoint epoch (Tier-1a). + #[cfg(test)] + pub fn dirty_epoch_now(&self) -> u64 { + self.dirty_epoch.load(Ordering::Relaxed) } /// Test-only: arm the next `reserve_and_stage` to simulate a `write_at` @@ -1022,10 +1569,7 @@ mod tests { const SEG: u64 = 4096; let dir = tmp("roll-multi"); let sh = Shard::open_with_segment_size(dir.clone(), SEG).unwrap(); - let h = tokio::spawn({ - let s = sh.clone(); - async move { s.run_committer().await } - }); + let h = sh.spawn_committer(); // ~200-byte records → ~20 per 4 KiB segment; 80 records ⇒ ≥3 segments. let payload = vec![b'x'; 200 - crate::wal::codec::HEADER_LEN]; @@ -1034,7 +1578,7 @@ mod tests { last = sh.reserve_and_stage(RecordKind::Append, 1, i * 200, &payload).unwrap(); } sh.wait_durable(last).await; - h.abort(); + h.stop(); let segs = segs_on_disk(&dir); assert!(segs.len() >= 3, "rolled to ≥3 segments, got {}", segs.len()); @@ -1070,10 +1614,7 @@ mod tests { const SEG: u64 = 4096; let dir = tmp("roll-durable"); let sh = Shard::open_with_segment_size(dir.clone(), SEG).unwrap(); - let h = tokio::spawn({ - let s = sh.clone(); - async move { s.run_committer().await } - }); + let h = sh.spawn_committer(); let payload = vec![b'y'; 150]; let mut last = 0; for i in 0..100u64 { @@ -1082,7 +1623,7 @@ mod tests { sh.wait_durable(last).await; assert_eq!(sh.durable_lsn(), last, "every record across rolls is durable"); assert!(segs_on_disk(&dir).len() >= 3, "spanned ≥3 segments"); - h.abort(); + h.stop(); let _ = std::fs::remove_dir_all(&dir); } @@ -1093,10 +1634,7 @@ mod tests { const SEG: u64 = 4096; let dir = tmp("roll-replay"); let sh = Shard::open_with_segment_size(dir.clone(), SEG).unwrap(); - let h = tokio::spawn({ - let s = sh.clone(); - async move { s.run_committer().await } - }); + let h = sh.spawn_committer(); let mut expect: Vec<(u64, u64, Vec)> = Vec::new(); let mut last = 0; for i in 0..120u64 { @@ -1106,7 +1644,7 @@ mod tests { expect.push((last, i * 7, p)); } sh.wait_durable(last).await; - h.abort(); + h.stop(); assert!(segs_on_disk(&dir).len() >= 3, "spanned ≥3 segments"); // Replay in lsn order across segments; collect every record. @@ -1132,10 +1670,7 @@ mod tests { const SEG: u64 = 4096; let dir = tmp("roll-recycle"); let sh = Shard::open_with_segment_size(dir.clone(), SEG).unwrap(); - let h = tokio::spawn({ - let s = sh.clone(); - async move { s.run_committer().await } - }); + let h = sh.spawn_committer(); let payload = vec![b'z'; 180]; let mut last = 0; for i in 0..120u64 { @@ -1156,7 +1691,7 @@ mod tests { assert_eq!(after.len(), 1, "all sealed segments recycled below the floor"); assert_eq!(after[0].0, active_start, "the active segment is retained"); assert!(seg_path(&dir, active_start).exists(), "active segment file remains"); - h.abort(); + h.stop(); let _ = std::fs::remove_dir_all(&dir); } @@ -1173,10 +1708,7 @@ mod tests { assert_eq!(total, 64); const SEG: u64 = 128; // exactly 2 records per segment let sh = Shard::open_with_segment_size(dir.clone(), SEG).unwrap(); - let h = tokio::spawn({ - let s = sh.clone(); - async move { s.run_committer().await } - }); + let h = sh.spawn_committer(); // 5 records: r1,r2 fill seg0 exactly (write_pos 64 then 128 == SEG, no roll // on r2 since 64+64==128 is NOT > 128). r3 rolls (128+64 > 128). r4 fills // the new seg. r5 rolls again. @@ -1185,7 +1717,7 @@ mod tests { last = sh.reserve_and_stage(RecordKind::Append, 5, i, &payload).unwrap(); } sh.wait_durable(last).await; - h.abort(); + h.stop(); let segs = segs_on_disk(&dir); assert_eq!(segs.len(), 3, "r1r2 | r3r4 | r5 ⇒ 3 segments"); @@ -1227,16 +1759,13 @@ mod tests { let l1 = sh.reserve_and_stage(RecordKind::Append, 1, 0, b"a").unwrap(); let _l2 = sh.reserve_only(); // #[cfg(test)] hook: assigns lsn, no write let l3 = sh.reserve_and_stage(RecordKind::Append, 1, 2, b"c").unwrap(); - let h = tokio::spawn({ - let s = sh.clone(); - async move { s.run_committer().await } - }); + let h = sh.spawn_committer(); sh.wait_durable(l1).await; // give the committer a beat to (incorrectly) over-advance if the watermark is broken tokio::time::sleep(std::time::Duration::from_millis(50)).await; assert!(sh.durable_lsn() >= l1, "l1 (and its contiguous prefix) is durable"); assert!(sh.durable_lsn() < l3, "MUST NOT advance past the unwritten l2 gap to l3"); - h.abort(); + h.stop(); } #[tokio::test] @@ -1256,17 +1785,14 @@ mod tests { // advance durable_lsn past the gap at lsn 1. let l2 = sh.reserve_and_stage(RecordKind::Append, 1, 4, b"ok").unwrap(); assert_eq!(l2, 2, "the failed stage still consumed lsn 1 (it stays a gap)"); - let h = tokio::spawn({ - let s = sh.clone(); - async move { s.run_committer().await } - }); + let h = sh.spawn_committer(); tokio::time::sleep(std::time::Duration::from_millis(50)).await; assert_eq!( sh.durable_lsn(), 0, "durable_lsn cannot advance past the unwritten (failed) lsn-1 gap" ); - h.abort(); + h.stop(); } #[tokio::test] @@ -1316,10 +1842,7 @@ mod tests { // A new append now lands at lsn 1 / offset 0 into the clean segment; the // committer makes it durable and nothing past it decodes as a record. - let h = tokio::spawn({ - let s = sh.clone(); - async move { s.run_committer().await } - }); + let h = sh.spawn_committer(); let lsn = sh.reserve_and_stage(RecordKind::Append, 1, 0, b"new").unwrap(); assert_eq!(lsn, 1, "fresh WAL starts at lsn 1"); sh.wait_durable(lsn).await; @@ -1337,7 +1860,7 @@ mod tests { } other => panic!("fresh record did not decode: {other:?}"), } - h.abort(); + h.stop(); let _ = std::fs::remove_dir_all(&dir); } @@ -1347,10 +1870,7 @@ mod tests { let sh = Shard::open(dir.clone()).unwrap(); // Spawn the committer so staged records become durable (advances durable_lsn). - let h = tokio::spawn({ - let s = sh.clone(); - async move { s.run_committer().await } - }); + let h = sh.spawn_committer(); // Build a real stream via the store so the dirty set can hold its // `Arc` (checkpoint reads `Shared.tail` + `Shared.file`). @@ -1415,7 +1935,7 @@ mod tests { assert!(seg_path(&dir, 1).exists(), "active segment never recycled"); let _ = l1; - h.abort(); + h.stop(); let _ = std::fs::remove_dir_all(&dir); } @@ -1426,10 +1946,7 @@ mod tests { // as records accumulate (a lagging checkpoint only delays recycling). let dir = tmp("ckpt-nonblock"); let sh = Shard::open(dir.clone()).unwrap(); - let h = tokio::spawn({ - let s = sh.clone(); - async move { s.run_committer().await } - }); + let h = sh.spawn_committer(); let size_before = sh.wal_size_bytes(); let mut last = 0; @@ -1448,7 +1965,7 @@ mod tests { ); assert!(seg_path(&dir, 1).exists(), "WAL segment retained (not recycled)"); - h.abort(); + h.stop(); let _ = std::fs::remove_dir_all(&dir); } @@ -1469,12 +1986,9 @@ mod tests { assert_eq!(sh.durable_lsn_now(), 0, "nothing durable until the committer runs"); // Now run the committer: one fdatasync should make all K durable at once. - let h = tokio::spawn({ - let s = sh.clone(); - async move { s.run_committer().await } - }); + let h = sh.spawn_committer(); sh.wait_durable(last).await; - h.abort(); + h.stop(); let snap = sh.stats_snapshot(); assert_eq!(snap.fsync_count, 1, "a single fdatasync committed the whole batch"); @@ -1496,10 +2010,7 @@ mod tests { let dir = tmp("shard-pos"); let sh = Shard::open(dir.clone()).unwrap(); - let h = tokio::spawn({ - let s = sh.clone(); - async move { s.run_committer().await } - }); + let h = sh.spawn_committer(); let mut lsns = Vec::new(); let mut payloads = Vec::new(); @@ -1512,7 +2023,7 @@ mod tests { let last = *lsns.last().unwrap(); sh.wait_durable(last).await; assert!(sh.durable_lsn() >= last, "durable_lsn reached the last staged lsn"); - h.abort(); + h.stop(); // Every record's bytes are on disk and decode correctly, back-to-back. let raw = std::fs::read(seg_path(&dir, 1)).unwrap(); @@ -1531,6 +2042,48 @@ mod tests { } } + #[tokio::test] + async fn dedicated_thread_committer_makes_durable_and_stops_cleanly() { + // The committer runs on its OWN dedicated OS thread (Tier-2a), NOT the + // tokio runtime. It must (a) make staged records durable while running, + // and (b) on a stop signal perform a FINAL DRAIN so even a batch staged + // immediately before the stop becomes durable, then exit so the thread + // joins cleanly (no detach, no hang). + let dir = tmp("dedicated-thread"); + let sh = Shard::open(dir.clone()).unwrap(); + let h = sh.spawn_committer(); + + // (a) Records made durable while the committer thread runs. + let mut last = 0; + for i in 0..10u64 { + last = sh.reserve_and_stage(RecordKind::Append, 1, i, b"live").unwrap(); + } + sh.wait_durable(last).await; + assert!(sh.durable_lsn() >= last, "records durable while committer runs"); + + // (b) Stage a final batch, then stop WITHOUT awaiting durability — the + // committer's final drain must still make them durable before it exits. + // `reserve_and_stage` returns only after `mark_written`, so by the time + // this loop finishes every record is contiguous-written; the final drain + // snapshots that watermark and fsyncs it. + let mut last2 = last; + for i in 0..5u64 { + last2 = sh + .reserve_and_stage(RecordKind::Append, 1, 100 + i, b"tail") + .unwrap(); + } + // `stop()` signals stop and JOINS the thread — blocks until it has drained + // and exited. + h.stop(); + assert_eq!( + sh.durable_lsn(), + last2, + "final drain on shutdown made the just-staged batch durable before the thread exited" + ); + + let _ = std::fs::remove_dir_all(&dir); + } + /// CQ-1 invariant: `register_dirty` must happen-before `reserve_and_stage`. /// /// At the moment `reserve_and_stage` begins (before any lsn is assigned), @@ -1606,4 +2159,228 @@ mod tests { let _ = std::fs::remove_dir_all(&dir); } + + /// Tier-1a hot path: re-registering an ALREADY-dirty stream within the same + /// checkpoint epoch must NOT re-push into the dirty collection. The first + /// `register_dirty` wins the 0→epoch CAS and pushes once; every subsequent + /// touch of that stream (the common per-append case) is a pure relaxed-load + /// branch that returns without taking the `dirty` lock or growing the Vec. + #[tokio::test] + async fn register_dirty_is_idempotent_within_an_epoch() { + let dir = tmp("dirty-idem"); + let sh = Shard::open(dir.clone()).unwrap(); + let store = crate::store::Store::new_with_tier( + dir.clone(), + crate::tier::TierConfig::default(), + ) + .unwrap(); + let st = match store.create("idem-stream", ckpt_test_cfg(), None, 0).unwrap() { + crate::store::CreateResult::Created(s) => s, + _ => panic!("create failed"), + }; + let sid = st.id; + + assert_eq!(sh.dirty_len(), 0, "precondition: empty dirty set"); + + // First touch this epoch: wins the CAS, pushes exactly once. + sh.register_dirty(sid, Arc::clone(&st)); + assert_eq!(sh.dirty_len(), 1, "first registration pushes once"); + assert!(sh.is_dirty(sid)); + + // Many re-touches in the SAME epoch: every one is the hot path (no push). + for _ in 0..1000 { + sh.register_dirty(sid, Arc::clone(&st)); + } + assert_eq!( + sh.dirty_len(), + 1, + "re-registering an already-dirty stream in the same epoch must NOT re-push" + ); + + // A DIFFERENT stream in the same epoch is a distinct first-touch → one push. + let st2 = match store.create("idem-stream-2", ckpt_test_cfg(), None, 0).unwrap() { + crate::store::CreateResult::Created(s) => s, + _ => panic!("create failed"), + }; + sh.register_dirty(st2.id, Arc::clone(&st2)); + assert_eq!(sh.dirty_len(), 2, "a distinct stream still registers once"); + + let _ = std::fs::remove_dir_all(&dir); + } + + /// Tier-1a no-loss: a stream re-touched AFTER a checkpoint drains the dirty set + /// must re-register (the checkpoint bumped the epoch, so the stream's stale + /// `dirty_epoch` no longer matches) and therefore land in the NEXT checkpoint. + /// This is the property that makes the lock-free hot path safe: draining never + /// silently swallows a stream's subsequent appends. + #[tokio::test] + async fn touched_after_checkpoint_drain_lands_in_next_checkpoint() { + let dir = tmp("dirty-next"); + let sh = Shard::open(dir.clone()).unwrap(); + let h = sh.spawn_committer(); + let store = crate::store::Store::new_with_tier( + dir.clone(), + crate::tier::TierConfig::default(), + ) + .unwrap(); + let st = match store.create("next-stream", ckpt_test_cfg(), None, 0).unwrap() { + crate::store::CreateResult::Created(s) => s, + _ => panic!("create failed"), + }; + let sid = st.id; + + let epoch0 = sh.dirty_epoch_now(); + + // Interval 1: append + register, make the record durable so checkpoint has + // a non-zero floor, then checkpoint (drains the stream, bumps the epoch). + sh.register_dirty(sid, Arc::clone(&st)); + let l1 = sh.reserve_and_stage(RecordKind::Append, sid, 0, b"first").unwrap(); + // Reflect a logical tail so checkpoint records it (file already exists). + st.shared.write().unwrap().tail = 5; + sh.wait_durable(l1).await; + assert!(sh.is_dirty(sid), "registered in interval 1"); + + sh.checkpoint().await.unwrap(); + assert_eq!( + sh.dirty_epoch_now(), + epoch0 + 1, + "checkpoint bumped the epoch" + ); + assert!(!sh.is_dirty(sid), "checkpoint drained the dirty set"); + assert_eq!(sh.dirty_len(), 0, "dirty set empty after drain"); + + // Interval 2: the SAME stream is touched again after the drain. Its + // dirty_epoch is stale (== old epoch), so register_dirty must re-push it. + sh.register_dirty(sid, Arc::clone(&st)); + assert!( + sh.is_dirty(sid), + "a stream touched after the drain re-registers (not lost)" + ); + assert_eq!(sh.dirty_len(), 1, "re-registered into the next interval's set"); + + // The next checkpoint drains it again — proving the post-drain append is + // covered, never dropped. + let l2 = sh.reserve_and_stage(RecordKind::Append, sid, 5, b"second").unwrap(); + st.shared.write().unwrap().tail = 11; + sh.wait_durable(l2).await; + sh.checkpoint().await.unwrap(); + assert!(!sh.is_dirty(sid), "second checkpoint drained the re-registration"); + assert_eq!(sh.dirty_epoch_now(), epoch0 + 2, "epoch bumped again"); + + h.stop(); + let _ = std::fs::remove_dir_all(&dir); + } + + /// Tier-1c (a): a waiter for lsn=K is woken EXACTLY when durable reaches >= K, + /// and NEVER before. We drive `publish_durable` directly (no committer) to set + /// the watermark precisely: a commit to K-1 must leave the waiter parked; the + /// commit to K must wake it. + #[tokio::test] + async fn waiter_woken_only_when_durable_reaches_its_lsn() { + use std::time::Duration; + let sh = Shard::open(tmp("wd-exact")).unwrap(); + + let waiter = tokio::spawn({ + let s = sh.clone(); + async move { s.wait_durable(10).await } + }); + // Let it register and park. + tokio::time::sleep(Duration::from_millis(30)).await; + assert_eq!(sh.waiter_count(), 1, "waiter parked while durable (0) < lsn (10)"); + assert!(!waiter.is_finished(), "waiter must not be woken before its lsn"); + + // Advance durable BELOW the waiter's lsn: must NOT wake it. + sh.publish_durable(9); + tokio::time::sleep(Duration::from_millis(30)).await; + assert!(!waiter.is_finished(), "durable=9 < lsn=10 ⇒ still parked"); + assert_eq!(sh.waiter_count(), 1, "waiter not drained below its lsn"); + + // Reach the waiter's lsn: it must wake now. + sh.publish_durable(10); + tokio::time::timeout(Duration::from_millis(500), waiter) + .await + .expect("waiter woken when durable reaches its lsn") + .unwrap(); + assert_eq!(sh.waiter_count(), 0, "the satisfied waiter was drained"); + } + + /// Tier-1c (b): committing watermark=K wakes EVERY waiter with lsn <= K in one + /// pass but leaves every lsn > K parked — and `waiters_woken` counts only the + /// satisfied ones (the coalescing proof: not a broadcast to all parked). + #[tokio::test] + async fn commit_wakes_only_satisfied_waiters_and_counts_them() { + use std::time::Duration; + let sh = Shard::open(tmp("wd-coalesce")).unwrap(); + + let lo = tokio::spawn({ + let s = sh.clone(); + async move { s.wait_durable(3).await } + }); + let mid = tokio::spawn({ + let s = sh.clone(); + async move { s.wait_durable(5).await } + }); + let hi = tokio::spawn({ + let s = sh.clone(); + async move { s.wait_durable(8).await } + }); + tokio::time::sleep(Duration::from_millis(30)).await; + assert_eq!(sh.waiter_count(), 3, "all three waiters parked"); + + // Commit watermark = 5: wakes lsn 3 and 5; lsn 8 stays parked. + sh.publish_durable(5); + tokio::time::timeout(Duration::from_millis(500), lo) + .await + .expect("lsn=3 woken (<= watermark 5)") + .unwrap(); + tokio::time::timeout(Duration::from_millis(500), mid) + .await + .expect("lsn=5 woken (== watermark 5)") + .unwrap(); + tokio::time::sleep(Duration::from_millis(30)).await; + assert!(!hi.is_finished(), "lsn=8 stays parked above the watermark"); + assert_eq!(sh.waiter_count(), 1, "only the unsatisfied (lsn=8) waiter remains"); + + // Coalescing proof: this commit woke exactly the 2 satisfied waiters, not + // all 3 parked subscribers (the old broadcast would have recorded 3). + assert_eq!( + sh.stats_snapshot().waiters_woken, + 2, + "waiters_woken counts only the satisfied prefix, not every parked waiter" + ); + + // Advancing to 8 finally wakes the last one. + sh.publish_durable(8); + tokio::time::timeout(Duration::from_millis(500), hi) + .await + .expect("lsn=8 woken once durable reaches it") + .unwrap(); + assert_eq!(sh.waiter_count(), 0, "all waiters drained"); + } + + /// Tier-1c (c): a waiter whose lsn is ALREADY durable returns immediately via + /// the fast path, WITHOUT registering in the heap (no park, no oneshot). + #[tokio::test] + async fn already_durable_waiter_returns_without_parking() { + use std::time::Duration; + let sh = Shard::open(tmp("wd-fast")).unwrap(); + + // Make lsn 5 durable up front (no waiters registered yet → fires nothing). + sh.publish_durable(5); + assert_eq!(sh.waiter_count(), 0, "no waiters before the fast-path call"); + + // A wait for an already-durable lsn must return immediately and register + // nothing in the heap. + tokio::time::timeout(Duration::from_millis(200), sh.wait_durable(3)) + .await + .expect("already-durable (3 <= 5) waiter returns without parking"); + tokio::time::timeout(Duration::from_millis(200), sh.wait_durable(5)) + .await + .expect("already-durable (5 == 5) waiter returns without parking"); + assert_eq!( + sh.waiter_count(), + 0, + "the fast path registers no waiter in the heap" + ); + } } diff --git a/packages/durable-streams-rust/src/wal/sim_tests.rs b/packages/durable-streams-rust/src/wal/sim_tests.rs new file mode 100644 index 0000000000..2757648c3d --- /dev/null +++ b/packages/durable-streams-rust/src/wal/sim_tests.rs @@ -0,0 +1,1083 @@ +//! Randomized crash/recovery simulation — a seeded fuzz harness for the WAL +//! recovery path. Design: docs/superpowers/specs/2026-07-02-wal-crash-simulation-design.md +//! +//! Each seed drives the REAL handler path (`handlers::handle`) with a random +//! workload (creates, appends, cancelled appends, closes, forks, deletes, +//! checkpoints), then simulates a crash by dropping the generation's tokio +//! runtime (aborting in-flight requests at whatever await point they reached), +//! stopping the committers, and optionally injecting disk faults constrained to +//! the documented fault model: +//! +//! - per-stream data files are fsynced only at checkpoint / recovery repair, so +//! any byte past a stream's known-fsynced floor may be truncated, scribbled, +//! or zero-extended (power loss / torn page writeback); +//! - WAL segment bytes belonging to records with `lsn > durable_lsn` at crash +//! time were never fdatasync'd (no ack was released for them), so a random +//! suffix of that region may be zeroed or scribbled. +//! +//! It then re-runs the real boot sequence (`WalSet::open` → sidecar pass → +//! `wal::recovery::recover` → `reset_after_recovery`) and checks the oracle: +//! every ACKED record is present, in order, whole; maybe-applied (cancelled / +//! in-flight-at-crash) records are each present-whole or absent; no torn or +//! foreign bytes; tails/file_base/closed-ness consistent; deleted streams stay +//! deleted; recovery itself never errors or panics. Multiple generations per +//! seed continue the workload on the recovered store to catch +//! recovery-of-recovery bugs. +//! +//! Reproduce a failure with the seed printed in the panic message: +//! `DS_SIM_SEED0= DS_SIM_SEEDS=1 cargo test crash_recovery_randomized`. +//! Scale the hunt with `DS_SIM_SEEDS` / `DS_SIM_GENS` / `DS_SIM_STEPS`. + +use std::path::PathBuf; +use std::sync::Arc; + +use bytes::Bytes; + +use crate::api::{Method, Req}; +use crate::handlers; +use crate::handlers::test_support::DurabilityGuard; +use crate::store::Store; +use crate::tier::TierConfig; +use crate::wal::codec::{decode_at, Decoded, RecordKind}; +use crate::wal::shard::CommitterHandle; +use crate::wal::walset::WalSet; + +/// Small segments so the workload rolls + recycles segments (the recovery paths +/// with the most history of bugs). Must comfortably exceed the largest payload +/// (8 KiB) + header. +const SEG_BYTES: u64 = 32 * 1024; + +// --------------------------------------------------------------------------- +// Deterministic PRNG (splitmix64) — no dev-dependency on `rand`. +// --------------------------------------------------------------------------- + +struct Rng(u64); + +impl Rng { + fn new(seed: u64) -> Self { + Rng(seed) + } + fn next_u64(&mut self) -> u64 { + self.0 = self.0.wrapping_add(0x9E37_79B9_7F4A_7C15); + let mut z = self.0; + z = (z ^ (z >> 30)).wrapping_mul(0xBF58_476D_1CE4_E5B9); + z = (z ^ (z >> 27)).wrapping_mul(0x94D0_49BB_1331_11EB); + z ^ (z >> 31) + } + fn below(&mut self, n: u64) -> u64 { + if n == 0 { + 0 + } else { + self.next_u64() % n + } + } + fn chance(&mut self, percent: u64) -> bool { + self.below(100) < percent + } + fn alnum(&mut self, len: usize) -> String { + const CS: &[u8] = b"abcdefghijklmnopqrstuvwxyz0123456789"; + (0..len) + .map(|_| CS[self.below(CS.len() as u64) as usize] as char) + .collect() + } +} + +// --------------------------------------------------------------------------- +// Oracle model +// --------------------------------------------------------------------------- + +#[derive(Clone, Copy, PartialEq, Eq, Debug)] +enum RecStatus { + /// 2xx ack observed — must survive every crash, byte-identical, in order. + Acked, + /// Cancelled / in-flight at crash / staged-at-crash — may be present + /// (whole) or absent, never torn. + Maybe, +} + +struct Rec { + wire: Vec, + status: RecStatus, + seq: u64, +} + +struct SModel { + name: String, + json: bool, + file_base: u64, + file_path: PathBuf, + id: u64, + recs: Vec, + next_seq: u64, + closed: bool, + deleted: bool, + has_children: bool, + /// Any `Maybe` rec not yet resolved by a recovery (blocks forking, whose + /// offset must be a known record boundary). + unsettled: bool, + /// Logical tail known fsynced into the data file (checkpoint or recovery + /// repair). Data-file faults may only touch bytes at/after this point. + floor: u64, +} + +impl SModel { + /// Record-boundary offsets (logical): file_base, then after each rec. + /// Only meaningful when `!unsettled` (every rec known present). + fn boundaries(&self) -> Vec { + let mut v = vec![self.file_base]; + let mut acc = self.file_base; + for r in &self.recs { + acc += r.wire.len() as u64; + v.push(acc); + } + v + } +} + +// --------------------------------------------------------------------------- +// Request builders (same shapes as e2e_tests.rs) +// --------------------------------------------------------------------------- + +fn put_req(path: &str, content_type: &str, extra: &[(&str, &str)]) -> Req { + let mut headers = vec![("content-type".to_string(), content_type.to_string())]; + for (k, v) in extra { + headers.push((k.to_string(), v.to_string())); + } + Req { + method: Method::Put, + path: path.to_string(), + query: None, + headers, + body: Bytes::new(), + } +} + +fn post_req(path: &str, content_type: &str, body: &[u8], extra: &[(&str, &str)]) -> Req { + let mut headers = vec![("content-type".to_string(), content_type.to_string())]; + for (k, v) in extra { + headers.push((k.to_string(), v.to_string())); + } + Req { + method: Method::Post, + path: path.to_string(), + query: None, + headers, + body: Bytes::copy_from_slice(body), + } +} + +fn delete_req(path: &str) -> Req { + Req { + method: Method::Delete, + path: path.to_string(), + query: None, + headers: vec![], + body: Bytes::new(), + } +} + +fn fork_offset(bytes: u64) -> String { + format!("{:016}_{:016}", 0, bytes) +} + +const OCTET: &str = "application/octet-stream"; +const JSON_CT: &str = "application/json"; + +// --------------------------------------------------------------------------- +// Simulation driver +// --------------------------------------------------------------------------- + +struct Sim { + seed: u64, + rng: Rng, + dir: PathBuf, + shards_n: usize, + models: Vec, + name_ctr: u64, + gen: u64, + log: Vec, +} + +impl Sim { + fn note(&mut self, s: String) { + self.log.push(s); + } + + fn fail(&self, msg: String) -> ! { + let tail: Vec<&String> = self.log.iter().rev().take(40).collect(); + let mut trace = String::new(); + for l in tail.into_iter().rev() { + trace.push_str(l); + trace.push('\n'); + } + panic!( + "\n=== SIM ORACLE VIOLATION ===\nseed={} gen={} dir={}\n{}\n--- last steps ---\n{}", + self.seed, + self.gen, + self.dir.display(), + msg, + trace + ); + } + + /// Build the next record for stream `mi` and return (payload, wire). + /// `wire` is the exact on-disk/read-surface byte image (JSON gets the `,` + /// delimiter `encode_wire` appends). + fn make_record(&mut self, mi: usize) -> (Vec, Vec) { + let seq = self.models[mi].next_seq; + self.models[mi].next_seq += 1; + let r = self.rng.below(100); + let fill_len = if r < 60 { + self.rng.below(120) as usize + } else if r < 90 { + 120 + self.rng.below(800) as usize + } else if r < 99 { + 1024 + self.rng.below(4096) as usize + } else { + 8192 + }; + let filler = self.rng.alnum(fill_len); + let name = self.models[mi].name.clone(); + if self.models[mi].json { + let payload = format!("{{\"s\":\"{name}\",\"i\":\"{seq:08}\",\"p\":\"{filler}\"}}").into_bytes(); + let mut wire = payload.clone(); + wire.push(b','); + (payload, wire) + } else { + let payload = format!("{name}#{seq:08}|{filler}|").into_bytes(); + (payload.clone(), payload) + } + } + + fn push_rec(&mut self, mi: usize, wire: Vec, status: RecStatus) { + let seq = self.models[mi].next_seq - 1; + if status == RecStatus::Maybe { + self.models[mi].unsettled = true; + } + self.models[mi].recs.push(Rec { wire, status, seq }); + } + + fn pick(&mut self, pred: impl Fn(&SModel) -> bool) -> Option { + let idxs: Vec = self + .models + .iter() + .enumerate() + .filter(|(_, m)| pred(m)) + .map(|(i, _)| i) + .collect(); + if idxs.is_empty() { + None + } else { + Some(idxs[self.rng.below(idxs.len() as u64) as usize]) + } + } +} + +/// Boot the exact main.rs WAL startup sequence for `dir` (spec §9). +fn boot( + dir: &std::path::Path, + shards: Option, + shards_n: usize, +) -> (Arc, Arc, Vec) { + let walset = WalSet::open_with_segment_size(dir, shards, shards_n, SEG_BYTES) + .expect("WalSet::open must succeed"); + let store = Arc::new( + Store::new_with_tier(dir.to_path_buf(), TierConfig::default()).expect("Store::new"), + ); + crate::wal::recovery::recover(&store, &walset) + .expect("recovery must not error on in-model faults"); + walset.reset_after_recovery().expect("reset_after_recovery"); + store + .wal + .set(Arc::clone(&walset)) + .unwrap_or_else(|_| panic!("WAL already attached")); + let mut committers = Vec::new(); + for shard in walset.shards() { + committers.push(shard.spawn_committer()); + } + (store, walset, committers) +} + +// --------------------------------------------------------------------------- +// Oracle verification +// --------------------------------------------------------------------------- + +fn escape_snippet(b: &[u8]) -> String { + b.iter() + .take(120) + .map(|&c| { + if (0x20..0x7f).contains(&c) { + (c as char).to_string() + } else { + format!("\\x{c:02x}") + } + }) + .collect() +} + +/// Match the recovered file bytes against the model. Returns per-rec presence. +/// Greedy in-issue-order pass (Acked must match; Maybe may skip), then a +/// permutation pass for the crash-tail: leftover bytes must be some ordering of +/// skipped Maybe wires. Errors describe the violation. +fn match_stream(model: &SModel, bytes: &[u8]) -> Result, String> { + let mut present = vec![false; model.recs.len()]; + let mut cursor = 0usize; + let mut skipped: Vec = Vec::new(); + for (i, rec) in model.recs.iter().enumerate() { + if bytes[cursor..].starts_with(&rec.wire) { + cursor += rec.wire.len(); + present[i] = true; + } else { + match rec.status { + RecStatus::Acked => { + return Err(format!( + "LOST/CORRUPT ACKED record seq={} ({} bytes) at file cursor {}.\n\ + expected: {}\n\ + found: {}", + rec.seq, + rec.wire.len(), + cursor, + escape_snippet(&rec.wire), + escape_snippet(&bytes[cursor.min(bytes.len())..]) + )); + } + RecStatus::Maybe => skipped.push(i), + } + } + } + // Crash-tail permutation: consume any remaining bytes as whole skipped + // Maybe records, in any order. + while cursor < bytes.len() { + let mut matched = false; + for &i in &skipped { + if !present[i] && bytes[cursor..].starts_with(&model.recs[i].wire) { + cursor += model.recs[i].wire.len(); + present[i] = true; + matched = true; + break; + } + } + if !matched { + return Err(format!( + "TORN/FOREIGN bytes at file cursor {} ({} bytes remain of {} total):\n{}", + cursor, + bytes.len() - cursor, + bytes.len(), + escape_snippet(&bytes[cursor..]) + )); + } + } + Ok(present) +} + +/// Full post-recovery oracle over every model. Updates each model to the +/// settled post-recovery truth (present Maybe → Acked; absent Maybe dropped; +/// floor = recovered frontier, which recovery fdatasync'd). +fn verify_recovery(sim: &mut Sim, store: &Arc) { + for mi in 0..sim.models.len() { + let (name, deleted) = (sim.models[mi].name.clone(), sim.models[mi].deleted); + if deleted { + if let Some(st) = store.get(&name) { + let soft = st.shared.read().unwrap().soft_deleted; + if !soft { + sim.fail(format!("stream {name}: DELETED stream resurrected after recovery")); + } + } + continue; + } + let Some(st) = store.get(&name) else { + sim.fail(format!("stream {name}: acked-created stream MISSING after recovery")); + }; + let bytes = std::fs::read(&st.file_path).unwrap_or_else(|e| { + sim.fail(format!("stream {name}: cannot read data file after recovery: {e}")) + }); + + // File/base/tail consistency. + let (file_base, durable_tail, tail) = { + let s = st.shared.read().unwrap(); + (s.file_base, s.durable_tail, s.tail) + }; + if file_base != sim.models[mi].file_base { + sim.fail(format!( + "stream {name}: file_base changed across recovery: expected {}, got {file_base}", + sim.models[mi].file_base + )); + } + if tail != file_base + bytes.len() as u64 { + sim.fail(format!( + "stream {name}: Shared.tail {tail} != file_base {file_base} + file_len {}", + bytes.len() + )); + } + if durable_tail != tail { + sim.fail(format!( + "stream {name}: durable_tail {durable_tail} != tail {tail} after recovery" + )); + } + let watch_tail = st.tail(); + if watch_tail.bytes != tail { + sim.fail(format!( + "stream {name}: watch tail {} != Shared.tail {tail} after recovery", + watch_tail.bytes + )); + } + + // Closed-ness durability. + if sim.models[mi].closed && !watch_tail.closed { + sim.fail(format!( + "stream {name}: close was ACKED but stream recovered open" + )); + } + + // Content: acked ⊆ recovered ⊆ issued, in order, whole records only. + let present = match match_stream(&sim.models[mi], &bytes) { + Ok(p) => p, + Err(e) => sim.fail(format!("stream {name}: {e}")), + }; + + // JSON read-surface validity. + if sim.models[mi].json && !bytes.is_empty() { + let text = String::from_utf8(bytes.clone()).unwrap_or_else(|_| { + sim.fail(format!("stream {name}: JSON stream contains non-UTF8 bytes")) + }); + let wrapped = format!("[{}]", text.trim_end_matches(',')); + if let Err(e) = serde_json::from_str::(&wrapped) { + sim.fail(format!( + "stream {name}: recovered JSON read surface invalid: {e}\n{}", + escape_snippet(&bytes) + )); + } + } + + // Settle the model to post-recovery truth. + let m = &mut sim.models[mi]; + let mut kept = Vec::new(); + for (i, mut r) in std::mem::take(&mut m.recs).into_iter().enumerate() { + if present[i] { + r.status = RecStatus::Acked; // durable now (recovery fdatasync'd the repair) + kept.push(r); + } + } + m.recs = kept; + m.unsettled = false; + m.floor = file_base + bytes.len() as u64; + m.id = st.id; + m.file_path = st.file_path.clone(); + } +} + +// --------------------------------------------------------------------------- +// Fault injection (crash-time, constrained to the fault model) +// --------------------------------------------------------------------------- + +/// Data-file power-loss faults: any byte at/after the stream's fsynced floor +/// may be truncated away, scribbled, or the file zero-extended (size-metadata +/// committed before data pages). +fn inject_data_file_faults(sim: &mut Sim) { + for mi in 0..sim.models.len() { + if sim.models[mi].deleted || !sim.rng.chance(35) { + continue; + } + let path = sim.models[mi].file_path.clone(); + let Ok(meta) = std::fs::metadata(&path) else { continue }; + let len = meta.len(); + let floor_pos = sim.models[mi].floor.saturating_sub(sim.models[mi].file_base); + let kind = sim.rng.below(3); + let name = sim.models[mi].name.clone(); + match kind { + 0 => { + // Truncate to a random point in [floor_pos, len]. + if len <= floor_pos { + continue; + } + let to = floor_pos + sim.rng.below(len - floor_pos + 1); + let f = std::fs::OpenOptions::new().write(true).open(&path).unwrap(); + f.set_len(to).unwrap(); + sim.note(format!("FAULT data-trunc {name}: {len} -> {to} (floor_pos {floor_pos})")); + } + 1 => { + // Scribble garbage over a random subrange of [floor_pos, len). + if len <= floor_pos { + continue; + } + let start = floor_pos + sim.rng.below(len - floor_pos); + let max = (len - start).min(256); + let glen = 1 + sim.rng.below(max) as usize; + let garbage: Vec = (0..glen).map(|_| sim.rng.next_u64() as u8).collect(); + use std::io::{Seek, SeekFrom, Write}; + let mut f = std::fs::OpenOptions::new().write(true).open(&path).unwrap(); + f.seek(SeekFrom::Start(start)).unwrap(); + f.write_all(&garbage).unwrap(); + sim.note(format!( + "FAULT data-scribble {name}: [{start}, {}) of len {len} (floor_pos {floor_pos})", + start + glen as u64 + )); + } + _ => { + // Zero-fill a subrange of the un-fsynced region: the size (inode) + // update was committed but those data pages never flushed. The + // file's LENGTH never grows — power loss cannot create bytes + // beyond the maximum length ever written. + if len <= floor_pos { + continue; + } + let start = floor_pos + sim.rng.below(len - floor_pos); + let zlen = 1 + sim.rng.below(len - start) as usize; + use std::io::{Seek, SeekFrom, Write}; + let mut f = std::fs::OpenOptions::new().write(true).open(&path).unwrap(); + f.seek(SeekFrom::Start(start)).unwrap(); + f.write_all(&vec![0u8; zlen]).unwrap(); + sim.note(format!( + "FAULT data-zero {name}: [{start}, {}) of len {len} (floor_pos {floor_pos})", + start + zlen as u64 + )); + } + } + } +} + +/// WAL suffix faults: bytes of records with `lsn > durable` were never +/// fdatasync'd (nothing gated on them was acked), so a random suffix of that +/// region may be zeroed (lost pages) or scribbled (torn write). +fn inject_wal_faults(sim: &mut Sim, durable: &[u64]) { + for (i, &d) in durable.iter().enumerate() { + if !sim.rng.chance(50) { + continue; + } + let shard_dir = sim.dir.join("wal").join(i.to_string()); + let Ok(rd) = std::fs::read_dir(&shard_dir) else { continue }; + let mut segs: Vec<(u64, PathBuf)> = rd + .flatten() + .filter_map(|e| { + let p = e.path(); + let stem = p.file_stem()?.to_str()?.parse::().ok()?; + (p.extension()?.to_str()? == "wal").then_some((stem, p)) + }) + .collect(); + segs.sort(); + let Some((_, seg_path)) = segs.last() else { continue }; + let Ok(bytes) = std::fs::read(seg_path) else { continue }; + + // Walk records: find the byte range [fault_from, logical_end) holding + // records with lsn > durable. + let mut off = 0usize; + let mut fault_from: Option = None; + while let Decoded::Record { lsn, total, .. } = decode_at(&bytes, off) { + if lsn > d && fault_from.is_none() { + fault_from = Some(off); + } + off += total; + } + let logical_end = off; + let Some(from) = fault_from else { continue }; + if from >= logical_end { + continue; + } + let p = from as u64 + sim.rng.below((logical_end - from) as u64 + 1); + if p as usize >= logical_end { + continue; + } + use std::io::{Seek, SeekFrom, Write}; + let mut f = std::fs::OpenOptions::new().write(true).open(seg_path).unwrap(); + if sim.rng.chance(50) { + // Zero from p to the end of the file's logical region (lost pages). + let zeros = vec![0u8; logical_end - p as usize]; + f.seek(SeekFrom::Start(p)).unwrap(); + f.write_all(&zeros).unwrap(); + sim.note(format!( + "FAULT wal-zero shard {i}: [{p}, {logical_end}) durable_lsn {d}" + )); + } else { + let glen = 1 + sim.rng.below(64) as usize; + let garbage: Vec = (0..glen).map(|_| sim.rng.next_u64() as u8 | 1).collect(); + f.seek(SeekFrom::Start(p)).unwrap(); + f.write_all(&garbage).unwrap(); + sim.note(format!( + "FAULT wal-scribble shard {i}: [{p}, {}) durable_lsn {d}", + p + glen as u64 + )); + } + f.sync_all().unwrap(); + } +} + +// --------------------------------------------------------------------------- +// Workload +// --------------------------------------------------------------------------- + +async fn ack_append(sim: &mut Sim, store: &Arc, mi: usize) { + let (payload, wire) = sim.make_record(mi); + let m = &sim.models[mi]; + let ct = if m.json { JSON_CT } else { OCTET }; + let name = m.name.clone(); + let resp = handlers::handle(Arc::clone(store), post_req(&name, ct, &payload, &[])).await; + if !(200..300).contains(&resp.status) { + sim.fail(format!( + "append to open stream {name} rejected with {} (payload {} bytes)", + resp.status, + payload.len() + )); + } + sim.note(format!("append {name} seq={} {}B acked", sim.models[mi].next_seq - 1, wire.len())); + sim.push_rec(mi, wire, RecStatus::Acked); +} + +async fn cancelled_append(sim: &mut Sim, store: &Arc, mi: usize) { + let (payload, wire) = sim.make_record(mi); + let m = &sim.models[mi]; + let ct = if m.json { JSON_CT } else { OCTET }; + let name = m.name.clone(); + let req = post_req(&name, ct, &payload, &[]); + let jh = tokio::spawn(handlers::handle(Arc::clone(store), req)); + for _ in 0..sim.rng.below(4) { + tokio::task::yield_now().await; + } + jh.abort(); + match jh.await { + Ok(resp) if (200..300).contains(&resp.status) => { + sim.note(format!("append {name} cancelled-but-acked ({}B)", wire.len())); + sim.push_rec(mi, wire, RecStatus::Acked); + } + Ok(resp) => { + sim.note(format!("append {name} cancelled, status {}", resp.status)); + sim.push_rec(mi, wire, RecStatus::Maybe); + } + Err(_) => { + sim.note(format!("append {name} cancelled mid-flight ({}B) -> maybe", wire.len())); + sim.push_rec(mi, wire, RecStatus::Maybe); + } + } +} + +async fn run_generation(sim: &mut Sim, store: &Arc, walset: &Arc, steps: u64) { + for _ in 0..steps { + let op = sim.rng.below(100); + match op { + // ---- create ---- + _ if op < 8 && sim.models.len() < 20 => { + let json = sim.rng.chance(40); + let name = format!("sim-{}", sim.name_ctr); + sim.name_ctr += 1; + let ct = if json { JSON_CT } else { OCTET }; + let resp = handlers::handle(Arc::clone(store), put_req(&name, ct, &[])).await; + if !(200..300).contains(&resp.status) { + sim.fail(format!("create {name} rejected: {}", resp.status)); + } + let st = store.get(&name).unwrap_or_else(|| { + sim.fail(format!("create {name} acked but store.get is None")) + }); + sim.note(format!("create {name} json={json}")); + sim.models.push(SModel { + name, + json, + file_base: 0, + file_path: st.file_path.clone(), + id: st.id, + recs: Vec::new(), + next_seq: 0, + closed: false, + deleted: false, + has_children: false, + unsettled: false, + floor: 0, + }); + } + // ---- cancelled append (network drop) ---- + _ if op < 14 => { + if let Some(mi) = sim.pick(|m| !m.deleted && !m.closed) { + cancelled_append(sim, store, mi).await; + } + } + // ---- close ---- + _ if op < 18 => { + if let Some(mi) = sim.pick(|m| !m.deleted && !m.closed) { + let name = sim.models[mi].name.clone(); + let ct = if sim.models[mi].json { JSON_CT } else { OCTET }; + let resp = handlers::handle( + Arc::clone(store), + post_req(&name, ct, b"", &[("stream-closed", "true")]), + ) + .await; + if !(200..300).contains(&resp.status) { + sim.fail(format!("close {name} rejected: {}", resp.status)); + } + sim.note(format!("close {name}")); + sim.models[mi].closed = true; + } + } + // ---- fork ---- + _ if op < 22 && sim.models.len() < 20 => { + if let Some(pi) = sim.pick(|m| !m.deleted && !m.unsettled) { + let bounds = sim.models[pi].boundaries(); + let at = bounds[sim.rng.below(bounds.len() as u64) as usize]; + let parent = sim.models[pi].name.clone(); + let json = sim.models[pi].json; + let ct = if json { JSON_CT } else { OCTET }; + let name = format!("sim-{}", sim.name_ctr); + sim.name_ctr += 1; + let resp = handlers::handle( + Arc::clone(store), + put_req( + &name, + ct, + &[ + ("stream-forked-from", parent.as_str()), + ("stream-fork-offset", &fork_offset(at)), + ], + ), + ) + .await; + if !(200..300).contains(&resp.status) { + sim.fail(format!( + "fork {name} from {parent}@{at} rejected: {}", + resp.status + )); + } + let st = store.get(&name).unwrap_or_else(|| { + sim.fail(format!("fork {name} acked but store.get is None")) + }); + let fb = st.shared.read().unwrap().file_base; + if fb != at { + sim.fail(format!("fork {name}: file_base {fb} != fork offset {at}")); + } + sim.note(format!("fork {name} from {parent}@{at}")); + sim.models[pi].has_children = true; + sim.models.push(SModel { + name, + json, + file_base: at, + file_path: st.file_path.clone(), + id: st.id, + recs: Vec::new(), + next_seq: 0, + closed: false, + deleted: false, + has_children: false, + unsettled: false, + floor: at, + }); + } + } + // ---- delete ---- + _ if op < 24 => { + if let Some(mi) = sim.pick(|m| !m.deleted && !m.has_children) { + let name = sim.models[mi].name.clone(); + let resp = handlers::handle(Arc::clone(store), delete_req(&name)).await; + if !(200..300).contains(&resp.status) { + sim.fail(format!("delete {name} rejected: {}", resp.status)); + } + sim.note(format!("delete {name}")); + sim.models[mi].deleted = true; + } + } + // ---- checkpoint ---- + _ if op < 30 => { + let si = sim.rng.below(sim.shards_n as u64) as usize; + let shard = Arc::clone(&walset.shards()[si]); + shard.checkpoint().await.unwrap_or_else(|e| { + sim.fail(format!("checkpoint shard {si} failed: {e}")) + }); + let tails = shard.read_durable_tails(); + for m in &mut sim.models { + if let Some(&t) = tails.get(&m.id) { + if t > m.floor { + m.floor = t; + } + } + } + sim.note(format!("checkpoint shard {si} ({} tails)", tails.len())); + } + // ---- live tail sanity ---- + // The reader-visible tail (durable_tail) may lawfully LAG the file + // length: a cancelled append leaves bytes in the file whose publish + // never ran (healed monotonically by the next acked append, or + // exposed by crash recovery). It must never EXCEED the file though. + _ if op < 33 => { + if let Some(mi) = sim.pick(|m| !m.deleted) { + let name = sim.models[mi].name.clone(); + if let Some(st) = store.get(&name) { + let len = std::fs::metadata(&st.file_path).map(|m| m.len()).unwrap_or(0); + let tail = st.tail().bytes; + let fb = sim.models[mi].file_base; + if tail > fb + len { + sim.fail(format!( + "stream {name}: live tail {tail} > file_base {fb} + file_len {len} \ + (published tail covers bytes the file does not have)" + )); + } + } + } + } + // ---- plain acked append ---- + _ => { + if let Some(mi) = sim.pick(|m| !m.deleted && !m.closed) { + ack_append(sim, store, mi).await; + } else { + // Everything closed/deleted: force a create next loop. + } + } + } + } + + // In-flight-at-crash appends: spawned over the real path, never awaited — + // the runtime drop (the crash) aborts them at whatever point they reached. + let inflight = sim.rng.below(3); + for _ in 0..inflight { + if let Some(mi) = sim.pick(|m| !m.deleted && !m.closed) { + let (payload, wire) = sim.make_record(mi); + let ct = if sim.models[mi].json { JSON_CT } else { OCTET }; + let name = sim.models[mi].name.clone(); + sim.note(format!("in-flight append {name} ({}B) at crash", wire.len())); + sim.push_rec(mi, wire, RecStatus::Maybe); + let req = post_req(&name, ct, &payload, &[]); + let store2 = Arc::clone(store); + tokio::spawn(async move { + let _ = handlers::handle(store2, req).await; + }); + } + } + if inflight > 0 { + // Let the spawned appends progress a random amount before the crash. + for _ in 0..sim.rng.below(6) { + tokio::task::yield_now().await; + } + } +} + +/// After the crash (runtime dropped, committers stopped): stage 0..=2 records +/// that reached the data file's page cache + the WAL staging buffer but whose +/// WAL bytes were never fdatasync'd — the classic torn-append shape. These are +/// exactly the bytes `inject_wal_faults` is then allowed to tear. +fn stage_torn_appends(sim: &mut Sim, store: &Arc, walset: &Arc) { + let n = sim.rng.below(3); + for _ in 0..n { + let Some(mi) = sim.pick(|m| !m.deleted && !m.closed) else { return }; + let (_, wire) = sim.make_record(mi); + let name = sim.models[mi].name.clone(); + let Some(st) = store.get(&name) else { continue }; + let cur_len = std::fs::metadata(&st.file_path).map(|m| m.len()).unwrap_or(0); + let offset = sim.models[mi].file_base + cur_len; + { + use std::io::Write; + let mut f = std::fs::OpenOptions::new() + .append(true) + .open(&st.file_path) + .unwrap(); + f.write_all(&wire).unwrap(); + } + let shard = walset.shard_for(st.id); + shard + .reserve_and_stage(RecordKind::Append, st.id, offset, &wire) + .unwrap(); + sim.note(format!( + "staged-at-crash append {name} @{offset} ({}B, never fdatasync'd)", + wire.len() + )); + sim.push_rec(mi, wire, RecStatus::Maybe); + } +} + +// --------------------------------------------------------------------------- +// Seed runner + test entry +// --------------------------------------------------------------------------- + +fn env_u64(name: &str, default: u64) -> u64 { + std::env::var(name) + .ok() + .and_then(|v| v.parse().ok()) + .unwrap_or(default) +} + +fn run_one_seed(seed: u64, gens: u64, steps: u64) { + use std::time::{SystemTime, UNIX_EPOCH}; + let dir = std::env::temp_dir().join(format!( + "ds-wal-sim-{seed}-{}-{}", + std::process::id(), + SystemTime::now().duration_since(UNIX_EPOCH).unwrap().as_nanos() + )); + let _ = std::fs::remove_dir_all(&dir); + + let mut rng = Rng::new(seed); + let shards_n = 1 + (rng.below(3) as usize); // 1..=3 shards + let mut sim = Sim { + seed, + rng, + dir: dir.clone(), + shards_n, + models: Vec::new(), + name_ctr: 0, + gen: 0, + log: Vec::new(), + }; + + for g in 0..=gens { + sim.gen = g; + sim.note(format!("--- generation {g} boot ---")); + // Forensics: snapshot the pre-boot (post-crash, post-fault) disk state + // so a violation can be inspected before recovery/reset mutate it. + if std::env::var("DS_SIM_SNAPSHOT").is_ok() && g > 0 { + let snap = dir.with_file_name(format!( + "{}-preboot-gen{g}", + dir.file_name().unwrap().to_str().unwrap() + )); + let _ = std::fs::remove_dir_all(&snap); + let _ = std::process::Command::new("cp") + .arg("-R") + .arg(&dir) + .arg(&snap) + .status(); + eprintln!("[sim] snapshot: {}", snap.display()); + } + let rt = tokio::runtime::Builder::new_current_thread() + .enable_all() + .build() + .unwrap(); + let last = g == gens; + let (store, walset, committers) = rt.block_on(async { + let (store, walset, committers) = if g == 0 { + boot(&dir, Some(sim.shards_n), sim.shards_n) + } else { + boot(&dir, None, sim.shards_n) + }; + // Oracle over the recovered state (trivially empty on gen 0). + verify_recovery(&mut sim, &store); + if !last { + run_generation(&mut sim, &store, &walset, steps).await; + } + (store, walset, committers) + }); + if last { + for h in committers { + h.stop(); + } + drop(store); + drop(walset); + drop(rt); + break; + } + + // ---- CRASH ---- + // Dropping the runtime aborts every in-flight task (requests, meta + // flushes) at its current await point; blocking writes already + // submitted finish first (a legal pre-crash ordering). + drop(rt); + // The committer threads are the "disk": stop + join them (their final + // drain fsync is a no-op for anything the oracle relies on). + for h in committers { + h.stop(); + } + // Durable frontier per shard, BEFORE staging the torn tail below — + // everything at/below this is fdatasync'd and must survive faults. + let durable: Vec = walset.shards().iter().map(|s| s.durable_lsn_now()).collect(); + // Stage page-cache-only appends (data file + WAL staging, no fsync). + if sim.rng.chance(60) { + stage_torn_appends(&mut sim, &store, &walset); + } + drop(store); + drop(walset); + + // ---- POWER-LOSS FAULTS ---- + if sim.rng.chance(55) { + inject_data_file_faults(&mut sim); + } + if sim.rng.chance(55) { + inject_wal_faults(&mut sim, &durable); + } + } + + let _ = std::fs::remove_dir_all(&dir); +} + +/// Forensic helper: `DS_DUMP_DIR= cargo test wal_forensic_dump -- --ignored --nocapture` +/// decodes every WAL segment (lsn, kind, stream_id, stream_offset, len) and +/// lists per-stream file sizes, for inspecting a failing sim snapshot. +#[test] +#[ignore] +fn wal_forensic_dump() { + let dir = PathBuf::from(std::env::var("DS_DUMP_DIR").expect("set DS_DUMP_DIR")); + for entry in std::fs::read_dir(dir.join("streams")).unwrap().flatten() { + let p = entry.path(); + if p.extension().is_none() { + eprintln!("stream file {:?}: {} bytes", p.file_name().unwrap(), p.metadata().unwrap().len()); + } + } + let wal_root = dir.join("wal"); + for sh in std::fs::read_dir(&wal_root).unwrap().flatten() { + let sp = sh.path(); + if !sp.is_dir() { + continue; + } + let mut segs: Vec<(u64, PathBuf)> = std::fs::read_dir(&sp) + .unwrap() + .flatten() + .filter_map(|e| { + let p = e.path(); + let stem = p.file_stem()?.to_str()?.parse::().ok()?; + (p.extension()?.to_str()? == "wal").then_some((stem, p)) + }) + .collect(); + segs.sort(); + let ckpt = std::fs::read_to_string(sp.join("checkpoint")).unwrap_or_default(); + let tails = std::fs::read_to_string(sp.join("tails")).unwrap_or_default(); + eprintln!("== shard {:?} checkpoint={} tails={}", sp.file_name().unwrap(), ckpt.trim(), tails.trim()); + for (start, seg) in segs { + let bytes = std::fs::read(&seg).unwrap(); + eprintln!("-- segment {start}.wal ({} bytes)", bytes.len()); + let mut off = 0usize; + loop { + match decode_at(&bytes, off) { + Decoded::Record { lsn, kind, stream_id, stream_offset, len, total, .. } => { + eprintln!( + " off={off:<8} lsn={lsn:<6} kind={kind:?} stream={stream_id} s_off={stream_offset} len={len}" + ); + off += total; + } + Decoded::Incomplete => { + eprintln!(" off={off:<8} "); + break; + } + Decoded::Torn => { + eprintln!(" off={off:<8} "); + break; + } + } + } + } + } +} + +/// Forensic helper: run `replay_from_checkpoint(0)` over DS_DUMP_DIR's shards +/// via the real WalSet::open path and print every record the walk yields. +#[test] +#[ignore] +fn wal_forensic_replay() { + let dir = PathBuf::from(std::env::var("DS_DUMP_DIR").expect("set DS_DUMP_DIR")); + let walset = WalSet::open_with_segment_size(&dir, None, 1, SEG_BYTES).unwrap(); + for (i, shard) in walset.shards().iter().enumerate() { + let mut n = 0usize; + shard + .replay_from_checkpoint(0, |kind, sid, soff, payload| { + n += 1; + eprintln!("shard {i}: {kind:?} stream={sid} s_off={soff} len={}", payload.len()); + }) + .unwrap(); + eprintln!("shard {i}: {n} records replayed"); + } +} + +/// Seeded randomized crash/recovery simulation. Fast deterministic defaults for +/// CI; scale with DS_SIM_SEEDS / DS_SIM_SEED0 / DS_SIM_GENS / DS_SIM_STEPS for +/// a long local hunt. +#[test] +fn crash_recovery_randomized_simulation() { + let _guard = DurabilityGuard::wal(); + let seeds = env_u64("DS_SIM_SEEDS", 4); + let seed0 = env_u64("DS_SIM_SEED0", 0x0001_5EED); + let gens = env_u64("DS_SIM_GENS", 3); + let steps = env_u64("DS_SIM_STEPS", 100); + for k in 0..seeds { + let seed = seed0 + k; + eprintln!("[sim] seed {seed} ({}/{seeds})", k + 1); + run_one_seed(seed, gens, steps); + } +} diff --git a/packages/durable-streams-rust/src/wal/telemetry.rs b/packages/durable-streams-rust/src/wal/telemetry.rs index 145093dadc..ca5f7755b6 100644 --- a/packages/durable-streams-rust/src/wal/telemetry.rs +++ b/packages/durable-streams-rust/src/wal/telemetry.rs @@ -42,13 +42,62 @@ //! commit path (CQ-2). At N shards × 1 Hz this is N `read_dir`s/sec — acceptable //! and off the append/commit path. -use std::sync::atomic::{AtomicU64, Ordering}; +use std::sync::atomic::{AtomicBool, AtomicU64, Ordering}; /// Upper-inclusive batch-size bucket boundaries (records-per-commit). The last /// (overflow) bucket catches everything `> 128`. Mirrors the OTel /// `BATCH_BUCKETS` view so the printed and exported distributions agree. pub const BATCH_BUCKETS: &[u64] = &[1, 2, 4, 8, 16, 32, 64, 128]; +// =========================================================================== +// Runtime contention-stats gate (`--wal-stats`, OFF by default). +// =========================================================================== +// +// The contention counters below (lock-wait nanos, wakeup fan-out) need a clock +// read around each lock acquisition. Reading `Instant::now()` on the per-append +// hot path is NOT free, so the timing is gated behind a runtime flag: when off, +// the hot path pays a single relaxed atomic load and skips the clock entirely; +// when on (`--wal-stats `), it times every contended acquisition and a +// plain stderr emitter prints per-shard contention lines every ``. +// +// This is deliberately INDEPENDENT of the heavy `telemetry` (OTLP) feature: the +// whole point is an always-available, zero-dependency way to *observe the lock +// contention* the saturation findings attribute the write ceiling to — no +// collector, no feature rebuild. + +/// Whether `--wal-stats` armed the contention timing + emitter. +static STATS_ENABLED: AtomicBool = AtomicBool::new(false); + +/// Arm (or disarm) the contention-stats timing on the hot path. Called once at +/// startup from `--wal-stats`; the emitter is spawned separately in `main`. +pub fn set_stats_enabled(on: bool) { + STATS_ENABLED.store(on, Ordering::Relaxed); +} + +/// True when `--wal-stats` armed the contention timing. One relaxed load; the +/// hot path reads this before any `Instant::now()` so a default run pays nothing +/// beyond the load. +#[inline] +pub fn stats_enabled() -> bool { + STATS_ENABLED.load(Ordering::Relaxed) +} + +/// Time `f` (a lock acquisition) and return its result, recording the wait via +/// `record` ONLY when stats are armed. When off this is just `f()` plus one +/// relaxed atomic load — no clock read. Keeps the timing boilerplate out of the +/// shard hot path while guaranteeing the clock is never touched in a default run. +#[inline] +pub fn timed_lock(record: impl FnOnce(u64), f: impl FnOnce() -> T) -> T { + if stats_enabled() { + let t0 = std::time::Instant::now(); + let out = f(); + record(t0.elapsed().as_nanos() as u64); + out + } else { + f() + } +} + /// Per-shard durability + batch-size counters. Cheap to update on the commit /// path (relaxed atomics only); read off-path by the 1 Hz emitter. #[derive(Debug)] @@ -67,6 +116,32 @@ pub struct ShardStats { /// size is `<= BATCH_BUCKETS[i]` and `> BATCH_BUCKETS[i-1]`; the final extra /// slot counts batches `> 128`. buckets: [AtomicU64; BATCH_BUCKETS.len() + 1], + + // ---- contention counters (`--wal-stats`; see the gate above) ---- + /// Σ nanoseconds spent acquiring the shard `inner` Mutex on the APPEND path + /// (phase-1 reserve + phase-2 mark_written), and the number of such + /// acquisitions. `avg_inner_wait = nanos / acquires`. This is the headline + /// contention signal: all of a shard's streams funnel through `inner`, so a + /// rising average here is the per-shard write-serialization the saturation + /// findings attribute the ceiling to. + inner_lock_wait_nanos: AtomicU64, + inner_lock_acquires: AtomicU64, + /// Σ nanoseconds spent acquiring the shard `dirty` Mutex (one acquisition + + /// HashMap insert PER append), and the count. Isolates the per-append global + /// dirty-set lock (Tier-1 target: make it lock-free) from `inner`. + dirty_lock_wait_nanos: AtomicU64, + dirty_lock_acquires: AtomicU64, + /// Number of records staged into this shard (one per `reserve_and_stage`). + /// The append throughput per shard; pairs with `fsync_count` to show the + /// real coalescing ratio (`staged / fsync_count`). + staged: AtomicU64, + /// Σ durability waiters woken across all commits. After the Tier-1c coalesced + /// wakeup this is the count of waiters each `publish_durable` ACTUALLY fires — + /// only those whose lsn the new watermark satisfies, not every parked + /// subscriber. `avg_wakeups = woken / fsync_count` should sit near ~1 (versus + /// the old `watch`-broadcast thundering herd, where it tracked the parked + /// subscriber count). + waiters_woken: AtomicU64, } impl Default for ShardStats { @@ -77,6 +152,12 @@ impl Default for ShardStats { last_batch: AtomicU64::new(0), max_batch: AtomicU64::new(0), buckets: Default::default(), + inner_lock_wait_nanos: AtomicU64::new(0), + inner_lock_acquires: AtomicU64::new(0), + dirty_lock_wait_nanos: AtomicU64::new(0), + dirty_lock_acquires: AtomicU64::new(0), + staged: AtomicU64::new(0), + waiters_woken: AtomicU64::new(0), } } } @@ -100,6 +181,30 @@ impl ShardStats { self.buckets[idx].fetch_add(1, Ordering::Relaxed); } + /// Record one append-path `inner` Mutex acquisition that waited `nanos`. + /// Called twice per append (reserve + mark_written) only when stats armed. + pub fn record_inner_lock_wait(&self, nanos: u64) { + self.inner_lock_wait_nanos.fetch_add(nanos, Ordering::Relaxed); + self.inner_lock_acquires.fetch_add(1, Ordering::Relaxed); + } + + /// Record one `dirty` Mutex acquisition that waited `nanos` (once per append). + pub fn record_dirty_lock_wait(&self, nanos: u64) { + self.dirty_lock_wait_nanos.fetch_add(nanos, Ordering::Relaxed); + self.dirty_lock_acquires.fetch_add(1, Ordering::Relaxed); + } + + /// Record one record staged into this shard (one per `reserve_and_stage`). + pub fn record_staged(&self) { + self.staged.fetch_add(1, Ordering::Relaxed); + } + + /// Record the durability waiters woken by one commit (the coalesced count of + /// oneshots `publish_durable` fired). Called once per successful commit. + pub fn record_waiters_woken(&self, n: u64) { + self.waiters_woken.fetch_add(n, Ordering::Relaxed); + } + /// The bucket index for a batch size (the first boundary it does not exceed, /// else the overflow slot). fn bucket_index(batch: u64) -> usize { @@ -126,6 +231,12 @@ impl ShardStats { last_batch: self.last_batch.load(Ordering::Relaxed), max_batch: self.max_batch.load(Ordering::Relaxed), buckets, + inner_lock_wait_nanos: self.inner_lock_wait_nanos.load(Ordering::Relaxed), + inner_lock_acquires: self.inner_lock_acquires.load(Ordering::Relaxed), + dirty_lock_wait_nanos: self.dirty_lock_wait_nanos.load(Ordering::Relaxed), + dirty_lock_acquires: self.dirty_lock_acquires.load(Ordering::Relaxed), + staged: self.staged.load(Ordering::Relaxed), + waiters_woken: self.waiters_woken.load(Ordering::Relaxed), } } } @@ -145,6 +256,12 @@ pub struct StatsSnapshot { pub last_batch: u64, pub max_batch: u64, pub buckets: [u64; BATCH_BUCKETS.len() + 1], + pub inner_lock_wait_nanos: u64, + pub inner_lock_acquires: u64, + pub dirty_lock_wait_nanos: u64, + pub dirty_lock_acquires: u64, + pub staged: u64, + pub waiters_woken: u64, } /// All derivations are telemetry/test-only (emitter + stats tests); targeted @@ -167,6 +284,36 @@ impl StatsSnapshot { self.max_batch } + /// Mean nanoseconds an append waited to acquire the shard `inner` Mutex. + /// `0` when no acquisition was timed. The headline per-shard write- + /// serialization signal — near-zero when uncontended, climbs under load. + pub fn avg_inner_wait_ns(&self) -> f64 { + if self.inner_lock_acquires == 0 { + 0.0 + } else { + self.inner_lock_wait_nanos as f64 / self.inner_lock_acquires as f64 + } + } + + /// Mean nanoseconds an append waited to acquire the per-append `dirty` Mutex. + pub fn avg_dirty_wait_ns(&self) -> f64 { + if self.dirty_lock_acquires == 0 { + 0.0 + } else { + self.dirty_lock_wait_nanos as f64 / self.dirty_lock_acquires as f64 + } + } + + /// Mean durability waiters woken per commit (`waiters_woken / fsync_count`). + /// The thundering-herd fan-out: how many parked appenders each commit wakes. + pub fn avg_waiters_woken(&self) -> f64 { + if self.fsync_count == 0 { + 0.0 + } else { + self.waiters_woken as f64 / self.fsync_count as f64 + } + } + /// The `q`-quantile (0.0..=1.0) batch size, read off the cumulative buckets. /// Returns the **upper boundary** of the bucket the quantile falls in (the /// conservative, OTel-explicit-bucket convention); the overflow bucket @@ -212,6 +359,12 @@ impl StatsSnapshot { for (a, b) in self.buckets.iter_mut().zip(other.buckets.iter()) { *a += *b; } + self.inner_lock_wait_nanos += other.inner_lock_wait_nanos; + self.inner_lock_acquires += other.inner_lock_acquires; + self.dirty_lock_wait_nanos += other.dirty_lock_wait_nanos; + self.dirty_lock_acquires += other.dirty_lock_acquires; + self.staged += other.staged; + self.waiters_woken += other.waiters_woken; } } @@ -314,6 +467,98 @@ mod emitter { #[cfg(feature = "telemetry")] pub use emitter::spawn_emitter; +// =========================================================================== +// Always-on contention emitter (`--wal-stats `, dependency-free). +// =========================================================================== +// +// Unlike the `telemetry`-feature `WAL_STATS` emitter above (which needs the OTLP +// dep tree only to be COMPILED, and prints batch gauges to stdout), this one is +// ALWAYS compiled and prints DELTA-based contention rates to stderr each tick. +// It is the measurement vehicle for the lock-contention investigation: no +// collector, no feature flag — just `--wal-stats 1` and read the `WAL_CONT` +// lines. Spawned from `main` only when `--wal-stats` is passed (which also arms +// `set_stats_enabled(true)` so the hot path actually times the acquisitions). + +mod stats_emitter { + use std::sync::Arc; + use std::time::Duration; + + use super::StatsSnapshot; + use crate::wal::walset::WalSet; + + /// Spawn the contention emitter, printing aggregate `WAL_CONT` lines every + /// `interval`. Deltas are taken against the previous tick so the numbers + /// reflect the live window, not a warmup-diluted cumulative average. + pub fn spawn_stats_emitter(walset: Arc, interval: Duration) { + tokio::spawn(async move { + let mut ticker = tokio::time::interval(interval); + ticker.set_missed_tick_behavior(tokio::time::MissedTickBehavior::Skip); + ticker.tick().await; // skip the immediate boot tick + + // Per-shard previous snapshots for delta computation. + let n = walset.shards().len(); + let mut prev: Vec = vec![StatsSnapshot::default(); n]; + + loop { + ticker.tick().await; + let dt = interval.as_secs_f64(); + let mut cur_agg = StatsSnapshot::default(); + let mut prev_agg = StatsSnapshot::default(); + for (i, shard) in walset.shards().iter().enumerate() { + let cur = shard.stats_snapshot(); + cur_agg.merge(&cur); + prev_agg.merge(&prev[i]); + prev[i] = cur; + } + print_delta(&cur_agg, &prev_agg, dt); + } + }); + } + + /// Print one aggregate `WAL_CONT` line from the (cur − prev) delta over `dt` + /// seconds. All `avg_*` fields are computed on the DELTA counts so they show + /// the contention *in this window*. + fn print_delta(cur: &StatsSnapshot, prev: &StatsSnapshot, dt: f64) { + let d_staged = cur.staged.saturating_sub(prev.staged); + let d_fsync = cur.fsync_count.saturating_sub(prev.fsync_count); + let d_records = cur.records_committed.saturating_sub(prev.records_committed); + let d_inner_ns = cur + .inner_lock_wait_nanos + .saturating_sub(prev.inner_lock_wait_nanos); + let d_inner_acq = cur + .inner_lock_acquires + .saturating_sub(prev.inner_lock_acquires); + let d_dirty_ns = cur + .dirty_lock_wait_nanos + .saturating_sub(prev.dirty_lock_wait_nanos); + let d_dirty_acq = cur + .dirty_lock_acquires + .saturating_sub(prev.dirty_lock_acquires); + let d_woken = cur.waiters_woken.saturating_sub(prev.waiters_woken); + + let staged_per_s = d_staged as f64 / dt; + let fsync_per_s = d_fsync as f64 / dt; + let batch_avg = if d_fsync == 0 { 0.0 } else { d_records as f64 / d_fsync as f64 }; + let inner_wait_us = if d_inner_acq == 0 { 0.0 } else { d_inner_ns as f64 / d_inner_acq as f64 / 1000.0 }; + let dirty_wait_us = if d_dirty_acq == 0 { 0.0 } else { d_dirty_ns as f64 / d_dirty_acq as f64 / 1000.0 }; + let woken_avg = if d_fsync == 0 { 0.0 } else { d_woken as f64 / d_fsync as f64 }; + // Lock-wait *load*: fraction of one core-second spent purely WAITING on + // each lock in this window (Σ wait nanos / window nanos). >1.0 means more + // than a whole core's worth of time was lost parking on that lock. + let inner_wait_load = d_inner_ns as f64 / (dt * 1e9); + let dirty_wait_load = d_dirty_ns as f64 / (dt * 1e9); + + eprintln!( + "WAL_CONT staged/s={staged_per_s:.0} fsync/s={fsync_per_s:.0} batch_avg={batch_avg:.1} \ + inner_wait_us={inner_wait_us:.2} inner_wait_load={inner_wait_load:.2} \ + dirty_wait_us={dirty_wait_us:.2} dirty_wait_load={dirty_wait_load:.2} \ + waiters_woken_avg={woken_avg:.1}" + ); + } +} + +pub use stats_emitter::spawn_stats_emitter; + /// No-op `spawn_emitter` (feature off): spawns nothing, prints nothing. A default /// build pays only the per-commit atomics in `record_batch`. #[cfg(not(feature = "telemetry"))] @@ -354,6 +599,54 @@ mod tests { assert_eq!(snap.quantile(1.0), 200, "top quantile reaches the overflow max"); } + #[test] + fn contention_counters_average_and_merge() { + let a = ShardStats::default(); + // Two inner acquisitions waiting 100ns and 300ns → avg 200ns. + a.record_inner_lock_wait(100); + a.record_inner_lock_wait(300); + // One dirty acquisition waiting 50ns. + a.record_dirty_lock_wait(50); + a.record_staged(); + a.record_staged(); + // One commit woke 8 waiters. + a.record_batch(2); + a.record_waiters_woken(8); + let sa = a.snapshot(); + assert_eq!(sa.inner_lock_acquires, 2); + assert_eq!(sa.avg_inner_wait_ns(), 200.0); + assert_eq!(sa.avg_dirty_wait_ns(), 50.0); + assert_eq!(sa.staged, 2); + assert_eq!(sa.avg_waiters_woken(), 8.0, "8 woken / 1 commit"); + + // Merge a second shard and confirm the contention fields fold in. + let b = ShardStats::default(); + b.record_inner_lock_wait(200); + b.record_dirty_lock_wait(150); + b.record_staged(); + b.record_batch(4); + b.record_waiters_woken(4); + let mut agg = sa.clone(); + agg.merge(&b.snapshot()); + assert_eq!(agg.inner_lock_acquires, 3); + assert_eq!(agg.inner_lock_wait_nanos, 600); + assert_eq!(agg.avg_inner_wait_ns(), 200.0, "600ns / 3 acquires"); + assert_eq!(agg.dirty_lock_wait_nanos, 200); + assert_eq!(agg.staged, 3); + assert_eq!(agg.waiters_woken, 12); + assert_eq!(agg.avg_waiters_woken(), 6.0, "12 woken / 2 commits"); + } + + #[test] + fn stats_gate_defaults_off_and_toggles() { + // The gate defaults off so default runs read no clock; toggling it is what + // `--wal-stats` does. (Process-global, so just prove the toggle works.) + super::set_stats_enabled(true); + assert!(super::stats_enabled()); + super::set_stats_enabled(false); + assert!(!super::stats_enabled()); + } + #[test] fn merge_aggregates() { let a = ShardStats::default(); diff --git a/packages/durable-streams-rust/src/wal/walset.rs b/packages/durable-streams-rust/src/wal/walset.rs index 669dade2f8..b8fe5609ea 100644 --- a/packages/durable-streams-rust/src/wal/walset.rs +++ b/packages/durable-streams-rust/src/wal/walset.rs @@ -21,9 +21,9 @@ use std::io; use std::path::Path; -use std::sync::Arc; +use std::sync::{Arc, Mutex}; -use super::shard::Shard; +use super::shard::{CommitterHandle, Shard}; /// The persisted-`N` file under the data dir: `/wal/shards`. const SHARDS_FILE: &str = "shards"; @@ -46,6 +46,12 @@ fn fnv1a(x: u64) -> u64 { pub struct WalSet { shards: Vec>, n: usize, + /// Handles to the per-shard dedicated committer OS threads (Tier-2a). Spawned + /// by [`WalSet::spawn_committers`], joined by [`WalSet::stop_committers`] on + /// the process shutdown path so in-flight commits complete and the threads are + /// reaped rather than detached. Behind a `Mutex` for interior mutability (the + /// `WalSet` is shared behind an `Arc`). + committers: Mutex>, } impl WalSet { @@ -113,7 +119,11 @@ impl WalSet { segment_size, )?); } - Ok(Arc::new(WalSet { shards, n })) + Ok(Arc::new(WalSet { + shards, + n, + committers: Mutex::new(Vec::new()), + })) } /// The shard a `stream_id` routes to — computed **only** from the persisted @@ -143,11 +153,32 @@ impl WalSet { Ok(()) } - /// Spawn each shard's committer (the tokio-task `run_committer`). + /// Spawn each shard's committer on its own **dedicated OS thread** (Tier-2a), + /// off the shared async runtime. The [`CommitterHandle`]s are retained so + /// [`WalSet::stop_committers`] can drain + join them on shutdown. pub fn spawn_committers(self: &Arc) { + let mut handles = self.committers.lock().unwrap(); for shard in &self.shards { - let shard = Arc::clone(shard); - tokio::spawn(shard.run_committer()); + handles.push(shard.spawn_committer()); + } + } + + /// Stop every committer thread: signal all of them first (so they shut down + /// concurrently), then join all. Each thread performs a **final drain** so any + /// already-contiguous-written records still become durable before it exits — + /// keeping the no-loss invariant across a graceful shutdown. Idempotent (a + /// second call finds the handle list empty). Called from the process shutdown + /// path (`main.rs`, after `engine_raw::drain`). + pub fn stop_committers(&self) { + let handles: Vec = + std::mem::take(&mut *self.committers.lock().unwrap()); + // Signal all, then join all, so a slow shard's final drain overlaps the + // others rather than serializing shutdown. + for h in &handles { + h.signal_stop(); + } + for h in handles { + h.join(); } } }