You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@lucene.apache.org by dw...@apache.org on 2021/03/10 09:49:33 UTC
[lucene] 03/09: SOLR-12730: add more debug logging.
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 efb73a39b03b3f4ac2fa139d4e0816a35c5d8b8d
Author: Andrzej Bialecki <ab...@apache.org>
AuthorDate: Mon Oct 29 20:06:31 2018 +0100
SOLR-12730: add more debug logging.
---
.../solr/cloud/autoscaling/IndexSizeTrigger.java | 19 +++++++++++++---
.../src/java/org/apache/solr/core/SolrCore.java | 26 ++++++++++++++++++++++
.../apache/solr/handler/admin/MetricsHandler.java | 8 +++++++
.../org/apache/solr/update/SolrIndexSplitter.java | 4 ++--
.../cloud/autoscaling/IndexSizeTriggerTest.java | 19 ++++++++++++++--
5 files changed, 69 insertions(+), 7 deletions(-)
diff --git a/solr/core/src/java/org/apache/solr/cloud/autoscaling/IndexSizeTrigger.java b/solr/core/src/java/org/apache/solr/cloud/autoscaling/IndexSizeTrigger.java
index 533ec53..e41297e 100644
--- a/solr/core/src/java/org/apache/solr/cloud/autoscaling/IndexSizeTrigger.java
+++ b/solr/core/src/java/org/apache/solr/cloud/autoscaling/IndexSizeTrigger.java
@@ -252,7 +252,7 @@ public class IndexSizeTrigger extends TriggerBase {
DocCollection docCollection = clusterState.getCollection(coll);
shards.forEach((sh, replicas) -> {
- // check only the leader of a replica in active shard
+ // check only the leader replica in an active shard
Slice s = docCollection.getSlice(sh);
if (s.getState() != Slice.State.ACTIVE) {
return;
@@ -262,6 +262,10 @@ public class IndexSizeTrigger extends TriggerBase {
if (r == null) {
return;
}
+ // not on this node
+ if (!r.getNodeName().equals(node)) {
+ return;
+ }
// find ReplicaInfo
ReplicaInfo info = null;
for (ReplicaInfo ri : replicas) {
@@ -282,6 +286,7 @@ public class IndexSizeTrigger extends TriggerBase {
String registry = SolrCoreMetricManager.createRegistryName(true, coll, sh, replicaName, null);
String tag = "metrics:" + registry + ":INDEX.sizeInBytes";
metricTags.put(tag, info);
+ metricTags.put("metrics:" + registry + ":INDEX.sizeDetails", info);
tag = "metrics:" + registry + ":SEARCHER.searcher.numDocs";
metricTags.put(tag, info);
});
@@ -297,14 +302,14 @@ public class IndexSizeTrigger extends TriggerBase {
} else {
// verify that it's a Number
if (!(size instanceof Number)) {
- log.warn("invalid size value - not a number: '" + size + "' is " + size.getClass().getName());
+ log.warn("invalid size value for tag " + tag + " - not a number: '" + size + "' is " + size.getClass().getName());
return;
}
ReplicaInfo currentInfo = currentSizes.computeIfAbsent(info.getCore(), k -> (ReplicaInfo)info.clone());
if (tag.contains("INDEX")) {
currentInfo.getVariables().put(BYTES_SIZE_PROP, ((Number) size).longValue());
- } else {
+ } else if (tag.contains("SEARCHER")) {
currentInfo.getVariables().put(DOCS_SIZE_PROP, ((Number) size).longValue());
}
}
@@ -458,6 +463,14 @@ public class IndexSizeTrigger extends TriggerBase {
if (ops.isEmpty()) {
return;
}
+ try {
+ ClusterState cs = cloudManager.getClusterStateProvider().getClusterState();
+ cs.forEachCollection(coll -> {
+ log.debug("##== Collection: {}", coll);
+ });
+ } catch (IOException e) {
+ throw new RuntimeException("oops: ", e);
+ }
if (processor.process(new IndexSizeEvent(getName(), eventTime.get(), ops, aboveSize, belowSize))) {
// update last event times
aboveSize.forEach((coll, replicas) -> {
diff --git a/solr/core/src/java/org/apache/solr/core/SolrCore.java b/solr/core/src/java/org/apache/solr/core/SolrCore.java
index 6e13039..abc4af6 100644
--- a/solr/core/src/java/org/apache/solr/core/SolrCore.java
+++ b/solr/core/src/java/org/apache/solr/core/SolrCore.java
@@ -443,6 +443,31 @@ public final class SolrCore implements SolrInfoBean, SolrMetricProducer, Closeab
return size;
}
+ String getIndexSizeDetails() {
+ Directory dir;
+ StringBuilder sb = new StringBuilder();
+ try {
+ if (directoryFactory.exists(getIndexDir())) {
+ dir = directoryFactory.get(getIndexDir(), DirContext.DEFAULT, solrConfig.indexConfig.lockType);
+ try {
+ String[] files = dir.listAll();
+ Arrays.sort(files);
+ for (String file : files) {
+ sb.append('\n');
+ sb.append(file);
+ sb.append('\t');
+ sb.append(String.valueOf(dir.fileLength(file)));
+ }
+ } finally {
+ directoryFactory.release(dir);
+ }
+ }
+ } catch (IOException e) {
+ SolrException.log(log, "IO error while trying to get the details of the Directory", e);
+ }
+ return sb.toString();
+ }
+
@Override
public String getName() {
return name;
@@ -1161,6 +1186,7 @@ public final class SolrCore implements SolrInfoBean, SolrMetricProducer, Closeab
manager.registerGauge(this, registry, () -> resourceLoader.getInstancePath().toString(), getMetricTag(), true, "instanceDir", Category.CORE.toString());
manager.registerGauge(this, registry, () -> isClosed() ? "(closed)" : getIndexDir(), getMetricTag(), true, "indexDir", Category.CORE.toString());
manager.registerGauge(this, registry, () -> isClosed() ? 0 : getIndexSize(), getMetricTag(), true, "sizeInBytes", Category.INDEX.toString());
+ manager.registerGauge(this, registry, () -> isClosed() ? "" : getIndexSizeDetails(), getMetricTag(), true, "sizeDetails", Category.INDEX.toString());
manager.registerGauge(this, registry, () -> isClosed() ? "(closed)" : NumberUtils.readableSize(getIndexSize()), getMetricTag(), true, "size", Category.INDEX.toString());
if (coreContainer != null) {
manager.registerGauge(this, registry, () -> coreContainer.getNamesForCore(this), getMetricTag(), true, "aliases", Category.CORE.toString());
diff --git a/solr/core/src/java/org/apache/solr/handler/admin/MetricsHandler.java b/solr/core/src/java/org/apache/solr/handler/admin/MetricsHandler.java
index 752e021..9b9f948 100644
--- a/solr/core/src/java/org/apache/solr/handler/admin/MetricsHandler.java
+++ b/solr/core/src/java/org/apache/solr/handler/admin/MetricsHandler.java
@@ -17,6 +17,7 @@
package org.apache.solr.handler.admin;
+import java.lang.invoke.MethodHandles;
import java.util.ArrayList;
import java.util.Collections;
import java.util.EnumSet;
@@ -41,6 +42,7 @@ import org.apache.solr.common.params.SolrParams;
import org.apache.solr.common.util.NamedList;
import org.apache.solr.common.util.SimpleOrderedMap;
import org.apache.solr.common.util.StrUtils;
+import org.apache.solr.common.util.Utils;
import org.apache.solr.core.CoreContainer;
import org.apache.solr.handler.RequestHandlerBase;
import org.apache.solr.metrics.SolrMetricManager;
@@ -49,11 +51,15 @@ import org.apache.solr.response.SolrQueryResponse;
import org.apache.solr.security.AuthorizationContext;
import org.apache.solr.security.PermissionNameProvider;
import org.apache.solr.util.stats.MetricUtils;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
/**
* Request handler to return metrics
*/
public class MetricsHandler extends RequestHandlerBase implements PermissionNameProvider {
+ private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());
+
final SolrMetricManager metricManager;
public static final String COMPACT_PARAM = "compact";
@@ -99,6 +105,8 @@ public class MetricsHandler extends RequestHandlerBase implements PermissionName
}
handleRequest(req.getParams(), (k, v) -> rsp.add(k, v));
+ log.debug("##== Req: {}", req);
+ log.debug("##== Rsp: {}", Utils.toJSONString(rsp.getValues()));
}
public void handleRequest(SolrParams params, BiConsumer<String, Object> consumer) throws Exception {
diff --git a/solr/core/src/java/org/apache/solr/update/SolrIndexSplitter.java b/solr/core/src/java/org/apache/solr/update/SolrIndexSplitter.java
index 334a29d..6ed0b1f 100644
--- a/solr/core/src/java/org/apache/solr/update/SolrIndexSplitter.java
+++ b/solr/core/src/java/org/apache/solr/update/SolrIndexSplitter.java
@@ -174,7 +174,7 @@ public class SolrIndexSplitter {
log.error("Original error closing IndexWriter:", e);
throw new SolrException(SolrException.ErrorCode.SERVER_ERROR, "Error reopening IndexWriter after failed close", e1);
}
- throw new SolrException(SolrException.ErrorCode.SERVER_ERROR, "Error closing current IndexWriter, aborting offline split...", e);
+ throw new SolrException(SolrException.ErrorCode.SERVER_ERROR, "Error closing current IndexWriter, aborting 'link' split...", e);
}
}
boolean success = false;
@@ -195,7 +195,7 @@ public class SolrIndexSplitter {
t = timings.sub("parentApplyBufferedUpdates");
ulog.applyBufferedUpdates();
t.stop();
- log.info("Splitting in 'offline' mode " + (success? "finished" : "FAILED") +
+ log.info("Splitting in 'link' mode " + (success? "finished" : "FAILED") +
": re-opened parent IndexWriter.");
}
}
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 c933c0a..934ec20 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")
+@LogLevel("org.apache.solr.cloud.autoscaling=DEBUG;org.apache.solr.handler.admin.MetricsHandler=DEBUG")
public class IndexSizeTriggerTest extends SolrCloudTestCase {
private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());
@@ -90,6 +90,7 @@ public class IndexSizeTriggerTest extends SolrCloudTestCase {
@BeforeClass
public static void setupCluster() throws Exception {
+ System.setProperty("solr.directoryFactory", "solr.StandardDirectoryFactory");
configureCluster(2)
.addConfig("conf", configset("cloud-minimal"))
.configure();
@@ -503,7 +504,8 @@ public class IndexSizeTriggerTest extends SolrCloudTestCase {
int aboveBytes = maxSize * 9 / 10;
- long waitForSeconds = 3 + random().nextInt(5);
+ // need to wait for recovery after splitting
+ long waitForSeconds = 10 + random().nextInt(5);
// the trigger is initially disabled so that we have time to add listeners
// and have them capture all events once the trigger is enabled
@@ -562,6 +564,7 @@ public class IndexSizeTriggerTest extends SolrCloudTestCase {
"'name' : 'index_size_trigger4'" +
"}" +
"}";
+ log.info("-- resuming trigger");
req = createAutoScalingRequest(SolrRequest.METHOD.POST, resumeTriggerCommand);
response = solrClient.request(req);
assertEquals(response.get("result").toString(), "success");
@@ -570,6 +573,7 @@ public class IndexSizeTriggerTest extends SolrCloudTestCase {
boolean await = finished.await(90000 / SPEED, TimeUnit.MILLISECONDS);
assertTrue("did not finish processing in time", await);
+ log.info("-- suspending trigger");
// suspend the trigger to avoid generating more events
String suspendTriggerCommand = "{" +
"'suspend-trigger' : {" +
@@ -624,6 +628,7 @@ public class IndexSizeTriggerTest extends SolrCloudTestCase {
finished = new CountDownLatch(1);
+ log.info("-- deleting documents");
for (int j = 0; j < 10; j++) {
UpdateRequest ureq = new UpdateRequest();
ureq.setParam("collection", collectionName);
@@ -632,6 +637,7 @@ public class IndexSizeTriggerTest extends SolrCloudTestCase {
}
solrClient.request(ureq);
}
+ cloudManager.getTimeSource().sleep(5000);
// make sure the actual index size is reduced by deletions, otherwise we may still violate aboveBytes
UpdateRequest ur = new UpdateRequest();
ur.setParam(UpdateParams.COMMIT, "true");
@@ -640,14 +646,17 @@ public class IndexSizeTriggerTest extends SolrCloudTestCase {
ur.setParam(UpdateParams.MAX_OPTIMIZE_SEGMENTS, "1");
ur.setParam(UpdateParams.WAIT_SEARCHER, "true");
ur.setParam(UpdateParams.OPEN_SEARCHER, "true");
+ log.info("-- requesting optimize / expungeDeletes / commit");
solrClient.request(ur, collectionName);
// wait for the segments to merge to reduce the index size
cloudManager.getTimeSource().sleep(50000);
+ log.info("-- requesting commit");
solrClient.commit(collectionName, true, true);
// resume the trigger
+ log.info("-- resuming trigger");
req = createAutoScalingRequest(SolrRequest.METHOD.POST, resumeTriggerCommand);
response = solrClient.request(req);
assertEquals(response.get("result").toString(), "success");
@@ -656,6 +665,12 @@ public class IndexSizeTriggerTest extends SolrCloudTestCase {
await = finished.await(90000 / SPEED, TimeUnit.MILLISECONDS);
assertTrue("did not finish processing in time", await);
+ log.info("-- suspending trigger");
+ req = createAutoScalingRequest(SolrRequest.METHOD.POST, suspendTriggerCommand);
+ response = solrClient.request(req);
+ assertEquals(response.get("result").toString(), "success");
+ System.exit(-1);
+
assertEquals(1, listenerEvents.size());
events = listenerEvents.get("capturing4");
assertNotNull("'capturing4' events not found", events);