You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@lucene.apache.org by er...@apache.org on 2020/05/09 17:09:21 UTC
[lucene-solr] branch master updated: SOLR-11934: Visit Solr logging,
it's too noisy.
This is an automated email from the ASF dual-hosted git repository.
erick pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/lucene-solr.git
The following commit(s) were added to refs/heads/master by this push:
new 15be0db SOLR-11934: Visit Solr logging, it's too noisy.
15be0db is described below
commit 15be0db58696d379c6f7e1a6d0afa18dd7cdd43d
Author: Erick Erickson <Er...@gmail.com>
AuthorDate: Sat May 9 12:49:59 2020 -0400
SOLR-11934: Visit Solr logging, it's too noisy.
---
solr/CHANGES.txt | 3 +++
.../src/java/org/apache/solr/core/QuerySenderListener.java | 2 +-
solr/core/src/java/org/apache/solr/core/SolrCore.java | 5 ++++-
.../src/java/org/apache/solr/search/SolrIndexSearcher.java | 5 ++++-
.../src/java/org/apache/solr/update/DirectUpdateHandler2.java | 10 +++++-----
solr/core/src/java/org/apache/solr/update/SolrIndexWriter.java | 2 +-
.../solr/update/processor/LogUpdateProcessorFactory.java | 3 ++-
7 files changed, 20 insertions(+), 10 deletions(-)
diff --git a/solr/CHANGES.txt b/solr/CHANGES.txt
index 99fce5b..24cb5f4 100644
--- a/solr/CHANGES.txt
+++ b/solr/CHANGES.txt
@@ -201,6 +201,9 @@ Other Changes
* SOLR-14466: Upgrade log4j2 to latest release (2.13.2) (Erick Erickson)
+* SOLR-11934: Visit Solr logging, it's too noisy. Note particularly that the messages for
+ opening a new searcher have changed and include the autowarm time. (Erick Erickson)
+
================== 8.5.1 ==================
Consult the LUCENE_CHANGES.txt file for additional, low level, changes in this release.
diff --git a/solr/core/src/java/org/apache/solr/core/QuerySenderListener.java b/solr/core/src/java/org/apache/solr/core/QuerySenderListener.java
index a0dbbb1..d4bb6c0 100644
--- a/solr/core/src/java/org/apache/solr/core/QuerySenderListener.java
+++ b/solr/core/src/java/org/apache/solr/core/QuerySenderListener.java
@@ -47,7 +47,7 @@ public class QuerySenderListener extends AbstractSolrEventListener {
@Override
public void newSearcher(SolrIndexSearcher newSearcher, SolrIndexSearcher currentSearcher) {
final SolrIndexSearcher searcher = newSearcher;
- log.info("QuerySenderListener sending requests to {}", newSearcher);
+ log.debug("QuerySenderListener sending requests to {}", newSearcher);
List<NamedList> allLists = (List<NamedList>)getArgs().get("queries");
if (allLists == null) return;
boolean createNewReqInfo = SolrRequestInfo.getRequestInfo() == null;
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 ca7df79..311e30c 100644
--- a/solr/core/src/java/org/apache/solr/core/SolrCore.java
+++ b/solr/core/src/java/org/apache/solr/core/SolrCore.java
@@ -2526,7 +2526,10 @@ public final class SolrCore implements SolrInfoBean, Closeable {
***/
newSearcher.register(); // register subitems (caches)
- log.info("{}Registered new searcher {}", logid, newSearcher);
+
+ if (log.isInfoEnabled()) {
+ log.info("{} Registered new searcher autowarm time: {} ms", logid, newSearcher.getWarmupTime());
+ }
} catch (Exception e) {
// an exception in register() shouldn't be fatal.
diff --git a/solr/core/src/java/org/apache/solr/search/SolrIndexSearcher.java b/solr/core/src/java/org/apache/solr/search/SolrIndexSearcher.java
index e2d8107..bf85d6c 100644
--- a/solr/core/src/java/org/apache/solr/search/SolrIndexSearcher.java
+++ b/solr/core/src/java/org/apache/solr/search/SolrIndexSearcher.java
@@ -242,7 +242,7 @@ public class SolrIndexSearcher extends IndexSearcher implements Closeable, SolrI
this.schema = schema;
this.name = "Searcher@" + Integer.toHexString(hashCode()) + "[" + core.getName() + "]"
+ (name != null ? " " + name : "");
- log.info("Opening [{}]", this.name);
+ log.debug("Opening [{}]", this.name);
if (directoryFactory.searchersReserveCommitPoints()) {
// reserve commit point for life of searcher
@@ -2448,5 +2448,8 @@ public class SolrIndexSearcher extends IndexSearcher implements Closeable, SolrI
+ 31 * Objects.hashCode(weights);
}
}
+ public long getWarmupTime() {
+ return warmupTime;
+ }
}
diff --git a/solr/core/src/java/org/apache/solr/update/DirectUpdateHandler2.java b/solr/core/src/java/org/apache/solr/update/DirectUpdateHandler2.java
index bf0bce6..901ac82 100644
--- a/solr/core/src/java/org/apache/solr/update/DirectUpdateHandler2.java
+++ b/solr/core/src/java/org/apache/solr/update/DirectUpdateHandler2.java
@@ -587,7 +587,7 @@ public class DirectUpdateHandler2 extends UpdateHandler implements SolrCoreState
boolean error=true;
try {
- log.info("start {}", cmd);
+ log.debug("start {}", cmd);
RefCounted<IndexWriter> iw = solrCoreState.getIndexWriter(core);
try {
SolrIndexWriter.setCommitData(iw.get(), cmd.getVersion());
@@ -596,7 +596,7 @@ public class DirectUpdateHandler2 extends UpdateHandler implements SolrCoreState
iw.decref();
}
- log.info("end_prepareCommit");
+ log.debug("end_prepareCommit");
error=false;
}
@@ -635,7 +635,7 @@ public class DirectUpdateHandler2 extends UpdateHandler implements SolrCoreState
solrCoreState.getCommitLock().lock();
}
- log.info("start {}", cmd);
+ log.debug("start {}", cmd);
// We must cancel pending commits *before* we actually execute the commit.
@@ -672,7 +672,7 @@ public class DirectUpdateHandler2 extends UpdateHandler implements SolrCoreState
SolrIndexWriter.setCommitData(writer, cmd.getVersion());
writer.commit();
} else {
- log.info("No uncommitted changes. Skipping IW.commit.");
+ log.debug("No uncommitted changes. Skipping IW.commit.");
}
// SolrCore.verbose("writer.commit() end");
@@ -721,7 +721,7 @@ public class DirectUpdateHandler2 extends UpdateHandler implements SolrCoreState
commitTracker.didCommit();
}
- log.info("end_commit_flush");
+ log.debug("end_commit_flush");
error=false;
}
diff --git a/solr/core/src/java/org/apache/solr/update/SolrIndexWriter.java b/solr/core/src/java/org/apache/solr/update/SolrIndexWriter.java
index 12323df..aa841f3 100644
--- a/solr/core/src/java/org/apache/solr/update/SolrIndexWriter.java
+++ b/solr/core/src/java/org/apache/solr/update/SolrIndexWriter.java
@@ -179,7 +179,7 @@ public class SolrIndexWriter extends IndexWriter {
@SuppressForbidden(reason = "Need currentTimeMillis, commit time should be used only for debugging purposes, " +
" but currently suspiciously used for replication as well")
public static void setCommitData(IndexWriter iw, long commitCommandVersion) {
- log.info("Calling setCommitData with IW:{} commitCommandVersion:{}", iw, commitCommandVersion);
+ log.debug("Calling setCommitData with IW:{} commitCommandVersion:{}", iw, commitCommandVersion);
final Map<String,String> commitData = new HashMap<>();
commitData.put(COMMIT_TIME_MSEC_KEY, String.valueOf(System.currentTimeMillis()));
commitData.put(COMMIT_COMMAND_VERSION, String.valueOf(commitCommandVersion));
diff --git a/solr/core/src/java/org/apache/solr/update/processor/LogUpdateProcessorFactory.java b/solr/core/src/java/org/apache/solr/update/processor/LogUpdateProcessorFactory.java
index 98d6856..8a4e7e8 100644
--- a/solr/core/src/java/org/apache/solr/update/processor/LogUpdateProcessorFactory.java
+++ b/solr/core/src/java/org/apache/solr/update/processor/LogUpdateProcessorFactory.java
@@ -62,7 +62,8 @@ public class LogUpdateProcessorFactory extends UpdateRequestProcessorFactory imp
@Override
public UpdateRequestProcessor getInstance(SolrQueryRequest req, SolrQueryResponse rsp, UpdateRequestProcessor next) {
- return log.isInfoEnabled() ? new LogUpdateProcessor(req, rsp, this, next) : next;
+ return (log.isInfoEnabled() || slowUpdateThresholdMillis >= 0) ?
+ new LogUpdateProcessor(req, rsp, this, next) : next;
}
static class LogUpdateProcessor extends UpdateRequestProcessor {