Merge "Reduce/enhance logging in AbstractLeader"

diff --git a/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/FollowerLogInformation.java b/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/FollowerLogInformation.java
index 73c81afd187d2791703c1428beacbc8348abda69..0beccd1b2b01ead56d4ea73235a3687fd73f408b 100644 (file)
--- a/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/FollowerLogInformation.java
+++ b/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/FollowerLogInformation.java
@@ -25,10 +25,13 @@ public interface FollowerLogInformation {
     long decrNextIndex();
 
     /**
+     * Sets the index of the next log entry for this follower.
      *
      * @param nextIndex
+     * @return true if the new index differed from the current index and the current index was updated, false
+     *              otherwise.
      */
-    void setNextIndex(long nextIndex);
+    boolean setNextIndex(long nextIndex);
 
     /**
      * Increment the value of the matchIndex
@@ -36,7 +39,14 @@ public interface FollowerLogInformation {
      */
     long incrMatchIndex();
 
-    void setMatchIndex(long matchIndex);
+    /**
+     * Sets the index of the highest log entry for this follower.
+     *
+     * @param matchIndex
+     * @return true if the new index differed from the current index and the current index was updated, false
+     *              otherwise.
+     */
+    boolean setMatchIndex(long matchIndex);
 
     /**
      * The identifier of the follower

diff --git a/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/FollowerLogInformationImpl.java b/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/FollowerLogInformationImpl.java
index 90e128256132437c5f2acd4cb861e0e74a759d44..288a540344bda27cab5276265ebcae6079c492fd 100644 (file)
--- a/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/FollowerLogInformationImpl.java
+++ b/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/FollowerLogInformationImpl.java
@@ -44,8 +44,13 @@ public class FollowerLogInformationImpl implements FollowerLogInformation {
     }
 
     @Override
-    public void setNextIndex(long nextIndex) {
-        this.nextIndex = nextIndex;
+    public boolean setNextIndex(long nextIndex) {
+        if(this.nextIndex != nextIndex) {
+            this.nextIndex = nextIndex;
+            return true;
+        }
+
+        return false;
     }
 
     @Override
@@ -54,8 +59,13 @@ public class FollowerLogInformationImpl implements FollowerLogInformation {
     }
 
     @Override
-    public void setMatchIndex(long matchIndex) {
-        this.matchIndex = matchIndex;
+    public boolean setMatchIndex(long matchIndex) {
+        if(this.matchIndex != matchIndex) {
+            this.matchIndex = matchIndex;
+            return true;
+        }
+
+        return false;
     }
 
     @Override

diff --git a/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/behaviors/AbstractLeader.java b/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/behaviors/AbstractLeader.java
index 831f8f9e7088ed2017a81a2ed6911fdfbedb8e5b..a4753a4fe432654554a64578af0b09233069146b 100644 (file)
--- a/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/behaviors/AbstractLeader.java
+++ b/opendaylight/md-sal/sal-akka-raft/src/main/java/org/opendaylight/controller/cluster/raft/behaviors/AbstractLeader.java
@@ -158,8 +158,6 @@ public abstract class AbstractLeader extends AbstractRaftActorBehavior {
 
         if(LOG.isTraceEnabled()) {
             LOG.trace("{}: handleAppendEntriesReply: {}", logName(), appendEntriesReply);
-        } else if(LOG.isDebugEnabled() && !appendEntriesReply.isSuccess()) {
-            LOG.debug("{}: handleAppendEntriesReply: {}", logName(), appendEntriesReply);
         }
 
         // Update the FollowerLogInformation
@@ -174,7 +172,7 @@ public abstract class AbstractLeader extends AbstractRaftActorBehavior {
 
         if(followerLogInformation.timeSinceLastActivity() >
                 context.getConfigParams().getElectionTimeOutInterval().toMillis()) {
-            LOG.error("{} : handleAppendEntriesReply delayed beyond election timeout, " +
+            LOG.warn("{} : handleAppendEntriesReply delayed beyond election timeout, " +
                             "appendEntriesReply : {}, timeSinceLastActivity : {}, lastApplied : {}, commitIndex : {}",
                     logName(), appendEntriesReply, followerLogInformation.timeSinceLastActivity(),
                     context.getLastApplied(), context.getCommitIndex());
@@ -182,12 +180,17 @@ public abstract class AbstractLeader extends AbstractRaftActorBehavior {
 
         followerLogInformation.markFollowerActive();
 
+        boolean updated = false;
         if (appendEntriesReply.isSuccess()) {
-            followerLogInformation
-                .setMatchIndex(appendEntriesReply.getLogLastIndex());
-            followerLogInformation
-                .setNextIndex(appendEntriesReply.getLogLastIndex() + 1);
+            updated = followerLogInformation.setMatchIndex(appendEntriesReply.getLogLastIndex());
+            updated = followerLogInformation.setNextIndex(appendEntriesReply.getLogLastIndex() + 1) || updated;
+
+            if(updated && LOG.isDebugEnabled()) {
+                LOG.debug("{}: handleAppendEntriesReply - FollowerLogInformation for {} updated: matchIndex: {}, nextIndex: {}", logName(),
+                        followerId, followerLogInformation.getMatchIndex(), followerLogInformation.getNextIndex());
+            }
         } else {
+            LOG.debug("{}: handleAppendEntriesReply: received unsuccessful reply: {}", logName(), appendEntriesReply);
 
             // TODO: When we find that the follower is out of sync with the
             // Leader we simply decrement that followers next index by 1.
@@ -224,8 +227,10 @@ public abstract class AbstractLeader extends AbstractRaftActorBehavior {
 
         // Apply the change to the state machine
         if (context.getCommitIndex() > context.getLastApplied()) {
-            LOG.debug("{}: handleAppendEntriesReply: applying to log - commitIndex: {}, lastAppliedIndex: {}",
-                    logName(), context.getCommitIndex(), context.getLastApplied());
+            if(LOG.isDebugEnabled()) {
+                LOG.debug("{}: handleAppendEntriesReply from {}: applying to log - commitIndex: {}, lastAppliedIndex: {}",
+                        logName(), followerId, context.getCommitIndex(), context.getLastApplied());
+            }
 
             applyLogToStateMachine(context.getCommitIndex());
         }
@@ -235,7 +240,7 @@ public abstract class AbstractLeader extends AbstractRaftActorBehavior {
         }
 
         //Send the next log entry immediately, if possible, no need to wait for heartbeat to trigger that event
-        sendUpdatesToFollower(followerId, followerLogInformation, false, false);
+        sendUpdatesToFollower(followerId, followerLogInformation, false, !updated);
         return this;
     }
 
@@ -469,9 +474,9 @@ public abstract class AbstractLeader extends AbstractRaftActorBehavior {
                 long leaderLastIndex = context.getReplicatedLog().lastIndex();
                 long leaderSnapShotIndex = context.getReplicatedLog().getSnapshotIndex();
 
-                if(!isHeartbeat || LOG.isTraceEnabled()) {
-                    LOG.debug("{}: Checking sendAppendEntries for follower {}, leaderLastIndex: {}, leaderSnapShotIndex: {}",
-                            logName(), followerId, leaderLastIndex, leaderSnapShotIndex);
+                if((!isHeartbeat && LOG.isDebugEnabled()) || LOG.isTraceEnabled()) {
+                    LOG.debug("{}: Checking sendAppendEntries for follower {}, followerNextIndex {}, leaderLastIndex: {}, leaderSnapShotIndex: {}",
+                            logName(), followerId, followerNextIndex, leaderLastIndex, leaderSnapShotIndex);
                 }
 
                 if (isFollowerActive && context.getReplicatedLog().isPresent(followerNextIndex)) {
@@ -556,7 +561,6 @@ public abstract class AbstractLeader extends AbstractRaftActorBehavior {
 
             } else if (!context.isSnapshotCaptureInitiated()) {
 
-                LOG.info("{}: Initiating Snapshot Capture to Install Snapshot, Leader:{}", logName(), getLeaderId());
                 ReplicatedLogEntry lastAppliedEntry = context.getReplicatedLog().get(context.getLastApplied());
                 long lastAppliedIndex = -1;
                 long lastAppliedTerm = -1;
@@ -572,10 +576,19 @@ public abstract class AbstractLeader extends AbstractRaftActorBehavior {
                 boolean isInstallSnapshotInitiated = true;
                 long replicatedToAllIndex = super.getReplicatedToAllIndex();
                 ReplicatedLogEntry replicatedToAllEntry = context.getReplicatedLog().get(replicatedToAllIndex);
-                actor().tell(new CaptureSnapshot(lastIndex(), lastTerm(), lastAppliedIndex, lastAppliedTerm,
-                    (replicatedToAllEntry != null ? replicatedToAllEntry.getIndex() : -1),
-                    (replicatedToAllEntry != null ? replicatedToAllEntry.getTerm() : -1),
-                    isInstallSnapshotInitiated), actor());
+
+                CaptureSnapshot captureSnapshot = new CaptureSnapshot(
+                        lastIndex(), lastTerm(), lastAppliedIndex, lastAppliedTerm,
+                        (replicatedToAllEntry != null ? replicatedToAllEntry.getIndex() : -1),
+                        (replicatedToAllEntry != null ? replicatedToAllEntry.getTerm() : -1),
+                        isInstallSnapshotInitiated);
+
+                if(LOG.isDebugEnabled()) {
+                    LOG.debug("{}: Initiating install snapshot to follower {}: {}", logName(), followerId,
+                            captureSnapshot);
+                }
+
+                actor().tell(captureSnapshot, actor());
                 context.setSnapshotCaptureInitiated(true);
             }
         }
@@ -622,10 +635,12 @@ public abstract class AbstractLeader extends AbstractRaftActorBehavior {
                     ).toSerializable(),
                     actor()
                 );
-                LOG.info("{}: InstallSnapshot sent to follower {}, Chunk: {}/{}",
-                        logName(), followerActor.path(),
-                        followerToSnapshot.getChunkIndex(),
-                        followerToSnapshot.getTotalChunks());
+
+                if(LOG.isDebugEnabled()) {
+                    LOG.debug("{}: InstallSnapshot sent to follower {}, Chunk: {}/{}",
+                            logName(), followerActor.path(), followerToSnapshot.getChunkIndex(),
+                            followerToSnapshot.getTotalChunks());
+                }
             }
         } catch (IOException e) {
             LOG.error("{}: InstallSnapshot failed for Leader.", logName(), e);