[HDDS-1102] Confusing error log when datanode tries to connect to a destroyed pipeline

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Won't Fix
• Component/s: Ozone Datanode
• Labels: TriagePending newbie ozone-log-cleanup pushed-to-craterlake test-badlands
• Target Version/s: 1.4.0
• Assignee: Shashikant Banerjee
• Reporter: Nilotpal Nandi
• Created: 14/Feb/19 10:32
• Updated: 22/Sep/23 04:10
• Resolved: 22/Sep/23 04:10

Description

steps taken:

--------------------

1. created 5 datanode cluster.
2. shutdown 2 datanodes
3. started the datanodes again.

One of the datanodes was shut down.

exception seen :

 

2019-02-14 07:37:26 INFO LeaderElection:230 - 6a0522ba-019e-4b77-ac1f-a9322cd525b8 got exception when requesting votes: {}
java.util.concurrent.ExecutionException: org.apache.ratis.thirdparty.io.grpc.StatusRuntimeException: INTERNAL: a3d1dd2d-554e-4e87-a2cf-076a229af352: group-FD6FA533F1FB not found.
 at java.util.concurrent.FutureTask.report(FutureTask.java:122)
 at java.util.concurrent.FutureTask.get(FutureTask.java:192)
 at org.apache.ratis.server.impl.LeaderElection.waitForResults(LeaderElection.java:214)
 at org.apache.ratis.server.impl.LeaderElection.askForVotes(LeaderElection.java:146)
 at org.apache.ratis.server.impl.LeaderElection.run(LeaderElection.java:102)
Caused by: org.apache.ratis.thirdparty.io.grpc.StatusRuntimeException: INTERNAL: a3d1dd2d-554e-4e87-a2cf-076a229af352: group-FD6FA533F1FB not found.
 at org.apache.ratis.thirdparty.io.grpc.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:233)
 at org.apache.ratis.thirdparty.io.grpc.stub.ClientCalls.getUnchecked(ClientCalls.java:214)
 at org.apache.ratis.thirdparty.io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:139)
 at org.apache.ratis.proto.grpc.RaftServerProtocolServiceGrpc$RaftServerProtocolServiceBlockingStub.requestVote(RaftServerProtocolServiceGrpc.java:265)
 at org.apache.ratis.grpc.server.GrpcServerProtocolClient.requestVote(GrpcServerProtocolClient.java:83)
 at org.apache.ratis.grpc.server.GrpcService.requestVote(GrpcService.java:187)
 at org.apache.ratis.server.impl.LeaderElection.lambda$submitRequests$0(LeaderElection.java:188)
 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 at java.lang.Thread.run(Thread.java:748)
2019-02-14 07:37:26 INFO LeaderElection:46 - 6a0522ba-019e-4b77-ac1f-a9322cd525b8: Election PASSED; received 1 response(s) [6a0522ba-019e-4b77-ac1f-a9322cd525b8<-61ad3bf3-e9b1-48e5-90e3-3b78c8b5bba5#0:OK-t7] and 1 exception(s); 6a0522ba-019e-4b77-ac1f-a9322cd525b8:t7, leader=null, voted=6a0522ba-019e-4b77-ac1f-a9322cd525b8, raftlog=6a0522ba-019e-4b77-ac1f-a9322cd525b8-SegmentedRaftLog:OPENED, conf=3: [61ad3bf3-e9b1-48e5-90e3-3b78c8b5bba5:172.20.0.8:9858, 6a0522ba-019e-4b77-ac1f-a9322cd525b8:172.20.0.6:9858, 0f377918-aafa-4d8a-972a-6ead54048fba:172.20.0.3:9858], old=null
2019-02-14 07:37:26 INFO LeaderElection:52 - 0: java.util.concurrent.ExecutionException: org.apache.ratis.thirdparty.io.grpc.StatusRuntimeException: INTERNAL: a3d1dd2d-554e-4e87-a2cf-076a229af352: group-FD6FA533F1FB not found.
2019-02-14 07:37:26 INFO RoleInfo:130 - 6a0522ba-019e-4b77-ac1f-a9322cd525b8: shutdown LeaderElection
2019-02-14 07:37:26 INFO RaftServerImpl:161 - 6a0522ba-019e-4b77-ac1f-a9322cd525b8 changes role from CANDIDATE to LEADER at term 7 for changeToLeader
2019-02-14 07:37:26 INFO RaftServerImpl:258 - 6a0522ba-019e-4b77-ac1f-a9322cd525b8: change Leader from null to 6a0522ba-019e-4b77-ac1f-a9322cd525b8 at term 7 for becomeLeader, leader elected after 1066ms
2019-02-14 07:37:26 INFO RaftServerConfigKeys:43 - raft.server.staging.catchup.gap = 1000 (default)
2019-02-14 07:37:26 INFO RaftServerConfigKeys:43 - raft.server.rpc.sleep.time = 25ms (default)
2019-02-14 07:37:26 INFO RaftServerConfigKeys:43 - raft.server.watch.timeout = 10s (default)
2019-02-14 07:37:26 INFO RaftServerConfigKeys:43 - raft.server.watch.timeout.denomination = 1s (default)
2019-02-14 07:37:26 INFO RaftServerConfigKeys:43 - raft.server.log.appender.snapshot.chunk.size.max = 16MB (=16777216) (default)
2019-02-14 07:37:26 INFO RaftServerConfigKeys:43 - raft.server.log.appender.buffer.byte-limit = 33554432 (custom)
2019-02-14 07:37:26 INFO RaftServerConfigKeys:43 - raft.server.log.appender.buffer.element-limit = 1 (custom)
2019-02-14 07:37:26 INFO GrpcConfigKeys$Server:43 - raft.grpc.server.leader.outstanding.appends.max = 128 (default)
2019-02-14 07:37:26 INFO RaftServerConfigKeys:43 - raft.server.rpc.request.timeout = 3000ms (default)
2019-02-14 07:37:26 INFO RaftServerConfigKeys:43 - raft.server.log.appender.snapshot.chunk.size.max = 16MB (=16777216) (default)
2019-02-14 07:37:26 INFO RaftServerConfigKeys:43 - raft.server.log.appender.buffer.byte-limit = 33554432 (custom)
2019-02-14 07:37:26 INFO RaftServerConfigKeys:43 - raft.server.log.appender.buffer.element-limit = 1 (custom)
2019-02-14 07:37:26 INFO GrpcConfigKeys$Server:43 - raft.grpc.server.leader.outstanding.appends.max = 128 (default)
2019-02-14 07:37:26 INFO RaftServerConfigKeys:43 - raft.server.rpc.request.timeout = 3000ms (default)
2019-02-14 07:37:26 INFO RoleInfo:139 - 6a0522ba-019e-4b77-ac1f-a9322cd525b8: start LeaderState
2019-02-14 07:37:26 INFO RaftLogWorker:303 - 6a0522ba-019e-4b77-ac1f-a9322cd525b8-RaftLogWorker: Rolling segment log-3_4 to index:4
2019-02-14 07:37:26 INFO RaftLogWorker:403 - 6a0522ba-019e-4b77-ac1f-a9322cd525b8-RaftLogWorker: Rolled log segment from /data/metadata/ratis/134f574e-c1b0-4556-a206-fd6fa533f1fb/current/log_inprogress_3 to /data/metadata/ratis/134f574e-c1b0-4556-a206-fd6fa533f1fb/current/log_3-4
2019-02-14 07:37:26 INFO RaftServerImpl:354 - 6a0522ba-019e-4b77-ac1f-a9322cd525b8: set configuration 5: [61ad3bf3-e9b1-48e5-90e3-3b78c8b5bba5:172.20.0.8:9858, 6a0522ba-019e-4b77-ac1f-a9322cd525b8:172.20.0.6:9858, 0f377918-aafa-4d8a-972a-6ead54048fba:172.20.0.3:9858], old=null at 5
/opt/starter.sh: line 162: 13 Killed $@