You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ratis.apache.org by "Burcu Ozkan (Jira)" <ji...@apache.org> on 2020/05/25 10:13:00 UTC

[jira] [Updated] (RATIS-946) GrpcLogAppender fails to fix failed AppendEntries with inconsistency in case of message losses

     [ https://issues.apache.org/jira/browse/RATIS-946?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Burcu Ozkan updated RATIS-946:
------------------------------
    Description: 
I am testing fault tolerance of Ratis, more specifically whether it can tolerate random message losses. Simply, I drop some of the messages and do not deliver them to the recipient.

In some tests where the servers have inconsistent logs, I observe executions in which the follower fails to synchronize with the leader.  The servers indefinitely exchange AppendEntries request and its failing reply, logging the following messages repeatedly:
{noformat}
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 19 -> 17
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1097)) - s0@group-AD42E7C24DDE: Failed appendEntries as previous log entry ((t:20, i:16)) is not found
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308912:FAIL,INCONSISTENCY,nextIndex:16,term:20,followerCommit:16
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 19 -> 16 {noformat}
Here is the part of the logs before the repeated messages:
{noformat}
...
impl.RoleInfo (RoleInfo.java:updateAndGet(143)) - s0: start FollowerState
impl.RaftServerImpl (ServerState.java:setLeader(255)) - s0@group-AD42E7C24DDE: change Leader from null to s1 at term 20 for appendEntries, leader elected after 3ms
client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-A0592557AEC3->s0@group-AD42E7C24DDE, cid=7, seq=0, RW, Message:6d3130, reply=RaftClientReply:client-A0592557AEC3->s0@group-AD42E7C24DDE, cid=7, FAILED org.apache.ratis.protocol.NotLeaderException: Server s0@group-AD42E7C24DDE is not the leader, logIndex=0, commits[s0:c14, s1:c13, s2:c13]
client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-3A32B89816B9->s0@group-AD42E7C24DDE, cid=8, seq=0, RW, Message:6d3131, reply=RaftClientReply:client-3A32B89816B9->s0@group-AD42E7C24DDE, cid=8, FAILED org.apache.ratis.protocol.NotLeaderException: Server s0@group-AD42E7C24DDE is not the leader, logIndex=0, commits[s0:c14, s1:c13, s2:c13]
client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-73072E12695E->s0@group-AD42E7C24DDE, cid=6, seq=0, RW, Message:6d3132, reply=RaftClientReply:client-73072E12695E->s0@group-AD42E7C24DDE, cid=6, FAILED org.apache.ratis.protocol.NotLeaderException: Server s0@group-AD42E7C24DDE is not the leader, logIndex=0, commits[s0:c14, s1:c13, s2:c13]
server.GrpcLogAppender (GrpcLogAppender.java:onCompleted(321)) - s0@group-AD42E7C24DDE->s1-AppendLogResponseHandler: follower responses appendEntries COMPLETED
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1088)) - s0@group-AD42E7C24DDE: Failed appendEntries: the first entry (index 15) is already committed (commit index: 16)
statemachine.SimpleStateMachine4Testing (SimpleStateMachine4Testing.java:put(200)) - s0: put 15, m11 -> (t:19, i:15), STATEMACHINELOGENTRY, client-3A32B89816B9, cid=8
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308907:FAIL,INCONSISTENCY,nextIndex:17,term:20,followerCommit:16
statemachine.SimpleStateMachine4Testing (SimpleStateMachine4Testing.java:put(200)) - s0: put 16, m10 -> (t:19, i:16), STATEMACHINELOGENTRY, client-A0592557AEC3, cid=7
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 17 -> 17
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s0@group-AD42E7C24DDE->s2: nextIndex: updateUnconditionally 18 -> 15
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s0@group-AD42E7C24DDE->s1: nextIndex: updateUnconditionally 18 -> 15
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1097)) - s0@group-AD42E7C24DDE: Failed appendEntries as previous log entry ((t:20, i:16)) is not found
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308908:FAIL,INCONSISTENCY,nextIndex:16,term:20,followerCommit:16
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 17 -> 16
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1088)) - s0@group-AD42E7C24DDE: Failed appendEntries: the first entry (index 16) is already committed (commit index: 16)
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308909:FAIL,INCONSISTENCY,nextIndex:17,term:20,followerCommit:16
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 17 -> 17
[ForkJoinPool.commonPool-worker-3] INFO client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-73072E12695E->s2@group-AD42E7C24DDE, cid=6, seq=0, RW, Message:6d3132, reply=RaftClientReply:client-73072E12695E->s2@group-AD42E7C24DDE, cid=6, FAILED org.apache.ratis.protocol.NotLeaderException: Server s2@group-AD42E7C24DDE is not the leader s1:0.0.0.0:49936, logIndex=0, commits[s2:c16, s0:c16, s1:c16]
[ForkJoinPool.commonPool-worker-1] INFO client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-3A32B89816B9->s2@group-AD42E7C24DDE, cid=8, seq=0, RW, Message:6d3131, reply=RaftClientReply:client-3A32B89816B9->s2@group-AD42E7C24DDE, cid=8, FAILED org.apache.ratis.protocol.NotLeaderException: Server s2@group-AD42E7C24DDE is not the leader s1:0.0.0.0:49936, logIndex=0, commits[s2:c16, s0:c16, s1:c16]
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1097)) - s0@group-AD42E7C24DDE: Failed appendEntries as previous log entry ((t:20, i:16)) is not found
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308910:FAIL,INCONSISTENCY,nextIndex:16,term:20,followerCommit:16
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 18 -> 16
statemachine.SimpleStateMachine4Testing (SimpleStateMachine4Testing.java:put(200)) - s1: put 17, m10 -> (t:20, i:17), STATEMACHINELOGENTRY, client-A0592557AEC3, cid=7
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1088)) - s0@group-AD42E7C24DDE: Failed appendEntries: the first entry (index 16) is already committed (commit index: 16)
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308911:FAIL,INCONSISTENCY,nextIndex:17,term:20,followerCommit:16
statemachine.SimpleStateMachine4Testing (SimpleStateMachine4Testing.java:put(200)) - s2: put 17, m10 -> (t:20, i:17), STATEMACHINELOGENTRY, client-A0592557AEC3, cid=7
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 19 -> 17
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1097)) - s0@group-AD42E7C24DDE: Failed appendEntries as previous log entry ((t:20, i:16)) is not found
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308912:FAIL,INCONSISTENCY,nextIndex:16,term:20,followerCommit:16
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 19 -> 16
..
{noformat}
 

I did not observe the problem when I test using Netty adapter.


 I attached a file listing the messages sent or dropped in the execution. Each line lists the sender/receiver of the message together with some message information, and the number of times the message is sent/received. The messages marked with "-D" are dropped. 

You can also find the full log of the execution attached.

  was:
I am testing fault tolerance of Ratis, more specifically whether it can tolerate random message losses. Simply, I drop some of the messages and do not deliver them to the recipient.

In some tests where the servers have inconsistent logs, I observe executions in which the follower fails to synchronize with the leader. 
The servers indefinitely exchange AppendEntries request and its failing reply, logging the following messages repeatedly:

 
{noformat}
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 19 -> 17
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1097)) - s0@group-AD42E7C24DDE: Failed appendEntries as previous log entry ((t:20, i:16)) is not found
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308912:FAIL,INCONSISTENCY,nextIndex:16,term:20,followerCommit:16
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 19 -> 16{noformat}
{{}}

 

 

Here is the part of the logs before the repeated messages:

 
{noformat}
...
impl.RoleInfo (RoleInfo.java:updateAndGet(143)) - s0: start FollowerState
impl.RaftServerImpl (ServerState.java:setLeader(255)) - s0@group-AD42E7C24DDE: change Leader from null to s1 at term 20 for appendEntries, leader elected after 3ms
client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-A0592557AEC3->s0@group-AD42E7C24DDE, cid=7, seq=0, RW, Message:6d3130, reply=RaftClientReply:client-A0592557AEC3->s0@group-AD42E7C24DDE, cid=7, FAILED org.apache.ratis.protocol.NotLeaderException: Server s0@group-AD42E7C24DDE is not the leader, logIndex=0, commits[s0:c14, s1:c13, s2:c13]
client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-3A32B89816B9->s0@group-AD42E7C24DDE, cid=8, seq=0, RW, Message:6d3131, reply=RaftClientReply:client-3A32B89816B9->s0@group-AD42E7C24DDE, cid=8, FAILED org.apache.ratis.protocol.NotLeaderException: Server s0@group-AD42E7C24DDE is not the leader, logIndex=0, commits[s0:c14, s1:c13, s2:c13]
client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-73072E12695E->s0@group-AD42E7C24DDE, cid=6, seq=0, RW, Message:6d3132, reply=RaftClientReply:client-73072E12695E->s0@group-AD42E7C24DDE, cid=6, FAILED org.apache.ratis.protocol.NotLeaderException: Server s0@group-AD42E7C24DDE is not the leader, logIndex=0, commits[s0:c14, s1:c13, s2:c13]
server.GrpcLogAppender (GrpcLogAppender.java:onCompleted(321)) - s0@group-AD42E7C24DDE->s1-AppendLogResponseHandler: follower responses appendEntries COMPLETED
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1088)) - s0@group-AD42E7C24DDE: Failed appendEntries: the first entry (index 15) is already committed (commit index: 16)
statemachine.SimpleStateMachine4Testing (SimpleStateMachine4Testing.java:put(200)) - s0: put 15, m11 -> (t:19, i:15), STATEMACHINELOGENTRY, client-3A32B89816B9, cid=8
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308907:FAIL,INCONSISTENCY,nextIndex:17,term:20,followerCommit:16
statemachine.SimpleStateMachine4Testing (SimpleStateMachine4Testing.java:put(200)) - s0: put 16, m10 -> (t:19, i:16), STATEMACHINELOGENTRY, client-A0592557AEC3, cid=7
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 17 -> 17
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s0@group-AD42E7C24DDE->s2: nextIndex: updateUnconditionally 18 -> 15
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s0@group-AD42E7C24DDE->s1: nextIndex: updateUnconditionally 18 -> 15
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1097)) - s0@group-AD42E7C24DDE: Failed appendEntries as previous log entry ((t:20, i:16)) is not found
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308908:FAIL,INCONSISTENCY,nextIndex:16,term:20,followerCommit:16
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 17 -> 16
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1088)) - s0@group-AD42E7C24DDE: Failed appendEntries: the first entry (index 16) is already committed (commit index: 16)
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308909:FAIL,INCONSISTENCY,nextIndex:17,term:20,followerCommit:16
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 17 -> 17
[ForkJoinPool.commonPool-worker-3] INFO client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-73072E12695E->s2@group-AD42E7C24DDE, cid=6, seq=0, RW, Message:6d3132, reply=RaftClientReply:client-73072E12695E->s2@group-AD42E7C24DDE, cid=6, FAILED org.apache.ratis.protocol.NotLeaderException: Server s2@group-AD42E7C24DDE is not the leader s1:0.0.0.0:49936, logIndex=0, commits[s2:c16, s0:c16, s1:c16]
[ForkJoinPool.commonPool-worker-1] INFO client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-3A32B89816B9->s2@group-AD42E7C24DDE, cid=8, seq=0, RW, Message:6d3131, reply=RaftClientReply:client-3A32B89816B9->s2@group-AD42E7C24DDE, cid=8, FAILED org.apache.ratis.protocol.NotLeaderException: Server s2@group-AD42E7C24DDE is not the leader s1:0.0.0.0:49936, logIndex=0, commits[s2:c16, s0:c16, s1:c16]
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1097)) - s0@group-AD42E7C24DDE: Failed appendEntries as previous log entry ((t:20, i:16)) is not found
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308910:FAIL,INCONSISTENCY,nextIndex:16,term:20,followerCommit:16
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 18 -> 16
statemachine.SimpleStateMachine4Testing (SimpleStateMachine4Testing.java:put(200)) - s1: put 17, m10 -> (t:20, i:17), STATEMACHINELOGENTRY, client-A0592557AEC3, cid=7
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1088)) - s0@group-AD42E7C24DDE: Failed appendEntries: the first entry (index 16) is already committed (commit index: 16)
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308911:FAIL,INCONSISTENCY,nextIndex:17,term:20,followerCommit:16
statemachine.SimpleStateMachine4Testing (SimpleStateMachine4Testing.java:put(200)) - s2: put 17, m10 -> (t:20, i:17), STATEMACHINELOGENTRY, client-A0592557AEC3, cid=7
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 19 -> 17
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1097)) - s0@group-AD42E7C24DDE: Failed appendEntries as previous log entry ((t:20, i:16)) is not found
impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308912:FAIL,INCONSISTENCY,nextIndex:16,term:20,followerCommit:16
impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 19 -> 16
..
{noformat}
 

I did not observe the problem when I test using Netty adapter.

 
I attached a file listing the messages sent or dropped in the execution. Each line lists the sender/receiver of the message together with some message information, and the number of times the message is sent/received. The messages marked with "-D" are dropped. 

You can also find the full log of the execution attached.


> GrpcLogAppender fails to fix failed AppendEntries with inconsistency in case of message losses
> ----------------------------------------------------------------------------------------------
>
>                 Key: RATIS-946
>                 URL: https://issues.apache.org/jira/browse/RATIS-946
>             Project: Ratis
>          Issue Type: Bug
>          Components: gRPC
>    Affects Versions: 0.6.0
>            Reporter: Burcu Ozkan
>            Priority: Major
>         Attachments: logs.txt, messages.txt
>
>
> I am testing fault tolerance of Ratis, more specifically whether it can tolerate random message losses. Simply, I drop some of the messages and do not deliver them to the recipient.
> In some tests where the servers have inconsistent logs, I observe executions in which the follower fails to synchronize with the leader.  The servers indefinitely exchange AppendEntries request and its failing reply, logging the following messages repeatedly:
> {noformat}
> impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 19 -> 17
> impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1097)) - s0@group-AD42E7C24DDE: Failed appendEntries as previous log entry ((t:20, i:16)) is not found
> impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308912:FAIL,INCONSISTENCY,nextIndex:16,term:20,followerCommit:16
> impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 19 -> 16 {noformat}
> Here is the part of the logs before the repeated messages:
> {noformat}
> ...
> impl.RoleInfo (RoleInfo.java:updateAndGet(143)) - s0: start FollowerState
> impl.RaftServerImpl (ServerState.java:setLeader(255)) - s0@group-AD42E7C24DDE: change Leader from null to s1 at term 20 for appendEntries, leader elected after 3ms
> client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-A0592557AEC3->s0@group-AD42E7C24DDE, cid=7, seq=0, RW, Message:6d3130, reply=RaftClientReply:client-A0592557AEC3->s0@group-AD42E7C24DDE, cid=7, FAILED org.apache.ratis.protocol.NotLeaderException: Server s0@group-AD42E7C24DDE is not the leader, logIndex=0, commits[s0:c14, s1:c13, s2:c13]
> client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-3A32B89816B9->s0@group-AD42E7C24DDE, cid=8, seq=0, RW, Message:6d3131, reply=RaftClientReply:client-3A32B89816B9->s0@group-AD42E7C24DDE, cid=8, FAILED org.apache.ratis.protocol.NotLeaderException: Server s0@group-AD42E7C24DDE is not the leader, logIndex=0, commits[s0:c14, s1:c13, s2:c13]
> client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-73072E12695E->s0@group-AD42E7C24DDE, cid=6, seq=0, RW, Message:6d3132, reply=RaftClientReply:client-73072E12695E->s0@group-AD42E7C24DDE, cid=6, FAILED org.apache.ratis.protocol.NotLeaderException: Server s0@group-AD42E7C24DDE is not the leader, logIndex=0, commits[s0:c14, s1:c13, s2:c13]
> server.GrpcLogAppender (GrpcLogAppender.java:onCompleted(321)) - s0@group-AD42E7C24DDE->s1-AppendLogResponseHandler: follower responses appendEntries COMPLETED
> impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1088)) - s0@group-AD42E7C24DDE: Failed appendEntries: the first entry (index 15) is already committed (commit index: 16)
> statemachine.SimpleStateMachine4Testing (SimpleStateMachine4Testing.java:put(200)) - s0: put 15, m11 -> (t:19, i:15), STATEMACHINELOGENTRY, client-3A32B89816B9, cid=8
> impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308907:FAIL,INCONSISTENCY,nextIndex:17,term:20,followerCommit:16
> statemachine.SimpleStateMachine4Testing (SimpleStateMachine4Testing.java:put(200)) - s0: put 16, m10 -> (t:19, i:16), STATEMACHINELOGENTRY, client-A0592557AEC3, cid=7
> impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 17 -> 17
> impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s0@group-AD42E7C24DDE->s2: nextIndex: updateUnconditionally 18 -> 15
> impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s0@group-AD42E7C24DDE->s1: nextIndex: updateUnconditionally 18 -> 15
> impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1097)) - s0@group-AD42E7C24DDE: Failed appendEntries as previous log entry ((t:20, i:16)) is not found
> impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308908:FAIL,INCONSISTENCY,nextIndex:16,term:20,followerCommit:16
> impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 17 -> 16
> impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1088)) - s0@group-AD42E7C24DDE: Failed appendEntries: the first entry (index 16) is already committed (commit index: 16)
> impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308909:FAIL,INCONSISTENCY,nextIndex:17,term:20,followerCommit:16
> impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 17 -> 17
> [ForkJoinPool.commonPool-worker-3] INFO client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-73072E12695E->s2@group-AD42E7C24DDE, cid=6, seq=0, RW, Message:6d3132, reply=RaftClientReply:client-73072E12695E->s2@group-AD42E7C24DDE, cid=6, FAILED org.apache.ratis.protocol.NotLeaderException: Server s2@group-AD42E7C24DDE is not the leader s1:0.0.0.0:49936, logIndex=0, commits[s2:c16, s0:c16, s1:c16]
> [ForkJoinPool.commonPool-worker-1] INFO client.GrpcClientProtocolService (GrpcClientProtocolService.java:lambda$processClientRequest$0(283)) - Failed RaftClientRequest:client-3A32B89816B9->s2@group-AD42E7C24DDE, cid=8, seq=0, RW, Message:6d3131, reply=RaftClientReply:client-3A32B89816B9->s2@group-AD42E7C24DDE, cid=8, FAILED org.apache.ratis.protocol.NotLeaderException: Server s2@group-AD42E7C24DDE is not the leader s1:0.0.0.0:49936, logIndex=0, commits[s2:c16, s0:c16, s1:c16]
> impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1097)) - s0@group-AD42E7C24DDE: Failed appendEntries as previous log entry ((t:20, i:16)) is not found
> impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308910:FAIL,INCONSISTENCY,nextIndex:16,term:20,followerCommit:16
> impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 18 -> 16
> statemachine.SimpleStateMachine4Testing (SimpleStateMachine4Testing.java:put(200)) - s1: put 17, m10 -> (t:20, i:17), STATEMACHINELOGENTRY, client-A0592557AEC3, cid=7
> impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1088)) - s0@group-AD42E7C24DDE: Failed appendEntries: the first entry (index 16) is already committed (commit index: 16)
> impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308911:FAIL,INCONSISTENCY,nextIndex:17,term:20,followerCommit:16
> statemachine.SimpleStateMachine4Testing (SimpleStateMachine4Testing.java:put(200)) - s2: put 17, m10 -> (t:20, i:17), STATEMACHINELOGENTRY, client-A0592557AEC3, cid=7
> impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 19 -> 17
> impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1097)) - s0@group-AD42E7C24DDE: Failed appendEntries as previous log entry ((t:20, i:16)) is not found
> impl.RaftServerImpl (RaftServerImpl.java:checkInconsistentAppendEntries(1063)) - s0@group-AD42E7C24DDE: inconsistency entries. Reply:s1<-s0#308912:FAIL,INCONSISTENCY,nextIndex:16,term:20,followerCommit:16
> impl.FollowerInfo (FollowerInfo.java:lambda$new$0(51)) - s1@group-AD42E7C24DDE->s0: nextIndex: updateUnconditionally 19 -> 16
> ..
> {noformat}
>  
> I did not observe the problem when I test using Netty adapter.
>  I attached a file listing the messages sent or dropped in the execution. Each line lists the sender/receiver of the message together with some message information, and the number of times the message is sent/received. The messages marked with "-D" are dropped. 
> You can also find the full log of the execution attached.



--
This message was sent by Atlassian Jira
(v8.3.4#803005)