BUG 2676 : Reduce default logging in Dummy Data Store

[controller.git] / opendaylight / md-sal / sal-dummy-distributed-datastore / src / main / java / org / opendaylight / controller / dummy / datastore / DummyShard.java

diff --git a/opendaylight/md-sal/sal-dummy-distributed-datastore/src/main/java/org/opendaylight/controller/dummy/datastore/DummyShard.java b/opendaylight/md-sal/sal-dummy-distributed-datastore/src/main/java/org/opendaylight/controller/dummy/datastore/DummyShard.java
index 34b41ccfcacd4f27d501ad7855980222aff350ad..0b72a32f1033884ba983c71b2651a4a88ad6c7b1 100644 (file)
--- a/opendaylight/md-sal/sal-dummy-distributed-datastore/src/main/java/org/opendaylight/controller/dummy/datastore/DummyShard.java
+++ b/opendaylight/md-sal/sal-dummy-distributed-datastore/src/main/java/org/opendaylight/controller/dummy/datastore/DummyShard.java
@@ -11,6 +11,9 @@ package org.opendaylight.controller.dummy.datastore;
 import akka.actor.Props;
 import akka.actor.UntypedActor;
 import akka.japi.Creator;
+import com.google.common.base.Stopwatch;
+import java.util.concurrent.TimeUnit;
+import org.opendaylight.controller.cluster.raft.ReplicatedLogEntry;
 import org.opendaylight.controller.cluster.raft.messages.AppendEntries;
 import org.opendaylight.controller.cluster.raft.messages.AppendEntriesReply;
 import org.opendaylight.controller.cluster.raft.messages.InstallSnapshot;
@@ -24,6 +27,9 @@ public class DummyShard extends UntypedActor{
     private final Configuration configuration;
     private final String followerId;
     private final Logger LOG = LoggerFactory.getLogger(DummyShard.class);
+    private long lastMessageIndex  = -1;
+    private long lastMessageSize = 0;
+    private Stopwatch appendEntriesWatch;
 
     public DummyShard(Configuration configuration, String followerId) {
         this.configuration = configuration;
@@ -54,12 +60,36 @@ public class DummyShard extends UntypedActor{
     }
 
     protected void handleAppendEntries(AppendEntries req) throws InterruptedException {
-        LOG.info("{} - Received AppendEntries message : leader term, index, size = {}, {}, {}", followerId, req.getTerm(),req.getLeaderCommit(), req.getEntries().size());
+        LOG.info("{} - Received AppendEntries message : leader term = {}, index = {}, prevLogIndex = {}, size = {}",
+                followerId, req.getTerm(),req.getLeaderCommit(), req.getPrevLogIndex(), req.getEntries().size());
+
+        if(appendEntriesWatch != null){
+            long elapsed = appendEntriesWatch.elapsed(TimeUnit.SECONDS);
+            if(elapsed >= 5){
+                LOG.error("More than 5 seconds since last append entry, elapsed Time = {} seconds" +
+                                ", leaderCommit = {}, prevLogIndex = {}, size = {}",
+                        elapsed, req.getLeaderCommit(), req.getPrevLogIndex(), req.getEntries().size());
+            }
+            appendEntriesWatch.reset().start();
+        } else {
+            appendEntriesWatch = Stopwatch.createStarted();
+        }
+
+        if(lastMessageIndex == req.getLeaderCommit() && req.getEntries().size() > 0 && lastMessageSize > 0){
+            LOG.error("{} - Duplicate message with leaderCommit = {} prevLogIndex = {} received", followerId, req.getLeaderCommit(), req.getPrevLogIndex());
+        }
+
+        lastMessageIndex = req.getLeaderCommit();
+        lastMessageSize = req.getEntries().size();
+
         long lastIndex = req.getLeaderCommit();
-        if (req.getEntries().size() > 0)
-            lastIndex = req.getEntries().get(0).getIndex();
+        if (req.getEntries().size() > 0) {
+            for(ReplicatedLogEntry entry : req.getEntries()) {
+                lastIndex = entry.getIndex();
+            }
+        }
 
-        if (configuration.shouldCauseTrouble()) {
+        if (configuration.shouldCauseTrouble() && req.getEntries().size() > 0) {
             boolean ignore = false;
 
             if (configuration.shouldDropReplies()) {