Skip to content

Fix dual meaning of return value of '0' from raft_msg_entry_response_committed#130

Open
kkennett wants to merge 1 commit into
willemt:masterfrom
kkennett:kkennett-fix
Open

Fix dual meaning of return value of '0' from raft_msg_entry_response_committed#130
kkennett wants to merge 1 commit into
willemt:masterfrom
kkennett:kkennett-fix

Conversation

@kkennett

@kkennett kkennett commented May 9, 2026

Copy link
Copy Markdown
==== Bug fix summary ====

raft_msg_entry_response_committed returned 0 (not yet committed)
when the entry's index was no longer in the log because it had
been compacted into a snapshot. Callers waiting on commit
confirmation could therefore wait indefinitely for entries that
were already committed.

Treat r->idx <= snapshot_last_idx as committed, and use
snapshot_last_term to detect entries invalidated by another
leader before compaction (return -1 in that case).

==== Detail ====

Symptom
-------

A caller that submits an entry via raft_recv_entry() and polls
raft_msg_entry_response_committed() to wait for the commit can see
the function return 0 indefinitely after the entry has been
committed, replicated to the entire cluster, and rolled into a
leader-side snapshot. Callers using a deadline ultimately time out
and treat the operation as failed, even though the entry is durably
committed.

Root cause
----------

raft_msg_entry_response_committed() answers "is entry r->idx
committed at term r->term?" by first looking up the entry in the
in-memory log via raft_get_entry_from_idx(). If the lookup misses
(ety == NULL), the function returns 0 (the protocol's "not yet"
sentinel).

After raft_end_snapshot() runs, the implementation calls
me->log_impl->poll(me->log, me->snapshot_last_idx + 1) and removes
all log entries <= snapshot_last_idx from the log. From that point
on, raft_get_entry_from_idx(snapshot_last_idx) returns NULL for
the compacted indices — by design.

But "absent from the in-memory log" is not the same as "not
committed". Per the Raft safety properties, any entry covered by the
snapshot is by definition committed and applied (the snapshot is
taken at last_applied_idx, which can never exceed commit_idx),
and a leader's snapshot will never roll back below the cluster's
committed history. So the function's early-out conflates two
distinct states: "I don't have this entry" and "this entry is gone
because it was committed and compacted". Only the second is what
callers ought to be told about, and the answer should be "yes,
committed".

Trigger conditions
------------------

This bug is latent as long as the wait loop's polling cadence is
fast relative to the time between (a) the entry reaching majority
replication and (b) the leader's next snapshot trigger that subsumes
that entry.

*** In a tight in-process test bench (sub-millisecond network), the
caller almost always observes the brief window where
commit_idx >= r->idx AND the entry is still in the log, and the
function returns 1.

The bug becomes deterministic when:

1. The snapshot threshold (here KV_SNAPSHOT_THRESHOLD = 32 
committed-but-uncompacted entries) is reached **on the same 
periodic tick** that just advanced commit_idx to cover the awaited 
entry, 

AND

2. The poll loop's cadence is slow enough that the snapshot completes 
between two consecutive polls of raft_msg_entry_response_committed().

Storm Agents Inc. hit this consistently on a 3-VM VirtualBox test
bench. Cluster bootstrap consumes ~7 log slots (ADD_NONVOTING +
ADD_VOTING config-change entries for each peer); 25 application writes
after that takes the leader's snapshottable count past 32. The 26th
write both crosses the threshold and reaches majority replication on
the same tick, so the snapshot fires immediately and removes the awaited
entry from the log before the caller's next poll. The caller then
spins for the full timeout (5 s configured in our case) seeing
commit_idx == r->idx but raft_msg_entry_response_committed()
returning 0 because raft_get_entry_from_idx(r->idx) is NULL.

Backward compatibility
----------------------

The change is actually a strengthening of the success cases: callers
that previously timed out on snapshotted-but-committed entries will
now correctly observe "committed". No caller can be hurt by being
told "yes, committed" for an entry that is in fact committed, and
the term-mismatch leg at the snapshot boundary preserves the
existing -1 return for the "overwritten by another leader" case.

Kurt Kennett
Storm Agents Inc.
kurt@stormagents.com

    raft_msg_entry_response_committed returned 0 (not yet committed)
    when the entry's index was no longer in the log because it had
    been compacted into a snapshot. Callers waiting on commit
    confirmation could therefore wait indefinitely for entries that
    were already committed.

    Treat r->idx <= snapshot_last_idx as committed, and use
    snapshot_last_term to detect entries invalidated by another
    leader before compaction (return -1 in that case).

    ==== Detail ====

    Symptom
    -------

    A caller that submits an entry via raft_recv_entry() and polls
    raft_msg_entry_response_committed() to wait for the commit can see
    the function return 0 indefinitely after the entry has been
    committed, replicated to the entire cluster, and rolled into a
    leader-side snapshot. Callers using a deadline ultimately time out
    and treat the operation as failed, even though the entry is durably
    committed.

    Root cause
    ----------

    raft_msg_entry_response_committed() answers "is entry r->idx
    committed at term r->term?" by first looking up the entry in the
    in-memory log via raft_get_entry_from_idx(). If the lookup misses
    (ety == NULL), the function returns 0 (the protocol's "not yet"
    sentinel).

    After raft_end_snapshot() runs, the implementation calls
    me->log_impl->poll(me->log, me->snapshot_last_idx + 1) and removes
    all log entries <= snapshot_last_idx from the log. From that point
    on, raft_get_entry_from_idx(snapshot_last_idx) returns NULL for
    the compacted indices — by design.

    But "absent from the in-memory log" is not the same as "not
    committed". Per the Raft safety properties, any entry covered by the
    snapshot is by definition committed and applied (the snapshot is
    taken at last_applied_idx, which can never exceed commit_idx),
    and a leader's snapshot will never roll back below the cluster's
    committed history. So the function's early-out conflates two
    distinct states: "I don't have this entry" and "this entry is gone
    because it was committed and compacted". Only the second is what
    callers ought to be told about, and the answer should be "yes,
    committed".

    Trigger conditions
    ------------------

    This bug is latent as long as the wait loop's polling cadence is
    fast relative to the time between (a) the entry reaching majority
    replication and (b) the leader's next snapshot trigger that subsumes
    that entry.

    *** In a tight in-process test bench (sub-millisecond network), the
    caller almost always observes the brief window where
    commit_idx >= r->idx AND the entry is still in the log, and the
    function returns 1.

    The bug becomes deterministic when:

    1. The snapshot threshold (here KV_SNAPSHOT_THRESHOLD = 32
       committed-but-uncompacted entries) is reached **on the same
       periodic tick** that just advanced commit_idx to cover the
       awaited entry, AND
    2. The poll loop's cadence is slow enough that the snapshot
       completes between two consecutive polls of
       raft_msg_entry_response_committed().

    Storm Agents Inc. hit this consistently on a 3-VM VirtualBox test
    bench. Cluster bootstrap consumes ~7 log slots (ADD_NONVOTING +
    ADD_VOTING config-change entries for each peer); 25 application writes
    after that takes the leader's snapshottable count past 32. The 26th
    write both crosses the threshold and reaches majority replication on
    the same tick, so the snapshot fires immediately and removes the awaited
    entry from the log before the caller's next poll. The caller then
    spins for the full timeout (5 s configured in our case) seeing
    commit_idx == r->idx but raft_msg_entry_response_committed()
    returning 0 because raft_get_entry_from_idx(r->idx) is NULL.

    Backward compatibility
    ----------------------

    The change is actually a strengthening of the success cases: callers
    that previously timed out on snapshotted-but-committed entries will
    now correctly observe "committed". No caller can be hurt by being
    told "yes, committed" for an entry that is in fact committed, and
    the term-mismatch leg at the snapshot boundary preserves the
    existing -1 return for the "overwritten by another leader" case.

    Kurt Kennett
    Storm Agents Inc.
    kurt@stormagents.com
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