You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ratis.apache.org by "Mukul Kumar Singh (JIRA)" <ji...@apache.org> on 2018/09/10 05:59:00 UTC
[jira] [Resolved] (RATIS-312) log append entry is failing in ratis
after leader election
[ https://issues.apache.org/jira/browse/RATIS-312?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Mukul Kumar Singh resolved RATIS-312.
-------------------------------------
Resolution: Duplicate
The problem here is same as RATIS-304. Duping it. And raising the priority of RATIS-304.
> log append entry is failing in ratis after leader election
> ----------------------------------------------------------
>
> Key: RATIS-312
> URL: https://issues.apache.org/jira/browse/RATIS-312
> Project: Ratis
> Issue Type: Bug
> Reporter: Nilotpal Nandi
> Priority: Major
>
> steps taken :
> -------------------
> # created 6 node ozone cluster.
> # copied a file from local through ozoneFS interface : ozone fs -copyFromLocal /etc/passwd /
> # created a copy of the passwd file - ozone fs -cp /passwd /passwd2
> # Now , tried to overwrite the key 'passwd2' with different content - ./ozone oz -putKey /fs-volume/fs-bucket/passwd2 -file /etc/services
> Observations :
> ------------------------
> PutKey ozone client request hang indefinitely because ratis client keeps re-trying.
> datanode log :
> ----------------------
> {noformat}
> 2018-09-06 13:32:53,506 INFO org.apache.ratis.server.impl.RaftServerImpl: d9654353-6240-4ac6-b561-04e0498ba522_9858: change Leader from null to 071106cd-87b7-4c2b-8ae0-f1c94c3485ca_9858 at term 11 for appendEntries, leader elected after 286ms
> 2018-09-06 13:32:53,510 INFO org.apache.ratis.server.storage.RaftLogWorker: Rolling segment:d9654353-6240-4ac6-b561-04e0498ba522_9858-RaftLogWorker index to:423
> 2018-09-06 13:32:53,518 INFO org.apache.ratis.server.impl.RaftServerImpl: d9654353-6240-4ac6-b561-04e0498ba522_9858-org.apache.ratis.server.impl.RoleInfo@6e79224c: Withhold vote from candidate 071106cd-87b7-4c2b-8ae0-f1c94c3485ca_9858 with term 11. State: leader=071106cd-87b7-4c2b-8ae0-f1c94c3485ca_9858, term=11, lastRpcElapsed=8ms
> 2018-09-06 13:32:53,518 INFO org.apache.ratis.server.impl.LogAppender: d9654353-6240-4ac6-b561-04e0498ba522_9858 stops appending log entries to follower 071106cd-87b7-4c2b-8ae0-f1c94c3485ca_9858(next=423, match=422, attendVote=true, lastRpcSendTime=299, lastRpcResponseTime=297)
> 2018-09-06 13:32:56,217 WARN org.apache.ratis.server.impl.LogAppender: GRpcLogAppender(d9654353-6240-4ac6-b561-04e0498ba522_9858 > d00d2193-4f96-4ee2-bd52-9d245a90e51f_9858): appendEntries Timeout, request=d9654353-6240-4ac6-b561-04e0498ba522_9858>d00d2193-4f96-4ee2-bd52-9d245a90e51f_9858#1675
> 2018-09-06 13:32:56,220 WARN org.apache.ratis.server.impl.LogAppender: GRpcLogAppender(d9654353-6240-4ac6-b561-04e0498ba522_9858 > 071106cd-87b7-4c2b-8ae0-f1c94c3485ca_9858): appendEntries Timeout, request=d9654353-6240-4ac6-b561-04e0498ba522_9858>071106cd-87b7-4c2b-8ae0-f1c94c3485ca_9858#1687
> 2018-09-06 17:20:14,788 INFO org.apache.ratis.server.impl.RaftServerImpl: d9654353-6240-4ac6-b561-04e0498ba522_9858: change Leader from 071106cd-87b7-4c2b-8ae0-f1c94c3485ca_9858 to null at term 12 for updateCurrentTerm
> 2018-09-06 17:20:14,800 INFO org.apache.ratis.server.impl.RaftServerImpl: d9654353-6240-4ac6-b561-04e0498ba522_9858: change Leader from null to d00d2193-4f96-4ee2-bd52-9d245a90e51f_9858 at term 12 for appendEntries, leader elected after 11ms
> 2018-09-06 17:20:19,116 INFO org.apache.ratis.server.impl.RaftServerImpl: d9654353-6240-4ac6-b561-04e0498ba522_9858: change Leader from d00d2193-4f96-4ee2-bd52-9d245a90e51f_9858 to null at term 13 for updateCurrentTerm
> 2018-09-06 17:20:19,123 INFO org.apache.ratis.server.impl.RaftServerImpl: d9654353-6240-4ac6-b561-04e0498ba522_9858: change Leader from null to 071106cd-87b7-4c2b-8ae0-f1c94c3485ca_9858 at term 13 for appendEntries, leader elected after 7ms
> 2018-09-06 17:20:21,991 WARN org.apache.ratis.grpc.server.RaftServerProtocolService: d9654353-6240-4ac6-b561-04e0498ba522_9858: Failed appendEntries 071106cd-87b7-4c2b-8ae0-f1c94c3485ca_9858->d9654353-6240-4ac6-b561-04e0498ba522_9858#1
> java.lang.IllegalStateException: Unexpected Index: previous is (t:11, i:457) but entries[0].getIndex()=0
> at org.apache.ratis.util.Preconditions.assertTrue(Preconditions.java:60)
> at org.apache.ratis.server.impl.RaftServerImpl.validateEntries(RaftServerImpl.java:800)
> at org.apache.ratis.server.impl.RaftServerImpl.appendEntriesAsync(RaftServerImpl.java:873)
> at org.apache.ratis.server.impl.RaftServerImpl.appendEntriesAsync(RaftServerImpl.java:838)
> at org.apache.ratis.server.impl.RaftServerProxy.appendEntriesAsync(RaftServerProxy.java:247)
> at org.apache.ratis.grpc.server.RaftServerProtocolService$1.onNext(RaftServerProtocolService.java:76)
> at org.apache.ratis.grpc.server.RaftServerProtocolService$1.onNext(RaftServerProtocolService.java:66)
> at org.apache.ratis.shaded.io.grpc.stub.ServerCalls$StreamingServerCallHandler$StreamingServerCallListener.onMessage(ServerCalls.java:248)
> at org.apache.ratis.shaded.io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.messagesAvailable(ServerCallImpl.java:263)
> at org.apache.ratis.shaded.io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1MessagesAvailable.runInContext(ServerImpl.java:683)
> at org.apache.ratis.shaded.io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
> at org.apache.ratis.shaded.io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> 2018-09-06 17:20:22,249 WARN org.apache.ratis.grpc.server.RaftServerProtocolService: d9654353-6240-4ac6-b561-04e0498ba522_9858: appendEntries onError: org.apache.ratis.shaded.io.grpc.StatusRuntimeException: CANCELLED: cancelled before receiving half close
> 2018-09-06 17:20:25,303 WARN org.apache.ratis.grpc.server.RaftServerProtocolService: d9654353-6240-4ac6-b561-04e0498ba522_9858: Failed appendEntries 071106cd-87b7-4c2b-8ae0-f1c94c3485ca_9858->d9654353-6240-4ac6-b561-04e0498ba522_9858#11
> java.lang.IllegalStateException: Unexpected Index: entries[1].getIndex()=0 but entries[0].getIndex()=0
> at org.apache.ratis.util.Preconditions.assertTrue(Preconditions.java:60)
> at org.apache.ratis.server.impl.RaftServerImpl.validateEntries(RaftServerImpl.java:812)
> at org.apache.ratis.server.impl.RaftServerImpl.appendEntriesAsync(RaftServerImpl.java:873)
> at org.apache.ratis.server.impl.RaftServerImpl.appendEntriesAsync(RaftServerImpl.java:838){noformat}
> cc - [~shashikant] , [~ljain]
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)