SOLR-11934: Visit Solr logging, it's too noisy.

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.

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;

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.

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;
+  }
 
 }

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;
     }

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));

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 {