缘起

最近阅读 [云原生分布式存储基石：etcd深入解析] (杜军 , 2019.1)
本系列笔记拟采用golang练习之

raft分布式一致性算法

  1. 分布式存储系统通常会通过维护多个副本来进行容错，
  2. 以提高系统的可用性。
  3. 这就引出了分布式存储系统的核心问题——如何保证多个副本的一致性？
  5. Raft算法把问题分解成了四个子问题：
  6. 1. 领袖选举（leader election）、
  7. 2. 日志复制（log replication）、
  8. 3. 安全性（safety）
  9. 4. 成员关系变化（membership changes）
  10. 这几个子问题。
  12. 源码gitee地址：
  13. https://gitee.com/ioly/learning.gooop
  15. 原文链接：
  16. https://my.oschina.net/ioly/blog/5011356

目标

  • 根据raft协议，实现高可用分布式强一致的kv存储

子目标（Day 12）

  • 终于可以“点火”了，来到这里不容易 _
    • 添加大量诊断日志
    • 修复若干细节问题
  • 编写单元测试代码：
    • 启动多个raft节点
    • 检测Leader选举是否成功
    • 向节点1写入若干数据
    • 向节点2写入若干数据
    • 在节点3读取数据
    • kill掉当前Leader节点，观察重新选举是否成功

单元测试

tRaftKVServer_test.go，在本地启动四个raft节点进行功能性测试

  1. package server
  3. import (
  4.     "learning/gooop/etcd/raft/debug"
  5.     "learning/gooop/etcd/raft/logger"
  6.     "learning/gooop/etcd/raft/rpc"
  7.     "testing"
  8.     "time"
  9.     nrpc "net/rpc"
  10. )
  12. func Test_RaftKVServer(t *testing.T) {
  13.     fnAssertTrue := func(b bool, msg string) {
  14.         if !b {
  15.             t.Fatal(msg)
  16.         }
  17.     }
  19.     logger.Exclude("RaftRPCServer.Ping")
  20.     logger.Exclude("RaftRPCServer.Heartbeat")
  21.     logger.Exclude("feLeaderHeartbeat")
  22.     logger.Exclude(").Heartbeat")
  24.     // start node 1 to 3
  25.     _ = new(tRaftKVServer).BeginServeTCP("./node-01")
  26.     _ = new(tRaftKVServer).BeginServeTCP("./node-02")
  27.     _ = new(tRaftKVServer).BeginServeTCP("./node-03")
  28.     _ = new(tRaftKVServer).BeginServeTCP("./node-04")
  30.     // wait for up
  31.     time.Sleep(1 * time.Second)
  32.     // tRaftLSMImplement(node-01,1).HandleStateChanged, state=2
  33.     fnAssertTrue(logger.Count("HandleStateChanged, state=3") == 1, "expecting leader node")
  34.     t.Logf("passing electing, leader=%v", debug.LeaderNodeID)
  36.     // put into node-1
  37.     c1,_ := nrpc.Dial("tcp", "localhost:3331")
  38.     defer c1.Close()
  39.     kcmd := new(rpc.KVCmd)
  40.     kcmd.OPCode = rpc.KVPut
  41.     kcmd.Key = []byte("key-01")
  42.     kcmd.Content = []byte("content 01")
  43.     kret := new(rpc.KVRet)
  44.     err := c1.Call("KVStoreRPCServer.ExecuteKVCmd", kcmd, kret)
  45.     fnAssertTrue(err == nil && kret.Code == rpc.KVOk, "expecting KVOk")
  46.     t.Log("passing put into node-01")
  48.     // put into node-2
  49.     c2,_ := nrpc.Dial("tcp", "localhost:3332")
  50.     defer c2.Close()
  51.     kcmd.Key = []byte("key-02")
  52.     kcmd.Content = []byte("content 02")
  53.     err = c2.Call("KVStoreRPCServer.ExecuteKVCmd", kcmd, kret)
  54.     fnAssertTrue(err == nil && kret.Code == rpc.KVOk, "expecting KVOk")
  55.     t.Log("passing put into node-02")
  57.     // get from node-3
  58.     c3,_ := nrpc.Dial("tcp", "localhost:3333")
  59.     defer c3.Close()
  60.     kcmd.OPCode = rpc.KVGet
  61.     kcmd.Key = []byte("key-02")
  62.     kcmd.Content = nil
  63.     kret.Content = nil
  64.     kret.Key = nil
  65.     err = c3.Call("KVStoreRPCServer.ExecuteKVCmd", kcmd, kret)
  66.     fnAssertTrue(err == nil && kret.Code == rpc.KVOk, "expecting KVOk")
  67.     fnAssertTrue(kret.Content != nil && string(kret.Content) == "content 02", "expecting content 02")
  68.     t.Log("passing get from node-04")
  70.     // kill leader node
  71.     debug.KilledNodeID = debug.LeaderNodeID
  72.     time.Sleep(2 * time.Second)
  73.     fnAssertTrue(logger.Count("HandleStateChanged, state=3") == 2, "expecting reelecting leader node")
  74.     t.Logf("passing reelecting, leader=%v", debug.LeaderNodeID)
  76.     time.Sleep(2 * time.Second)
  77. }

测试输出

可以观察到5个passing，测试ok，重新选举的时延也在预期范围内，约700ms

  1. API server listening at: [::]:46709
  2. === RUN   Test_RaftKVServer
  3. 16:51:09.329792609 tRaftKVServer.BeginServeTCP, starting node-01, port=3331
  4. 16:51:09.329864584 tBrokenState(from=node-01, to=node-01@localhost:3331).whenStartThenBeginDial
  5. 16:51:09.329888978 tBrokenState(from=node-01, to=node-02@localhost:3332).whenStartThenBeginDial
  6. 16:51:09.329903778 tBrokenState(from=node-01, to=node-03@localhost:3333).whenStartThenBeginDial
  7. 16:51:09.329912231 tBrokenState(from=node-01, to=node-04@localhost:3334).whenStartThenBeginDial
  8. 16:51:09.329920585 tFollowerState(node-01).init
  9. 16:51:09.329926372 tFollowerState(node-01).initEventHandlers
  10. 16:51:09.329941794 tFollowerState(node-01).Start
  11. 16:51:09.330218761 tRaftKVServer.BeginServeTCP, service ready at port=3331
  12. 16:51:09.330549519 tFollowerState(node-01).whenStartThenBeginWatchLeaderTimeout, begin
  13. 16:51:09.333852427 tRaftKVServer.BeginServeTCP, starting node-02, port=3332
  14. 16:51:09.333893483 tBrokenState(from=node-02, to=node-01@localhost:3331).whenStartThenBeginDial
  15. 16:51:09.333925018 tBrokenState(from=node-02, to=node-02@localhost:3332).whenStartThenBeginDial
  16. 16:51:09.333955573 tBrokenState(from=node-02, to=node-03@localhost:3333).whenStartThenBeginDial
  17. 16:51:09.33397762 tBrokenState(from=node-02, to=node-04@localhost:3334).whenStartThenBeginDial
  18. 16:51:09.333990318 tFollowerState(node-02).init
  19. 16:51:09.333997643 tFollowerState(node-02).initEventHandlers
  20. 16:51:09.334015293 tFollowerState(node-02).Start
  21. 16:51:09.334089713 tRaftKVServer.BeginServeTCP, service ready at port=3332
  22. 16:51:09.334290701 tFollowerState(node-02).whenStartThenBeginWatchLeaderTimeout, begin
  23. 16:51:09.337803901 tRaftKVServer.BeginServeTCP, starting node-03, port=3333
  24. 16:51:09.337842816 tBrokenState(from=node-03, to=node-01@localhost:3331).whenStartThenBeginDial
  25. 16:51:09.337866444 tBrokenState(from=node-03, to=node-02@localhost:3332).whenStartThenBeginDial
  26. 16:51:09.337880481 tBrokenState(from=node-03, to=node-03@localhost:3333).whenStartThenBeginDial
  27. 16:51:09.337893773 tBrokenState(from=node-03, to=node-04@localhost:3334).whenStartThenBeginDial
  28. 16:51:09.337905184 tFollowerState(node-03).init
  29. 16:51:09.337912795 tFollowerState(node-03).initEventHandlers
  30. 16:51:09.337945677 tFollowerState(node-03).Start
  31. 16:51:09.338027861 tRaftKVServer.BeginServeTCP, service ready at port=3333
  32. 16:51:09.338089164 tFollowerState(node-03).whenStartThenBeginWatchLeaderTimeout, begin
  33. 16:51:09.341594205 tRaftKVServer.BeginServeTCP, starting node-04, port=3334
  34. 16:51:09.34163547 tBrokenState(from=node-04, to=node-01@localhost:3331).whenStartThenBeginDial
  35. 16:51:09.341679869 tBrokenState(from=node-04, to=node-02@localhost:3332).whenStartThenBeginDial
  36. 16:51:09.341694419 tBrokenState(from=node-04, to=node-03@localhost:3333).whenStartThenBeginDial
  37. 16:51:09.3417269 tBrokenState(from=node-04, to=node-04@localhost:3334).whenStartThenBeginDial
  38. 16:51:09.341741739 tFollowerState(node-04).init
  39. 16:51:09.341770267 tFollowerState(node-04).initEventHandlers
  40. 16:51:09.341793763 tFollowerState(node-04).Start
  41. 16:51:09.34213956 tRaftKVServer.BeginServeTCP, service ready at port=3334
  42. 16:51:09.342361058 tFollowerState(node-04).whenStartThenBeginWatchLeaderTimeout, begin
  43. 16:51:09.481747744 tBrokenState(from=node-01, to=node-04@localhost:3334).whenDialOKThenSetConn
  44. 16:51:09.481770012 tBrokenState(from=node-01, to=node-01@localhost:3331).whenDialOKThenSetConn
  45. 16:51:09.481771692 tBrokenState(from=node-01, to=node-04@localhost:3334).whenDialOKThenSwitchToConnectedState
  46. 16:51:09.481791046 tBrokenState(from=node-01, to=node-04@localhost:3334).beDisposing
  47. 16:51:09.481781787 tBrokenState(from=node-01, to=node-01@localhost:3331).whenDialOKThenSwitchToConnectedState
  48. 16:51:09.481807689 tBrokenState(from=node-01, to=node-01@localhost:3331).beDisposing
  49. 16:51:09.481747893 tBrokenState(from=node-01, to=node-02@localhost:3332).whenDialOKThenSetConn
  50. 16:51:09.481933708 tBrokenState(from=node-01, to=node-02@localhost:3332).whenDialOKThenSwitchToConnectedState
  51. 16:51:09.481955515 tBrokenState(from=node-01, to=node-02@localhost:3332).beDisposing
  52. 16:51:09.481747742 tBrokenState(from=node-01, to=node-03@localhost:3333).whenDialOKThenSetConn
  53. 16:51:09.481973577 tBrokenState(from=node-01, to=node-03@localhost:3333).whenDialOKThenSwitchToConnectedState
  54. 16:51:09.481980127 tBrokenState(from=node-01, to=node-03@localhost:3333).beDisposing
  55. 16:51:09.485403927 tBrokenState(from=node-02, to=node-01@localhost:3331).whenDialOKThenSetConn
  56. 16:51:09.485692968 tBrokenState(from=node-02, to=node-01@localhost:3331).whenDialOKThenSwitchToConnectedState
  57. 16:51:09.485707781 tBrokenState(from=node-02, to=node-01@localhost:3331).beDisposing
  58. 16:51:09.485462572 tBrokenState(from=node-02, to=node-02@localhost:3332).whenDialOKThenSetConn
  59. 16:51:09.485520127 tBrokenState(from=node-02, to=node-03@localhost:3333).whenDialOKThenSetConn
  60. 16:51:09.485723854 tBrokenState(from=node-02, to=node-02@localhost:3332).whenDialOKThenSwitchToConnectedState
  61. 16:51:09.485733962 tBrokenState(from=node-02, to=node-02@localhost:3332).beDisposing
  62. 16:51:09.485733667 tBrokenState(from=node-02, to=node-03@localhost:3333).whenDialOKThenSwitchToConnectedState
  63. 16:51:09.485749968 tBrokenState(from=node-02, to=node-03@localhost:3333).beDisposing
  64. 16:51:09.485474638 tBrokenState(from=node-02, to=node-04@localhost:3334).whenDialOKThenSetConn
  65. 16:51:09.485780798 tBrokenState(from=node-02, to=node-04@localhost:3334).whenDialOKThenSwitchToConnectedState
  66. 16:51:09.485787997 tBrokenState(from=node-02, to=node-04@localhost:3334).beDisposing
  67. 16:51:09.489019463 tBrokenState(from=node-03, to=node-02@localhost:3332).whenDialOKThenSetConn
  68. 16:51:09.489141518 tBrokenState(from=node-03, to=node-02@localhost:3332).whenDialOKThenSwitchToConnectedState
  69. 16:51:09.489165663 tBrokenState(from=node-03, to=node-02@localhost:3332).beDisposing
  70. 16:51:09.489021724 tBrokenState(from=node-03, to=node-03@localhost:3333).whenDialOKThenSetConn
  71. 16:51:09.489191277 tBrokenState(from=node-03, to=node-03@localhost:3333).whenDialOKThenSwitchToConnectedState
  72. 16:51:09.489199495 tBrokenState(from=node-03, to=node-03@localhost:3333).beDisposing
  73. 16:51:09.489021727 tBrokenState(from=node-03, to=node-04@localhost:3334).whenDialOKThenSetConn
  74. 16:51:09.489019621 tBrokenState(from=node-03, to=node-01@localhost:3331).whenDialOKThenSetConn
  75. 16:51:09.489217044 tBrokenState(from=node-03, to=node-04@localhost:3334).whenDialOKThenSwitchToConnectedState
  76. 16:51:09.489222223 tBrokenState(from=node-03, to=node-01@localhost:3331).whenDialOKThenSwitchToConnectedState
  77. 16:51:09.489234054 tBrokenState(from=node-03, to=node-01@localhost:3331).beDisposing
  78. 16:51:09.489225544 tBrokenState(from=node-03, to=node-04@localhost:3334).beDisposing
  79. 16:51:09.492701804 tBrokenState(from=node-04, to=node-01@localhost:3331).whenDialOKThenSetConn
  80. 16:51:09.492720605 tBrokenState(from=node-04, to=node-01@localhost:3331).whenDialOKThenSwitchToConnectedState
  81. 16:51:09.492728029 tBrokenState(from=node-04, to=node-01@localhost:3331).beDisposing
  82. 16:51:09.492702391 tBrokenState(from=node-04, to=node-02@localhost:3332).whenDialOKThenSetConn
  83. 16:51:09.492764 tBrokenState(from=node-04, to=node-02@localhost:3332).whenDialOKThenSwitchToConnectedState
  84. 16:51:09.492771402 tBrokenState(from=node-04, to=node-02@localhost:3332).beDisposing
  85. 16:51:09.492778635 tBrokenState(from=node-04, to=node-04@localhost:3334).whenDialOKThenSetConn
  86. 16:51:09.492791174 tBrokenState(from=node-04, to=node-04@localhost:3334).whenDialOKThenSwitchToConnectedState
  87. 16:51:09.492799699 tBrokenState(from=node-04, to=node-04@localhost:3334).beDisposing
  88. 16:51:09.492844734 tBrokenState(from=node-04, to=node-03@localhost:3333).whenDialOKThenSetConn
  89. 16:51:09.492855638 tBrokenState(from=node-04, to=node-03@localhost:3333).whenDialOKThenSwitchToConnectedState
  90. 16:51:09.492863777 tBrokenState(from=node-04, to=node-03@localhost:3333).beDisposing
  91. 16:51:10.238765817 tFollowerState(node-01).whenLeaderHeartbeatTimeoutThenSwitchToCandidateState, term=0
  92. 16:51:10.238808459 tFollowerState(node-01).feDisposing, disposed=true
  93. 16:51:10.238885964 tRaftLSMImplement(node-01,1).HandleStateChanged, state=2
  94. 16:51:10.238892892 tRaftLSMImplement(node-01,1).meStateChanged, 2
  95. 16:51:10.238897706 tCandidateState(node-01).whenStartThenAskForVote
  96. 16:51:10.238902038 tCandidateState(node-01).ceAskingForVote, term=1
  97. 16:51:10.238907133 tCandidateState(node-01).ceAskingForVote, vote to myself
  98. 16:51:10.2389139 tCandidateState(node-01).ceAskingForVote, ticketCount=1
  99. 16:51:10.238920737 tCandidateState(node-01).whenAskingForVoteThenWatchElectionTimeout
  100. 16:51:10.239208777 tFollowerState(node-04).feCandidateRequestVote, reset last vote
  101. 16:51:10.239233375 tFollowerState(node-04).feVoteToCandidate, candidate=node-01, term=1
  102. 16:51:10.239261011 tFollowerState(node-02).feCandidateRequestVote, reset last vote
  103. 16:51:10.239273156 tFollowerState(node-02).feVoteToCandidate, candidate=node-01, term=1
  104. 16:51:10.239288823 tRaftLSMImplement(node-04,1).RequestVote, cmd=&{node-01 1 0 0}, ret=&{0 1}, err=<nil>
  105. 16:51:10.239303552 RaftRPCServer.RequestVote, cmd=&{node-01 1 0 0}, ret=&{0 1}, e=<nil>
  106. 16:51:10.239343533 tRaftLSMImplement(node-02,1).RequestVote, cmd=&{node-01 1 0 0}, ret=&{0 1}, err=<nil>
  107. 16:51:10.239390716 tFollowerState(node-03).feCandidateRequestVote, reset last vote
  108. 16:51:10.239431327 tFollowerState(node-03).feVoteToCandidate, candidate=node-01, term=1
  109. 16:51:10.239442927 tCandidateState(node-01).handleRequestVoteOK, peer=node-04, term=1
  110. 16:51:10.239455262 tCandidateState(node-01).ceReceiveTicket, mTicketCount=2
  111. 16:51:10.239463079 tCandidateState(node-01).whenReceiveTicketThenCheckTicketCount
  112. 16:51:10.239473836 tRaftLSMImplement(node-03,1).RequestVote, cmd=&{node-01 1 0 0}, ret=&{0 1}, err=<nil>
  113. 16:51:10.239488078 RaftRPCServer.RequestVote, cmd=&{node-01 1 0 0}, ret=&{0 1}, e=<nil>
  114. 16:51:10.239412948 RaftRPCServer.RequestVote, cmd=&{node-01 1 0 0}, ret=&{0 1}, e=<nil>
  115. 16:51:10.239578689 tCandidateState(node-01).handleRequestVoteOK, peer=node-03, term=1
  116. 16:51:10.239593183 tCandidateState(node-01).ceReceiveTicket, mTicketCount=3
  117. 16:51:10.239601334 tCandidateState(node-01).whenReceiveTicketThenCheckTicketCount
  118. 16:51:10.239629478 tCandidateState(node-01).whenWinningTheVoteThenSwitchToLeader
  119. 16:51:10.239639823 tCandidateState(node-01).ceDisposing, mTicketCount=0
  120. 16:51:10.239696198 tCandidateState(node-01).ceDisposing, mDisposedFlag=true
  121. 16:51:10.239752502 tRaftLSMImplement(node-01,2).HandleStateChanged, state=3
  122. 16:51:10.239764172 tRaftLSMImplement(node-01,2).meStateChanged, 3
  123.     tRaftKVServer_test.go:34: passing electing, leader=node-01
  124. 16:51:10.366875446 tRaftLSMImplement(node-02,1).AppendLog, cmd=&{node-01 1 0xc0004961c0}, ret=&{0 1 0 0}, err=<nil>
  125. 16:51:10.366931566 RaftRPCServer.AppendLog, cmd=&{node-01 1 0xc0004961c0}, ret=&{0 1 0 0}, e=<nil>
  126. 16:51:10.370788589 tRaftLSMImplement(node-03,1).AppendLog, cmd=&{node-01 1 0xc00043c5c0}, ret=&{0 1 0 0}, err=<nil>
  127. 16:51:10.370829944 RaftRPCServer.AppendLog, cmd=&{node-01 1 0xc00043c5c0}, ret=&{0 1 0 0}, e=<nil>
  128. 16:51:10.374865684 tRaftLSMImplement(node-04,1).AppendLog, cmd=&{node-01 1 0xc000496580}, ret=&{0 1 0 0}, err=<nil>
  129. 16:51:10.374904568 RaftRPCServer.AppendLog, cmd=&{node-01 1 0xc000496580}, ret=&{0 1 0 0}, e=<nil>
  130. 16:51:10.375163435 tRaftLSMImplement(node-02,1).CommitLog, cmd=&{node-01 1 1}, ret=&{1}, err=<nil>
  131. 16:51:10.375176692 RaftRPCServer.CommitLog, cmd=&{node-01 1 1}, ret=&{1}, e=<nil>
  132. 16:51:10.375444843 tRaftLSMImplement(node-03,1).CommitLog, cmd=&{node-01 1 1}, ret=&{1}, err=<nil>
  133. 16:51:10.375512284 RaftRPCServer.CommitLog, cmd=&{node-01 1 1}, ret=&{1}, e=<nil>
  134. 16:51:10.375797446 tRaftLSMImplement(node-04,1).CommitLog, cmd=&{node-01 1 1}, ret=&{1}, err=<nil>
  135. 16:51:10.375859612 RaftRPCServer.CommitLog, cmd=&{node-01 1 1}, ret=&{1}, e=<nil>
  136. 16:51:10.379551174 tRaftLSMImplement(node-01,3).ExecuteKVCmd, cmd=&{1 [107 101 121 45 48 49] [99 111 110 116 101 110 116 32 48 49]}, ret=&{0 [] []}, err=<nil>
  137. 16:51:10.379577233 KVStoreRPCServer.ExecuteKVCmd, cmd=&{1 [107 101 121 45 48 49] [99 111 110 116 101 110 116 32 48 49]}, ret=&{0 [] []}, e=<nil>
  138.     tRaftKVServer_test.go:46: passing put into node-01
  139. 16:51:10.387761245 tRaftLSMImplement(node-02,1).AppendLog, cmd=&{node-01 1 0xc000496d80}, ret=&{0 1 0 0}, err=<nil>
  140. 16:51:10.387777654 RaftRPCServer.AppendLog, cmd=&{node-01 1 0xc000496d80}, ret=&{0 1 0 0}, e=<nil>
  141. 16:51:10.391348874 tRaftLSMImplement(node-03,1).AppendLog, cmd=&{node-01 1 0xc000496e40}, ret=&{0 1 0 0}, err=<nil>
  142. 16:51:10.391387707 RaftRPCServer.AppendLog, cmd=&{node-01 1 0xc000496e40}, ret=&{0 1 0 0}, e=<nil>
  143. 16:51:10.395137344 tRaftLSMImplement(node-04,1).AppendLog, cmd=&{node-01 1 0xc000496f00}, ret=&{0 1 0 0}, err=<nil>
  144. 16:51:10.395155304 RaftRPCServer.AppendLog, cmd=&{node-01 1 0xc000496f00}, ret=&{0 1 0 0}, e=<nil>
  145. 16:51:10.395343688 tRaftLSMImplement(node-02,1).CommitLog, cmd=&{node-01 1 1}, ret=&{1}, err=<nil>
  146. 16:51:10.395357145 RaftRPCServer.CommitLog, cmd=&{node-01 1 1}, ret=&{1}, e=<nil>
  147. 16:51:10.395495604 tRaftLSMImplement(node-03,1).CommitLog, cmd=&{node-01 1 1}, ret=&{1}, err=<nil>
  148. 16:51:10.3955081 RaftRPCServer.CommitLog, cmd=&{node-01 1 1}, ret=&{1}, e=<nil>
  149. 16:51:10.395667457 tRaftLSMImplement(node-04,1).CommitLog, cmd=&{node-01 1 1}, ret=&{1}, err=<nil>
  150. 16:51:10.395688067 RaftRPCServer.CommitLog, cmd=&{node-01 1 1}, ret=&{1}, e=<nil>
  151. 16:51:10.399174064 tRaftLSMImplement(node-01,3).ExecuteKVCmd, cmd=&{1 [107 101 121 45 48 50] [99 111 110 116 101 110 116 32 48 50]}, ret=&{0 [] []}, err=<nil>
  152. 16:51:10.399217896 KVStoreRPCServer.ExecuteKVCmd, cmd=&{1 [107 101 121 45 48 50] [99 111 110 116 101 110 116 32 48 50]}, ret=&{0 [] []}, e=<nil>
  153. 16:51:10.399373787 tRaftLSMImplement(node-02,1).ExecuteKVCmd, cmd=&{1 [107 101 121 45 48 50] [99 111 110 116 101 110 116 32 48 50]}, ret=&{0 [] []}, err=<nil>
  154. 16:51:10.399397275 KVStoreRPCServer.ExecuteKVCmd, cmd=&{1 [107 101 121 45 48 50] [99 111 110 116 101 110 116 32 48 50]}, ret=&{0 [] []}, e=<nil>
  155.     tRaftKVServer_test.go:55: passing put into node-02
  156. 16:51:10.400256236 tRaftLSMImplement(node-01,3).ExecuteKVCmd, cmd=&{0 [107 101 121 45 48 50] []}, ret=&{0 [] [99 111 110 116 101 110 116 32 48 50]}, err=<nil>
  157. 16:51:10.400298117 KVStoreRPCServer.ExecuteKVCmd, cmd=&{0 [107 101 121 45 48 50] []}, ret=&{0 [] [99 111 110 116 101 110 116 32 48 50]}, e=<nil>
  158. 16:51:10.400639059 tRaftLSMImplement(node-03,1).ExecuteKVCmd, cmd=&{0 [107 101 121 45 48 50] []}, ret=&{0 [] [99 111 110 116 101 110 116 32 48 50]}, err=<nil>
  159. 16:51:10.400663438 KVStoreRPCServer.ExecuteKVCmd, cmd=&{0 [107 101 121 45 48 50] []}, ret=&{0 [] [99 111 110 116 101 110 116 32 48 50]}, e=<nil>
  160.     tRaftKVServer_test.go:68: passing get from node-04
  161. 16:51:10.431051964 tRaftKVServer.whenStartThenWatchDebugKill, killing node-01
  162. 2021/04/07 16:51:10 rpc.Serve: accept:accept tcp [::]:3331: use of closed network connection
  163. 16:51:11.19072568 tFollowerState(node-02).whenLeaderHeartbeatTimeoutThenSwitchToCandidateState, term=1
  164. 16:51:11.190755031 tFollowerState(node-02).feDisposing, disposed=true
  165. 16:51:11.190856259 tRaftLSMImplement(node-02,1).HandleStateChanged, state=2
  166. 16:51:11.190885201 tRaftLSMImplement(node-02,1).meStateChanged, 2
  167. 16:51:11.190898966 tCandidateState(node-02).whenStartThenAskForVote
  168. 16:51:11.190908485 tCandidateState(node-02).ceAskingForVote, term=2
  169. 16:51:11.1909172 tCandidateState(node-02).ceAskingForVote, vote to myself
  170. 16:51:11.19093098 tCandidateState(node-02).ceAskingForVote, ticketCount=1
  171. 16:51:11.190944035 tCandidateState(node-02).whenAskingForVoteThenWatchElectionTimeout
  172. 16:51:11.191694746 tFollowerState(node-03).feVoteToCandidate, candidate=node-02, term=2
  173. 16:51:11.191724769 tRaftLSMImplement(node-01,3).RequestVote, cmd=&{node-02 2 0 0}, ret=&{0 0}, err=<nil>
  174. 16:51:11.192305012 RaftRPCServer.RequestVote, cmd=&{node-02 2 0 0}, ret=&{0 0}, e=<nil>
  175. 16:51:11.192223342 tFollowerState(node-04).feCandidateRequestVote, reset last vote
  176. 16:51:11.192464666 tFollowerState(node-04).feVoteToCandidate, candidate=node-02, term=2
  177. 16:51:11.19253627 tRaftLSMImplement(node-04,1).RequestVote, cmd=&{node-02 2 0 0}, ret=&{0 2}, err=<nil>
  178. 16:51:11.192208542 tRaftLSMImplement(node-03,1).RequestVote, cmd=&{node-02 2 0 0}, ret=&{0 2}, err=<nil>
  179. 16:51:11.192613581 tCandidateState(node-02).handleRequestVoteOK, peer=node-01, term=2
  180. 16:51:11.192627483 tCandidateState(node-02).ceReceiveTicket, mTicketCount=2
  181. 16:51:11.192634994 tCandidateState(node-02).whenReceiveTicketThenCheckTicketCount
  182. 16:51:11.19260158 RaftRPCServer.RequestVote, cmd=&{node-02 2 0 0}, ret=&{0 2}, e=<nil>
  183. 16:51:11.192764937 tCandidateState(node-02).handleRequestVoteOK, peer=node-03, term=2
  184. 16:51:11.192778197 tCandidateState(node-02).ceReceiveTicket, mTicketCount=3
  185. 16:51:11.192784986 tCandidateState(node-02).whenReceiveTicketThenCheckTicketCount
  186. 16:51:11.192806525 tCandidateState(node-02).whenWinningTheVoteThenSwitchToLeader
  187. 16:51:11.192815315 tCandidateState(node-02).ceDisposing, mTicketCount=0
  188. 16:51:11.192836837 tCandidateState(node-02).ceDisposing, mDisposedFlag=true
  189. 16:51:11.192853274 tRaftLSMImplement(node-02,2).HandleStateChanged, state=3
  190. 16:51:11.192863098 tRaftLSMImplement(node-02,2).meStateChanged, 3
  191. 16:51:11.193007386 tFollowerState(node-01).init
  192. 16:51:11.193017792 tFollowerState(node-01).initEventHandlers
  193. 16:51:11.193037127 tRaftLSMImplement(node-01,3).HandleStateChanged, state=1
  194. 16:51:11.193046674 tRaftLSMImplement(node-01,3).meStateChanged, 1
  195. 16:51:11.193053504 tFollowerState(node-01).Start
  196. 16:51:11.19313721 tFollowerState(node-01).whenStartThenBeginWatchLeaderTimeout, begin
  197. 16:51:11.192549822 RaftRPCServer.RequestVote, cmd=&{node-02 2 0 0}, ret=&{0 2}, e=<nil>
  198.     tRaftKVServer_test.go:74: passing reelecting, leader=node-02
  199. --- PASS: Test_RaftKVServer (5.09s)
  200. PASS
  202. Debugger finished with exit code 0

debug.go

支持单元测试的上下文变量

  1. package debug
  3. // KilledNodeID was used to detect whether a node should stop wroking, written by unit test code
  4. var KilledNodeID = ""
  6. // LeaderNodeID presents current leader node's ID, written by lsm/tLeaderState
  7. var LeaderNodeID = ""

（未完待续）