Skip to content

fix(wal): read the log and replay refs through the caller's manifest - #107

Open
cyharyanto wants to merge 1 commit into
tobi:mainfrom
introspection-org:wt-events-fold
Open

cyharyanto wants to merge 1 commit into
tobi:mainfrom
introspection-org:wt-events-fold

Conversation

@cyharyanto

@cyharyanto cyharyanto commented Oct 19, 2026 •

Copy link
Copy Markdown

Summary

  • The events bridge can drop a push without a trace. When a checkpoint lands while the bridge is catching up, the bridge emits nothing for the entries it folded and still advances its cursor, so no webhook ever fires for that push and no gap is counted. This breaks docs/EVENTS.md's "No lost events".
  • The cause is a check-then-use race over the manifest. catch_up takes head_seq and min_seq from one manifest, then RepoHandle::read_log resolved a fresher one on its own and read segments through it. A checkpoint in between trims those segments from the fresher manifest, so the read returns nothing.
  • The fix removes the second resolve from every log and ref-replay read. read_log, refs_at_seq, refs_as_of and the checkpoint-time helpers now take the caller's &Manifest; RepoHandle::fresh_manifest() is the explicit way to get the freshest one. A caller can no longer read through a different manifest than the one its bounds came from.

Problem

This is a TOCTOU race: Bridge::catch_up takes its bounds from one manifest, and read_log read the log through a newer one, which a checkpoint written in between has trimmed.

sequenceDiagram
    autonumber
    participant B as Bridge (catch_up)
    participant S as Store
    participant C as Another instance
    Note over S: manifest M1: head_seq 2, segment for seq 2
    B->>S: sync_refs: read M1
    Note over B: from = cursor 1, head = 2, no gap
    C->>S: write checkpoint folding seq 2
    Note over S: manifest M2: min_seq 3, segment for seq 2 trimmed
    rect rgba(220, 38, 38, 0.18)
        Note over B,S: Bug: read_log resolves the manifest again
        B->>S: read_log(2..=2): freshness_check
        S-->>B: M2, not the M1 the bounds came from
        Note over B: M2 lists no segment for seq 2, so 0 entries
    end
    B->>S: CAS cursor to 2
    Note over B,S: seq 2 never published, no gap counted
Loading

Nothing records the loss: published only fires when emitted > 0, and the gap warning only when the cursor is behind min_seq, which it is not. Every later wake-up, the sweep included, sees cursor == head.

An age-triggered checkpoint makes the window common on a quiet repository: a push that finds the last checkpoint older than checkpoint_interval is followed by a checkpoint almost at once. In one deployment, two of a repository's three pushes in a day were lost this way, each followed by an age checkpoint folding it 290 to 340 ms later; the one that got through came 17 minutes after a checkpoint.

The same pattern, bounds from one manifest and the read through another, was in:

  • refs_at_seq, which validated seq against one manifest() and replayed through another (replay_refs): a checkpoint in between turns its Corrupt into an empty ref snapshot;
  • refs_as_of, whose replay_refs judged the checkpoint by checkpoint_times(), which read its own manifest(): a newer checkpoint's time can reject the older one and silently drop refs;
  • pin_coverage_refs, which checked coverage on one manifest and fell back to refs_at_seq, which re-resolved;
  • apply_delta, which learned checkpoint times from the held manifest rather than the one it was about to adopt;
  • GET …/settings, the policy dry-run, walgit settings history and walgit wal rewind, which took min_seq or a cut from one manifest and read through read_log's.

Objective

Every read of the log or of replayed refs must go through the manifest its caller took its bounds from, so a checkpoint written in between can no longer make a read return less than the caller saw committed.

Changes

Change Before After Reason
RepoHandle::read_log Resolved the freshest manifest itself, then read through it Takes &Manifest and reads through it; read_log_impl is removed A checkpoint trims segments only from the manifest it writes, and leaves the segment objects, so the caller's manifest still reads every entry up to its head_seq
RepoHandle::fresh_manifest Inside read_log_impl Public: the held manifest, or the store's if newer (one conditional GET) Callers that want the freshest manifest take it explicitly, then read through it
refs_at_seq, refs_as_of, replay_refs Each called handle.manifest() Take &Manifest Validation and replay use one manifest
checkpoint_times, learn_checkpoint_times Read self.manifest() Take &Manifest; apply_delta passes the manifest it adopts The times judged are the checkpoint's being used
bridge.rs, settings.rs, web/ui.rs, settings_cmd.rs, wal_cmd.rs, snapshots.rs Called read_log/refs_at_seq with bounds from another manifest Pass the manifest the bounds came from; the overview reads the log through the manifest it renders Same reason
tests/events.rs No case for a concurrent checkpoint bridge_publishes_entries_a_concurrent_checkpoint_folds Regression test below
Test call sites read_log(1, None) read_log(&handle.manifest(), 1, None), or fresh_manifest() where another handle wrote New signature

Principles

  • IV, every read revalidates: unchanged. Each path still revalidates once, by sync_refs or fresh_manifest(), and now reads the log through that one snapshot rather than a second, later one.
  • VII, round trips: the bridge catch-up, the settings history and policy dry-run, the repository overview and walgit settings history each made two conditional manifest GETs (the sync, then read_log's own) and now make one; walgit wal ls and wal show still make one. No budget in docs/ROUNDTRIPS.md changes.

Testing

  • Regression test, deterministic. The bridge's instance runs with wal.freshness_ttl so it keeps the manifest it holds; it publishes seq 1, takes a push at seq 2, and a sibling instance on the same store writes a checkpoint folding seq 2 before catch_up. Before the fix catch_up reports (from 1, head 2, emitted 0, gap None); with it, seq 2 is published and the cursor reaches 2. It failed 10 of 10 runs against the old read_log and passed 20 of 20 with the fix; no sleeps or timing.
  • just warnings, just clippy and just sim (19 passed) are clean. just test: 429 passed; the 3 failures are api_v1::v1_surface_and_browser_lane, static_http::ui_assets_etag_304_and_precompressed and web_ui::assets_have_content_type_and_immutable_cache, which need web/dist from pnpm run build and fail the same way on main without it. cargo fmt --check is clean.
  • refs_at_seq, refs_as_of and apply_delta have no added test: their two reads happened inside one call, so a test cannot interleave them; with one manifest passed in, the window no longer exists.

Not in this PR

  • A gap counted before the bridge reads (a checkpoint folds entries before catch_up starts) is still counted and warned rather than published. walgit wal rewind already reads folded segments directly as log/<seq>.pb, so the bridge could backfill the same way.
  • The same check-then-use shape outside log and ref replay, which needs its own repro: the remote pack reader (sync_objects, and remote_reader's AlreadyRunning path returning a reader without checking its revision), and compact_repo planning from a config read separately from the manifest it compacts.

catch_up took head_seq from one manifest while read_log resolved a fresher
one; a checkpoint in between trims that one's segments, so the bridge
emitted nothing and advanced its cursor past the push. read_log,
refs_at_seq, refs_as_of and the checkpoint-time helpers now take the
caller's manifest, and fresh_manifest() is the explicit way to get the
newest one.

Round trips: the bridge catch-up, the settings history and policy dry-run,
the repository overview and `walgit settings history` each made two
conditional manifest GETs (the sync, then read_log's own) and now make one;
`walgit wal ls` and `wal show` still make one. No budget in
docs/ROUNDTRIPS.md changes.
@cyharyanto

Copy link
Copy Markdown
Author

I've just done a check across upstream, its open PRs and issues, and the 23 forks pushed since main's last commit (80e9a20), to see whether anything already fixes this. Nothing does:

This follows bf65c01, which added read_log_manifest and D43's "producers capture manifest … coherently"; this PR applies the same rule to readers.

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant