$ time go test -run 2B Test (2B): basic agreement ... ... Passed -- 1.631851583 Test (2B): RPC byte count ... ... Passed -- 3.335011512211 Test (2B): agreement despite follower disconnection ... ... Passed -- 6.3364174897 Test (2B): no agreement if too many followers disconnect ... ... Passed -- 4.95116278383 Test (2B): concurrent Start()s ... ... Passed -- 2.131646486 Test (2B): rejoin of partitioned leader ... ... Passed -- 8.13111269964 Test (2B): leader backs up quickly over incorrect follower logs ... ... Passed -- 28.651342953354102 Test (2B): RPC counts aren't too high ... ... Passed -- 3.4 3 30 9050 12 PASS ok raft 58.142s real 0m58.475s user 0m2.477s sys 0m1.406s $
type Raft struct { mu sync.Mutex // Lock to protect shared access to this peer's state peers []*labrpc.ClientEnd // RPC end points of all peers persister *Persister // Object to hold this peer's persisted state me int// this peer's index into peers[] dead int32// set by Kill()
// Your data here (2A, 2B, 2C). // Look at the paper's Figure 2 for a description of what // state a Raft server must maintain. // 根据论文的要求定义 // 2A currentTerm int// Server当前的term voteFor int// Server在选举阶段的投票给了谁 voteGrantedNum int// 收集到的投票数量 state int// 当前状态 heartbeatTimer *time.Timer // 心跳超时时间 electionTimeout *time.Timer // 随机选举时间 // 2B logs []Entry commitIndex int// 已提交日志序号 lastApplied int// 已应用日志序号 nextIndex []int// 下一个待发送日志序号,leader 特有 matchIndex []int// 已同步日志序号,leader 特有 applyChan chan ApplyMsg // 日志都是存在这里client取(2B) }
Entry数据结构
1 2 3 4 5 6
// 定义日志具体细节 type Entry struct { Index int// 日志索引,也就是第几行 Term int// 任期 Command interface{} // 具体命令内容 }
// lots of successful commands to new group. for i := 0; i < 50; i++ { cfg.one(rand.Int(), 3, true) }
// now another partitioned leader and one follower leader2 := cfg.checkOneLeader() other := (leader1 + 2) % servers if leader2 == other { other = (leader2 + 1) % servers } cfg.disconnect(other)
// lots more commands that won't commit for i := 0; i < 50; i++ { cfg.rafts[leader2].Start(rand.Int()) }
time.Sleep(RaftElectionTimeout / 2)
// bring original leader back to life, for i := 0; i < servers; i++ { cfg.disconnect(i) } cfg.connect((leader1 + 0) % servers) cfg.connect((leader1 + 1) % servers) cfg.connect(other)
// lots of successful commands to new group. for i := 0; i < 50; i++ { cfg.one(rand.Int(), 3, true) }
// now everyone for i := 0; i < servers; i++ { cfg.connect(i) } cfg.one(rand.Int(), servers, true)
Test (2B): leader backs up quickly over incorrect follower logs ... 003590 INFO S1term:1=state:1=[StartElect] 003592 INFO S1-term:1-state:1 => 4[RPC-Vote] 003592 INFO S1-term:1-state:1 => 2[RPC-Vote] 003594 INFO S1-term:1-state:1 => 3[RPC-Vote] 003608 INFO S1-term:1-state:1 => 0[RPC-Vote] 003611 INFO S2:term:0 ==> S1-term:1[Enter-RequestVote] 003612 INFO S2 ==> S1-term:1[RequestVote] 003612 INFO S2:state:0:term:0-changeTo-state:0:term:1[RequestVote1] 003612 INFO S2:state:0-changeTo-state:0[RequestVote2] 003612 INFO S0:term:0 ==> S1-term:1[Enter-RequestVote] 003612 INFO S0 ==> S1-term:1[RequestVote] 003612 INFO S0:state:0:term:0-changeTo-state:0:term:1[RequestVote1] 003612 INFO S0:state:0-changeTo-state:0[RequestVote2] 003613 INFO S1-term:1-state:1 => 0[RPC-Vote-Over] 003613 TIMR S1Vote<--0[Vote] 003613 INFO S1-term:1-state:1 => 2[RPC-Vote-Over] 003613 TIMR S1Vote<--2[Vote] 003613 INFO S1:state:1-changeTo-state:2[BecomeLeader] 003613 INFO S3:term:0 ==> S1-term:1[Enter-RequestVote] 003613 INFO S3 ==> S1-term:1[RequestVote] 003613 INFO S3:state:0:term:0-changeTo-state:0:term:1[RequestVote1] 003613 INFO S3:state:0-changeTo-state:0[RequestVote2] 003614 INFO S1-term:1-state:2 => 3[RPC-Vote-Over] 003613 LEAD S1-term:1-state:2[BecomeLeader] 003614 LEAD S1-term:1-state:2[BeginHeart] 003612 INFO S4:term:0 ==> S1-term:1[Enter-RequestVote] 003616 INFO S4 ==> S1-term:1[RequestVote] 003616 INFO S4:state:0-changeTo-state:0[RequestVote2] 003617 INFO S1-term:1-state:2 => 4[RPC-Vote-Over] 004110 INFO S1command1[ReceiveLog] 004110 INFO S1:[][Start-Before] 004110 INFO S1:[{111}][Start-After] 004111 LEAD S1-term:1-state:2[BeginHeart] 004113 INFO S3:state:0:term:1-ReceiveFrom-S1[AppendEntries] 004113 INFO S4:state:0:term:1-ReceiveFrom-S1[AppendEntries] 004113 INFO S4:term:[][Add-Before] 004113 INFO S4FromS1:[{111}][Adding] 004113 INFO S4FromS1:[{111}][Add-After] 004113 INFO S0:state:0:term:1-ReceiveFrom-S1[AppendEntries] 004113 INFO S0:term:[][Add-Before] 004113 INFO S0FromS1:[{111}][Adding] 004113 INFO S0FromS1:[{111}][Add-After] 004113 INFO S2:state:0:term:1-ReceiveFrom-S1[AppendEntries] 004114 INFO S2:term:[][Add-Before] 004114 INFO S2FromS1:[{111}][Adding] 004114 INFO S2FromS1:[{111}][Add-After] 004114 INFO S1[Heartbeat] cnt,len(rf.peers) 35 004113 INFO S3:term:[][Add-Before] 004114 INFO S3FromS1:[{111}][Adding] 004114 INFO S3FromS1:[{111}][Add-After] 004524 LEAD S1-term:1-state:2[BeginHeart] [TestBackup2B]==pass1 006030 LEAD S1-term:1-state:2[BeginHeart] 007537 LEAD S1-term:1-state:2[BeginHeart] 009045 LEAD S1-term:1-state:2[BeginHeart] Pass==checkOneLeader() leader1: 1 [TestBackup2B]==pass2 009661 INFO S1command2[ReceiveLog] 009662 INFO S1:[{111}][Start-Before] 009662 INFO S1:[{111} {212}][Start-After] 009662 LEAD S1-term:1-state:2[BeginHeart] 009662 INFO S1command3[ReceiveLog] 009662 INFO S1:[{111} {212}][Start-Before] 009662 INFO S1:[{111} {212} {313}][Start-After] 009662 LEAD S1-term:1-state:2[BeginHeart] [TestBackup2B]==pass3 009664 INFO S2:state:0:term:1-ReceiveFrom-S1[AppendEntries] 009664 INFO S2:term:[{111}][Add-Before] 009664 INFO S2FromS1:[{212}][Adding] 009664 INFO S2FromS1:[{111} {212}][Add-After] 009664 INFO S2:state:0:term:1-ReceiveFrom-S1[AppendEntries] 009664 INFO S2:term:[{111}][Add-Before] 009664 INFO S2FromS1:[{212} {313}][Adding] 009664 INFO S2FromS1:[{111} {212} {313}][Add-After] 010557 LEAD S1-term:1-state:2[BeginHeart] 011250 INFO S3term:2=state:1=[StartElect] 011250 INFO S3-term:2-state:1 => 4[RPC-Vote] 011251 INFO S3-term:2-state:1 => 1[RPC-Vote] 011251 INFO S3-term:2-state:1 => 2[RPC-Vote] 011251 INFO S3-term:2-state:1 => 0[RPC-Vote] 012070 LEAD S1-term:1-state:2[BeginHeart] 012669 INFO S4term:2=state:1=[StartElect] 012671 INFO S4-term:2-state:1 => 3[RPC-Vote] 012671 INFO S4-term:2-state:1 => 1[RPC-Vote] 012672 INFO S4-term:2-state:1 => 0[RPC-Vote] 012673 INFO S4-term:2-state:1 => 2[RPC-Vote] 013574 LEAD S1-term:1-state:2[BeginHeart] [TestBackup2B]==pass4 014850 INFO S0term:2=state:1=[StartElect] 014850 INFO S0-term:2-state:1 => 4[RPC-Vote] 014851 INFO S0-term:2-state:1 => 2[RPC-Vote] 014851 INFO S4:term:2 ==> S0-term:2[Enter-RequestVote] 014851 INFO S4 ==> S0-term:2[RequestVote] 014851 INFO S4:state:1:term:2-requestOther[RequestVote2]%!(EXTRA int=0, int=2) 014851 INFO S0-term:2-state:1 => 1[RPC-Vote] 014852 INFO S0-term:2-state:1 => 4[RPC-Vote-Over] 014852 INFO S0-term:2-state:1 => 3[RPC-Vote] 014853 INFO S3:term:2 ==> S0-term:2[Enter-RequestVote] 014853 INFO S3 ==> S0-term:2[RequestVote] 014853 INFO S3:state:1:term:2-requestOther[RequestVote2]%!(EXTRA int=0, int=2) 014853 INFO S0-term:2-state:1 => 3[RPC-Vote-Over] 015077 LEAD S1-term:1-state:2[BeginHeart] 016561 INFO S3term:3=state:1=[StartElect] 016561 INFO S3-term:3-state:1 => 0[RPC-Vote] 016562 INFO S3-term:3-state:1 => 4[RPC-Vote] 016562 INFO S3-term:3-state:1 => 1[RPC-Vote] 016562 INFO S3-term:3-state:1 => 2[RPC-Vote] 016562 INFO S0:term:2 ==> S3-term:3[Enter-RequestVote] 016562 INFO S0 ==> S3-term:3[RequestVote] 016563 INFO S0:state:1:term:2-changeTo-state:0:term:3[RequestVote1] 016563 INFO S0:state:0-changeTo-state:0[RequestVote2] 016563 INFO S4:term:2 ==> S3-term:3[Enter-RequestVote] 016563 INFO S4 ==> S3-term:3[RequestVote] 016563 INFO S3-term:3-state:1 => 0[RPC-Vote-Over] 016563 INFO S4:state:1:term:2-changeTo-state:0:term:3[RequestVote1] 016563 TIMR S3Vote<--0[Vote] 016563 INFO S4:state:0-changeTo-state:0[RequestVote2] 016563 INFO S3-term:3-state:1 => 4[RPC-Vote-Over] 016563 TIMR S3Vote<--4[Vote] 016563 INFO S3:state:1-changeTo-state:2[BecomeLeader] 016563 LEAD S3-term:3-state:2[BecomeLeader] 016563 LEAD S3-term:3-state:2[BeginHeart] 016588 LEAD S3-term:3-state:2[BeginHeart] 016589 LEAD S1-term:1-state:2[BeginHeart] 016815 INFO S3command4[ReceiveLog] 016815 INFO S3:[{111}][Start-Before] 016815 INFO S3:[{111} {234}][Start-After] 016815 LEAD S3-term:3-state:2[BeginHeart] 016817 INFO S4:state:0:term:3-ReceiveFrom-S3[AppendEntries] 016817 INFO S4:term:[{111}][Add-Before] 016817 INFO S4FromS3:[{234}][Adding] 016817 INFO S4FromS3:[{111} {234}][Add-After] 016817 INFO S0:state:0:term:3-ReceiveFrom-S3[AppendEntries] 016817 INFO S0:term:[{111}][Add-Before] 016817 INFO S0FromS3:[{234}][Adding] 016817 INFO S0FromS3:[{111} {234}][Add-After] 016818 INFO S3[Heartbeat] cnt,len(rf.peers) 35 018025 INFO S2term:2=state:1=[StartElect] 018030 INFO S2-term:2-state:1 => 4[RPC-Vote] 018031 INFO S2-term:2-state:1 => 1[RPC-Vote] 018032 INFO S2-term:2-state:1 => 0[RPC-Vote] 018032 INFO S2-term:2-state:1 => 3[RPC-Vote] 018106 LEAD S3-term:3-state:2[BeginHeart] 018106 LEAD S1-term:1-state:2[BeginHeart] 018234 INFO S3command5[ReceiveLog] 018234 INFO S3:[{111} {234}][Start-Before] 018235 INFO S3:[{111} {234} {335}][Start-After] 018235 LEAD S3-term:3-state:2[BeginHeart] 018237 INFO S0:state:0:term:3-ReceiveFrom-S3[AppendEntries] 018237 INFO S0:term:[{111} {234}][Add-Before] 018237 INFO S0FromS3:[{335}][Adding] 018237 INFO S0FromS3:[{111} {234} {335}][Add-After] 018237 INFO S4:state:0:term:3-ReceiveFrom-S3[AppendEntries] 018237 INFO S4:term:[{111} {234}][Add-Before] 018237 INFO S4FromS3:[{335}][Adding] 018237 INFO S4FromS3:[{111} {234} {335}][Add-After] 018238 INFO S3[Heartbeat] cnt,len(rf.peers) 35 019618 LEAD S3-term:3-state:2[BeginHeart] 019618 LEAD S1-term:1-state:2[BeginHeart] [TestBackup2B]==pass6 020674 INFO S0:term:3 ==> S3-term:2[Enter-RequestVote] 020675 INFO S0 ==> S3-term:2[RequestVote] 020678 INFO S3-term:3-state:2 => 0[RPC-Vote-Over] 020796 INFO S2term:3=state:1=[StartElect] 020805 INFO S2-term:3-state:1 => 4[RPC-Vote] 020809 INFO S2-term:3-state:1 => 0[RPC-Vote] 020811 INFO S2-term:3-state:1 => 3[RPC-Vote] 020811 INFO S2-term:3-state:1 => 1[RPC-Vote] 021126 LEAD S1-term:1-state:2[BeginHeart] 021126 LEAD S3-term:3-state:2[BeginHeart] 022630 LEAD S3-term:3-state:2[BeginHeart] 022632 LEAD S1-term:1-state:2[BeginHeart] 024076 INFO S2term:4=state:1=[StartElect] 024077 INFO S2-term:4-state:1 => 4[RPC-Vote] 024078 INFO S2-term:4-state:1 => 3[RPC-Vote] 024078 INFO S2-term:4-state:1 => 0[RPC-Vote] 024078 INFO S2-term:4-state:1 => 1[RPC-Vote] 024141 LEAD S1-term:1-state:2[BeginHeart] 024145 LEAD S3-term:3-state:2[BeginHeart] Pass==checkOneLeader() leader2: 3 other: 4 [TestBackup2B]==pass7 024386 INFO S3command6[ReceiveLog] 024386 INFO S3:[{111} {234} {335}][Start-Before] 024386 INFO S3:[{111} {234} {335} {436}][Start-After] 024386 LEAD S3-term:3-state:2[BeginHeart] 024386 INFO S3command7[ReceiveLog] 024386 INFO S3:[{111} {234} {335} {436}][Start-Before] 024386 INFO S3:[{111} {234} {335} {436} {537}][Start-After] 024387 LEAD S3-term:3-state:2[BeginHeart] [TestBackup2B]==pass8 024389 INFO S0:state:0:term:3-ReceiveFrom-S3[AppendEntries] 024389 INFO S0:term:[{111} {234} {335}][Add-Before] 024389 INFO S0FromS3:[{436}][Adding] 024389 INFO S0FromS3:[{111} {234} {335} {436}][Add-After] 024390 INFO S0:state:0:term:3-ReceiveFrom-S3[AppendEntries] 024390 INFO S0:term:[{111} {234} {335}][Add-Before] 024390 INFO S0FromS3:[{436} {537}][Adding] 024390 INFO S0FromS3:[{111} {234} {335} {436} {537}][Add-After] 025647 LEAD S1-term:1-state:2[BeginHeart] 025653 LEAD S3-term:3-state:2[BeginHeart] 026405 INFO S2term:5=state:1=[StartElect] 026405 INFO S2-term:5-state:1 => 4[RPC-Vote] 026406 INFO S2-term:5-state:1 => 3[RPC-Vote] 026406 INFO S2-term:5-state:1 => 1[RPC-Vote] 026406 INFO S2-term:5-state:1 => 0[RPC-Vote] 027406 LEAD S1-term:1-state:2[BeginHeart] 027408 LEAD S3-term:3-state:2[BeginHeart] 028572 INFO S2term:6=state:1=[StartElect] 028573 INFO S2-term:6-state:1 => 4[RPC-Vote] 028573 INFO S2-term:6-state:1 => 1[RPC-Vote] 028573 INFO S2-term:6-state:1 => 3[RPC-Vote] 028573 INFO S2-term:6-state:1 => 0[RPC-Vote] 028907 LEAD S1-term:1-state:2[BeginHeart] 028918 LEAD S3-term:3-state:2[BeginHeart] [TestBackup2B]==pass9 029388 INFO S1command8[ReceiveLog] 029388 INFO S1:[{111} {212} {313}][Start-Before] 029388 INFO S1:[{111} {212} {313} {418}][Start-After] 029388 LEAD S1-term:1-state:2[BeginHeart] 029997 INFO S4term:4=state:1=[StartElect] 029998 INFO S4-term:4-state:1 => 3[RPC-Vote] 029998 INFO S4-term:4-state:1 => 0[RPC-Vote] 029998 INFO S4-term:4-state:1 => 1[RPC-Vote] 029998 INFO S4-term:4-state:1 => 2[RPC-Vote] 030000 INFO S2:term:6 ==> S4-term:4[Enter-RequestVote] 030000 INFO S2 ==> S4-term:4[RequestVote] 030000 INFO S4-term:4-state:1 => 2[RPC-Vote-Over] 030000 INFO S1:term:3 ==> S4-term:4[Enter-RequestVote] 030000 INFO S1 ==> S4-term:4[RequestVote] 030001 INFO S1:state:0:term:3-changeTo-state:0:term:4[RequestVote1] 030001 INFO S1:state:0-changeTo-state:0[RequestVote2] 030001 INFO S4-term:6-state:0 => 1[RPC-Vote-Over] 030422 LEAD S3-term:3-state:2[BeginHeart] 031050 INFO S2term:7=state:1=[StartElect] 031051 INFO S2-term:7-state:1 => 4[RPC-Vote] 031051 INFO S2-term:7-state:1 => 1[RPC-Vote] 031052 INFO S2-term:7-state:1 => 3[RPC-Vote] 031052 INFO S2-term:7-state:1 => 0[RPC-Vote] 031052 INFO S4:term:6 ==> S2-term:7[Enter-RequestVote] 031053 INFO S4 ==> S2-term:7[RequestVote] 031053 INFO S4:state:0:term:6-changeTo-state:0:term:7[RequestVote1] 031053 INFO S4:state:0:term:7-LogFailOK[RequestVote3]%!(EXTRA int=0, int=7) 031055 INFO S1:term:4 ==> S2-term:7[Enter-RequestVote] 031055 INFO S1 ==> S2-term:7[RequestVote] 031055 INFO S1:state:0:term:4-changeTo-state:0:term:7[RequestVote1] 031055 INFO S1:state:0:term:7-LogFailOK[RequestVote3]%!(EXTRA int=0, int=7) 031056 INFO S2-term:7-state:1 => 1[RPC-Vote-Over] 031055 INFO S2-term:7-state:1 => 4[RPC-Vote-Over] 031879 INFO S0term:4=state:1=[StartElect] 031880 INFO S0-term:4-state:1 => 4[RPC-Vote] 031880 INFO S0-term:4-state:1 => 2[RPC-Vote] 031880 INFO S0-term:4-state:1 => 3[RPC-Vote] 031880 INFO S0-term:4-state:1 => 1[RPC-Vote] 031927 LEAD S3-term:3-state:2[BeginHeart] 033440 LEAD S3-term:3-state:2[BeginHeart] 033468 INFO S4term:8=state:1=[StartElect] 033469 INFO S4-term:8-state:1 => 3[RPC-Vote] 033469 INFO S4-term:8-state:1 => 0[RPC-Vote] 033470 INFO S4-term:8-state:1 => 2[RPC-Vote] 033471 INFO S4-term:8-state:1 => 1[RPC-Vote] 033471 INFO S2:term:7 ==> S4-term:8[Enter-RequestVote] 033472 INFO S2 ==> S4-term:8[RequestVote] 033472 INFO S2:state:1:term:7-changeTo-state:0:term:8[RequestVote1] 033472 INFO S2:state:0-changeTo-state:0[RequestVote2] 033472 INFO S1:term:7 ==> S4-term:8[Enter-RequestVote] 033472 INFO S1 ==> S4-term:8[RequestVote] 033472 INFO S1:state:0:term:7-changeTo-state:0:term:8[RequestVote1] 033472 INFO S1:state:0-changeTo-state:0[RequestVote2] 033472 INFO S4-term:8-state:1 => 2[RPC-Vote-Over] 033472 TIMR S4Vote<--2[Vote] 033473 INFO S4-term:8-state:1 => 1[RPC-Vote-Over] 033473 TIMR S4Vote<--1[Vote] 033473 INFO S4:state:1-changeTo-state:2[BecomeLeader] 033473 LEAD S4-term:8-state:2[BecomeLeader] 033473 LEAD S4-term:8-state:2[BeginHeart] 034551 INFO S0term:5=state:1=[StartElect] 034552 INFO S0-term:5-state:1 => 4[RPC-Vote] 034552 INFO S0-term:5-state:1 => 2[RPC-Vote] 034552 INFO S0-term:5-state:1 => 3[RPC-Vote] 034552 INFO S0-term:5-state:1 => 1[RPC-Vote] 034951 LEAD S3-term:3-state:2[BeginHeart] 034952 LEAD S4-term:8-state:2[BeginHeart] 034954 INFO S1:state:0:term:8-ReceiveFrom-S4[AppendEntries] 034954 INFO S1:term:[{111}][Add-Before] 034954 INFO S1FromS4:[{234} {335}][Adding] 034954 INFO S1FromS4:[{111} {234} {335}][Add-After] 034955 INFO S2:state:0:term:8-ReceiveFrom-S4[AppendEntries] 034955 INFO S2:term:[{111}][Add-Before] 034955 INFO S2FromS4:[{234} {335}][Adding] 034955 INFO S2FromS4:[{111} {234} {335}][Add-After] 037185 LEAD S3-term:3-state:2[BeginHeart] 037185 LEAD S4-term:8-state:2[BeginHeart] 037201 INFO S1:term:8 ==> S2-term:6[Enter-RequestVote] 037201 INFO S1 ==> S2-term:6[RequestVote] 037201 INFO S2-term:8-state:0 => 1[RPC-Vote-Over] 037740 INFO S1:term:8 ==> S2-term:3[Enter-RequestVote] 037740 INFO S1 ==> S2-term:3[RequestVote] 037741 INFO S2-term:8-state:0 => 1[RPC-Vote-Over] 037938 INFO S1:term:8 ==> S2-term:4[Enter-RequestVote] 037939 INFO S1 ==> S2-term:4[RequestVote] 037939 INFO S2-term:8-state:0 => 1[RPC-Vote-Over] 038691 LEAD S4-term:8-state:2[BeginHeart] 038693 INFO S4:term:8 ==> S2-term:2[Enter-RequestVote] 038694 INFO S4 ==> S2-term:2[RequestVote] 038692 LEAD S3-term:3-state:2[BeginHeart] 038694 INFO S2-term:8-state:0 => 4[RPC-Vote-Over] 039984 INFO S0term:6=state:1=[StartElect] 039985 INFO S0-term:6-state:1 => 4[RPC-Vote] 039985 INFO S0-term:6-state:1 => 2[RPC-Vote] 039986 INFO S0-term:6-state:1 => 1[RPC-Vote] 039986 INFO S0-term:6-state:1 => 3[RPC-Vote] 040203 LEAD S3-term:3-state:2[BeginHeart] 040204 LEAD S4-term:8-state:2[BeginHeart] 041708 LEAD S4-term:8-state:2[BeginHeart] 041709 LEAD S3-term:3-state:2[BeginHeart] 043219 LEAD S3-term:3-state:2[BeginHeart] 043220 LEAD S4-term:8-state:2[BeginHeart] 043885 INFO S0term:7=state:1=[StartElect] 043886 INFO S0-term:7-state:1 => 4[RPC-Vote] 043886 INFO S0-term:7-state:1 => 2[RPC-Vote] 043887 INFO S0-term:7-state:1 => 1[RPC-Vote] 043887 INFO S0-term:7-state:1 => 3[RPC-Vote] 044733 LEAD S4-term:8-state:2[BeginHeart] 044733 LEAD S3-term:3-state:2[BeginHeart] 045684 INFO S4:term:8 ==> S2-term:5[Enter-RequestVote] 045684 INFO S4 ==> S2-term:5[RequestVote] 045685 INFO S2-term:8-state:0 => 4[RPC-Vote-Over] 046235 LEAD S4-term:8-state:2[BeginHeart] 046235 LEAD S3-term:3-state:2[BeginHeart] 047741 LEAD S4-term:8-state:2[BeginHeart] 047747 LEAD S3-term:3-state:2[BeginHeart] 048161 INFO S0term:8=state:1=[StartElect] 048162 INFO S0-term:8-state:1 => 4[RPC-Vote] 048162 INFO S0-term:8-state:1 => 2[RPC-Vote] 048162 INFO S0-term:8-state:1 => 1[RPC-Vote] 048163 INFO S0-term:8-state:1 => 3[RPC-Vote] 049254 LEAD S3-term:3-state:2[BeginHeart] 049255 LEAD S4-term:8-state:2[BeginHeart] 049426 INFO S4command8[ReceiveLog] 049427 INFO S4:[{111} {234} {335}][Start-Before] 049427 INFO S4:[{111} {234} {335} {488}][Start-After] 049427 LEAD S4-term:8-state:2[BeginHeart] 049430 INFO S1:state:0:term:8-ReceiveFrom-S4[AppendEntries] 049430 INFO S1:term:[{111} {234} {335}][Add-Before] 049430 INFO S1FromS4:[{488}][Adding] 049430 INFO S1FromS4:[{111} {234} {335} {488}][Add-After] 049430 INFO S2:state:0:term:8-ReceiveFrom-S4[AppendEntries] 049430 INFO S2:term:[{111} {234} {335}][Add-Before] 049430 INFO S2FromS4:[{488}][Adding] 049431 INFO S2FromS4:[{111} {234} {335} {488}][Add-After] 049432 INFO S4[Heartbeat] cnt,len(rf.peers) 35 050729 INFO S0term:9=state:1=[StartElect] 050730 INFO S0-term:9-state:1 => 4[RPC-Vote] 050730 INFO S0-term:9-state:1 => 1[RPC-Vote] 050731 INFO S0-term:9-state:1 => 2[RPC-Vote] 050731 INFO S0-term:9-state:1 => 3[RPC-Vote] 050763 LEAD S3-term:3-state:2[BeginHeart] 050763 LEAD S4-term:8-state:2[BeginHeart] 050935 INFO S4command9[ReceiveLog] 050935 INFO S4:[{111} {234} {335} {488}][Start-Before] 050936 INFO S4:[{111} {234} {335} {488} {589}][Start-After] 050936 LEAD S4-term:8-state:2[BeginHeart] 050937 INFO S1:state:0:term:8-ReceiveFrom-S4[AppendEntries] 050937 INFO S1:term:[{111} {234} {335} {488}][Add-Before] 050937 INFO S1FromS4:[{589}][Adding] 050937 INFO S1FromS4:[{111} {234} {335} {488} {589}][Add-After] 050937 INFO S2:state:0:term:8-ReceiveFrom-S4[AppendEntries] 050937 INFO S2:term:[{111} {234} {335} {488}][Add-Before] 050937 INFO S2FromS4:[{589}][Adding] 050937 INFO S2FromS4:[{111} {234} {335} {488} {589}][Add-After] 050938 INFO S4[Heartbeat] cnt,len(rf.peers) 35 052268 LEAD S4-term:8-state:2[BeginHeart] 052268 LEAD S3-term:3-state:2[BeginHeart] [TestBackup2B]==pass10 [TestBackup2B]==pass11 052400 INFO S3command10[ReceiveLog] 052400 INFO S3:[{111} {234} {335} {436} {537}][Start-Before] 052400 INFO S3:[{111} {234} {335} {436} {537} {6310}][Start-After] 052400 LEAD S3-term:3-state:2[BeginHeart] 052574 INFO S1:term:8 ==> S2-term:5[Enter-RequestVote] 052574 INFO S1 ==> S2-term:5[RequestVote] 052575 INFO S2-term:8-state:0 => 1[RPC-Vote-Over] 053522 INFO S3:state:0:term:8-ReceiveFrom-S4[AppendEntries] 053522 INFO S3:term:[{111} {234} {335}][Add-Before] 053522 INFO S3FromS4:[{488} {589}][Adding] 053522 INFO S3FromS4:[{111} {234} {335} {488} {589}][Add-After] 053523 INFO S4:term:8 ==> S2-term:3[Enter-RequestVote] 053524 INFO S4 ==> S2-term:3[RequestVote] 053524 INFO S2-term:8-state:0 => 4[RPC-Vote-Over] 053777 LEAD S4-term:8-state:2[BeginHeart] 054829 INFO S3:state:0:term:8-ReceiveFrom-S4[AppendEntries] 054829 INFO S3:term:[{111} {234} {335}][Add-Before] 054829 INFO S3FromS4:[{488}][Adding] 054829 INFO S3FromS4:[{111} {234} {335} {488}][Add-After] 055130 INFO S0term:10=state:1=[StartElect] 055131 INFO S0-term:10-state:1 => 4[RPC-Vote] 055131 INFO S0-term:10-state:1 => 2[RPC-Vote] 055131 INFO S0-term:10-state:1 => 1[RPC-Vote] 055131 INFO S0-term:10-state:1 => 3[RPC-Vote] 055132 INFO S1:term:8 ==> S0-term:10[Enter-RequestVote] 055132 INFO S1 ==> S0-term:10[RequestVote] 055132 INFO S2:term:8 ==> S0-term:10[Enter-RequestVote] 055132 INFO S1:state:0:term:8-changeTo-state:0:term:10[RequestVote1] 055132 INFO S2 ==> S0-term:10[RequestVote] 055132 INFO S2:state:0:term:8-changeTo-state:0:term:10[RequestVote1] 055132 INFO S1:state:0:term:10-LogFailOK[RequestVote3]%!(EXTRA int=0, int=10) 055132 INFO S2:state:0:term:10-LogFailOK[RequestVote3]%!(EXTRA int=0, int=10) 055132 INFO S3:term:8 ==> S0-term:10[Enter-RequestVote] 055132 INFO S3 ==> S0-term:10[RequestVote] 055132 INFO S3:state:0:term:8-changeTo-state:0:term:10[RequestVote1] 055132 INFO S3:state:0:term:10-LogFailOK[RequestVote3]%!(EXTRA int=0, int=10) 055132 INFO S4:term:9 ==> S0-term:10[Enter-RequestVote] 055132 INFO S0-term:10-state:1 => 1[RPC-Vote-Over] 055133 INFO S4 ==> S0-term:10[RequestVote] 055133 INFO S4:state:0:term:9-changeTo-state:0:term:10[RequestVote1] 055133 INFO S4:state:0:term:10-LogFailOK[RequestVote3]%!(EXTRA int=0, int=10) 055133 INFO S0-term:10-state:1 => 3[RPC-Vote-Over] 055133 INFO S0-term:10-state:1 => 2[RPC-Vote-Over] 055133 INFO S0-term:10-state:1 => 4[RPC-Vote-Over] 055467 INFO S1:term:10 ==> S0-term:5[Enter-RequestVote] 055468 INFO S1 ==> S0-term:5[RequestVote] 055468 INFO S0-term:10-state:1 => 1[RPC-Vote-Over] 055890 INFO S4term:11=state:1=[StartElect] 055890 INFO S4-term:11-state:1 => 3[RPC-Vote] 055891 INFO S4-term:11-state:1 => 1[RPC-Vote] 055891 INFO S4-term:11-state:1 => 2[RPC-Vote] 055891 INFO S4-term:11-state:1 => 0[RPC-Vote] 055891 INFO S3:term:10 ==> S4-term:11[Enter-RequestVote] 055891 INFO S3 ==> S4-term:11[RequestVote] 055892 INFO S1:term:10 ==> S4-term:11[Enter-RequestVote] 055892 INFO S2:term:10 ==> S4-term:11[Enter-RequestVote] 055892 INFO S2 ==> S4-term:11[RequestVote] 055892 INFO S1 ==> S4-term:11[RequestVote] 055892 INFO S1:state:0:term:10-changeTo-state:0:term:11[RequestVote1] 055892 INFO S1:state:0-changeTo-state:0[RequestVote2] 055892 INFO S2:state:0:term:10-changeTo-state:0:term:11[RequestVote1] 055892 INFO S0:term:10 ==> S4-term:11[Enter-RequestVote] 055892 INFO S0 ==> S4-term:11[RequestVote] 055892 INFO S0:state:1:term:10-changeTo-state:0:term:11[RequestVote1] 055892 INFO S0:state:0-changeTo-state:0[RequestVote2] 055892 INFO S3:state:0:term:10-changeTo-state:0:term:11[RequestVote1] 055892 INFO S3:state:0-changeTo-state:0[RequestVote2] 055892 INFO S2:state:0-changeTo-state:0[RequestVote2] 055892 INFO S4-term:11-state:1 => 1[RPC-Vote-Over] 055892 TIMR S4Vote<--1[Vote] 055892 INFO S4-term:11-state:1 => 0[RPC-Vote-Over] 055892 TIMR S4Vote<--0[Vote] 055892 INFO S4:state:1-changeTo-state:2[BecomeLeader] 055892 LEAD S4-term:11-state:2[BecomeLeader] 055892 LEAD S4-term:11-state:2[BeginHeart] 055892 INFO S4-term:11-state:1 => 3[RPC-Vote-Over] 055892 INFO S4-term:11-state:2 => 2[RPC-Vote-Over] 056796 LEAD S4-term:11-state:2[BeginHeart] 056801 INFO S0:state:0:term:11-ReceiveFrom-S4[AppendEntries] 056802 INFO S0:term:[{111} {234} {335}][Add-Before] 056803 INFO S0FromS4:[{488} {589}][Adding] 056803 INFO S0FromS4:[{111} {234} {335} {488} {589}][Add-After] 057735 INFO S3:term:11 ==> S0-term:9[Enter-RequestVote] 057736 INFO S3 ==> S0-term:9[RequestVote] 057737 INFO S0-term:11-state:0 => 3[RPC-Vote-Over] 058299 LEAD S4-term:11-state:2[BeginHeart] 059264 INFO S1:term:11 ==> S3-term:2[Enter-RequestVote] 059264 INFO S1 ==> S3-term:2[RequestVote] 059265 INFO S3-term:11-state:0 => 1[RPC-Vote-Over] 059439 INFO S1:term:11 ==> S0-term:8[Enter-RequestVote] 059439 INFO S1 ==> S0-term:8[RequestVote] 059440 INFO S0-term:11-state:0 => 1[RPC-Vote-Over] 059806 LEAD S4-term:11-state:2[BeginHeart] 060177 INFO S1:term:11 ==> S2-term:2[Enter-RequestVote] 060177 INFO S1 ==> S2-term:2[RequestVote] 060178 INFO S2-term:11-state:0 => 1[RPC-Vote-Over] 060980 INFO S3:term:11 ==> S2-term:7[Enter-RequestVote] 060980 INFO S3 ==> S2-term:7[RequestVote] 060980 INFO S2-term:11-state:0 => 3[RPC-Vote-Over] 061020 INFO S4:term:11 ==> S0-term:4[Enter-RequestVote] 061020 INFO S4 ==> S0-term:4[RequestVote] 061020 INFO S0-term:11-state:0 => 4[RPC-Vote-Over] 061308 LEAD S4-term:11-state:2[BeginHeart] 062475 INFO S3:term:11 ==> S2-term:4[Enter-RequestVote] 062476 INFO S3 ==> S2-term:4[RequestVote] 062476 INFO S2-term:11-state:0 => 3[RPC-Vote-Over] 063105 LEAD S4-term:11-state:2[BeginHeart] 063114 INFO S1:term:11 ==> S4-term:2[Enter-RequestVote] 063114 INFO S1 ==> S4-term:2[RequestVote] 063114 INFO S4-term:11-state:2 => 1[RPC-Vote-Over] 064020 INFO S0:term:11 ==> S4-term:4[Enter-RequestVote] 064020 INFO S0 ==> S4-term:4[RequestVote] 064020 INFO S4-term:11-state:2 => 0[RPC-Vote-Over] 064560 INFO S3:term:11 ==> S4-term:2[Enter-RequestVote] 064560 INFO S3 ==> S4-term:2[RequestVote] 064561 INFO S4-term:11-state:2 => 3[RPC-Vote-Over] 064620 LEAD S4-term:11-state:2[BeginHeart] 065309 INFO S3:term:11 ==> S0-term:5[Enter-RequestVote] 065314 INFO S3 ==> S0-term:5[RequestVote] 065315 INFO S0-term:11-state:0 => 3[RPC-Vote-Over] 065345 INFO S0:term:11 ==> S2-term:6[Enter-RequestVote] 065345 INFO S0 ==> S2-term:6[RequestVote] 065345 INFO S2-term:11-state:0 => 0[RPC-Vote-Over] 065898 INFO S4:term:11 ==> S0-term:7[Enter-RequestVote] 065898 INFO S4 ==> S0-term:7[RequestVote] 065898 INFO S0-term:11-state:0 => 4[RPC-Vote-Over] 066130 LEAD S4-term:11-state:2[BeginHeart] 067640 LEAD S4-term:11-state:2[BeginHeart] 068029 INFO S0:term:11 ==> S4-term:2[Enter-RequestVote] 068029 INFO S0 ==> S4-term:2[RequestVote] 068030 INFO S4-term:11-state:2 => 0[RPC-Vote-Over] 069037 INFO S2:term:11 ==> S4-term:2[Enter-RequestVote] 069038 INFO S2 ==> S4-term:2[RequestVote] 069038 INFO S4-term:11-state:2 => 2[RPC-Vote-Over] 069151 LEAD S4-term:11-state:2[BeginHeart] 069334 INFO S0:term:11 ==> S4-term:8[Enter-RequestVote] 069335 INFO S0 ==> S4-term:8[RequestVote] 069335 INFO S4-term:11-state:2 => 0[RPC-Vote-Over] 069613 INFO S4:term:11 ==> S3-term:2[Enter-RequestVote] 069613 INFO S4 ==> S3-term:2[RequestVote] 069613 INFO S3-term:11-state:0 => 4[RPC-Vote-Over] 070473 INFO S0:term:11 ==> S2-term:4[Enter-RequestVote] 070474 INFO S0 ==> S2-term:4[RequestVote] 070475 INFO S2-term:11-state:0 => 0[RPC-Vote-Over] 070665 LEAD S4-term:11-state:2[BeginHeart] 071747 INFO S2:term:11 ==> S3-term:2[Enter-RequestVote] 071748 INFO S2 ==> S3-term:2[RequestVote] 071749 INFO S3-term:11-state:0 => 2[RPC-Vote-Over] 072169 LEAD S4-term:11-state:2[BeginHeart] 073000 INFO S4command10[ReceiveLog] 073001 INFO S4:[{111} {234} {335} {488} {589}][Start-Before] 073001 INFO S4:[{111} {234} {335} {488} {589} {61110}][Start-After] 073001 LEAD S4-term:11-state:2[BeginHeart] 073002 INFO S0:state:0:term:11-ReceiveFrom-S4[AppendEntries] 073002 INFO S0:term:[{111} {234} {335} {488} {589}][Add-Before] 073005 INFO S0FromS4:[{61110}][Adding] 073005 INFO S0FromS4:[{111} {234} {335} {488} {589} {61110}][Add-After] 073006 INFO S1:state:0:term:11-ReceiveFrom-S4[AppendEntries] 073006 INFO S1:term:[{111} {234} {335} {488} {589}][Add-Before] 073006 INFO S1FromS4:[{61110}][Adding] 073006 INFO S1FromS4:[{111} {234} {335} {488} {589} {61110}][Add-After] 073007 INFO S4[Heartbeat] cnt,len(rf.peers) 35 073022 INFO S2:state:0:term:11-ReceiveFrom-S4[AppendEntries] 073022 INFO S2:term:[{111} {234} {335} {488} {589}][Add-Before] 073022 INFO S2FromS4:[{61110}][Adding] 073022 INFO S2FromS4:[{111} {234} {335} {488} {589} {61110}][Add-After] 073678 LEAD S4-term:11-state:2[BeginHeart] 073815 INFO S4:term:11 ==> S0-term:8[Enter-RequestVote] 073815 INFO S4 ==> S0-term:8[RequestVote] 073816 INFO S0-term:11-state:0 => 4[RPC-Vote-Over] 074216 INFO S3:term:11 ==> S4-term:4[Enter-RequestVote] 074217 INFO S3 ==> S4-term:4[RequestVote] 074217 INFO S4-term:11-state:2 => 3[RPC-Vote-Over] 074328 INFO S4:term:11 ==> S2-term:4[Enter-RequestVote] 074328 INFO S4 ==> S2-term:4[RequestVote] 074329 INFO S2-term:11-state:0 => 4[RPC-Vote-Over] 074448 INFO S2:term:11 ==> S0-term:2[Enter-RequestVote] 074448 INFO S2 ==> S0-term:2[RequestVote] 074448 INFO S0-term:11-state:0 => 2[RPC-Vote-Over] 074986 INFO S3:term:11 ==> S2-term:6[Enter-RequestVote] 074986 INFO S3 ==> S2-term:6[RequestVote] 074987 INFO S2-term:11-state:0 => 3[RPC-Vote-Over] 075181 LEAD S4-term:11-state:2[BeginHeart] 075327 INFO S2:term:11 ==> S0-term:8[Enter-RequestVote] 075327 INFO S2 ==> S0-term:8[RequestVote] 075328 INFO S0-term:11-state:0 => 2[RPC-Vote-Over] 075845 INFO S1:term:11 ==> S0-term:2[Enter-RequestVote] 075845 INFO S1 ==> S0-term:2[RequestVote] 075848 INFO S0-term:11-state:0 => 1[RPC-Vote-Over] 076691 LEAD S4-term:11-state:2[BeginHeart] 078192 LEAD S4-term:11-state:2[BeginHeart] 078750 INFO S3:term:11 ==> S0-term:4[Enter-RequestVote] 078750 INFO S3 ==> S0-term:4[RequestVote] 078750 INFO S0-term:11-state:0 => 3[RPC-Vote-Over] 079696 LEAD S4-term:11-state:2[BeginHeart] 079874 INFO S2:term:11 ==> S3-term:3[Enter-RequestVote] 079875 INFO S2 ==> S3-term:3[RequestVote] 079876 INFO S3-term:11-state:0 => 2[RPC-Vote-Over] 081197 LEAD S4-term:11-state:2[BeginHeart] 081264 INFO S1:term:11 ==> S3-term:3[Enter-RequestVote] 081264 INFO S1 ==> S3-term:3[RequestVote] 081265 INFO S3-term:11-state:0 => 1[RPC-Vote-Over] 081375 INFO S4:term:11 ==> S0-term:6[Enter-RequestVote] 081375 INFO S4 ==> S0-term:6[RequestVote] 081376 INFO S0-term:11-state:0 => 4[RPC-Vote-Over] 082017 INFO S4:term:11 ==> S2-term:6[Enter-RequestVote] 082017 INFO S4 ==> S2-term:6[RequestVote] 082018 INFO S2-term:11-state:0 => 4[RPC-Vote-Over] 082051 INFO S0:term:11 ==> S2-term:5[Enter-RequestVote] 082051 INFO S0 ==> S2-term:5[RequestVote] 082052 INFO S2-term:11-state:0 => 0[RPC-Vote-Over] 082887 LEAD S4-term:11-state:2[BeginHeart] 084393 LEAD S4-term:11-state:2[BeginHeart] 085900 LEAD S4-term:11-state:2[BeginHeart] 087402 LEAD S4-term:11-state:2[BeginHeart] 087655 INFO S1:term:11 ==> S0-term:6[Enter-RequestVote] 087656 INFO S1 ==> S0-term:6[RequestVote] 087657 INFO S0-term:11-state:0 => 1[RPC-Vote-Over] 088928 LEAD S4-term:11-state:2[BeginHeart] 089334 INFO S3:term:11 ==> S2-term:5[Enter-RequestVote] 089335 INFO S3 ==> S2-term:5[RequestVote] 089335 INFO S2-term:11-state:0 => 3[RPC-Vote-Over] 089791 INFO S0:term:11 ==> S2-term:7[Enter-RequestVote] 089791 INFO S0 ==> S2-term:7[RequestVote] 089792 INFO S2-term:11-state:0 => 0[RPC-Vote-Over] 090443 LEAD S4-term:11-state:2[BeginHeart] 091273 INFO S2:term:11 ==> S0-term:9[Enter-RequestVote] 091274 INFO S2 ==> S0-term:9[RequestVote] 091274 INFO S0-term:11-state:0 => 2[RPC-Vote-Over] 091532 INFO S0:term:11 ==> S2-term:3[Enter-RequestVote] 091532 INFO S0 ==> S2-term:3[RequestVote] 091532 INFO S2-term:11-state:0 => 0[RPC-Vote-Over] 091651 INFO S3:term:11 ==> S2-term:3[Enter-RequestVote] 091652 INFO S3 ==> S2-term:3[RequestVote] 091652 INFO S2-term:11-state:0 => 3[RPC-Vote-Over] 092029 LEAD S4-term:11-state:2[BeginHeart] 093068 INFO S4command10[ReceiveLog] 093068 INFO S4:[{111} {234} {335} {488} {589} {61110}][Start-Before] 093068 INFO S4:[{111} {234} {335} {488} {589} {61110} {71110}][Start-After] 093068 LEAD S4-term:11-state:2[BeginHeart] 093070 INFO S0:state:0:term:11-ReceiveFrom-S4[AppendEntries] 093070 INFO S0:term:[{111} {234} {335} {488} {589} {61110}][Add-Before] 093070 INFO S0FromS4:[{71110}][Adding] 093070 INFO S0FromS4:[{111} {234} {335} {488} {589} {61110} {71110}][Add-After] 093070 INFO S1:state:0:term:11-ReceiveFrom-S4[AppendEntries] 093071 INFO S1:term:[{111} {234} {335} {488} {589} {61110}][Add-Before] 093071 INFO S1FromS4:[{71110}][Adding] 093071 INFO S1FromS4:[{111} {234} {335} {488} {589} {61110} {71110}][Add-After] 093071 INFO S4[Heartbeat] cnt,len(rf.peers) 35 093071 INFO S2:state:0:term:11-ReceiveFrom-S4[AppendEntries] 093071 INFO S2:term:[{111} {234} {335} {488} {589} {61110}][Add-Before] 093071 INFO S2FromS4:[{71110}][Adding] 093071 INFO S2FromS4:[{111} {234} {335} {488} {589} {61110} {71110}][Add-After] 093341 INFO S4:term:11 ==> S0-term:5[Enter-RequestVote] 093341 INFO S4 ==> S0-term:5[RequestVote] 093341 INFO S0-term:11-state:0 => 4[RPC-Vote-Over] 093532 LEAD S4-term:11-state:2[BeginHeart] 093665 INFO S4:term:11 ==> S0-term:9[Enter-RequestVote] 093665 INFO S4 ==> S0-term:9[RequestVote] 093666 INFO S0-term:11-state:0 => 4[RPC-Vote-Over] 095038 LEAD S4-term:11-state:2[BeginHeart] 095039 INFO S1:term:11 ==> S0-term:9[Enter-RequestVote] 095039 INFO S1 ==> S0-term:9[RequestVote] 095039 INFO S0-term:11-state:0 => 1[RPC-Vote-Over] 096159 INFO S3:term:11 ==> S4-term:8[Enter-RequestVote] 096160 INFO S3 ==> S4-term:8[RequestVote] 096161 INFO S4-term:11-state:2 => 3[RPC-Vote-Over] 096549 LEAD S4-term:11-state:2[BeginHeart] 097435 INFO S2:term:11 ==> S0-term:5[Enter-RequestVote] 097435 INFO S2 ==> S0-term:5[RequestVote] 097436 INFO S0-term:11-state:0 => 2[RPC-Vote-Over] 097546 INFO S1:term:11 ==> S0-term:4[Enter-RequestVote] 097547 INFO S1 ==> S0-term:4[RequestVote] 097547 INFO S0-term:11-state:0 => 1[RPC-Vote-Over] 097991 INFO S0:term:11 ==> S2-term:2[Enter-RequestVote] 097992 INFO S0 ==> S2-term:2[RequestVote] 097992 INFO S2-term:11-state:0 => 0[RPC-Vote-Over] 098062 LEAD S4-term:11-state:2[BeginHeart] 098086 INFO S2:term:11 ==> S0-term:4[Enter-RequestVote] 098087 INFO S2 ==> S0-term:4[RequestVote] 098087 INFO S0-term:11-state:0 => 2[RPC-Vote-Over] 099568 LEAD S4-term:11-state:2[BeginHeart] 101084 LEAD S4-term:11-state:2[BeginHeart] 101391 INFO S3:term:11 ==> S0-term:8[Enter-RequestVote] 101391 INFO S3 ==> S0-term:8[RequestVote] 101392 INFO S0-term:11-state:0 => 3[RPC-Vote-Over] 102594 LEAD S4-term:11-state:2[BeginHeart] 104103 LEAD S4-term:11-state:2[BeginHeart] 105058 INFO S2:term:11 ==> S0-term:7[Enter-RequestVote] 105058 INFO S2 ==> S0-term:7[RequestVote] 105059 INFO S0-term:11-state:0 => 2[RPC-Vote-Over] 105621 LEAD S4-term:11-state:2[BeginHeart] 106396 INFO S3:term:11 ==> S0-term:7[Enter-RequestVote] 106397 INFO S3 ==> S0-term:7[RequestVote] 106398 INFO S0-term:11-state:0 => 3[RPC-Vote-Over] 107135 LEAD S4-term:11-state:2[BeginHeart] 107547 INFO S2:term:11 ==> S0-term:6[Enter-RequestVote] 107548 INFO S2 ==> S0-term:6[RequestVote] 107550 INFO S0-term:11-state:0 => 2[RPC-Vote-Over] 108036 INFO S3:term:11 ==> S0-term:6[Enter-RequestVote] 108036 INFO S3 ==> S0-term:6[RequestVote] 108037 INFO S0-term:11-state:0 => 3[RPC-Vote-Over] 108644 LEAD S4-term:11-state:2[BeginHeart] 110156 LEAD S4-term:11-state:2[BeginHeart] 110392 INFO S3:term:11 ==> S2-term:2[Enter-RequestVote] 110392 INFO S3 ==> S2-term:2[RequestVote] 110393 INFO S2-term:11-state:0 => 3[RPC-Vote-Over] 111658 LEAD S4-term:11-state:2[BeginHeart] 112401 INFO S1:term:11 ==> S0-term:7[Enter-RequestVote] 112401 INFO S1 ==> S0-term:7[RequestVote] 112401 INFO S0-term:11-state:0 => 1[RPC-Vote-Over] 113164 LEAD S4-term:11-state:2[BeginHeart] 113229 INFO S4command10[ReceiveLog] 113229 INFO S4:[{111} {234} {335} {488} {589} {61110} {71110}][Start-Before] 113229 INFO S4:[{111} {234} {335} {488} {589} {61110} {71110} {81110}][Start-After] 113230 LEAD S4-term:11-state:2[BeginHeart] 113231 INFO S0:state:0:term:11-ReceiveFrom-S4[AppendEntries] 113231 INFO S0:term:[{111} {234} {335} {488} {589} {61110} {71110}][Add-Before] 113231 INFO S0FromS4:[{81110}][Adding] 113231 INFO S0FromS4:[{111} {234} {335} {488} {589} {61110} {71110} {81110}][Add-After] 113232 INFO S1:state:0:term:11-ReceiveFrom-S4[AppendEntries] 113232 INFO S1:term:[{111} {234} {335} {488} {589} {61110} {71110}][Add-Before] 113232 INFO S1FromS4:[{81110}][Adding] 113232 INFO S1FromS4:[{111} {234} {335} {488} {589} {61110} {71110} {81110}][Add-After] 113232 INFO S4[Heartbeat] cnt,len(rf.peers) 35 113232 INFO S2:state:0:term:11-ReceiveFrom-S4[AppendEntries] 113232 INFO S2:term:[{111} {234} {335} {488} {589} {61110} {71110}][Add-Before] 113232 INFO S2FromS4:[{81110}][Adding] 113232 INFO S2FromS4:[{111} {234} {335} {488} {589} {61110} {71110} {81110}][Add-After] 114675 LEAD S4-term:11-state:2[BeginHeart] 116176 LEAD S4-term:11-state:2[BeginHeart] 117684 LEAD S4-term:11-state:2[BeginHeart] 119194 LEAD S4-term:11-state:2[BeginHeart] 120697 LEAD S4-term:11-state:2[BeginHeart] 122202 LEAD S4-term:11-state:2[BeginHeart] 123704 LEAD S4-term:11-state:2[BeginHeart] 125206 LEAD S4-term:11-state:2[BeginHeart] 126716 LEAD S4-term:11-state:2[BeginHeart] 128226 LEAD S4-term:11-state:2[BeginHeart] 129728 LEAD S4-term:11-state:2[BeginHeart] 131244 LEAD S4-term:11-state:2[BeginHeart] 132747 LEAD S4-term:11-state:2[BeginHeart] 133387 INFO S4command10[ReceiveLog] 133388 INFO S4:[{111} {234} {335} {488} {589} {61110} {71110} {81110}][Start-Before] 133389 INFO S4:[{111} {234} {335} {488} {589} {61110} {71110} {81110} {91110}][Start-After] 133389 LEAD S4-term:11-state:2[BeginHeart] 133396 INFO S1:state:0:term:11-ReceiveFrom-S4[AppendEntries] 133402 INFO S1:term:[{111} {234} {335} {488} {589} {61110} {71110} {81110}][Add-Before] 133403 INFO S1FromS4:[{91110}][Adding] 133403 INFO S1FromS4:[{111} {234} {335} {488} {589} {61110} {71110} {81110} {91110}][Add-After] 133398 INFO S2:state:0:term:11-ReceiveFrom-S4[AppendEntries] 133406 INFO S2:term:[{111} {234} {335} {488} {589} {61110} {71110} {81110}][Add-Before] 133406 INFO S2FromS4:[{91110}][Adding] 133406 INFO S2FromS4:[{111} {234} {335} {488} {589} {61110} {71110} {81110} {91110}][Add-After] 133407 INFO S4[Heartbeat] cnt,len(rf.peers) 35 133401 INFO S0:state:0:term:11-ReceiveFrom-S4[AppendEntries] 133408 INFO S0:term:[{111} {234} {335} {488} {589} {61110} {71110} {81110}][Add-Before] 133408 INFO S0FromS4:[{91110}][Adding] 133408 INFO S0FromS4:[{111} {234} {335} {488} {589} {61110} {71110} {81110} {91110}][Add-After] 134252 LEAD S4-term:11-state:2[BeginHeart] 135771 LEAD S4-term:11-state:2[BeginHeart] 137283 LEAD S4-term:11-state:2[BeginHeart] 138796 LEAD S4-term:11-state:2[BeginHeart] 140300 LEAD S4-term:11-state:2[BeginHeart] 141808 LEAD S4-term:11-state:2[BeginHeart] 143324 LEAD S4-term:11-state:2[BeginHeart] 144839 LEAD S4-term:11-state:2[BeginHeart] 146339 LEAD S4-term:11-state:2[BeginHeart] 147845 LEAD S4-term:11-state:2[BeginHeart] 149381 LEAD S4-term:11-state:2[BeginHeart] 150890 LEAD S4-term:11-state:2[BeginHeart] 152401 LEAD S4-term:11-state:2[BeginHeart] --- FAIL: TestBackupCopy2B (15.35s) config.go:616: [point2]one(10) failed to reach agreement FAIL exit status 1 FAIL 6.824/raft 15.356s