[ratis] branch master updated: RATIS-1858. Follower keeps logging first election timeout. (#894)

[szetszwo]

This is an automated email from the ASF dual-hosted git repository.

szetszwo pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/ratis.git


The following commit(s) were added to refs/heads/master by this push:
     new 5c47d3b4c RATIS-1858. Follower keeps logging first election timeout. 
(#894)
5c47d3b4c is described below

commit 5c47d3b4cafffa8e2bc21276f302d70efbbed5a9
Author: Tsz-Wo Nicholas Sze <szets...@apache.org>
AuthorDate: Thu Jul 27 10:52:11 2023 -0700

    RATIS-1858. Follower keeps logging first election timeout. (#894)
---
 .../org/apache/ratis/server/impl/RaftServerImpl.java     |  8 +++++++-
 .../java/org/apache/ratis/server/impl/ServerState.java   | 16 ++++++++--------
 2 files changed, 15 insertions(+), 9 deletions(-)

diff --git 
a/ratis-server/src/main/java/org/apache/ratis/server/impl/RaftServerImpl.java 
b/ratis-server/src/main/java/org/apache/ratis/server/impl/RaftServerImpl.java
index e429518e6..a857faa87 100644
--- 
a/ratis-server/src/main/java/org/apache/ratis/server/impl/RaftServerImpl.java
+++ 
b/ratis-server/src/main/java/org/apache/ratis/server/impl/RaftServerImpl.java
@@ -551,6 +551,12 @@ class RaftServerImpl implements RaftServer.Division,
     });
   }
 
+  void setFirstElection(Object reason) {
+    if (firstElectionSinceStartup.compareAndSet(true, false)) {
+      LOG.info("{}: set firstElectionSinceStartup to false for {}", 
getMemberId(), reason);
+    }
+  }
+
   /**
    * Change the server state to Follower if this server is in a different role 
or force is true.
    * @param newTerm The new term.
@@ -579,7 +585,7 @@ class RaftServerImpl implements RaftServer.Division,
         role.shutdownFollowerState();
       }
       role.startFollowerState(this, reason);
-      firstElectionSinceStartup.set(false);
+      setFirstElection(reason);
     }
     return metadataUpdated;
   }
diff --git 
a/ratis-server/src/main/java/org/apache/ratis/server/impl/ServerState.java 
b/ratis-server/src/main/java/org/apache/ratis/server/impl/ServerState.java
index 59a392f8e..2f2f36d79 100644
--- a/ratis-server/src/main/java/org/apache/ratis/server/impl/ServerState.java
+++ b/ratis-server/src/main/java/org/apache/ratis/server/impl/ServerState.java
@@ -69,7 +69,7 @@ class ServerState {
   /** local storage for log and snapshot */
   private final MemoizedCheckedSupplier<RaftStorageImpl, IOException> 
raftStorage;
   private final SnapshotManager snapshotManager;
-  private volatile Timestamp lastNoLeaderTime;
+  private final AtomicReference<Timestamp> lastNoLeaderTime;
   private final TimeDuration noLeaderTimeout;
 
   private final ReadRequests readRequests;
@@ -120,7 +120,7 @@ class ServerState {
         stateMachine.getStateMachineStorage());
 
     // On start the leader is null, start the clock now
-    this.lastNoLeaderTime = Timestamp.currentTime();
+    this.lastNoLeaderTime = new AtomicReference<>(Timestamp.currentTime());
     this.noLeaderTimeout = 
RaftServerConfigKeys.Notification.noLeaderTimeout(prop);
 
     final LongSupplier getSnapshotIndexFromStateMachine = () -> 
Optional.ofNullable(stateMachine.getLatestSnapshot())
@@ -246,15 +246,15 @@ class ServerState {
   void setLeader(RaftPeerId newLeaderId, Object op) {
     final RaftPeerId oldLeaderId = leaderId.getAndSet(newLeaderId);
     if (!Objects.equals(oldLeaderId, newLeaderId)) {
-      String suffix;
+      final String suffix;
       if (newLeaderId == null) {
         // reset the time stamp when a null leader is assigned
-        lastNoLeaderTime = Timestamp.currentTime();
+        lastNoLeaderTime.set(Timestamp.currentTime());
         suffix = "";
       } else {
-        Timestamp previous = lastNoLeaderTime;
-        lastNoLeaderTime = null;
+        final Timestamp previous = lastNoLeaderTime.getAndSet(null);
         suffix = ", leader elected after " + previous.elapsedTimeMs() + "ms";
+        server.setFirstElection(op);
         server.getStateMachine().event().notifyLeaderChanged(getMemberId(), 
newLeaderId);
       }
       LOG.info("{}: change Leader from {} to {} at term {} for {}{}",
@@ -266,14 +266,14 @@ class ServerState {
   }
 
   boolean shouldNotifyExtendedNoLeader() {
-    return Optional.ofNullable(lastNoLeaderTime)
+    return Optional.ofNullable(lastNoLeaderTime.get())
         .map(Timestamp::elapsedTime)
         .filter(t -> t.compareTo(noLeaderTimeout) > 0)
         .isPresent();
   }
 
   long getLastLeaderElapsedTimeMs() {
-    return 
Optional.ofNullable(lastNoLeaderTime).map(Timestamp::elapsedTimeMs).orElse(0L);
+    return 
Optional.ofNullable(lastNoLeaderTime.get()).map(Timestamp::elapsedTimeMs).orElse(0L);
   }
 
   void becomeLeader() {