hashicorp / hashicorp/raft

Livelock with InstallSnapshot when logs are out-of-sync

Open
#697 2 comments 0 reactions 0 assignees View on GitHub
Dominant language
Go
Stars
9.1k
Forks
1.1k
Avg merge
3h 27m
Merged PRs (30d)
2

Description

Hello,

When testing this library with [Antithesis](https://antithesis.com/), we encountered a bug where a follower node can get stuck in an infinite loop of attempting to receive snapshots from a leader and rejecting subsequent AppendEntries.

Version tested: 4c8f61ac9255bb95fb3b8319dfcf0ae53ab325b6

## Impact

**Liveness** - A healthy follower node is unable to replicate logs and is effectively not able to participate in the consensus protocol.
**Resource Exhaustion** - The follower's logs grow quadratically leading to a memory / disk blowup.

## Root Cause

The handling of InstallSnapshot RPC does not handle Rule 7 from Figure 13 in the Raft paper:
> [if the existing entry at `lastIncludedIndex` conflicts,] discard the entire log

## Triggers

When a follower has uncommitted logs that diverge from the leader at some index say K, and it receives an InstallSnapshot RPC from the leader until index K, then it retains the stale (i.e., out-of-sync) logs until K while updating the FSM to a committed state at an index K. Then, when the next AppendEntries RPC arrives with `lastLogIndex=K`, the follower looks up its (stale) logs which have a different term at index K, rejects the AppendEntries, and gets another InstallSnapshot. This results in an infinite loop of InstallSnapshot RPCs that sometimes lead to OOM with log volume, other times lead to too many files being opened (due to the temporary snapshot files), and other times just lead to the node being stalled and unable to replicate.

## Reproducing

The bug is hard to reproduce exactly without Antithesis, but the general approach we followed in our test environment was as follows:
- **State machine**: Simple chain-of-blocks (the FSM maintains a running hash of all input commands received)
- **Cluster**: 3 nodes, no membership changes
- **Client**: Random workload of Apply commands intermixed with occasional Leadership Transfer commands.
- **Fault Injection**: Network partitions, node restarts
- **Test oracles**: Check for Raft safety invariants from the paper at all times + check liveness of commit progress / FSM convergence when fault injection is turned off.

### Sample Logs from a 3-node test

Most logs are from `raft`, whereas the last line below is from an [Antithesis `eventually` test command](https://antithesis.com/docs/product/test_templates/test_composer_reference/#eventually-command) that checks for the cluster's ability to converge all nodes to the same FSM state when fault injection is turned off and the network fully recovers.

```
2026-07-07T17:17:13.073Z [INFO] node-0: snapshot network transfer progress: read-bytes=0 percent-complete="0.00%"
2026-07-07T17:17:15.954Z [ERROR] node-1: failed to appendEntries to: peer="{Voter node-0 raft-node-0:8300}" error="msgpack decode error [pos 29848]: read tcp 10.89.0.7:48504->10.89.0.4:8300: i/o timeout"
2026-07-07T17:17:23.073Z [INFO] node-0: snapshot network transfer progress: read-bytes=0 percent-complete="0.00%"
2026-07-07T17:17:26.038Z [ERROR] node-1: failed to appendEntries to: peer="{Voter node-0 raft-node-0:8300}" error="msgpack decode error [pos 29848]: read tcp 10.89.0.7:35706->10.89.0.4:8300: i/o timeout"
2026-07-07T17:17:33.073Z [INFO] node-0: snapshot network transfer progress: read-bytes=0 percent-complete="0.00%"
2026-07-07T17:17:36.135Z [ERROR] node-1: failed to appendEntries to: peer="{Voter node-0 raft-node-0:8300}" error="msgpack decode error [pos 30394]: read tcp 10.89.0.7:37032->10.89.0.4:8300: i/o timeout"
2026-07-07T17:17:43.072Z [INFO] node-0: snapshot network transfer progress: read-bytes=0 percent-complete="0.00%"
2026-07-07T17:17:46.249Z [ERROR] node-1: failed to appendEntries to: peer="{Voter node-0 raft-node-0:8300}" error="msgpack decode error [pos 29575]: read tcp 10.89.0.7:54324->10.89.0.4:8300: i/o timeout"
2026-07-07T17:17:53.073Z [INFO] node-0: snapshot network transfer progress: read-bytes=0 percent-complete="0.00%"
2026-07-07T17:17:56.381Z [ERROR] node-1: failed to appendEntries to: peer="{Voter node-0 raft-node-0:8300}" error="msgpack decode error [pos 30303]: read tcp 10.89.0.7:57842->10.89.0.4:8300: i/o timeout"
2026-07-07T17:18:03.072Z [INFO] node-0: snapshot network transfer progress: read-bytes=0 percent-complete="0.00%"
2026-07-07T17:18:06.626Z [ERROR] node-1: failed to appendEntries to: peer="{Voter node-0 raft-node-0:8300}" error="msgpack decode error [pos 31122]: read tcp 10.89.0.7:46978->10.89.0.4:8300: i/o timeout"
2026-07-07T17:18:13.073Z [INFO] node-0: snapshot network transfer progress: read-bytes=0 percent-complete="0.00%"
2026-07-07T17:18:17.032Z [ERROR] node-1: failed to appendEntries to: peer="{Voter node-0 raft-node-0:8300}" error="msgpack decode error [pos 30758]: read tcp 10.89.0.7:54192->10.89.0.4:8300: i/o timeout"
2026-07-07T17:18:23.073Z [INFO] node-0: snapshot network transfer progress: read-bytes=0 percent-complete="0.00%"
2026-07-07T17:18:27.745Z [ERROR] node-1: failed to appendEntries to: peer="{Voter node-0 raft-node-0:8300}" error="msgpack decode error [pos 31850]: read tcp 10.89.0.7:36218->10.89.0.4:8300: i/o timeout"
2026-07-07T17:18:33.073Z [INFO] node-0: snapshot network transfer progress: read-bytes=0 percent-complete="0.00%"
2026-07-07T17:18:39.083Z [ERROR] node-1: failed to appendEntries to: peer="{Voter node-0 raft-node-0:8300}" error="msgpack decode error [pos 33943]: read tcp 10.89.0.7:53700->10.89.0.4:8300: i/o timeout"
2026-07-07T17:18:43.073Z [INFO] node-0: snapshot network transfer progress: read-bytes=0 percent-complete="0.00%"
2026-07-07T17:18:51.725Z [ERROR] node-1: failed to appendEntries to: peer="{Voter node-0 raft-node-0:8300}" error="msgpack decode error [pos 38402]: read tcp 10.89.0.7:52390->10.89.0.4:8300: i/o timeout"
2026-07-07T17:18:53.073Z [INFO] node-0: snapshot network transfer progress: read-bytes=0 percent-complete="0.00%"
2026-07-07T17:18:55.497Z [ERROR] eventually-fsm-convergence: convergence-check give-up; cluster healthy but did not converge: attempts_taken=24 per_node="map[raft-node-0:8400:map[applied_index:534 last_index:535 reachable:true state:Follower term:74 value:23641] raft-node-1:8400:map[applied_index:569 last_index:569 reachable:true state:Leader term:74 value:25232] raft-node-2:8400:map[applied_index:569 last_index:569 reachable:true state:Follower term:74 value:25232]]"
```

## Related Issues

This is different from the liveness issue I reported in #696 as it is not related to leadership transfers.

Contributor guide

Open the contributing guide

Research direction

Start by tracing the InstallSnapshot RPC and subsequent AppendEntries handling, using Rule 7 in the Raft paper as the behavioral reference. Reproduce the divergent-log scenario with partitions, restarts, and snapshot delivery, then verify that the follower converges with the leader without repeated snapshots, log growth, or stalled replication.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
distributed-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Active
Clarity
Mostly clear
Newbie friendliness
48/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.