SOLR-3180: improve logging

git-svn-id: https://svn.apache.org/repos/asf/lucene/dev/trunk@1423591 13f79535-47bb-0310-9956-ffa450edef68

solr/core/src/test/org/apache/solr/cloud/ChaosMonkeySafeLeaderTest.java

@@ -49,6 +49,8 @@ public class ChaosMonkeySafeLeaderTest extends AbstractFullDistribZkTestBase {
   @Before
   @Override
   public void setUp() throws Exception {
+    useFactory("solr.StandardDirectoryFactory");
+
     super.setUp();
     
     System.setProperty("numShards", Integer.toString(sliceCount));

solr/core/src/test/org/apache/solr/cloud/RecoveryZkTest.java

@@ -89,7 +89,7 @@ public class RecoveryZkTest extends AbstractFullDistribZkTestBase {
 
     // test that leader and replica have same doc count
     
-    checkShardConsistency("shard1", false); 
+    checkShardConsistency("shard1", false, false);
     SolrQuery query = new SolrQuery("*:*");
     query.setParam("distrib", "false");
     long client1Docs = shardToJetty.get("shard1").get(0).client.solrClient.query(query).getResults().getNumFound();

solr/core/src/test/org/apache/solr/cloud/SyncSliceTest.java

@@ -114,7 +114,7 @@ public class SyncSliceTest extends AbstractFullDistribZkTestBase {
     waitForRecoveriesToFinish(false);
 
     // shard should be inconsistent
-    String shardFailMessage = checkShardConsistency("shard1", true);
+    String shardFailMessage = checkShardConsistency("shard1", true, false);
     assertNotNull(shardFailMessage);
     
     ModifiableSolrParams params = new ModifiableSolrParams();
@@ -209,7 +209,7 @@ public class SyncSliceTest extends AbstractFullDistribZkTestBase {
     waitForRecoveriesToFinish(false);
     
     // shard should be inconsistent
-    shardFailMessage = checkShardConsistency("shard1", true);
+    shardFailMessage = checkShardConsistency("shard1", true, false);
     assertNotNull(
         "shard1 shoul have just been set up to be inconsistent - but it's still consistent",
         shardFailMessage); 

solr/test-framework/src/java/org/apache/solr/cloud/AbstractFullDistribZkTestBase.java

@@ -740,10 +740,14 @@ public abstract class AbstractFullDistribZkTestBase extends AbstractDistribZkTes
   }
   
   protected void checkShardConsistency(String shard) throws Exception {
-    checkShardConsistency(shard, false);
+    checkShardConsistency(shard, false, false);
   }
 
-  protected String checkShardConsistency(String shard, boolean verbose)
+  /* Returns a non-null string if replicas within the same shard are not consistent.
+   * If expectFailure==false, the exact differences found will be logged since this would be an unexpected failure.
+   * verbose causes extra debugging into to be displayed, even if everything is consistent.
+   */
+  protected String checkShardConsistency(String shard, boolean expectFailure, boolean verbose)
       throws Exception {
     
     List<CloudJettyRunner> solrJetties = shardToJetty.get(shard);
@@ -770,8 +774,7 @@ public abstract class AbstractFullDistribZkTestBase extends AbstractDistribZkTes
       if (verbose) System.err.println("PROPS:" + props);
 
       try {
-        SolrQuery query = new SolrQuery("*:*");
+        SolrParams query = params("q","*:*", "rows","0", "distrib","false", "tests","checkShardConsistency"); // "tests" is just a tag that won't do anything except be echoed in logs
-        query.set("distrib", false);
         num = cjetty.client.solrClient.query(query).getResults().getNumFound();
       } catch (SolrServerException e) {
         if (verbose) System.err.println("error contacting client: "
@@ -789,7 +792,6 @@ public abstract class AbstractFullDistribZkTestBase extends AbstractDistribZkTes
         live = true;
       }
       if (verbose) System.err.println(" live:" + live);
-      
       if (verbose) System.err.println(" num:" + num + "\n");
 
       boolean active = props.getStr(ZkStateReader.STATE_PROP).equals(
@@ -799,13 +801,14 @@ public abstract class AbstractFullDistribZkTestBase extends AbstractDistribZkTes
           failMessage = shard + " is not consistent.  Got " + lastNum + " from " + lastJetty.url + "lastClient"
               + " and got " + num + " from " + cjetty.url;
 
-          if (verbose || true) {
+          if (!expectFailure || verbose) {
             System.err.println("######" + failMessage);
             SolrQuery query = new SolrQuery("*:*");
             query.set("distrib", false);
             query.set("fl","id,_version_");
-            query.set("rows","1000");
+            query.set("rows","100000");
             query.set("sort","id asc");
+            query.set("tests","checkShardConsistency/showDiff");
 
             SolrDocumentList lst1 = lastJetty.client.solrClient.query(query).getResults();
             SolrDocumentList lst2 = cjetty.client.solrClient.query(query).getResults();
@@ -822,9 +825,24 @@ public abstract class AbstractFullDistribZkTestBase extends AbstractDistribZkTes
     
   }
   
-  void showDiff(SolrDocumentList a, SolrDocumentList b, String aName, String bName) {
+  private String toStr(SolrDocumentList lst) {
-    System.err.println("######"+aName+ ": " + a);
+    if (lst.size() <= 10) return lst.toString();
-    System.err.println("######"+bName+ ": " + b);
+
+    StringBuilder sb = new StringBuilder("SolrDocumentList[sz=" + lst.size());
+    if (lst.size() != lst.getNumFound()) {
+      sb.append(" numFound=" + lst.getNumFound());
+    }
+    sb.append("]=");
+    sb.append(lst.subList(0,5).toString());
+    sb.append(" , [...] , ");
+    sb.append(lst.subList(lst.size()-5, lst.size()).toString());
+
+    return sb.toString();
+  }
+
+  Set<Map> showDiff(SolrDocumentList a, SolrDocumentList b, String aName, String bName) {
+    System.err.println("######"+aName+ ": " + toStr(a));
+    System.err.println("######"+bName+ ": " + toStr(b));
     System.err.println("###### sizes=" + a.size() + "," + b.size());
     
     Set<Map> setA = new HashSet<Map>();
@@ -848,30 +866,30 @@ public abstract class AbstractFullDistribZkTestBase extends AbstractDistribZkTes
     if (onlyInB.size() > 0) {
       System.err.println("###### Only in " + bName + ": " + onlyInB);
     }
+
+    onlyInA.addAll(b);
+    return onlyInA;
   }
 
+  /* Checks both shard replcia consistency and against the control shard.
+  * The test will be failed if differences are found.
+  */
   protected void checkShardConsistency() throws Exception {
     checkShardConsistency(true, false);
   }
 
+  /* Checks shard consistency and optionally checks against the control shard.
+   * The test will be failed if differences are found.
+   */
   protected void checkShardConsistency(boolean checkVsControl, boolean verbose)
       throws Exception {
-    SolrParams q = params("q","*:*","fl","id","rows","100000");
-
-    SolrDocumentList controlDocList = controlClient.query(q).getResults();
-    long docs = controlDocList.getNumFound();
-
-    SolrDocumentList cloudDocList = cloudClient.query(q).getResults();
-    long cloudClientDocs = cloudDocList.getNumFound();
-
-    if (verbose) System.err.println("Control Docs:" + docs);
 
     updateMappingsFromZk(jettys, clients);
     
     Set<String> theShards = shardToJetty.keySet();
     String failMessage = null;
     for (String shard : theShards) {
-      String shardFailMessage = checkShardConsistency(shard, verbose);
+      String shardFailMessage = checkShardConsistency(shard, false, verbose);
       if (shardFailMessage != null && failMessage == null) {
         failMessage = shardFailMessage;
       }
@@ -881,46 +899,87 @@ public abstract class AbstractFullDistribZkTestBase extends AbstractDistribZkTes
       fail(failMessage);
     }
 
-    if (checkVsControl) {
+    if (!checkVsControl) return;
-      // now check that the right # are on each shard
+
-      theShards = shardToJetty.keySet();
+    SolrParams q = params("q","*:*","rows","0", "tests","checkShardConsistency(vsControl)");    // add a tag to aid in debugging via logs
-      int cnt = 0;
+
-      for (String s : theShards) {
+    SolrDocumentList controlDocList = controlClient.query(q).getResults();
-        int times = shardToJetty.get(s).size();
+    long controlDocs = controlDocList.getNumFound();
-        for (int i = 0; i < times; i++) {
+
-          try {
+    SolrDocumentList cloudDocList = cloudClient.query(q).getResults();
-            CloudJettyRunner cjetty = shardToJetty.get(s).get(i);
+    long cloudClientDocs = cloudDocList.getNumFound();
-            ZkNodeProps props = cjetty.info;
+
-            SolrServer client = cjetty.client.solrClient;
+
-            boolean active = props.getStr(ZkStateReader.STATE_PROP).equals(
+
-                ZkStateReader.ACTIVE);
+
-            if (active) {
+    // now check that the right # are on each shard
-              SolrQuery query = new SolrQuery("*:*");
+    theShards = shardToJetty.keySet();
-              query.set("distrib", false);
+    int cnt = 0;
-              long results = client.query(query).getResults().getNumFound();
+    for (String s : theShards) {
-              if (verbose) System.err.println(new ZkCoreNodeProps(props)
+      int times = shardToJetty.get(s).size();
-                  .getCoreUrl() + " : " + results);
+      for (int i = 0; i < times; i++) {
-              if (verbose) System.err.println("shard:"
+        try {
-                  + props.getStr(ZkStateReader.SHARD_ID_PROP));
+          CloudJettyRunner cjetty = shardToJetty.get(s).get(i);
-              cnt += results;
+          ZkNodeProps props = cjetty.info;
-              break;
+          SolrServer client = cjetty.client.solrClient;
-            }
+          boolean active = props.getStr(ZkStateReader.STATE_PROP).equals(
-          } catch (Exception e) {
+              ZkStateReader.ACTIVE);
-            // if we have a problem, try the next one
+          if (active) {
-            if (i == times - 1) {
+            SolrQuery query = new SolrQuery("*:*");
-              throw e;
+            query.set("distrib", false);
-            }
+            long results = client.query(query).getResults().getNumFound();
+            if (verbose) System.err.println(new ZkCoreNodeProps(props)
+                .getCoreUrl() + " : " + results);
+            if (verbose) System.err.println("shard:"
+                + props.getStr(ZkStateReader.SHARD_ID_PROP));
+            cnt += results;
+            break;
+          }
+        } catch (Exception e) {
+          // if we have a problem, try the next one
+          if (i == times - 1) {
+            throw e;
           }
         }
       }
+    }
 
 
-      if (docs != cnt || cloudClientDocs != docs) {
+    if (controlDocs != cnt || cloudClientDocs != controlDocs) {
-        String msg = "document count mismatch.  control=" + docs + " sum(shards)="+ cnt + " cloudClient="+cloudClientDocs;
+      String msg = "document count mismatch.  control=" + controlDocs + " sum(shards)="+ cnt + " cloudClient="+cloudClientDocs;
-        log.error(msg);
+      log.error(msg);
-        showDiff(controlDocList, cloudDocList,"controlDocList","cloudDocList");
+
-        fail(msg);
+      // re-execute the query getting ids
+      q = params("q","*:*","rows","100000", "fl","id", "tests","checkShardConsistency(vsControl)/getIds");    // add a tag to aid in debugging via logs
+      controlDocList = controlClient.query(q).getResults();
+      if (controlDocs != controlDocList.getNumFound()) {
+        log.error("Something changed! control now " + controlDocList.getNumFound());
+      };
+
+      cloudDocList = cloudClient.query(q).getResults();
+      if (cloudClientDocs != cloudDocList.getNumFound()) {
+        log.error("Something changed! cloudClient now " + cloudDocList.getNumFound());
+      };
+
+      Set<Map> differences = showDiff(controlDocList, cloudDocList,"controlDocList","cloudDocList");
+
+      // get versions for the mismatched ids
+      StringBuilder ids = new StringBuilder("id:(");
+      for (Map doc : differences) {
+        ids.append(" "+doc.get("id"));
       }
+      ids.append(")");
+
+      // get versions for those ids that don't match
+      q = params("q",ids.toString(),"rows","100000", "fl","id,_version_", "sort","id asc",
+                 "tests","checkShardConsistency(vsControl)/getVers");    // add a tag to aid in debugging via logs
+
+      SolrDocumentList a = controlClient.query(q).getResults();
+      SolrDocumentList b = cloudClient.query(q).getResults();
+
+      log.error("controlClient :" + a + "\n\tcloudClient :" + b);
+
+      fail(msg);
     }
   }
   
@@ -1159,7 +1218,7 @@ public abstract class AbstractFullDistribZkTestBase extends AbstractDistribZkTes
       Set<String> theShards = shardToJetty.keySet();
       String failMessage = null;
       for (String shard : theShards) {
-        failMessage = checkShardConsistency(shard, false);
+        failMessage = checkShardConsistency(shard, true, false);
       }
       
       if (failMessage != null) {