[lucene-solr] 02/02: SOLR-14566: Add rid to all distributed search requests

[ge...@apache.org]

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

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

commit 3eec81431a77d47b0c08e1841462f6ae90cccd48
Author: Jason Gerlowski <ja...@lucidworks.com>
AuthorDate: Thu Jun 18 12:45:20 2020 -0400

    SOLR-14566: Add rid to all distributed search requests
---
 solr/CHANGES.txt                                   |  3 ++
 .../solr/handler/component/DebugComponent.java     | 27 +--------------
 .../solr/handler/component/SearchHandler.java      | 34 ++++++++++++++++++-
 .../solr/handler/component/DebugComponentTest.java | 38 +++++++++++-----------
 4 files changed, 56 insertions(+), 46 deletions(-)

diff --git a/solr/CHANGES.txt b/solr/CHANGES.txt
index 80c467a..8f6ce3c 100644
--- a/solr/CHANGES.txt
+++ b/solr/CHANGES.txt
@@ -141,6 +141,9 @@ Improvements
 * SOLR-14442: bin/solr and bin\solr.cmd invoke jstack <SOLR_PID> before forceful termination, if jstack is available.
   Also, bin\solr.cmd executes forceful termination even port is unbinded  already (Christine Poerschke via Mikhail Khludnev).
 
+* SOLR-14566: Request ID's ('rid') are now added by default to distributed search requests, and can be used to correlate logs
+  from the receiving coordinator node with those from downstream shard requests. (Jason Gerlowski)
+
 Optimizations
 ---------------------
 * SOLR-8306: Do not collect expand documents when expand.rows=0 (Marshall Sanders, Amelia Henderson)
diff --git a/solr/core/src/java/org/apache/solr/handler/component/DebugComponent.java b/solr/core/src/java/org/apache/solr/handler/component/DebugComponent.java
index 31fbf99..a88d356 100644
--- a/solr/core/src/java/org/apache/solr/handler/component/DebugComponent.java
+++ b/solr/core/src/java/org/apache/solr/handler/component/DebugComponent.java
@@ -56,11 +56,6 @@ public class DebugComponent extends SearchComponent
   public static final String COMPONENT_NAME = "debug";
   
   /**
-   * A counter to ensure that no RID is equal, even if they fall in the same millisecond
-   */
-  private static final AtomicLong ridCounter = new AtomicLong();
-  
-  /**
    * Map containing all the possible stages as key and
    * the corresponding readable purpose as value
    */
@@ -148,29 +143,9 @@ public class DebugComponent extends SearchComponent
     }
   }
 
-
   private void doDebugTrack(ResponseBuilder rb) {
-    String rid = getRequestId(rb.req);
+    final String rid = rb.req.getParams().get(CommonParams.REQUEST_ID);
     rb.addDebug(rid, "track", CommonParams.REQUEST_ID);//to see it in the response
-    rb.rsp.addToLog(CommonParams.REQUEST_ID, rid); //to see it in the logs of the landing core
-    
-  }
-
-  public static String getRequestId(SolrQueryRequest req) {
-    String rid = req.getParams().get(CommonParams.REQUEST_ID);
-    if(rid == null || "".equals(rid)) {
-      rid = generateRid(req);
-      ModifiableSolrParams params = new ModifiableSolrParams(req.getParams());
-      params.add(CommonParams.REQUEST_ID, rid);//add rid to the request so that shards see it
-      req.setParams(params);
-    }
-    return rid;
-  }
-
-  @SuppressForbidden(reason = "Need currentTimeMillis, only used for naming")
-  private static String generateRid(SolrQueryRequest req) {
-    String hostName = req.getCore().getCoreContainer().getHostName();
-    return hostName + "-" + req.getCore().getName() + "-" + System.currentTimeMillis() + "-" + ridCounter.getAndIncrement();
   }
 
   @Override
diff --git a/solr/core/src/java/org/apache/solr/handler/component/SearchHandler.java b/solr/core/src/java/org/apache/solr/handler/component/SearchHandler.java
index 2051b20..b3fb438 100644
--- a/solr/core/src/java/org/apache/solr/handler/component/SearchHandler.java
+++ b/solr/core/src/java/org/apache/solr/handler/component/SearchHandler.java
@@ -24,7 +24,9 @@ import java.util.HashSet;
 import java.util.LinkedList;
 import java.util.List;
 import java.util.Set;
+import java.util.concurrent.atomic.AtomicLong;
 
+import org.apache.commons.lang3.StringUtils;
 import org.apache.lucene.index.ExitableDirectoryReader;
 import org.apache.lucene.search.TotalHits;
 import org.apache.solr.client.solrj.SolrServerException;
@@ -36,6 +38,7 @@ import org.apache.solr.common.params.ModifiableSolrParams;
 import org.apache.solr.common.params.ShardParams;
 import org.apache.solr.common.util.NamedList;
 import org.apache.solr.common.util.SimpleOrderedMap;
+import org.apache.solr.common.util.SuppressForbidden;
 import org.apache.solr.core.CloseHook;
 import org.apache.solr.core.CoreContainer;
 import org.apache.solr.core.PluginInfo;
@@ -70,6 +73,11 @@ public class SearchHandler extends RequestHandlerBase implements SolrCoreAware,
 
   private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());
 
+  /**
+   * A counter to ensure that no RID is equal, even if they fall in the same millisecond
+   */
+  private static final AtomicLong ridCounter = new AtomicLong();
+
   protected volatile List<SearchComponent> components;
   private ShardHandlerFactory shardHandlerFactory;
   private PluginInfo shfInfo;
@@ -298,7 +306,8 @@ public class SearchHandler extends RequestHandlerBase implements SolrCoreAware,
     final RTimerTree timer = rb.isDebug() ? req.getRequestTimer() : null;
 
     final ShardHandler shardHandler1 = getAndPrepShardHandler(req, rb); // creates a ShardHandler object only if it's needed
-    
+
+    tagRequestWithRequestId(rb);
     if (timer == null) {
       // non-debugging prepare phase
       for( SearchComponent c : components ) {
@@ -500,6 +509,29 @@ public class SearchHandler extends RequestHandlerBase implements SolrCoreAware,
     }
   }
 
+  private void tagRequestWithRequestId(ResponseBuilder rb) {
+    String rid = getRequestId(rb.req);
+    if (StringUtils.isBlank(rb.req.getParams().get(CommonParams.REQUEST_ID))) {
+      ModifiableSolrParams params = new ModifiableSolrParams(rb.req.getParams());
+      params.add(CommonParams.REQUEST_ID, rid);//add rid to the request so that shards see it
+      rb.req.setParams(params);
+    }
+    if (rb.isDistrib) {
+      rb.rsp.addToLog(CommonParams.REQUEST_ID, rid); //to see it in the logs of the landing core
+    }
+  }
+
+  public static String getRequestId(SolrQueryRequest req) {
+    String rid = req.getParams().get(CommonParams.REQUEST_ID);
+    return StringUtils.isNotBlank(rid) ? rid : generateRid(req);
+  }
+
+  @SuppressForbidden(reason = "Need currentTimeMillis, only used for naming")
+  private static String generateRid(SolrQueryRequest req) {
+    String hostName = req.getCore().getCoreContainer().getHostName();
+    return hostName + "-" + req.getCore().getName() + "-" + System.currentTimeMillis() + "-" + ridCounter.getAndIncrement();
+  }
+
   //////////////////////// SolrInfoMBeans methods //////////////////////
 
   @Override
diff --git a/solr/core/src/test/org/apache/solr/handler/component/DebugComponentTest.java b/solr/core/src/test/org/apache/solr/handler/component/DebugComponentTest.java
index 0062fcf..0dca101 100644
--- a/solr/core/src/test/org/apache/solr/handler/component/DebugComponentTest.java
+++ b/solr/core/src/test/org/apache/solr/handler/component/DebugComponentTest.java
@@ -36,6 +36,9 @@ import org.junit.Test;
  *
  **/
 public class DebugComponentTest extends SolrTestCaseJ4 {
+
+  private static final String ANY_RID = "ANY_RID";
+
   @BeforeClass
   public static void beforeClass() throws Exception {
     initCore("solrconfig.xml", "schema.xml");
@@ -205,6 +208,8 @@ public class DebugComponentTest extends SolrTestCaseJ4 {
       req = req("q", "test query", "distrib", "true");
       rb = new ResponseBuilder(req, new SolrQueryResponse(), components);
       rb.isDistrib = true;
+      addRequestId(rb, ANY_RID);
+
       //expecting the same results with debugQuery=true or debug=track
       if(random().nextBoolean()) {
         rb.setDebug(true);
@@ -217,7 +222,7 @@ public class DebugComponentTest extends SolrTestCaseJ4 {
         rb.setDebugResults(random().nextBoolean());
       }
       component.prepare(rb);
-      ensureRidPresent(rb, null);
+      ensureTrackRecordsRid(rb, ANY_RID);
     }
    
     req = req("q", "test query", "distrib", "true", CommonParams.REQUEST_ID, "123");
@@ -225,24 +230,7 @@ public class DebugComponentTest extends SolrTestCaseJ4 {
     rb.isDistrib = true;
     rb.setDebug(true);
     component.prepare(rb);
-    ensureRidPresent(rb, "123");
-  }
-  
-  @SuppressWarnings("unchecked")
-  private void ensureRidPresent(ResponseBuilder rb, String expectedRid) {
-    SolrQueryRequest req = rb.req;
-    SolrQueryResponse resp = rb.rsp;
-    //a generated request ID should be added to the request
-    String rid = req.getParams().get(CommonParams.REQUEST_ID);
-    if(expectedRid == null) {
-      assertTrue(rid + " Doesn't match expected pattern.", Pattern.matches(".*-collection1-[0-9]*-[0-9]+", rid));
-    } else {
-      assertEquals("Expecting " + expectedRid + " but found " + rid, expectedRid, rid);
-    }
-    //The request ID is added to the debug/track section
-    assertEquals(rid, ((NamedList<Object>) rb.getDebugInfo().get("track")).get(CommonParams.REQUEST_ID));
-    //RID must be added to the toLog, so that it's included in the main request log
-    assertEquals(rid, resp.getToLog().get(CommonParams.REQUEST_ID));
+    ensureTrackRecordsRid(rb, "123");
   }
 
   //
@@ -279,4 +267,16 @@ public class DebugComponentTest extends SolrTestCaseJ4 {
     );
 
   }
+
+  @SuppressWarnings("unchecked")
+  private void ensureTrackRecordsRid(ResponseBuilder rb, String expectedRid) {
+    final String rid = (String) ((NamedList<Object>) rb.getDebugInfo().get("track")).get(CommonParams.REQUEST_ID);
+    assertEquals("Expecting " + expectedRid + " but found " + rid, expectedRid, rid);
+  }
+
+  private void addRequestId(ResponseBuilder rb, String requestId) {
+    ModifiableSolrParams params = new ModifiableSolrParams(rb.req.getParams());
+    params.add(CommonParams.REQUEST_ID, requestId);
+    rb.req.setParams(params);
+  }
 }