From 5a4d2f28527e6379cbcc8a6347263938039528e5 Mon Sep 17 00:00:00 2001
From: Tsz-Wo Nicholas Sze <szetszwo@apache.org>
Date: Tue, 25 Jul 2023 10:34:55 -0700
Subject: [PATCH] RATIS-1858. Follower keeps logging first election timeout.

---
 .../apache/ratis/server/impl/RaftServerImpl.java |  8 +++++++-
 .../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 e429518e66..a857faa870 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 @@ public void close() {
     });
   }
 
+  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 @@ private synchronized boolean changeToFollower(
         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 59a392f8e9..2f2f36d79a 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 @@ void grantVote(RaftPeerId candidateId) {
   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 @@ void setLeader(RaftPeerId newLeaderId, Object op) {
   }
 
   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() {