Uploaded image for project: 'Ratis'
  1. Ratis
  2. RATIS-980

Fix leader election happens too fast

    XMLWordPrintableJSON

Details

    • Improvement
    • Status: Resolved
    • Major
    • Resolution: Fixed
    • None
    • 1.0.0
    • server
    • None

    Description

      2020-06-18T00:46:43.5446126Z 2020-06-18 00:46:43,543 [Thread-12] INFO impl.FollowerState (FollowerState.java:run(117)) - s2@group-3E7C5CE5BBB6-FollowerState was interrupted: java.lang.InterruptedException: sleep interrupted
      2020-06-18T00:46:43.6287348Z 2020-06-18 00:46:43,624 [nioEventLoopGroup-5-1] DEBUG impl.RaftServerImpl (RaftServerImpl.java:requestVote(841)) - s1@group-3E7C5CE5BBB6 replies to vote request: s0<-s1#0:OK-t1. Peer's state: s1@group-3E7C5CE5BBB6:t1, leader=null, voted=s0, raftlog=s1@group-3E7C5CE5BBB6-SegmentedRaftLog:OPENED:c-1,f-1,i0, conf=-1: [s0:0.0.0.0:33663, s1:0.0.0.0:42355, s2:0.0.0.0:43021], old=null
      2020-06-18T00:46:43.6302903Z 2020-06-18 00:46:43,625 [nioEventLoopGroup-9-1] DEBUG impl.RaftServerImpl (RaftServerImpl.java:requestVote(841)) - s2@group-3E7C5CE5BBB6 replies to vote request: s0<-s2#0:OK-t1. Peer's state: s2@group-3E7C5CE5BBB6:t1, leader=null, voted=s0, raftlog=s2@group-3E7C5CE5BBB6-SegmentedRaftLog:OPENED:c-1,f-1,i0, conf=-1: [s0:0.0.0.0:33663, s1:0.0.0.0:42355, s2:0.0.0.0:43021], old=null
      2020-06-18T00:46:43.6400885Z 2020-06-18 00:46:43,635 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO impl.LeaderElection (LeaderElection.java:logAndReturn(61)) - s0@group-3E7C5CE5BBB6-LeaderElection1: Election PASSED; received 1 response(s) [s0<-s1#0:OK-t1] and 0 exception(s); s0@group-3E7C5CE5BBB6:t1, leader=null, voted=s0, raftlog=s0@group-3E7C5CE5BBB6-SegmentedRaftLog:OPENED:c-1,f-1,i0, conf=-1: [s0:0.0.0.0:33663, s1:0.0.0.0:42355, s2:0.0.0.0:43021], old=null
      2020-06-18T00:46:43.6401898Z 2020-06-18 00:46:43,636 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO impl.RoleInfo (RoleInfo.java:shutdownLeaderElection(134)) - s0: shutdown LeaderElection
      2020-06-18T00:46:43.6402754Z 2020-06-18 00:46:43,636 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO impl.RaftServerImpl (RaftServerImpl.java:setRole(174)) - s0@group-3E7C5CE5BBB6: changes role from CANDIDATE to LEADER at term 1 for changeToLeader
      2020-06-18T00:46:43.6403983Z 2020-06-18 00:46:43,636 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO impl.RaftServerImpl (ServerState.java:setLeader(255)) - s0@group-3E7C5CE5BBB6: change Leader from null to s0 at term 1 for becomeLeader, leader elected after 618ms
      2020-06-18T00:46:43.6404833Z 2020-06-18 00:46:43,639 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO server.RaftServerConfigKeys (ConfUtils.java:logGet(44)) - raft.server.staging.catchup.gap = 1000 (default)
      2020-06-18T00:46:43.6416295Z 2020-06-18 00:46:43,639 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO server.RaftServerConfigKeys (ConfUtils.java:logGet(44)) - raft.server.rpc.sleep.time = 25ms (default)
      2020-06-18T00:46:43.6440194Z 2020-06-18 00:46:43,643 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO metrics.RatisMetrics (RatisMetrics.java:lambda$create$0(39)) - Creating Metrics Registry : ratis.log_appender.s0@group-3E7C5CE5BBB6
      2020-06-18T00:46:43.6442875Z 2020-06-18 00:46:43,643 [s0@group-3E7C5CE5BBB6-LeaderElection1] WARN impl.MetricRegistriesImpl (MetricRegistriesImpl.java:lambda$create$1(61)) - First MetricRegistry has been created without registering reporters. You may need to call MetricRegistries.global().addReportRegistration(...) before.
      2020-06-18T00:46:43.6500584Z 2020-06-18 00:46:43,646 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO server.RaftServerConfigKeys (ConfUtils.java:logGet(44)) - raft.server.write.element-limit = 4096 (default)
      2020-06-18T00:46:43.6509832Z 2020-06-18 00:46:43,650 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO server.RaftServerConfigKeys (ConfUtils.java:logGet(44)) - raft.server.write.byte-limit = 64MB (=67108864) (default)
      2020-06-18T00:46:43.6641705Z 2020-06-18 00:46:43,656 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO server.RaftServerConfigKeys (ConfUtils.java:logGet(44)) - raft.server.watch.timeout = 10s (default)
      2020-06-18T00:46:43.6648171Z 2020-06-18 00:46:43,658 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO server.RaftServerConfigKeys (ConfUtils.java:logGet(44)) - raft.server.watch.timeout.denomination = 1s (default)
      2020-06-18T00:46:43.6651041Z 2020-06-18 00:46:43,658 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO server.RaftServerConfigKeys (ConfUtils.java:logGet(44)) - raft.server.watch.element-limit = 65536 (default)
      2020-06-18T00:46:43.6697072Z 2020-06-18 00:46:43,669 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO server.RaftServerConfigKeys (ConfUtils.java:logGet(44)) - raft.server.log.appender.snapshot.chunk.size.max = 16MB (=16777216) (default)
      2020-06-18T00:46:43.6713970Z 2020-06-18 00:46:43,669 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO server.RaftServerConfigKeys (ConfUtils.java:logGet(44)) - raft.server.log.appender.buffer.byte-limit = 4MB (=4194304) (default)
      2020-06-18T00:46:43.6714691Z 2020-06-18 00:46:43,670 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO server.RaftServerConfigKeys (ConfUtils.java:logGet(44)) - raft.server.log.appender.buffer.element-limit = 0 (default)
      2020-06-18T00:46:43.6761166Z 2020-06-18 00:46:43,674 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO server.RaftServerConfigKeys (ConfUtils.java:logGet(44)) - raft.server.log.appender.snapshot.chunk.size.max = 16MB (=16777216) (default)
      2020-06-18T00:46:43.6803817Z 2020-06-18 00:46:43,674 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO server.RaftServerConfigKeys (ConfUtils.java:logGet(44)) - raft.server.log.appender.buffer.byte-limit = 4MB (=4194304) (default)
      2020-06-18T00:46:43.6804409Z 2020-06-18 00:46:43,676 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO server.RaftServerConfigKeys (ConfUtils.java:logGet(44)) - raft.server.log.appender.buffer.element-limit = 0 (default)
      2020-06-18T00:46:43.6805103Z 2020-06-18 00:46:43,678 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO impl.RoleInfo (RoleInfo.java:updateAndGet(143)) - s0: start LeaderState
      2020-06-18T00:46:43.6910694Z 2020-06-18 00:46:43,690 [s0@group-3E7C5CE5BBB6-LeaderElection1] DEBUG raftlog.RaftLog (SegmentedRaftLog.java:appendImpl(454)) - truncateIndex=-1, arrayIndex=0
      2020-06-18T00:46:43.6944267Z 2020-06-18 00:46:43,693 [s0@group-3E7C5CE5BBB6-LeaderElection1] INFO segmented.SegmentedRaftLogWorker (SegmentedRaftLogWorker.java:startLogSegment(391)) - s0@group-3E7C5CE5BBB6-SegmentedRaftLogWorker: Starting segment from index:0
      2020-06-18T00:46:43.7132697Z 2020-06-18 00:46:43,712 [Thread-14] INFO impl.FollowerState (FollowerState.java:run(108)) - s1@group-3E7C5CE5BBB6-FollowerState: change to CANDIDATE, lastRpcTime:175ms, electionTimeout:169ms

      Attachments

        Issue Links

          links to

          Web Link GitHub Pull Request #130

          Activity

            People

              yjxxtd runzhiwang
              yjxxtd runzhiwang
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0h
                  0h
                  Logged:
                  Time Spent - 0.5h
                  0.5h