etcd/raft 故障切換中位時間由 1.25 s 降至 343 ms，經 2,000 次模擬領導者崩潰測試
Cutting etcd/raft failover from 1.25 s to 343 ms, checked against 2,000 simulated leader crashes
Hamed Yousefi 使用 faultline 測試 etcd/raft，將 ElectionTick 設為 3 後，2,000 次模擬崩潰的故障切換中位時間為 343 ms，低於預設設定的 1.249 s。
When the leader of a three-node etcd/raft cluster dies, the other two servers wait between 1 and 1.9 seconds before one of them holds an election. That's with a tick every 100 ms and the settings from etcd/raft's README: ElectionTick 10 and HeartbeatTick 1. Until a new leader is in place, no write commits. I wanted that gap under a second.
Lowering ElectionTick is a one-line change. What I didn't know was what it does once servers crash and links drop. On a test cluster I could kill leaders and time the gap, but every attempt sees different timing. When one is slow, there's no way to run it again and see why.
So I tried it with faultline, the deterministic simulation testing tool for Go I've been building. Version 0.1.1 came out today. A faultline test runs a distributed system in virtual time on a simulated network and disk. Every random choice in the simulation comes from a seed, so a run replays exactly.
faultline includes a harness for etcd/raft v3.7.0. It runs a cluster of RawNodes with a write-ahead log on the simulated disk and clients that write and read keys, and checks raft's safety properties after every event. It tests the raft library with your settings. The key-value store, the log and the transport on top are the harness's own, not your service's.
Is a shorter timeout still safe?
I started with safety. The first test runs 500 seeds with elections after 3 ticks instead of 10. Each seed runs 60 seconds of virtual time under partitions, an isolated leader, cut and lossy links, crashes, pauses, failed disk syncs and clock drift. The last 10 seconds are quiet, and the cluster must make progress again.
func TestFastElectionsStaySafe(t *testing.T) {
cfg := etcdraft.DefaultConfig()
cfg.ElectionTick = 3 // elections after 3 to 5 ticks of 100 ms, instead of 10 to 19
etcdraft.Test(t, cfg, faultline.Options{Seeds: 500})
}
$ go test -run '^TestFastElectionsStaySafe$' .
ok example.com/failover 37.110s
No seed broke a safety check or left the cluster stuck. That makes the change safe in these runs. It says nothing yet about how fast failover got.
How long does failover take?
Then I timed it. The next test crashes whichever server leads at 5 seconds, with no other faults, and checks the time until another server becomes leader. etcdraft.Setup builds the cluster inside faultline.Run, and LeaderChanges lists every change of leadership in the run:
// failover crashes whichever server leads at 5s. check gets the time until the next leader and
// the number of elections it took.
func failover(t *testing.T, cfg etcdraft.Config, seeds int, check func(time.Duration, uint64) error) {
cfg.Faults = etcdraft.FaultsNone // no faults except the crash below
cfg.Duration = 20 * time.Second
opts := faultline.Options{Seeds: seeds, Duration: cfg.Duration, Net: etcdraft.NetConfig()}
faultline.Run(t, opts, func(w *faultline.World) {
c := etcdraft.Setup(w, cfg)
crash := kernel.Time(5 * time.Second)
w.Plan(fault.Script(fault.Event{At: crash, Kind: fault.KindCrash, Role: "leader"}))
w.Final("new leader after the crash", func() error {
var oldTerm uint64
for _, ch := range c.LeaderChanges() {
if ch.State != raft.StateLeader {
continue
}
if ch.At <= crash {
oldTerm = ch.Term
continue
}
return check(time.Duration(ch.At-crash), ch.Term-oldTerm)
}
return errors.New("no new leader after the crash")
})
})
}
func TestFailoverUnderOneSecond(t *testing.T) {
cfg := etcdraft.DefaultConfig()
cfg.ElectionTick = 3
failover(t, cfg, 200, func(d time.Duration, _ uint64) error {
if d > time.Second {
return fmt.Errorf("new leader %v after the crash", d)
}
return nil
})
}
It failed on the 45th seed:
$ go test -run '^TestFailoverUnderOneSecond$' .
--- FAIL: TestFailoverUnderOneSecond (1.14s)
failover_test.go:30: faultline: running 200 seeds from base 0xf41bc040834225b9 (test name)
--- FAIL: TestFailoverUnderOneSecond/seed=0xe05bdf977f330e42 (0.19s)
faultline: final check "new leader after the crash" failed after the run at t=20.000000000s
new leader 1.783042452s after the crash
replay: FAULTLINE_SEED=0xe05bdf977f330e42 go test -v -run '^TestFailoverUnderOneSecond$' example.com/failover
artifacts: /tmp/faultline-501/example.com_failover/TestFailoverUnderOneSecond/e05bdf977f330e42/
failover_test.go:30: faultline: stopping after failing seed 0xe05bdf977f330e42; 155 of 200 seeds not run (set Options.KeepGoing to run all)
FAIL
FAIL example.com/failover 1.678s
FAIL
Reading the slow seed
This time I could run the slow one again as often as I liked. The replay command runs the identical run, with the same events at the same virtual times. The failing seed also left an artifact directory, and its text timeline shows what happened after the crash:
grep -E "fault.crash|became (candidate|leader)" timeline.txt
254 0.220702122s n3#1 etcdraft.raft_log 3 became candidate at term 2 level=info <-253
300 0.225595569s n3#1 etcdraft.raft_log 3 became leader at term 2 level=info <-299
18833 5.000000000s n3#1 fault.crash crash n3 id=1 source=script node=n3 effect=applied <-18832
18905 5.473915956s n2#1 etcdraft.raft_log 2 became candidate at term 3 level=info <-18904
18916 5.474188777s n1#1 etcdraft.raft_log 1 became candidate at term 3 level=info <-18915
19083 5.873566634s n1#1 etcdraft.raft_log 1 became candidate at term 4 level=info <-19082
19094 5.874618666s n2#1 etcdraft.raft_log 2 became candidate at term 4 level=info <-19093
19271 6.374222166s n1#1 etcdraft.raft_log 1 became candidate at term 5 level=info <-19270
19290 6.375359195s n2#1 etcdraft.raft_log 2 became candidate at term 5 level=info <-19289
19457 6.774700502s n1#1 etcdraft.raft_log 1 became candidate at term 6 level=info <-19456
19505 6.783042452s n1#1 etcdraft.raft_log 1 became leader at term 6 level=info <-19504
n1 and n2 became candidates within about a millisecond of each other, three rounds in a row. Each voted for itself, so neither got the second vote it needed, and both waited out another timeout. In the fourth round only n1 ran, and it won.
etcd/raft picks each server's timeout in whole ticks: electionTimeout + rand.Intn(electionTimeout), drawn from crypto/rand, which faultline seeds for every run. With ElectionTick 3, a server waits 3, 4 or 5 ticks. The harness starts each server's ticks at a random point within the first interval, as real servers that started at different times would. In this seed, n1's and n2's ticks landed less than half a millisecond apart, and they kept drawing the same number of ticks.
How often does it happen?
One slow seed doesn't give a rate. The next test runs 2,000 crashes per setting and records the time to the next leader and the number of election rounds it took. More than one round means at least one round elected nobody, as in the seed above:
func TestFailoverDistribution(t *testing.T) {
for _, c := range []struct {
name string
tick time.Duration
ticks int
}{
{"10 ticks of 100ms", 100 * time.Millisecond, 10},
{"3 ticks of 100ms", 100 * time.Millisecond, 3},
{"10 ticks of 30ms", 30 * time.Millisecond, 10},
} {
var took []time.Duration
var repeated, slow int
t.Run(c.name, func(t *testing.T) {
cfg := etcdraft.DefaultConfig()
cfg.TickInterval, cfg.ElectionTick = c.tick, c.ticks
failover(t, cfg, 2000, func(d time.Duration, elections uint64) error {
took = append(took, d)
if elections > 1 {
repeated++ // at least one election round elected nobody
}
if d > time.Second {
slow++
}
return nil
})
})
slices.Sort(took)
n := len(took)
ms := func(d time.Duration) time.Duration { return d.Round(time.Millisecond) }
t.Logf("%-17s median %v, p99 %v, max %v; repeated elections in %d, over 1s in %d of %d",
c.name, ms(took[n/2]), ms(took[n*99/100]), ms(took[n-1]), repeated, slow, n)
}
}
$ go test -v -run '^TestFailoverDistribution$' . | grep repeated
failover_test.go:91: 10 ticks of 100ms median 1.249s, p99 1.893s, max 3.155s; repeated elections in 16, over 1s in 1797 of 2000
failover_test.go:91: 3 ticks of 100ms median 343ms, p99 622ms, max 1.177s; repeated elections in 27, over 1s in 1 of 2000
failover_test.go:91: 10 ticks of 30ms median 381ms, p99 814ms, max 1.418s; repeated elections in 32, over 1s in 7 of 2000
With 3 ticks, half the failovers finished within 343 ms and 99% within 622 ms, against 1.249 s and 1.893 s with the default. One failover in 2,000 took more than a second. About 1.4% needed more than one round.
Fewer ticks or shorter ticks?
The third line is the other way to reach a 300 ms timeout: keep 10 ticks and make each one 30 ms. I expected it to repeat elections less often, because a server then picks from 10 timeouts instead of 3. It didn't. Its median was close, and its tail was worse: 7 failovers over a second, and a p99 of 814 ms.
Three more settings, 2,000 crashes each, point at the reason. Settings whose shortest timeout is 300 ms repeated an election in 24 to 32 of 2,000 failovers, whether they used 3, 10 or 20 ticks. Settings that start at 600 ms or later repeated one in 14 to 20. So the timeout in milliseconds, not the number of ticks, seems to set how often two servers start an election together.
30 ms ticks also cost something that 3 ticks don't. With HeartbeatTick 1, the leader sends a heartbeat every tick, so 30 ms ticks send heartbeats more than three times as often. The same settings passed 500 seeds of the full fault mix, like the 3-tick version:
func TestShortTicksStaySafe(t *testing.T) {
cfg := etcdraft.DefaultConfig()
cfg.TickInterval = 30 * time.Millisecond
etcdraft.Test(t, cfg, faultline.Options{Seeds: 500})
}
$ go test -run '^TestShortTicksStaySafe$' .
ok example.com/failover 43.569s
What a shorter timeout costs
A shorter timeout reacts faster to every missed heartbeat, not only to a dead leader. I counted the elections in 200 runs of 60 seconds for each setting. With no faults, all three settings held exactly one election per run, the first. Under the default faults, the default setting held 8.95 per run, and the two 300 ms settings 12.7 and 12.4. Each election is a short window with no leader. Some of the extra ones are faster reactions to real failures; others are elections a longer timeout would have ridden out, and these runs don't separate the two.
etcd/raft's documentation suggests ElectionTick = 10 * HeartbeatTick "to avoid unnecessary leader switching". In these runs, the 3:1 setting and the 10:1 setting held the same number of extra elections, so the timeout in milliseconds mattered and the ratio didn't. On a network that loses messages in bursts, the ratio may still matter. The harness doesn't model that kind of loss.
What this doesn't tell you
The harness runs etcd/raft with its own state machine, log and transport. Your service's code is not in the run. To test it, you port it to faultline's node API, and the harness is one worked example of such a port.
The network is a model with 1 ms of latency and up to 2 ms of jitter. One message in 100 is delayed by up to 50 ms more, one in 1,000 is lost, and one in 1,000 is duplicated. A real network with longer stalls, or a process with long garbage collection pauses, needs more headroom than these runs show. Inside the simulation a callback takes no time, so CPU load doesn't slow the cluster down.
Try it
Every test above runs with go test, against the released modules. All four took under four minutes on my laptop, an Apple M4 Max with Go 1.27.1:
go get github.com/hmdsefi/faultline/harness/etcdraft@v0.1.1
I first ran these tests on v0.1.0, and v0.1.1 gives the same numbers. v0.1.1 also adds faultline.RunSeeds, which keeps a failing seed like the slow one above as a regression test.
Test etcd/raft with the harness covers the rest of the harness: cluster sizes, fault presets, snapshots and membership changes. The documentation starts with how an AI coding agent runs the same loop, from a failing seed to a pinned regression test, and the repository is on GitHub.
來源：DEV Community · dev.to