Hello team,
I initiated three nodes, namely n0, n1, and n2, using the following commands:
ID=n0; ${BIN}/server.sh arithmetic server --id ${ID} --storage /tmp/ratis/${ID}
--peers ${PEERS}
ID=n1; ${BIN}/server.sh arithmetic server --id ${ID} --storage /tmp/ratis/${ID}
--peers ${PEERS}
ID=n2; ${BIN}/server.sh arithmetic server --id ${ID} --storage /tmp/ratis/${ID}
--peers ${PEERS}
Based on the logs, it appears that n2 is the leader:
INFO StateMachine:166 - LEADER:n2-1: a = 10 = 10
However, when I attempted to stop the n2 node (leader) and start a new node,
n3, with peers n0, n1, and n3, the n3 server failed to start. Attached are the
log files for review.
I am seeking assistance in understanding the reason for this error preventing
the successful start of the n3 node.
In another scenario:
I started three nodes, n0, n1, and n2, using similar commands, and logs
indicated that n1 was the leader:
INFO StateMachine:166 - LEADER:n1-1: a = 10 = 10
Upon stopping the non-leader node, n2, I attempted to start a new node, n3,
with peers n0, n1, and n3. The n3 server started but generated errors such as:
2023-12-11 12:43:13 INFO RaftServer$Division:377 - n3@group-6F7570313233:
changes role from CANDIDATE to FOLLOWER at term 1 for REJECTED
These errors were resolved by running the append command using the admin client.
I appreciate your assistance in resolving this issues.
Thanks,
Mahesh Reddy
CONFIDENTIALITY NOTICE This e-mail message and any attachments are only for the
use of the intended recipient and may contain information that is privileged,
confidential or exempt from disclosure under applicable law. If you are not the
intended recipient, any disclosure, distribution or other use of this e-mail
message or attachments is prohibited. If you have received this e-mail message
in error, please delete and notify the sender immediately. Thank you.
BIN=ratis-examples/src/main/bin
PEERS=n0:127.0.0.1:6000,n1:127.0.0.1:6001,n3:127.0.0.1:6003
e156510@D0YQ455XC4 ratis %
e156510@D0YQ455XC4 ratis % ID=n3; ${BIN}/server.sh arithmetic server --id
${ID} --storage /tmp/ratis/${ID} --peers ${PEERS}
Found
/Users/e156510/IdeaProjects/raft/ratis/ratis-examples/target/ratis-examples-3.0.0-SNAPSHOT.jar
2023-12-11 12:32:28 INFO RaftServer:46 - raft.rpc.type = GRPC (default)
2023-12-11 12:32:29 INFO GrpcConfigKeys:53 - raft.grpc.admin.host = null
(fallback to raft.grpc.server.host)
2023-12-11 12:32:29 INFO GrpcConfigKeys:53 - raft.grpc.admin.port = 6003
(fallback to raft.grpc.server.port)
2023-12-11 12:32:29 INFO GrpcConfigKeys:53 - raft.grpc.client.host = null
(fallback to raft.grpc.server.host)
2023-12-11 12:32:29 INFO GrpcConfigKeys:53 - raft.grpc.client.port = 6003
(fallback to raft.grpc.server.port)
2023-12-11 12:32:29 INFO GrpcConfigKeys:46 - raft.grpc.server.host = null
(default)
2023-12-11 12:32:29 INFO GrpcConfigKeys:46 - raft.grpc.server.port = 6003
(custom)
2023-12-11 12:32:29 INFO GrpcService:46 - raft.grpc.message.size.max = 64MB
(=67108864) (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.appender.buffer.byte-limit = 4MB (=4194304) (default)
2023-12-11 12:32:29 INFO GrpcService:46 - raft.grpc.flow.control.window = 1MB
(=1048576) (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.rpc.request.timeout = 3000ms (default)
2023-12-11 12:32:29 INFO GrpcConfigKeys:46 -
raft.grpc.server.heartbeat.channel = true (default)
2023-12-11 12:32:29 INFO GrpcConfigKeys:46 -
raft.grpc.server.async.request.thread.pool.cached = true (default)
2023-12-11 12:32:29 INFO GrpcConfigKeys:46 -
raft.grpc.server.async.request.thread.pool.size = 32 (default)
2023-12-11 12:32:29 INFO DataStreamServerImpl:46 - raft.datastream.type =
DISABLED (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.sleep.deviation.threshold = 300ms (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 - raft.server.close.threshold
= 60s (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.leaderelection.leader.step-down.wait-time = 10s (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 - raft.server.storage.dir =
[/tmp/ratis/n3] (custom)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.threadpool.proxy.cached = true (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.threadpool.proxy.size = 0 (default)
2023-12-11 12:32:29 INFO RaftServer:100 - n3: addNew
group-6F7570313233:[n0|127.0.0.1:6000, n1|127.0.0.1:6001, n3|127.0.0.1:6003]
returns group-6F7570313233:java.util.concurrent.CompletableFuture@30af5b6b[Not
completed]
2023-12-11 12:32:29 INFO RaftServer$Division:255 - n3: new RaftServerImpl for
group-6F7570313233:[n0|127.0.0.1:6000, n1|127.0.0.1:6001, n3|127.0.0.1:6003]
with ArithmeticStateMachine:uninitialized
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 - raft.server.rpc.timeout.min
= 150ms (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 - raft.server.rpc.timeout.max
= 300ms (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 - raft.server.rpc.sleep.time
= 25ms (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.rpc.slowness.timeout = 60s (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.leaderelection.leader.step-down.wait-time = 10s (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.sleep.deviation.threshold = 300ms (default)
2023-12-11 12:32:29 INFO RaftServer$Division:113 - n3@group-6F7570313233:
ConfigurationManager, init=-1: peers:[n0|127.0.0.1:6000, n1|127.0.0.1:6001,
n3|127.0.0.1:6003]|listeners:[], old=null, confs=<EMPTY_MAP>
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.notification.no-leader.timeout = 60s (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 - raft.server.read.timeout =
10s (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.retrycache.expirytime = 60s (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.retrycache.statistics.expirytime = 100ms (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 - raft.server.read.option =
DEFAULT (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.read.read-after-write-consistent.write-index-cache.expiry-time =
60s (default)
2023-12-11 12:32:29 INFO MetricRegistries:64 - Loaded MetricRegistries class
org.apache.ratis.metrics.impl.MetricRegistriesImpl
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.rpc.request.timeout = 3000ms (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.appender.install.snapshot.enabled = true (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.threadpool.server.cached = true (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.threadpool.server.size = 0 (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.threadpool.client.cached = true (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.threadpool.client.size = 0 (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.storage.free-space.min = 0MB (=0) (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.corruption.policy = EXCEPTION (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 - raft.server.storage.dir =
[/tmp/ratis/n3] (custom)
2023-12-11 12:32:29 INFO RaftStorageDirectory:138 - The storage directory
/private/tmp/ratis/n3/64656d6f-5261-6674-4772-6f7570313233 does not exist.
Creating ...
2023-12-11 12:32:29 INFO RaftStorageDirectory:232 - Lock on
/tmp/ratis/n3/64656d6f-5261-6674-4772-6f7570313233/in_use.lock acquired by
nodename 96025@D0YQ455XC4
2023-12-11 12:32:29 INFO RaftStorage:97 - Storage directory
/tmp/ratis/n3/64656d6f-5261-6674-4772-6f7570313233 has been successfully
formatted.
2023-12-11 12:32:29 WARN StateMachine:100 - The snapshot info is null.
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 - raft.server.log.use.memory
= false (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 - raft.server.log.purge.gap =
1024 (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.appender.buffer.byte-limit = 4MB (=4194304) (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.statemachine.data.read.timeout = 1000ms (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.purge.preservation.log.num = 0 (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.segment.size.max = 32MB (=33554432) (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.segment.cache.num.max = 6 (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.segment.cache.size.max = 200MB (=209715200) (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.appender.buffer.byte-limit = 4MB (=4194304) (default)
2023-12-11 12:32:29 INFO AwaitToRun:81 -
Thread[n3@group-6F7570313233-cacheEviction-AwaitToRun,5,main] started
2023-12-11 12:32:29 INFO SegmentedRaftLogWorker:184 - new
n3@group-6F7570313233-SegmentedRaftLogWorker for RaftStorageImpl:Storage
Directory /tmp/ratis/n3/64656d6f-5261-6674-4772-6f7570313233
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.queue.byte-limit = 64MB (=67108864) (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.queue.element-limit = 4096 (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.segment.size.max = 32MB (=33554432) (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.preallocated.size = 4MB (=4194304) (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.force.sync.num = 128 (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.statemachine.data.sync = true (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.statemachine.data.sync.timeout = 10s (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.statemachine.data.sync.timeout.retry = -1 (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.write.buffer.size = 64KB (=65536) (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.appender.buffer.byte-limit = 4MB (=4194304) (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.unsafe-flush.enabled = false (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.async-flush.enabled = false (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.statemachine.data.caching.enabled = false (default)
2023-12-11 12:32:29 INFO SegmentedRaftLogWorker:135 -
n3@group-6F7570313233-SegmentedRaftLogWorker: flushIndex: setUnconditionally 0
-> -1
2023-12-11 12:32:29 INFO SegmentedRaftLogWorker:135 -
n3@group-6F7570313233-SegmentedRaftLogWorker: safeCacheEvictIndex:
setUnconditionally 0 -> -1
2023-12-11 12:32:29 INFO RaftServer$Division:390 - n3@group-6F7570313233:
start as a follower, conf=-1: peers:[n0|127.0.0.1:6000, n1|127.0.0.1:6001,
n3|127.0.0.1:6003]|listeners:[], old=null
2023-12-11 12:32:29 INFO RaftServer$Division:377 - n3@group-6F7570313233:
changes role from null to FOLLOWER at term 0 for startAsFollower
2023-12-11 12:32:29 INFO RoleInfo:138 - n3: start
n3@group-6F7570313233-FollowerState
2023-12-11 12:32:29 INFO RaftServerConfigKeys:53 -
raft.server.rpc.first-election.timeout.min = 150ms (fallback to
raft.server.rpc.timeout.min)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:53 -
raft.server.rpc.first-election.timeout.max = 300ms (fallback to
raft.server.rpc.timeout.max)
2023-12-11 12:32:29 INFO JmxRegister:44 - Successfully registered JMX Bean
with object name Ratis:service=RaftServer,group=group-6F7570313233,id=n3
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.snapshot.trigger-when-stop.enabled = true (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.snapshot.auto.trigger.enabled = false (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.snapshot.retention.file.num = -1 (default)
2023-12-11 12:32:29 INFO RaftServerConfigKeys:46 -
raft.server.log.purge.upto.snapshot.index = false (default)
2023-12-11 12:32:29 INFO RaftServer:406 - n3: start RPC server
2023-12-11 12:32:30 INFO GrpcService:302 - n3: GrpcService started, listening
on 6003
2023-12-11 12:32:30 INFO JvmPauseMonitor:146 - JvmPauseMonitor-n3: Started
2023-12-11 12:32:30 INFO FollowerState:143 -
n3@group-6F7570313233-FollowerState: change to CANDIDATE,
lastRpcElapsedTime:177179458ns, electionTimeout:172ms
2023-12-11 12:32:30 INFO RoleInfo:109 - n3: shutdown
n3@group-6F7570313233-FollowerState
2023-12-11 12:32:30 INFO RaftServer$Division:377 - n3@group-6F7570313233:
changes role from FOLLOWER to CANDIDATE at term 0 for changeToCandidate
2023-12-11 12:32:30 INFO RaftServerConfigKeys:46 -
raft.server.leaderelection.pre-vote = true (default)
2023-12-11 12:32:30 INFO RoleInfo:138 - n3: start
n3@group-6F7570313233-LeaderElection1
2023-12-11 12:32:30 INFO LeaderElection:323 -
n3@group-6F7570313233-LeaderElection1 PRE_VOTE round 0: submit vote requests at
term 0 for -1: peers:[n0|127.0.0.1:6000, n1|127.0.0.1:6001,
n3|127.0.0.1:6003]|listeners:[], old=null
2023-12-11 12:32:30 INFO RaftServerConfigKeys:53 -
raft.server.rpc.first-election.timeout.min = 150ms (fallback to
raft.server.rpc.timeout.min)
2023-12-11 12:32:30 INFO RaftServerConfigKeys:53 -
raft.server.rpc.first-election.timeout.max = 300ms (fallback to
raft.server.rpc.timeout.max)
2023-12-11 12:32:30 INFO GrpcServerProtocolClient:65 - Build channel for n0
2023-12-11 12:32:30 INFO GrpcServerProtocolClient:65 - Build channel for n1
2023-12-11 12:32:30 INFO LeaderElection:89 -
n3@group-6F7570313233-LeaderElection1: PRE_VOTE TIMEOUT received 0 response(s)
and 0 exception(s):
2023-12-11 12:32:30 INFO LeaderElection:325 -
n3@group-6F7570313233-LeaderElection1 PRE_VOTE round 0: result TIMEOUT
2023-12-11 12:32:30 INFO LeaderElection:323 -
n3@group-6F7570313233-LeaderElection1 PRE_VOTE round 1: submit vote requests at
term 0 for -1: peers:[n0|127.0.0.1:6000, n1|127.0.0.1:6001,
n3|127.0.0.1:6003]|listeners:[], old=null
2023-12-11 12:32:30 INFO RaftServerConfigKeys:53 -
raft.server.rpc.first-election.timeout.min = 150ms (fallback to
raft.server.rpc.timeout.min)
2023-12-11 12:32:30 INFO RaftServerConfigKeys:53 -
raft.server.rpc.first-election.timeout.max = 300ms (fallback to
raft.server.rpc.timeout.max)
2023-12-11 12:32:30 INFO LeaderElection:89 -
n3@group-6F7570313233-LeaderElection1: PRE_VOTE SHUTDOWN received 1 response(s)
and 0 exception(s):
2023-12-11 12:32:30 INFO LeaderElection:93 - Response 0: n3<-n0#0:FAIL-t3
2023-12-11 12:32:30 INFO LeaderElection:325 -
n3@group-6F7570313233-LeaderElection1 PRE_VOTE round 1: result SHUTDOWN
2023-12-11 12:32:30 INFO RaftServer:416 - n3: close
2023-12-11 12:32:30 INFO GrpcService:311 - n3: shutdown server
GrpcServerProtocolService now
2023-12-11 12:32:30 INFO RaftServer$Division:514 - n3@group-6F7570313233:
shutdown
2023-12-11 12:32:30 INFO JmxRegister:73 - Successfully un-registered JMX Bean
with object name Ratis:service=RaftServer,group=group-6F7570313233,id=n3
2023-12-11 12:32:30 INFO RoleInfo:129 - n3: shutdown
n3@group-6F7570313233-LeaderElection1
2023-12-11 12:32:30 INFO StateMachineUpdater:157 -
n3@group-6F7570313233-StateMachineUpdater: set stopIndex = -1
2023-12-11 12:32:30 INFO GrpcServerProtocolClient:103 - n1 Close channels
2023-12-11 12:32:30 INFO GrpcServerProtocolClient:103 - n0 Close channels
2023-12-11 12:32:30 INFO RaftServer$Division:423 - n3@group-6F7570313233:
applyIndex: -1
2023-12-11 12:32:30 INFO AwaitToRun:49 -
n3@group-6F7570313233-cacheEviction-AwaitToRun-AwaitForSignal is interrupted
2023-12-11 12:32:30 INFO GrpcService:320 - n3: shutdown server
GrpcServerProtocolService successfully
2023-12-11 12:32:30 INFO SegmentedRaftLogWorker:243 -
n3@group-6F7570313233-SegmentedRaftLogWorker close()
2023-12-11 12:32:30 INFO JvmPauseMonitor:152 - JvmPauseMonitor-n3: Stopped
e156510@D0YQ455XC4 ratis %
e156510@D0YQ455XC4 ratis %
e156510@D0YQ455XC4 ratis %
