Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

1.3.9 jraft 下2个节点时无法选主 #810

Closed
funky-eyes opened this issue Apr 10, 2022 · 22 comments · Fixed by #812
Closed

1.3.9 jraft 下2个节点时无法选主 #810

funky-eyes opened this issue Apr 10, 2022 · 22 comments · Fixed by #812
Assignees
@fengjiachun

Comments

@funky-eyes
Copy link
Contributor

Describe the bug

A clear and concise description of what the bug is.

Expected behavior

20:01:48.270  INFO --- [   JRaft-RPC-Processor-10] com.alipay.sofa.jraft.core.Replicator    : Replicator=Replicator [state=Created, statInfo=<running=null, firstLogIndex=0, lastLogIncluded=0, lastLogIndex=0, lastTermIncluded=0>, peerId=192.168.31.181:9093, type=Follower]@192.168.31.181:9093 is started
20:01:48.283  INFO --- [aft-FSMCaller-Disruptor-0] io.seata.server.raft.RaftStateMachine    : session map: 0 
20:01:48.283  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStart: term=55.
20:01:49.273 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:01:50.275 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:01:50.275 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:01:50.276  WARN --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> steps down when alive nodes don't satisfy quorum, term=55, deadNodes=192.168.31.181:9091,192.168.31.181:9093, conf=192.168.31.181:9091,192.168.31.181:9092,192.168.31.181:9093.
20:01:50.276  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStop: status=Status[ERAFTTIMEDOUT<10001>: Majority of the group dies: 2/3].
20:01:50.276  INFO --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.Replicator    : Replicator Replicator [state=Probe, statInfo=<running=IDLE, firstLogIndex=1207, lastLogIncluded=0, lastLogIndex=1207, lastTermIncluded=0>, peerId=192.168.31.181:9093, type=Follower] is going to quit
20:01:51.560  INFO --- [ault-executor-4-thread-15] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received PreVoteRequest from 192.168.31.181:9093, term=56, currTerm=55, granted=true, requestLastLogId=LogId [index=1207, term=55], lastLogId=LogId [index=1207, term=55].
20:01:52.562  INFO --- [ault-executor-4-thread-13] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received RequestVoteRequest from 192.168.31.181:9093, term=56, currTerm=55.
20:01:52.565  WARN --- [ault-executor-4-thread-13] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:01:52.565  INFO --- [ault-executor-4-thread-13] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=56, votedFor=0.0.0.0:0, cost time=2 ms
20:01:52.567  WARN --- [ault-executor-4-thread-13] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:01:52.567  INFO --- [ault-executor-4-thread-13] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=56, votedFor=192.168.31.181:9093, cost time=2 ms
20:01:53.563  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onStartFollowing: LeaderChangeContext [leaderId=192.168.31.181:9093, term=56, status=Status[ENEWLEADER<10011>: Follower receives message from new leader with the same term.]].
20:01:55.892  INFO --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> term 56 start preVote.
20:01:55.892  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onStopFollowing: LeaderChangeContext [leaderId=192.168.31.181:9093, term=56, status=Status[ERAFTTIMEDOUT<10001>: Lost connection from leader 192.168.31.181:9093.]].
20:01:56.894 ERROR --- [ATA/192.168.31.181:9092>0] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:01:56.894  WARN --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> channel init failed, address=192.168.31.181:9091.

Actual behavior

Steps to reproduce

Minimal yet complete reproducer code (or GitHub URL to code)

Environment

  • SOFAJRaft version: 1.3.9
  • JVM version (e.g. java -version): 1.8
  • OS version (e.g. uname -a): windows
  • Maven version: 3.6.2
  • IDE version: 2021.02
@killme2008
Copy link
Contributor

这日志很明显了

 onStopFollowing: LeaderChangeContext [leaderId=192.168.31.181:9093, term=56, status=Status[ERAFTTIMEDOUT<10001>: Lost connection from leader 192.168.31.181:9093.]].

网络问题

@funky-eyes
Copy link
Contributor Author

这日志很明显了

 onStopFollowing: LeaderChangeContext [leaderId=192.168.31.181:9093, term=56, status=Status[ERAFTTIMEDOUT<10001>: Lost connection from leader 192.168.31.181:9093.]].

网络问题

你可以看下ip，都是一台机器，降级到1.3.7或以下就没问题

@funky-eyes
Copy link
Contributor Author

这日志很明显了

 onStopFollowing: LeaderChangeContext [leaderId=192.168.31.181:9093, term=56, status=Status[ERAFTTIMEDOUT<10001>: Lost connection from leader 192.168.31.181:9093.]].

网络问题

这是我自己故意kill leader触发重选举，不止一个用户出现这种情况了，五群里有个哥们跟我一样

@killme2008
Copy link
Contributor

这是你的所有日志了？ 目前给出的日志说明不了什么。

另外在 windows 上的行为，我们不保证正确性啊，没有在 windows 系统验证。

@killme2008
Copy link
Contributor

我看日志是 192.168.31.181:9091 先挂，然后选举出来是 192.168.31.181:9093，接下来 192.168.31.181:9093 也失去连接了，当然选不出来了，因为 2/3 都挂了。

@funky-eyes
Copy link
Contributor Author

我看日志是 192.168.31.181:9091 先挂，然后选举出来是 192.168.31.181:9093，接下来 192.168.31.181:9093 也失去连接了，当然选不出来了，因为 2/3 都挂了。

没有都挂，或者2台，日志很明显就是已经选出主了，结果又说达不到可用的数量，1.3.7就没问题，要不要录个视频给你？windows不保证正确性？raft下跟平台有什么关系，raft算法的结果应该是具备一致性的，你看sofastack五群吧，没必要给你整个莫须有的问题出来

@funky-eyes
Copy link
Contributor Author

另外将electionTimeoutMs拉长可以缓解，怀疑高版本下是升级了什么依赖，或者你们改动了什么，导致轻微网络抖动就出现重选举，或心跳断开，我本机其实本身就不存在什么网络问题，如果你觉得是我写的有问题，不妨自己在高版本下跑一下官方的计数器那个demo

@funky-eyes
Copy link
Contributor Author

@killme2008 #781 老哥，是不是这个issue的问题引发的？

@killme2008
Copy link
Contributor

killme2008 commented Apr 11, 2022 •
edited
Loading

raft 算法跟平台没关系，但是实现是有关系的，我们这个实现只在 linux/mac 下做过正确性验证（jepsen）， windows 上由于一些文件 api 语义的差异（比如日志里那个 warn 你也看到了），我们是不保证的。

其次，目前单纯从你发过来的日志，只能看到就是网络断开了，至于为什么，需要你提供更多日志或者自行分析

最后，跟 #781 可能有关系，如果你有日志佐证后续心跳没有发了的话。

@killme2008
Copy link
Contributor

看了下 release note，从 1.3.7 到 1.3.9 并没有什么特别大的修改，跟网络相关的可能是 bolt 做了升级，你可以单纯在 1.3.9 降级下 bolt 看看。

@funky-eyes
Copy link
Contributor Author

手动下线leader节点

20:48:21.292  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStart: term=17.
20:48:23.276  INFO --- [SpringContextShutdownHook] i.s.core.rpc.netty.NettyServerBootstrap  : Shutting server down, the listen port: 8091
20:48:23.607  INFO --- [aft-FSMCaller-Disruptor-0] io.seata.server.raft.RaftStateMachine    : globalSessionMap size :0, branchSessionMap map size: 0
20:48:23.624  WARN --- [ JRaft-Closure-Executor-5] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9091\snapshot\temp on windows.
20:48:23.624  INFO --- [ JRaft-Closure-Executor-5] c.a.s.j.s.s.local.LocalSnapshotStorage   : Deleting snapshot sessionStore\9091\snapshot\snapshot_83.
20:48:23.624  INFO --- [ JRaft-Closure-Executor-5] c.a.s.j.s.s.local.LocalSnapshotStorage   : Renaming sessionStore\9091\snapshot\temp to sessionStore\9091\snapshot\snapshot_83.
20:48:23.625  WARN --- [ JRaft-Closure-Executor-5] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9091\snapshot on windows.
20:48:23.626  INFO --- [ JRaft-Closure-Executor-6] c.a.s.j.storage.impl.RocksDBLogStorage   : Truncated prefix logs in data path: sessionStore\9091\log from log index 80 to 80, cost 0 ms.
20:48:26.283  INFO --- [SpringContextShutdownHook] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9091> shutdown, currTerm=17 state=STATE_LEADER.
20:48:26.285  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStop: status=Status[ESHUTDOWN<1007>: Raft node is going to quit.].
20:48:26.285  INFO --- [SpringContextShutdownHook] com.alipay.sofa.jraft.core.Replicator    : Replicator Replicator [state=Replicate, statInfo=<running=IDLE, firstLogIndex=83, lastLogIncluded=0, lastLogIndex=83, lastTermIncluded=0>, peerId=192.168.31.181:9093, type=Follower] is going to quit
20:48:26.286  INFO --- [vent-executor-16-thread-1] c.a.sofa.jraft.rpc.RpcRequestProcessor   : Destroyed peer request context for SEATA/PeerPair[192.168.31.181:9091 -> 192.168.31.181:9093]
20:48:26.287  INFO --- [vent-executor-16-thread-1] c.a.sofa.jraft.rpc.RpcRequestProcessor   : Destroyed peer request context for SEATA/PeerPair[192.168.31.181:9091 -> 192.168.31.181:9092]
20:48:26.290  WARN --- [ JRaft-Closure-Executor-6] com.alipay.sofa.jraft.core.Replicator    : Replicator Replicator [state=Replicate, statInfo=<running=IDLE, firstLogIndex=83, lastLogIncluded=0, lastLogIndex=83, lastTermIncluded=0>, peerId=192.168.31.181:9092, type=Follower] stops sending entries.
20:48:26.292  INFO --- [    JRaft-RPC-Processor-8] com.alipay.sofa.jraft.core.Replicator    : Replicator Replicator [state=Replicate, statInfo=<running=IDLE, firstLogIndex=83, lastLogIncluded=0, lastLogIndex=83, lastTermIncluded=0>, peerId=192.168.31.181:9092, type=Follower] is going to quit
20:48:26.302  WARN --- [SpringContextShutdownHook] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9091\raft_meta on windows.
20:48:26.302  INFO --- [SpringContextShutdownHook] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9091\raft_meta, term=17, votedFor=192.168.31.181:9091, cost time=12 ms
20:48:26.302  WARN --- [SpringContextShutdownHook] com.alipay.sofa.jraft.util.ThreadId      : ThreadId: Replicator [state=Destroyed, statInfo=<running=IDLE, firstLogIndex=83, lastLogIncluded=0, lastLogIndex=83, lastTermIncluded=0>, peerId=192.168.31.181:9092, type=Follower] already destroyed, ignore error code: 1001
20:48:26.302  INFO --- [SpringContextShutdownHook] c.alipay.sofa.jraft.core.FSMCallerImpl   : Shutting down FSMCaller...
20:48:26.302  INFO --- [SpringContextShutdownHook] c.a.sofa.jraft.core.StateMachineAdapter  : onShutdown.
20:48:26.305  INFO --- [Raft-NodeImpl-Disruptor-0] com.alipay.sofa.jraft.core.NodeImpl      : The number of active nodes decrement to 0.
20:48:26.306  INFO --- [    JRaft-RPC-Processor-8] c.a.s.jraft.util.LogThreadPoolExecutor   : ThreadPool is terminated: JRaft-RPC-Processor, com.alipay.sofa.jraft.util.MetricThreadPoolExecutor@2a7b4bcb[Shutting down, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 9].
20:48:26.306  INFO --- [-Node-ScheduleThreadPool9] c.a.s.j.u.LogScheduledThreadPoolExecutor : ThreadPool is terminated: JRaft-Node-ScheduleThreadPool, com.alipay.sofa.jraft.util.MetricScheduledThreadPoolExecutor@88a7589[Shutting down, pool size = 13, active threads = 0, queued tasks = 0, completed tasks = 48].
20:48:26.306  INFO --- [SpringContextShutdownHook] c.alipay.sofa.jraft.util.RepeatedTimer   : Destroy timer: RepeatedTimer{timeout=null, stopped=true, running=false, destroyed=true, invoking=false, timeoutMs=2000, name='JRaft-ElectionTimer-<SEATA/192.168.31.181:9091>'}.
20:48:26.307  INFO --- [SpringContextShutdownHook] c.alipay.sofa.jraft.util.RepeatedTimer   : Destroy timer: RepeatedTimer{timeout=null, stopped=true, running=false, destroyed=true, invoking=false, timeoutMs=2000, name='JRaft-VoteTimer-<SEATA/192.168.31.181:9091>'}.
20:48:26.307  INFO --- [SpringContextShutdownHook] c.alipay.sofa.jraft.util.RepeatedTimer   : Destroy timer: RepeatedTimer{timeout=null, stopped=true, running=false, destroyed=true, invoking=false, timeoutMs=1000, name='JRaft-StepDownTimer-<SEATA/192.168.31.181:9091>'}.
20:48:26.307  INFO --- [SpringContextShutdownHook] c.alipay.sofa.jraft.util.RepeatedTimer   : Destroy timer: RepeatedTimer{timeout=null, stopped=true, running=false, destroyed=true, invoking=false, timeoutMs=10000, name='JRaft-SnapshotTimer-<SEATA/192.168.31.181:9091>'}.
20:48:26.308  INFO --- [SpringContextShutdownHook] com.alipay.sofa.jraft.RaftGroupService   : Stop the RaftGroupService successfully.
20:48:26.309  INFO --- [SpringContextShutdownHook] c.a.s.jraft.util.LogThreadPoolExecutor   : ThreadPool is terminated: JRaft-RPC-Processor, com.alipay.sofa.jraft.util.MetricThreadPoolExecutor@2774b1c1[Shutting down, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0].
20:48:26.314  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.storage.impl.RocksDBLogStorage   : DB destroyed, the db path is: sessionStore\9091\log.

Process finished with exit code 130

7093端口日志

20:49:25.676  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStop: status=Status[ERAFTTIMEDOUT<10001>: Majority of the group dies: 2/3].
20:49:27.014  INFO --- [aft-FSMCaller-Disruptor-0] io.seata.server.raft.RaftStateMachine    : globalSessionMap size :0, branchSessionMap map size: 0
20:49:27.017  WARN --- [ JRaft-Closure-Executor-7] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9093\snapshot\temp on windows.
20:49:27.017  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Deleting snapshot sessionStore\9093\snapshot\snapshot_93.
20:49:27.017  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Renaming sessionStore\9093\snapshot\temp to sessionStore\9093\snapshot\snapshot_93.
20:49:27.018  WARN --- [ JRaft-Closure-Executor-7] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9093\snapshot on windows.
20:49:27.018  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Deleting snapshot sessionStore\9093\snapshot\snapshot_91.
20:49:27.019  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.storage.impl.RocksDBLogStorage   : Truncated prefix logs in data path: sessionStore\9093\log from log index 90 to 92, cost 0 ms.
20:49:27.205  INFO --- [fault-executor-4-thread-5] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> received PreVoteRequest from 192.168.31.181:9092, term=29, currTerm=28, granted=true, requestLastLogId=LogId [index=93, term=28], lastLogId=LogId [index=93, term=28].
20:49:27.839  INFO --- [ATA/192.168.31.181:9093>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> term 28 start preVote.
20:49:28.851 ERROR --- [ATA/192.168.31.181:9093>0] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:49:28.851  WARN --- [ATA/192.168.31.181:9093>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> channel init failed, address=192.168.31.181:9091.
20:49:28.852  INFO --- [fault-executor-4-thread-1] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> received RequestVoteRequest from 192.168.31.181:9092, term=29, currTerm=28.
20:49:28.854  WARN --- [fault-executor-4-thread-1] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9093\raft_meta on windows.
20:49:28.854  INFO --- [fault-executor-4-thread-1] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9093\raft_meta, term=29, votedFor=0.0.0.0:0, cost time=2 ms
20:49:28.857  WARN --- [fault-executor-4-thread-1] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9093\raft_meta on windows.
20:49:28.857  INFO --- [fault-executor-4-thread-1] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9093\raft_meta, term=29, votedFor=192.168.31.181:9092, cost time=2 ms
20:49:28.857  WARN --- [    JRaft-RPC-Processor-5] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> received invalid PreVoteResponse from 192.168.31.181:9092, term=28, currTerm=29.
20:49:29.863  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onStartFollowing: LeaderChangeContext [leaderId=192.168.31.181:9092, term=29, status=Status[ENEWLEADER<10011>: Follower receives message from new leader with the same term.]].
20:49:32.146  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onStopFollowing: LeaderChangeContext [leaderId=192.168.31.181:9092, term=29, status=Status[ERAFTTIMEDOUT<10001>: Lost connection from leader 192.168.31.181:9092.]].
20:49:32.146  INFO --- [ATA/192.168.31.181:9093>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> term 29 start preVote.
20:49:33.150 ERROR --- [ATA/192.168.31.181:9093>0] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:49:33.151  WARN --- [ATA/192.168.31.181:9093>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> channel init failed, address=192.168.31.181:9091.
20:49:33.152  INFO --- [    JRaft-RPC-Processor-6] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> received PreVoteResponse from 192.168.31.181:9092, term=29, granted=true.
20:49:33.152  INFO --- [    JRaft-RPC-Processor-6] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> start vote and grant vote self, term=29.
20:49:34.156 ERROR --- [    JRaft-RPC-Processor-6] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:49:34.157  WARN --- [    JRaft-RPC-Processor-6] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> channel init failed, address=192.168.31.181:9091.
20:49:34.168  WARN --- [    JRaft-RPC-Processor-6] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9093\raft_meta on windows.
20:49:34.168  INFO --- [    JRaft-RPC-Processor-6] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9093\raft_meta, term=30, votedFor=192.168.31.181:9093, cost time=12 ms
20:49:35.016  INFO --- [fault-executor-4-thread-8] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> received PreVoteRequest from 192.168.31.181:9092, term=30, currTerm=30, granted=true, requestLastLogId=LogId [index=94, term=29], lastLogId=LogId [index=94, term=29].
20:49:35.031  INFO --- [    JRaft-RPC-Processor-7] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> become leader of group, term=30, conf=192.168.31.181:9091,192.168.31.181:9092,192.168.31.181:9093, oldConf=.
20:49:36.036 ERROR --- [    JRaft-RPC-Processor-7] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:49:36.036 ERROR --- [    JRaft-RPC-Processor-7] com.alipay.sofa.jraft.core.Replicator    : Fail to init sending channel to 192.168.31.181:9091.
20:49:36.036 ERROR --- [    JRaft-RPC-Processor-7] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to start replicator to peer=192.168.31.181:9091, replicatorType=Follower.
20:49:36.036 ERROR --- [    JRaft-RPC-Processor-7] com.alipay.sofa.jraft.core.NodeImpl      : Fail to add a replicator, peer=192.168.31.181:9091.
20:49:36.037  INFO --- [    JRaft-RPC-Processor-7] com.alipay.sofa.jraft.core.Replicator    : Replicator=Replicator [state=Created, statInfo=<running=null, firstLogIndex=0, lastLogIncluded=0, lastLogIndex=0, lastTermIncluded=0>, peerId=192.168.31.181:9092, type=Follower]@192.168.31.181:9092 is started
20:49:36.039  INFO --- [aft-FSMCaller-Disruptor-0] io.seata.server.raft.RaftStateMachine    : session map: 0 
20:49:36.040  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStart: term=30.
20:49:37.016  INFO --- [aft-FSMCaller-Disruptor-0] io.seata.server.raft.RaftStateMachine    : globalSessionMap size :0, branchSessionMap map size: 0
20:49:37.029  WARN --- [ JRaft-Closure-Executor-7] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9093\snapshot\temp on windows.
20:49:37.029  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Deleting snapshot sessionStore\9093\snapshot\snapshot_95.
20:49:37.029  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Renaming sessionStore\9093\snapshot\temp to sessionStore\9093\snapshot\snapshot_95.
20:49:37.030  WARN --- [ JRaft-Closure-Executor-7] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9093\snapshot on windows.
20:49:37.030  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Deleting snapshot sessionStore\9093\snapshot\snapshot_93.
20:49:37.032  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.storage.impl.RocksDBLogStorage   : Truncated prefix logs in data path: sessionStore\9093\log from log index 92 to 94, cost 0 ms.
20:49:37.038 ERROR --- [ATA/192.168.31.181:9093>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:49:38.040 ERROR --- [ATA/192.168.31.181:9093>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:49:38.041 ERROR --- [ATA/192.168.31.181:9093>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:49:38.041  WARN --- [ATA/192.168.31.181:9093>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> steps down when alive nodes don't satisfy quorum, term=30, deadNodes=192.168.31.181:9091,192.168.31.181:9092, conf=192.168.31.181:9091,192.168.31.181:9092,192.168.31.181:9093.
20:49:38.042  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStop: status=Status[ERAFTTIMEDOUT<10001>: Majority of the group dies: 2/3].
20:49:38.042  INFO --- [ATA/192.168.31.181:9093>0] com.alipay.sofa.jraft.core.Replicator    : Replicator Replicator [state=Probe, statInfo=<running=IDLE, firstLogIndex=95, lastLogIncluded=0, lastLogIndex=95, lastTermIncluded=0>, peerId=192.168.31.181:9092, type=Follower] is going to quit
20:49:39.309  INFO --- [fault-executor-4-thread-2] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> received PreVoteRequest from 192.168.31.181:9092, term=31, currTerm=30, granted=true, requestLastLogId=LogId [index=95, term=30], lastLogId=LogId [index=95, term=30].
20:49:40.311  INFO --- [fault-executor-4-thread-4] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9093> received RequestVoteRequest from 192.168.31.181:9092, term=31, currTerm=30.
20:49:40.314  WARN --- [fault-executor-4-thread-4] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9093\raft_meta on windows.
20:49:40.314  INFO --- [fault-executor-4-thread-4] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9093\raft_meta, term=31, votedFor=0.0.0.0:0, cost time=2 ms
20:49:40.316  WARN --- [fault-executor-4-thread-4] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9093\raft_meta on windows.
20:49:40.316  INFO --- [fault-executor-4-thread-4] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9093\raft_meta, term=31, votedFor=192.168.31.181:9092, cost time=2 ms
20:49:41.320  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onStartFollowing: LeaderChangeContext [leaderId=192.168.31.181:9092, term=31, status=Status[ENEWLEADER<10011>: Follower receives message from new leader with the same term.]].

7092:

20:49:46.365  WARN --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> channel init failed, address=192.168.31.181:9091.
20:49:46.366  INFO --- [ault-executor-4-thread-19] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received RequestVoteRequest from 192.168.31.181:9093, term=32, currTerm=31.
20:49:46.377  WARN --- [ault-executor-4-thread-19] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:49:46.377  INFO --- [ault-executor-4-thread-19] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=32, votedFor=0.0.0.0:0, cost time=11 ms
20:49:46.379  WARN --- [ault-executor-4-thread-19] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:49:46.379  INFO --- [ault-executor-4-thread-19] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=32, votedFor=192.168.31.181:9093, cost time=1 ms
20:49:46.380  WARN --- [    JRaft-RPC-Processor-5] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received invalid PreVoteResponse from 192.168.31.181:9093, term=31, currTerm=32.
20:49:47.384  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onStartFollowing: LeaderChangeContext [leaderId=192.168.31.181:9093, term=32, status=Status[ENEWLEADER<10011>: Follower receives message from new leader with the same term.]].
20:49:50.316  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onStopFollowing: LeaderChangeContext [leaderId=192.168.31.181:9093, term=32, status=Status[ERAFTTIMEDOUT<10001>: Lost connection from leader 192.168.31.181:9093.]].
20:49:50.316  INFO --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> term 32 start preVote.
20:49:51.319 ERROR --- [ATA/192.168.31.181:9092>0] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:49:51.319  WARN --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> channel init failed, address=192.168.31.181:9091.
20:49:51.321  INFO --- [    JRaft-RPC-Processor-6] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received PreVoteResponse from 192.168.31.181:9093, term=32, granted=true.
20:49:51.321  INFO --- [    JRaft-RPC-Processor-6] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> start vote and grant vote self, term=32.
20:49:52.323 ERROR --- [    JRaft-RPC-Processor-6] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:49:52.323  WARN --- [    JRaft-RPC-Processor-6] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> channel init failed, address=192.168.31.181:9091.
20:49:52.335  WARN --- [    JRaft-RPC-Processor-6] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:49:52.335  INFO --- [    JRaft-RPC-Processor-6] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=33, votedFor=192.168.31.181:9092, cost time=12 ms
20:49:52.565  INFO --- [fault-executor-4-thread-3] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received PreVoteRequest from 192.168.31.181:9093, term=33, currTerm=33, granted=true, requestLastLogId=LogId [index=97, term=32], lastLogId=LogId [index=97, term=32].
20:49:52.579  INFO --- [    JRaft-RPC-Processor-7] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> become leader of group, term=33, conf=192.168.31.181:9091,192.168.31.181:9092,192.168.31.181:9093, oldConf=.
20:49:53.581 ERROR --- [    JRaft-RPC-Processor-7] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:49:53.581 ERROR --- [    JRaft-RPC-Processor-7] com.alipay.sofa.jraft.core.Replicator    : Fail to init sending channel to 192.168.31.181:9091.
20:49:53.581 ERROR --- [    JRaft-RPC-Processor-7] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to start replicator to peer=192.168.31.181:9091, replicatorType=Follower.
20:49:53.581 ERROR --- [    JRaft-RPC-Processor-7] com.alipay.sofa.jraft.core.NodeImpl      : Fail to add a replicator, peer=192.168.31.181:9091.
20:49:53.581  INFO --- [    JRaft-RPC-Processor-7] com.alipay.sofa.jraft.core.Replicator    : Replicator=Replicator [state=Created, statInfo=<running=null, firstLogIndex=0, lastLogIncluded=0, lastLogIndex=0, lastTermIncluded=0>, peerId=192.168.31.181:9093, type=Follower]@192.168.31.181:9093 is started
20:49:53.592  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.storage.impl.RocksDBLogStorage   : Truncated prefix logs in data path: sessionStore\9092\log from log index 95 to 97, cost 0 ms.
20:49:53.592  INFO --- [aft-FSMCaller-Disruptor-0] io.seata.server.raft.RaftStateMachine    : session map: 0 
20:49:53.593  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStart: term=33.
20:49:54.594 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:49:55.604 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:49:55.605 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:49:55.605  WARN --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> steps down when alive nodes don't satisfy quorum, term=33, deadNodes=192.168.31.181:9091,192.168.31.181:9093, conf=192.168.31.181:9091,192.168.31.181:9092,192.168.31.181:9093.
20:49:55.605  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStop: status=Status[ERAFTTIMEDOUT<10001>: Majority of the group dies: 2/3].
20:49:55.605  INFO --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.Replicator    : Replicator Replicator [state=Probe, statInfo=<running=IDLE, firstLogIndex=98, lastLogIncluded=0, lastLogIndex=98, lastTermIncluded=0>, peerId=192.168.31.181:9093, type=Follower] is going to quit
20:49:56.626  INFO --- [ault-executor-4-thread-12] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received PreVoteRequest from 192.168.31.181:9093, term=34, currTerm=33, granted=true, requestLastLogId=LogId [index=98, term=33], lastLogId=LogId [index=98, term=33].
20:49:57.632  INFO --- [ault-executor-4-thread-16] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received RequestVoteRequest from 192.168.31.181:9093, term=34, currTerm=33.
20:49:57.645  WARN --- [ault-executor-4-thread-16] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:49:57.645  INFO --- [ault-executor-4-thread-16] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=34, votedFor=0.0.0.0:0, cost time=12 ms
20:49:57.648  WARN --- [ault-executor-4-thread-16] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:49:57.648  INFO --- [ault-executor-4-thread-16] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=34, votedFor=192.168.31.181:9093, cost time=3 ms
20:49:58.665  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onStartFollowing: LeaderChangeContext [leaderId=192.168.31.181:9093, term=34, status=Status[ENEWLEADER<10011>: Follower receives message from new leader with the same term.]].
20:50:01.260  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onStopFollowing: LeaderChangeContext [leaderId=192.168.31.181:9093, term=34, status=Status[ERAFTTIMEDOUT<10001>: Lost connection from leader 192.168.31.181:9093.]].
20:50:01.260  INFO --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> term 34 start preVote.
20:50:02.267 ERROR --- [ATA/192.168.31.181:9092>0] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:50:02.267  WARN --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> channel init failed, address=192.168.31.181:9091.
20:50:02.269  INFO --- [    JRaft-RPC-Processor-8] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received PreVoteResponse from 192.168.31.181:9093, term=34, granted=true.
20:50:02.269  INFO --- [    JRaft-RPC-Processor-8] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> start vote and grant vote self, term=34.
20:50:03.274 ERROR --- [    JRaft-RPC-Processor-8] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:50:03.274  WARN --- [    JRaft-RPC-Processor-8] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> channel init failed, address=192.168.31.181:9091.
20:50:03.285  WARN --- [    JRaft-RPC-Processor-8] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:50:03.286  INFO --- [    JRaft-RPC-Processor-8] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=35, votedFor=192.168.31.181:9092, cost time=12 ms
20:50:03.288  INFO --- [    JRaft-RPC-Processor-9] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> become leader of group, term=35, conf=192.168.31.181:9091,192.168.31.181:9092,192.168.31.181:9093, oldConf=.
20:50:04.303 ERROR --- [    JRaft-RPC-Processor-9] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:50:04.304 ERROR --- [    JRaft-RPC-Processor-9] com.alipay.sofa.jraft.core.Replicator    : Fail to init sending channel to 192.168.31.181:9091.
20:50:04.304 ERROR --- [    JRaft-RPC-Processor-9] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to start replicator to peer=192.168.31.181:9091, replicatorType=Follower.
20:50:04.304 ERROR --- [    JRaft-RPC-Processor-9] com.alipay.sofa.jraft.core.NodeImpl      : Fail to add a replicator, peer=192.168.31.181:9091.
20:50:04.305  INFO --- [    JRaft-RPC-Processor-9] com.alipay.sofa.jraft.core.Replicator    : Replicator=Replicator [state=Created, statInfo=<running=null, firstLogIndex=0, lastLogIncluded=0, lastLogIndex=0, lastTermIncluded=0>, peerId=192.168.31.181:9093, type=Follower]@192.168.31.181:9093 is started
20:50:04.307  INFO --- [aft-FSMCaller-Disruptor-0] io.seata.server.raft.RaftStateMachine    : globalSessionMap size :0, branchSessionMap map size: 0
20:50:04.310  INFO --- [aft-FSMCaller-Disruptor-0] io.seata.server.raft.RaftStateMachine    : session map: 0 
20:50:04.310  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStart: term=35.
20:50:04.311  WARN --- [ JRaft-Closure-Executor-7] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\snapshot\temp on windows.
20:50:04.311  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Deleting snapshot sessionStore\9092\snapshot\snapshot_98.
20:50:04.311  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Renaming sessionStore\9092\snapshot\temp to sessionStore\9092\snapshot\snapshot_98.
20:50:04.312  WARN --- [ JRaft-Closure-Executor-7] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\snapshot on windows.
20:50:04.312  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Deleting snapshot sessionStore\9092\snapshot\snapshot_96.
20:50:04.315  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.storage.impl.RocksDBLogStorage   : Truncated prefix logs in data path: sessionStore\9092\log from log index 97 to 97, cost 0 ms.
20:50:05.308 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:50:06.317 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:50:06.317 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:50:06.318  WARN --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> steps down when alive nodes don't satisfy quorum, term=35, deadNodes=192.168.31.181:9091,192.168.31.181:9093, conf=192.168.31.181:9091,192.168.31.181:9092,192.168.31.181:9093.
20:50:06.318  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStop: status=Status[ERAFTTIMEDOUT<10001>: Majority of the group dies: 2/3].
20:50:06.318  INFO --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.Replicator    : Replicator Replicator [state=Probe, statInfo=<running=IDLE, firstLogIndex=100, lastLogIncluded=0, lastLogIndex=100, lastTermIncluded=0>, peerId=192.168.31.181:9093, type=Follower] is going to quit
20:50:07.599  INFO --- [ault-executor-4-thread-11] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received PreVoteRequest from 192.168.31.181:9093, term=36, currTerm=35, granted=true, requestLastLogId=LogId [index=100, term=35], lastLogId=LogId [index=100, term=35].
20:50:08.608  INFO --- [ault-executor-4-thread-14] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received RequestVoteRequest from 192.168.31.181:9093, term=36, currTerm=35.
20:50:08.619  WARN --- [ault-executor-4-thread-14] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:50:08.619  INFO --- [ault-executor-4-thread-14] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=36, votedFor=0.0.0.0:0, cost time=11 ms
20:50:08.621  WARN --- [ault-executor-4-thread-14] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:50:08.621  INFO --- [ault-executor-4-thread-14] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=36, votedFor=192.168.31.181:9093, cost time=3 ms
20:50:09.638  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onStartFollowing: LeaderChangeContext [leaderId=192.168.31.181:9093, term=36, status=Status[ENEWLEADER<10011>: Follower receives message from new leader with the same term.]].
20:50:12.578  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onStopFollowing: LeaderChangeContext [leaderId=192.168.31.181:9093, term=36, status=Status[ERAFTTIMEDOUT<10001>: Lost connection from leader 192.168.31.181:9093.]].
20:50:12.578  INFO --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> term 36 start preVote.
20:50:13.589 ERROR --- [ATA/192.168.31.181:9092>0] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:50:13.590  WARN --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> channel init failed, address=192.168.31.181:9091.
20:50:13.591  INFO --- [   JRaft-RPC-Processor-10] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received PreVoteResponse from 192.168.31.181:9093, term=36, granted=true.
20:50:13.592  INFO --- [   JRaft-RPC-Processor-10] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> start vote and grant vote self, term=36.
20:50:14.599 ERROR --- [   JRaft-RPC-Processor-10] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:50:14.599  WARN --- [   JRaft-RPC-Processor-10] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> channel init failed, address=192.168.31.181:9091.
20:50:14.602  WARN --- [   JRaft-RPC-Processor-10] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:50:14.602  INFO --- [   JRaft-RPC-Processor-10] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=37, votedFor=192.168.31.181:9092, cost time=2 ms
20:50:14.602  INFO --- [aft-FSMCaller-Disruptor-0] io.seata.server.raft.RaftStateMachine    : globalSessionMap size :0, branchSessionMap map size: 0
20:50:14.604  WARN --- [ JRaft-Closure-Executor-7] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\snapshot\temp on windows.
20:50:14.605  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Deleting snapshot sessionStore\9092\snapshot\snapshot_100.
20:50:14.605  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Renaming sessionStore\9092\snapshot\temp to sessionStore\9092\snapshot\snapshot_100.
20:50:14.605  WARN --- [ JRaft-Closure-Executor-7] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\snapshot on windows.
20:50:14.605  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Deleting snapshot sessionStore\9092\snapshot\snapshot_98.
20:50:14.607  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.storage.impl.RocksDBLogStorage   : Truncated prefix logs in data path: sessionStore\9092\log from log index 97 to 99, cost 0 ms.
20:50:15.546  WARN --- [   JRaft-RPC-Processor-11] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> RequestVote to 192.168.31.181:9093 error: Status[EINTERNAL<1004>: RPC exception:Invoke timeout when invoke with callback.The address is 192.168.31.181:9093].
20:50:15.553  INFO --- [ault-executor-4-thread-17] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received PreVoteRequest from 192.168.31.181:9093, term=37, currTerm=37, granted=true, requestLastLogId=LogId [index=101, term=36], lastLogId=LogId [index=101, term=36].
20:50:15.911  WARN --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Candidate node <SEATA/192.168.31.181:9092> term 37 steps down when election reaching vote timeout: fail to get quorum vote-granted.
20:50:15.911  INFO --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> term 37 start preVote.
20:50:16.914 ERROR --- [ATA/192.168.31.181:9092>0] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:50:16.914  WARN --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> channel init failed, address=192.168.31.181:9091.
20:50:16.915  INFO --- [   JRaft-RPC-Processor-12] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received PreVoteResponse from 192.168.31.181:9093, term=37, granted=true.
20:50:16.915  INFO --- [   JRaft-RPC-Processor-12] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> start vote and grant vote self, term=37.
20:50:17.918 ERROR --- [   JRaft-RPC-Processor-12] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:50:17.918  WARN --- [   JRaft-RPC-Processor-12] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> channel init failed, address=192.168.31.181:9091.
20:50:17.929  WARN --- [   JRaft-RPC-Processor-12] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:50:17.929  INFO --- [   JRaft-RPC-Processor-12] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=38, votedFor=192.168.31.181:9092, cost time=11 ms
20:50:17.933  INFO --- [   JRaft-RPC-Processor-13] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> become leader of group, term=38, conf=192.168.31.181:9091,192.168.31.181:9092,192.168.31.181:9093, oldConf=.
20:50:18.935 ERROR --- [   JRaft-RPC-Processor-13] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:50:18.935 ERROR --- [   JRaft-RPC-Processor-13] com.alipay.sofa.jraft.core.Replicator    : Fail to init sending channel to 192.168.31.181:9091.
20:50:18.935 ERROR --- [   JRaft-RPC-Processor-13] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to start replicator to peer=192.168.31.181:9091, replicatorType=Follower.
20:50:18.935 ERROR --- [   JRaft-RPC-Processor-13] com.alipay.sofa.jraft.core.NodeImpl      : Fail to add a replicator, peer=192.168.31.181:9091.
20:50:18.935  INFO --- [   JRaft-RPC-Processor-13] com.alipay.sofa.jraft.core.Replicator    : Replicator=Replicator [state=Created, statInfo=<running=null, firstLogIndex=0, lastLogIncluded=0, lastLogIndex=0, lastTermIncluded=0>, peerId=192.168.31.181:9093, type=Follower]@192.168.31.181:9093 is started
20:50:18.947  INFO --- [aft-FSMCaller-Disruptor-0] io.seata.server.raft.RaftStateMachine    : session map: 0 
20:50:18.947  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStart: term=38.
20:50:19.938 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:50:20.941 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:50:20.941 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:50:20.941  WARN --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> steps down when alive nodes don't satisfy quorum, term=38, deadNodes=192.168.31.181:9091,192.168.31.181:9093, conf=192.168.31.181:9091,192.168.31.181:9092,192.168.31.181:9093.
20:50:20.942  INFO --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.Replicator    : Replicator Replicator [state=Probe, statInfo=<running=IDLE, firstLogIndex=102, lastLogIncluded=0, lastLogIndex=102, lastTermIncluded=0>, peerId=192.168.31.181:9093, type=Follower] is going to quit
20:50:20.942  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStop: status=Status[ERAFTTIMEDOUT<10001>: Majority of the group dies: 2/3].
20:50:22.775  INFO --- [fault-executor-4-thread-9] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received PreVoteRequest from 192.168.31.181:9093, term=39, currTerm=38, granted=true, requestLastLogId=LogId [index=102, term=38], lastLogId=LogId [index=102, term=38].
20:50:23.018  INFO --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> term 38 start preVote.
20:50:24.022 ERROR --- [ATA/192.168.31.181:9092>0] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:50:24.022  WARN --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> channel init failed, address=192.168.31.181:9091.
20:50:24.023  INFO --- [ault-executor-4-thread-11] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received RequestVoteRequest from 192.168.31.181:9093, term=39, currTerm=38.
20:50:24.025  WARN --- [ault-executor-4-thread-11] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:50:24.026  INFO --- [ault-executor-4-thread-11] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=39, votedFor=0.0.0.0:0, cost time=3 ms
20:50:24.026  WARN --- [   JRaft-RPC-Processor-14] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received invalid PreVoteResponse from 192.168.31.181:9093, term=38, currTerm=39.
20:50:24.030  WARN --- [ault-executor-4-thread-11] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:50:24.030  INFO --- [ault-executor-4-thread-11] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=39, votedFor=192.168.31.181:9093, cost time=4 ms
20:50:24.604  INFO --- [aft-FSMCaller-Disruptor-0] io.seata.server.raft.RaftStateMachine    : globalSessionMap size :0, branchSessionMap map size: 0
20:50:24.617  WARN --- [ JRaft-Closure-Executor-7] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\snapshot\temp on windows.
20:50:24.618  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Deleting snapshot sessionStore\9092\snapshot\snapshot_102.
20:50:24.618  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Renaming sessionStore\9092\snapshot\temp to sessionStore\9092\snapshot\snapshot_102.
20:50:24.619  WARN --- [ JRaft-Closure-Executor-7] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\snapshot on windows.
20:50:24.619  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Deleting snapshot sessionStore\9092\snapshot\snapshot_100.
20:50:24.621  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.storage.impl.RocksDBLogStorage   : Truncated prefix logs in data path: sessionStore\9092\log from log index 99 to 101, cost 1 ms.
20:50:25.036  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onStartFollowing: LeaderChangeContext [leaderId=192.168.31.181:9093, term=39, status=Status[ENEWLEADER<10011>: Follower receives message from new leader with the same term.]].
20:50:27.772  INFO --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> term 39 start preVote.
20:50:27.772  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onStopFollowing: LeaderChangeContext [leaderId=192.168.31.181:9093, term=39, status=Status[ERAFTTIMEDOUT<10001>: Lost connection from leader 192.168.31.181:9093.]].
20:50:28.775 ERROR --- [ATA/192.168.31.181:9092>0] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:50:28.775  WARN --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> channel init failed, address=192.168.31.181:9091.
20:50:28.776  INFO --- [   JRaft-RPC-Processor-15] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received PreVoteResponse from 192.168.31.181:9093, term=39, granted=true.
20:50:28.776  INFO --- [   JRaft-RPC-Processor-15] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> start vote and grant vote self, term=39.
20:50:29.778 ERROR --- [   JRaft-RPC-Processor-15] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:50:29.778  WARN --- [   JRaft-RPC-Processor-15] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> channel init failed, address=192.168.31.181:9091.
20:50:29.781  WARN --- [   JRaft-RPC-Processor-15] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\raft_meta on windows.
20:50:29.781  INFO --- [   JRaft-RPC-Processor-15] c.a.s.j.s.impl.LocalRaftMetaStorage      : Save raft meta, path=sessionStore\9092\raft_meta, term=40, votedFor=192.168.31.181:9092, cost time=2 ms
20:50:29.783  INFO --- [   JRaft-RPC-Processor-16] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> become leader of group, term=40, conf=192.168.31.181:9091,192.168.31.181:9092,192.168.31.181:9093, oldConf=.
20:50:30.786 ERROR --- [   JRaft-RPC-Processor-16] c.a.s.j.rpc.impl.AbstractClientService   : Fail to connect 192.168.31.181:9091, remoting exception: com.alipay.remoting.exception.RemotingException: Create connection failed. The address is 192.168.31.181:9091.
20:50:30.786 ERROR --- [   JRaft-RPC-Processor-16] com.alipay.sofa.jraft.core.Replicator    : Fail to init sending channel to 192.168.31.181:9091.
20:50:30.786 ERROR --- [   JRaft-RPC-Processor-16] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to start replicator to peer=192.168.31.181:9091, replicatorType=Follower.
20:50:30.786 ERROR --- [   JRaft-RPC-Processor-16] com.alipay.sofa.jraft.core.NodeImpl      : Fail to add a replicator, peer=192.168.31.181:9091.
20:50:30.786  INFO --- [   JRaft-RPC-Processor-16] com.alipay.sofa.jraft.core.Replicator    : Replicator=Replicator [state=Created, statInfo=<running=null, firstLogIndex=0, lastLogIncluded=0, lastLogIndex=0, lastTermIncluded=0>, peerId=192.168.31.181:9093, type=Follower]@192.168.31.181:9093 is started
20:50:30.799  INFO --- [aft-FSMCaller-Disruptor-0] io.seata.server.raft.RaftStateMachine    : session map: 0 
20:50:30.799  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStart: term=40.
20:50:31.789 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:50:32.792 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:50:32.792 ERROR --- [ATA/192.168.31.181:9092>0] c.a.sofa.jraft.core.ReplicatorGroupImpl  : Fail to check replicator connection to peer=192.168.31.181:9091, replicatorType=Follower.
20:50:32.792  WARN --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> steps down when alive nodes don't satisfy quorum, term=40, deadNodes=192.168.31.181:9091,192.168.31.181:9093, conf=192.168.31.181:9091,192.168.31.181:9092,192.168.31.181:9093.
20:50:32.793  INFO --- [aft-FSMCaller-Disruptor-0] c.a.sofa.jraft.core.StateMachineAdapter  : onLeaderStop: status=Status[ERAFTTIMEDOUT<10001>: Majority of the group dies: 2/3].
20:50:32.793  INFO --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.Replicator    : Replicator Replicator [state=Probe, statInfo=<running=IDLE, firstLogIndex=104, lastLogIncluded=0, lastLogIndex=104, lastTermIncluded=0>, peerId=192.168.31.181:9093, type=Follower] is going to quit
20:50:34.178  INFO --- [fault-executor-4-thread-6] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> received PreVoteRequest from 192.168.31.181:9093, term=41, currTerm=40, granted=true, requestLastLogId=LogId [index=104, term=40], lastLogId=LogId [index=104, term=40].
20:50:34.606  INFO --- [aft-FSMCaller-Disruptor-0] io.seata.server.raft.RaftStateMachine    : globalSessionMap size :0, branchSessionMap map size: 0
20:50:34.608  WARN --- [ JRaft-Closure-Executor-7] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\snapshot\temp on windows.
20:50:34.609  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Deleting snapshot sessionStore\9092\snapshot\snapshot_104.
20:50:34.609  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Renaming sessionStore\9092\snapshot\temp to sessionStore\9092\snapshot\snapshot_104.
20:50:34.609  WARN --- [ JRaft-Closure-Executor-7] com.alipay.sofa.jraft.util.Utils         : Unable to fsync directory sessionStore\9092\snapshot on windows.
20:50:34.609  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.s.s.local.LocalSnapshotStorage   : Deleting snapshot sessionStore\9092\snapshot\snapshot_102.
20:50:34.611  INFO --- [ JRaft-Closure-Executor-7] c.a.s.j.storage.impl.RocksDBLogStorage   : Truncated prefix logs in data path: sessionStore\9092\log from log index 101 to 103, cost 0 ms.
20:50:35.019  INFO --- [ATA/192.168.31.181:9092>0] com.alipay.sofa.jraft.core.NodeImpl      : Node <SEATA/192.168.31.181:9092> term 40 start preVote.

@funky-eyes
Copy link
Contributor Author

funky-eyes commented Apr 11, 2022 •
edited
Loading

升级1.3.10.bugfix无效,降级1.3.7后恢复正常
2个节点时,无限出现重选主
@fengjiachun @killme2008

@killme2008
Copy link
Contributor

猜测跟 bolt 1.6.4 对超时的改进有关系，你可以降级 bolt 到 1.6.4 以下的版本（通过 maven exclusions)， jraft 保持 1.3.9 或者 1.3.10 看看。

通过你的描述调大 electionTimeoutMs 能解决，大概率是这个问题。

@fengjiachun
Copy link
Contributor

@a364176773 感谢提供日志，我也来看下

@fengjiachun
Copy link
Contributor

fengjiachun commented Apr 12, 2022 •
edited
Loading

大概有了一些线索，你既然是本地，就把 ip 地址换成 127.0.0.1（本地环回接口和外网 ip 是不同的通信方式） ，这个问题就不会再现了，所以基本可以得出结论是网络问题

如果你用对外的 ip，那么你降级 bolt 到 1.6.2（jraft 1.3.7 版本引用的 bolt 版本为 1.6.2） 也可以解决问题（问题得到缓解，但偶尔也会切主，这个估计还是因为 1.6.2 bolt 建连有阻塞），这个有点奇怪，我还不知道 bolt 做了啥，后续可能要继续查一下

@funky-eyes
Copy link
Contributor Author

好的，谢谢二位，我将会试一下直接使用127.0.0.1下是否会改善，届时将继续反馈到此issue

@zhipingu
Copy link

我晚上又试了一下，1.3.10.bugfix版本，还是不行，只要是两个节点，就选不出来主，第三个节点启动后，才能选出主

@zhipingu
Copy link

这次把rpcconnectiontimeout和electiontimeout设置成了3秒都不行

@killme2008
Copy link
Contributor

这个尝试是说将 ip 修改为 127.0.0.1 的环路地址，还是说降级了 bolt ?

@fengjiachun
Copy link
Contributor

fengjiachun commented Apr 13, 2022 •
edited
Loading

大概找到原因了，我先简单说下，bolt 的建连超时与 jraft 的 ET 相同时（在 jraft 中 ET 同时也是 rpcTimeout ），会触发一个 bug，大概可以描述为：
如果一个连接建连的耗时为 x， 那么在这个连接上发起调用的话在 （rpcTimeout - x） 时间后就会在 client 被触发超时，这个 rpc 请求将不会发往对端，这也导致了 prevote 请求无法发出去，jraft 在上层复用了默认的 ctx，而 bolt 内部也会修改 ctx，回修改 connect time，今天我会提一个 pr 修复这个问题

顺便可以解答以下几个问题：

  1. 127.0.0.1 在我本地运行良好，为什么？
    大概是本地环回接口建连不论成功失败不会耗时这么长

  2. 为什么将 ET 调大就解决问题了？
    ET 同时也是 jraft 的 rpcTimeout，rpcTimeout 大于 bolt 建连的默认时间（1s）就有时间来发送 rpc 请求了

  3. 为什么 @zhipingu 说 ET 设置三秒也能复现问题
    bolt 的 connect timeout 有个全局并发问题，可能导致 3 秒被设置到 bolt 的建连超时中，我已经提交 bug，见这里 Connection timeout sofa-bolt#291

@zhipingu
Copy link

将 ip 修改为 127.0.0.1 的环路地址

@zhipingu
Copy link

家纯老师找到原因了就好，太强了

@fengjiachun fengjiachun mentioned this issue Apr 13, 2022
Merged
@fengjiachun fengjiachun self-assigned this Apr 13, 2022
@fengjiachun fengjiachun mentioned this issue Apr 20, 2022
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@fengjiachun fengjiachun

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

fix connect bug sofastack/sofa-jraft
4 participants
@killme2008 @fengjiachun @funky-eyes @zhipingu