Skip to content

Snapshot install compacts the Raft log before the store data it covers is durable #8425

Description

@miotte

Observed behavior

Installing a stream snapshot compacts the Raft log that has been covering the
applied data. monitorStream flushes the store first for exactly that reason,
and treats a failure as fatal:

// Make sure all pending data is flushed before allowing snapshots.
if err := mset.flushAllPending(); err != nil {

That flush is fileStore.FlushAllPendingcheckAndFlushLastBlock
flushPendingMsgsLocked, and that only syncs when the block is in sync always
mode:

if mb.syncAlways {
    if err = mb.mfd.Sync(); err != nil {
...
} else {
    mb.needSync = true
}

So with a sync_interval configured — the default — the flush is a write(2).
The log entries covering the applied data are compacted away while that data is
still only in the page cache, and it stays that way until the next periodic
sync. Compaction is driven by log volume (65,536 entries or 8MB since the last
snapshot) rather than by the sync interval, so under load this window opens
seconds after the write rather than minutes.

Two more callers install a snapshot with no flush at all, so they can compact
while the data has not even left the pending buffer:

  • JetStreamSnapshotStream (jetstream_cluster.go)
  • the "Try our best to redo our invalidated snapshot as well" path in runCatchup

Those two do not require power loss to lose data. With async flush the pending
writes are still process memory, while the Raft entries covering them have
already been written out (the WAL filestore is created with AsyncFlush: false),
so a plain process crash after one of those snapshot installs loses data the log
would otherwise have replayed.

Reproduced with a three-node cluster and an R3 file-backed stream in the default
sync mode: publish, wait for the async flush loop to write the block out, then
trigger the upper-layer snapshot. The Raft log goes from first=1 last=11 to
first=12 — every entry covering those messages discarded — while needSync is
still set on the block that holds them, meaning it was never fsynced.

Expected behavior

When the log is compacted, whatever it covered should already be on stable
storage.

To be clear about the scope: this is not a request to change the default sync
policy. The Raft WAL follows the same sync interval, so fixing this alone does
not make deferred-sync mode crash safe, and it is not an argument about what the
default should be. It is that the recovery source should not be discarded ahead
of the data it covers.

Server and client version

Reproduced on main at d998ae741. The same code path is present in the latest
release, v2.14.3: FlushAllPending there is also just checkAndFlushLastBlock
(filestore.go:5357), with the same if mb.syncAlways gate in
flushPendingMsgsLocked (filestore.go:8316).

No client involved — reproduced with an in-tree test.

Host environment

Linux, arm64, container. Not environment-specific; it is a code path rather than
anything about the filesystem or platform.

Steps to reproduce

  1. Start a three-node cluster and create an R3 file-backed stream, leaving the
    sync configuration at its default.
  2. Publish some messages and wait for replication.
  3. Wait for the async flush loop to write the block out. needSync is set on the
    block at that point, and is only cleared by an actual sync.
  4. Trigger the upper-layer snapshot.
  5. Observe that the Raft log has been compacted past the entries carrying those
    messages while the block still has needSync set.

TestJetStreamClusterSnapshotSyncsStoreBeforeCompact in the linked PR does this
deterministically and fails on an unpatched tree with:

Log compacted to first index 12, but block 1 was never synced

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions