[lucene] 04/09: Added more debug logging on how and why commits are reserved and deleted

[dw...@apache.org]

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

dweiss pushed a commit to branch jira/solr-12730
in repository https://gitbox.apache.org/repos/asf/lucene.git

commit 514fef4f29c5f6c7a274f674577d3f4fda41342a
Author: Shalin Shekhar Mangar <sh...@apache.org>
AuthorDate: Tue Oct 30 15:43:12 2018 +0530

    Added more debug logging on how and why commits are reserved and deleted
---
 .../org/apache/solr/cloud/overseer/ReplicaMutator.java    |  4 ++--
 .../org/apache/solr/core/IndexDeletionPolicyWrapper.java  | 15 +++++++++++++--
 .../solr/cloud/autoscaling/IndexSizeTriggerTest.java      |  2 +-
 3 files changed, 16 insertions(+), 5 deletions(-)

diff --git a/solr/core/src/java/org/apache/solr/cloud/overseer/ReplicaMutator.java b/solr/core/src/java/org/apache/solr/cloud/overseer/ReplicaMutator.java
index 68a42b9..82a0610 100644
--- a/solr/core/src/java/org/apache/solr/cloud/overseer/ReplicaMutator.java
+++ b/solr/core/src/java/org/apache/solr/cloud/overseer/ReplicaMutator.java
@@ -394,7 +394,7 @@ public class ReplicaMutator {
           }
         }
         if (allActive) {
-          log.info("Shard: {} - all replicas are active. Finding status of fellow sub-shards", sliceName);
+          log.info("Shard: {} - all {} replicas are active. Finding status of fellow sub-shards", sliceName, slice.getReplicasMap().size());
           // find out about other sub shards
           Map<String, Slice> allSlicesCopy = new HashMap<>(collection.getSlicesMap());
           List<Slice> subShardSlices = new ArrayList<>();
@@ -413,7 +413,7 @@ public class ReplicaMutator {
                     break outer;
                   }
                 }
-                log.info("Shard: {} - Fellow sub-shard: {} has all replicas active", sliceName, otherSlice.getName());
+                log.info("Shard: {} - Fellow sub-shard: {} has all {} replicas active", sliceName, otherSlice.getName(), otherSlice.getReplicasMap().size());
                 subShardSlices.add(otherSlice);
               }
             }
diff --git a/solr/core/src/java/org/apache/solr/core/IndexDeletionPolicyWrapper.java b/solr/core/src/java/org/apache/solr/core/IndexDeletionPolicyWrapper.java
index 40e65b7..ee7ed36 100644
--- a/solr/core/src/java/org/apache/solr/core/IndexDeletionPolicyWrapper.java
+++ b/solr/core/src/java/org/apache/solr/core/IndexDeletionPolicyWrapper.java
@@ -130,6 +130,7 @@ public final class IndexDeletionPolicyWrapper extends IndexDeletionPolicy {
     if (reserveCount == null) reserveCount = new AtomicInteger();
     reserveCount.incrementAndGet();
     savedCommits.put(indexCommitGen, reserveCount);
+    log.debug("Saving commit point for generation {}", indexCommitGen);
   }
 
   /** Release a previously saved commit point */
@@ -138,6 +139,7 @@ public final class IndexDeletionPolicyWrapper extends IndexDeletionPolicy {
     if (reserveCount == null) return;// this should not happen
     if (reserveCount.decrementAndGet() <= 0) {
       savedCommits.remove(indexCommitGen);
+      log.debug("Releasing commit point for generation {}", indexCommitGen);
     }
   }
 
@@ -189,11 +191,20 @@ public final class IndexDeletionPolicyWrapper extends IndexDeletionPolicy {
     @Override
     public void delete() {
       Long gen = delegate.getGeneration();
+      log.debug("Checking whether we can delete commit point with generation: {}", gen);
       Long reserve = reserves.get(gen);
-      if (reserve != null && System.nanoTime() < reserve) return;
-      if (savedCommits.containsKey(gen)) return;
+      long currentTime = System.nanoTime();
+      if (reserve != null && currentTime < reserve) {
+        log.debug("Commit point with generation: {} not deleted because its reserve {} is less than current time {}", gen, reserve, currentTime);
+        return;
+      }
+      if (savedCommits.containsKey(gen))  {
+        log.debug("Commit point with generation: {} not deleted because it is saved");
+        return;
+      }
       if (snapshotMgr.isSnapshotted(gen)) return;
       delegate.delete();
+      log.debug("Commit point with generation: {} deleted", gen);
     }
 
     @Override
diff --git a/solr/core/src/test/org/apache/solr/cloud/autoscaling/IndexSizeTriggerTest.java b/solr/core/src/test/org/apache/solr/cloud/autoscaling/IndexSizeTriggerTest.java
index 934ec20..a3f75dc 100644
--- a/solr/core/src/test/org/apache/solr/cloud/autoscaling/IndexSizeTriggerTest.java
+++ b/solr/core/src/test/org/apache/solr/cloud/autoscaling/IndexSizeTriggerTest.java
@@ -67,7 +67,7 @@ import static org.apache.solr.common.cloud.ZkStateReader.SOLR_AUTOSCALING_CONF_P
 /**
  *
  */
-@LogLevel("org.apache.solr.cloud.autoscaling=DEBUG;org.apache.solr.handler.admin.MetricsHandler=DEBUG")
+@LogLevel("org.apache.solr.cloud.autoscaling=DEBUG;org.apache.solr.handler.admin.MetricsHandler=DEBUG;org.apache.solr.core.SolrDeletionPolicy=DEBUG;org.apache.solr.core.IndexDeletionPolicyWrapper=DEBUG;org.apache.solr.client.solrj.cloud.autoscaling=DEBUG;org.apache.solr.cloud.api.collections=DEBUG;org.apache.solr.cloud.Overseer=DEBUG;org.apache.solr.cloud.overseer=DEBUGorg.apache.solr.client.solrj.cloud.autoscaling=DEBUG;org.apache.solr.cloud.api.collections=DEBUG;org.apache.solr.cloud.O [...]
 public class IndexSizeTriggerTest extends SolrCloudTestCase {
   private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());