`memtrace start` aborts with a 192 GiB allocation failure: record-index snapshot stores a WAL offset that is not a frame boundary

[MartinJepsen]

Summary

memtrace start dies during startup with:

memory allocation of 206158430160 bytes failed

The WAL is not corrupt. The bad value is the WAL resume offset persisted in record_index.snapshot: it points 51 bytes into a record rather than at a frame boundary. WAL tail replay therefore starts mid-record, reads payload bytes as a frame length, and hands an unvalidated u32::MAX straight to a capacity-reserving allocation:

4294967295 (0xFFFFFFFF) × 48 bytes = 206158430160   ← exactly the failed allocation

Because this is an allocation-failure abort rather than a handled error, the store is permanently unstartable until a user manually deletes the snapshot — with no message saying so. Deleting record_index.snapshot fully recovers the store (details below); no data is lost, since the snapshot is derived state.

Notably, the sibling property_idx recovery path in the same startup already handles its own corrupt snapshot gracefully (falling back to iter_live rebuild, then self-heals). The record-index path aborts the process instead. That asymmetry is the bug.

Environment

memtrace	1.1.6-nightly.20260823.977d333 (global npm install)
MemDB / memcore-server	0.1.1, engine real, bind 127.0.0.1:50051
Node	v22.23.2
OS	Ubuntu 24.04.4 LTS on WSL2, kernel 6.6.114.1-microsoft-standard-WSL2, x86_64
Host	14 cores, 27 GB RAM (so 192 GiB is unsatisfiable by any margin)
MemDB mode	local, store at <repo>/.memdb/memtrace

Observed failure

<repo>/.memdb/memcore-server.log:

{"level":"INFO","fields":{"message":"MemDB starting","version":"0.1.1","bind":"127.0.0.1:50051","engine":"real"},"target":"memcore_server"}
{"level":"INFO","fields":{"message":"record-index snapshot is stale; replaying WAL tail","snapshot":799367,"observed":6967049},"target":"memcore_grpc::real_engine::wal"}
{"level":"INFO","fields":{"message":"record-index snapshot recovered; replaying WAL tail","entries":379578,"tail_from":799367,"observed":6967049,"tail_bytes":6167682},"target":"memcore_grpc::real_engine::wal"}
memory allocation of 206158430160 bytes failed

The process aborts. Every subsequent memtrace start repeats it — the state is on disk, so it is deterministic, not a transient.

Root cause

1. The WAL segment is intact

I parsed <repo>/.memdb/memtrace/wal/000014.wal (6,967,049 bytes) end to end. Each record ends with a 12-byte trailer: len: u32 LE, magic 0xDEADBEEF, magic 0x8271A2CF; a record spans [trailer_end - len, trailer_end).

records found:            7784
trailers valid:           7784   (both magics present, plausible len)
non-contiguous records:   0      (every record starts where the previous ended)
last record ends at:      6967049 == file length

So the segment is fully self-consistent, correctly terminated, with no torn tail. observed: 6967049 in the log matches the file length exactly.

2. The persisted resume offset is not a frame boundary

record_index.snapshot header:

00000000: 5844 4952 0100 0000 8732 0c00 0000 0000  XDIR............
00000010: baca 0500 0000 0000 ...                  ................

• XDIR, version 1
• bytes 8..16 = 0x000c3287 = 799367 — the WAL offset in the log's "snapshot":799367 / "tail_from":799367
• bytes 16..24 = 0x0005caba = 379578 — the log's "entries":379578

But 799367 is not a record boundary. The real boundaries around it are 798783, 799316, 799849, 800382. Offset 799367 falls 51 bytes inside the record spanning [799316, 799849) (len 533).

3. Mid-record replay reads a sentinel as a length

Every record payload contains an i64::MAX sentinel — the byte pattern ff ff ff ff ff ff ff 7f (7758 occurrences, ~one per record; presumably an "open interval" / no-tombstone valid-to field).

Starting replay at 799367 lands the parser out of phase, and the first sentinel at or after that offset is at 799412, just 45 bytes in. Reading a u32 LE there yields 0xFFFFFFFF:

u32 at 799412        = 0xFFFFFFFF = 4294967295
4294967295 × 48      = 206158430160 bytes = 191.99999995 GiB
failed allocation    = 206158430160 bytes          ← exact match

The count is exactly u32::MAX and the element stride is exactly 48 bytes. That exact match is the proof: a bogus 32-bit count decoded from misaligned payload bytes is passed to something like Vec::with_capacity(n) / reserve(n) for a 48-byte element type, with no bound check.

Two checks that would each have caught it before allocating:

• The decoded size (206 GB) vastly exceeds tail_bytes: 6167682 — already logged one line earlier, so the bound was in hand.
• No 0xDEADBEEF / 0x8271A2CF magic was verified at the implied frame position before trusting the length.

4. Why the offset was wrong in the first place

This part I could not determine from disk state alone, and it is the part worth instrumenting. Candidates, in the order I'd rank them:

1. The checkpoint records a byte position that isn't clamped to a completed frame — e.g. bytes-consumed by a partially-decoded record, or a position captured before the trailer was appended. 799367 is 51 bytes past the boundary 799316, so it looks like a position captured part-way through encoding/decoding one record rather than a wild pointer.
2. Cross-segment offset reuse. The snapshot's mtime was ~2.5 h older than the segment's (09:28 vs 12:03), and after recovery the engine logged record-index checkpoint compacted closed WAL segments {"removed":1} and rolled to 000015.wal. If an offset from a previous segment generation is applied to the current segment without a generation/segment-id guard, it is meaningless as a byte position — and nothing in the header appears to identify which segment the offset belongs to.
3. A truncation/rollover elsewhere that shifted the segment without invalidating the snapshot.

The header has room to make hypothesis 2 detectable and currently does not: there is no segment id, no LSN-to-offset cross-check, and no checksum of the record expected at that offset.

Suggested fixes

Immediate (stops the abort — small, local, no format change):

1. Never reserve capacity from an unvalidated decoded count. Bound the decoded length against the bytes actually remaining in the segment (tail_bytes, already computed) and against a MAX_RECORD_BYTES constant, and reject before allocating. Prefer try_reserve over with_capacity/reserve on any path fed by on-disk data so an implausible value becomes a Result, not an abort.
2. Verify the frame magics before trusting len. The format has two magic constants for exactly this purpose; checking 0xDEADBEEF + 0x8271A2CF at the implied trailer position makes a misaligned read a detectable error instead of a 192 GiB allocation.

Validate the resume offset (fixes the actual trigger):

3. Bounds- and boundary-check the persisted offset before replaying from it. Reject offset > segment_len; then confirm the offset is a real frame boundary (the format supports this cheaply — the trailer immediately preceding it must carry both magics and a len that walks back to another boundary). If it fails, log a WARN and fall back to full replay from 0.
4. Fail soft, like property_idx already does. In the same startup, the property-index path logged property idx snapshot fast-path unavailable: falling back to iter_live rebuild (skipped 1 corrupt record(s) between offsets 275644416 and 280623844), rebuilt, and self-healed a fresh snapshot. Give the record index the same policy: a bad snapshot should cost a slow start, never an unstartable store. Full replay of this WAL from 0 took 4.7 s to MemDB ready.
5. Make the snapshot self-validating. Store the WAL segment id (and ideally its generation/inode) alongside the offset, plus either the LSN of the record ending at that offset or a checksum of it. Refuse an offset whose segment identity doesn't match the segment being replayed — that alone kills hypothesis 2 as a failure mode.
6. Only ever persist a post-trailer position. Derive the checkpoint offset from the end of a fully committed frame, and assert in debug builds that it lands on a boundary before writing it (debug_assert!(is_frame_boundary(off))). Ordering the snapshot write after the segment fsync closes the window where an offset can outrun what's durable.

Diagnosability:

7. Turn the abort into an actionable error. A raw Rust OOM abort tells a user nothing. record-index snapshot at <path> stores WAL offset 799367, which is not a frame boundary in 000014.wal (nearest: 799316, 799849); discarding snapshot and replaying from 0 would have made this self-service, and the eventual manual fix (deleting the snapshot) is one that could just as well have been automatic.
8. Add a regression test — it's trivially constructible. Take any valid WAL segment, write a snapshot whose offset is boundary + k for small k, and start the engine: it must recover, not abort. A property test over k and a fuzz target on the frame decoder (arbitrary bytes, arbitrary start offset — assert "errors, never aborts or allocates unbounded") would cover the whole class.

Workaround for other users

The snapshot is derived state, so deleting it is safe and forces a clean full replay from offset 0:

# with the server stopped
mv <repo>/.memdb/memtrace/wal/record_index.snapshot /tmp/record_index.snapshot.bak
memtrace start

Result on my store: MemDB ready in 4702 ms, property_idx self-healed in the same pass, the closed segment was compacted away, and the rebuilt snapshot came back as 386 KB (vs the stale 18 MB one). No data loss observed.

[blocksorg]

Mention Blocks like a regular teammate with your question or request:

@blocks can you add technical details to this issue?
@blocks make the following changes ...
@blocks create an issue from what was mentioned in the following comment ...
@blocks explain the following code ...
@blocks are there any security or performance concerns?

Run @blocks /help for more information.

Workspace settings | Disable this message