You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@lucene.apache.org by ge...@apache.org on 2020/06/18 16:50:14 UTC
[lucene-solr] branch SOLR_14566_add_now_to_coordinator_logging2
created (now 3eec814)
This is an automated email from the ASF dual-hosted git repository.
gerlowskija pushed a change to branch SOLR_14566_add_now_to_coordinator_logging2
in repository https://gitbox.apache.org/repos/asf/lucene-solr.git.
at 3eec814 SOLR-14566: Add rid to all distributed search requests
This branch includes the following new commits:
new 99f3c81 Revert "SOLR-14566: Log NOW value on coordinator node for dist search requests"
new 3eec814 SOLR-14566: Add rid to all distributed search requests
The 2 revisions listed above as "new" are entirely new to this
repository and will be described in separate emails. The revisions
listed as "add" were already present in the repository and have only
been added to this reference.
[lucene-solr] 01/02: Revert "SOLR-14566: Log NOW value on
coordinator node for dist search requests"
Posted by 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 99f3c81906c8377c154462430a1a79d4ce6561ec
Author: Jason Gerlowski <ja...@lucidworks.com>
AuthorDate: Thu Jun 18 11:01:42 2020 -0400
Revert "SOLR-14566: Log NOW value on coordinator node for dist search requests"
This reverts commit 460cd727db8194524041dd7b002c24a420a28eef.
---
solr/CHANGES.txt | 3 ---
.../java/org/apache/solr/handler/component/SearchHandler.java | 11 ++---------
2 files changed, 2 insertions(+), 12 deletions(-)
diff --git a/solr/CHANGES.txt b/solr/CHANGES.txt
index cc24a73..80c467a 100644
--- a/solr/CHANGES.txt
+++ b/solr/CHANGES.txt
@@ -141,9 +141,6 @@ 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: Solr now logs the NOW value on coordinator requests that is used on downstream per-shard requests. This
- allows easier association between shard requests and their corresponding coordinator request when reading logs. (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/SearchHandler.java b/solr/core/src/java/org/apache/solr/handler/component/SearchHandler.java
index 0c8e508..2051b20 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
@@ -25,7 +25,6 @@ import java.util.LinkedList;
import java.util.List;
import java.util.Set;
-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;
@@ -371,12 +370,6 @@ public class SearchHandler extends RequestHandlerBase implements SolrCoreAware,
rb.finished = new ArrayList<>();
int nextStage = 0;
-
- final String nowTimestamp = (rb.requestInfo != null) ? Long.toString(rb.requestInfo.getNOW().getTime()) : null;
- if (StringUtils.isNotEmpty(nowTimestamp)) {
- rsp.addToLog("NOW", nowTimestamp);
- }
-
do {
rb.stage = nextStage;
nextStage = ResponseBuilder.STAGE_DONE;
@@ -411,9 +404,9 @@ public class SearchHandler extends RequestHandlerBase implements SolrCoreAware,
params.set(ShardParams.SHARDS_PURPOSE, sreq.purpose);
params.set(ShardParams.SHARD_URL, shard); // so the shard knows what was asked
params.set(CommonParams.OMIT_HEADER, false);
- if (nowTimestamp != null) {
+ if (rb.requestInfo != null) {
// we could try and detect when this is needed, but it could be tricky
- params.set("NOW", nowTimestamp);
+ params.set("NOW", Long.toString(rb.requestInfo.getNOW().getTime()));
}
String shardQt = params.get(ShardParams.SHARDS_QT);
if (shardQt != null) {
[lucene-solr] 02/02: SOLR-14566: Add rid to all distributed search
requests
Posted by 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);
+ }
}