You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@lucene.apache.org by ma...@apache.org on 2020/11/10 19:06:47 UTC

[lucene-solr] branch reference_impl_dev updated: @1140 Cleanup logging.

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

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


The following commit(s) were added to refs/heads/reference_impl_dev by this push:
     new ed4a4ba  @1140 Cleanup logging.
ed4a4ba is described below

commit ed4a4baf57f4298c56cb0f4c0edaed612bcbabe7
Author: markrmiller@gmail.com <ma...@gmail.com>
AuthorDate: Tue Nov 10 13:06:29 2020 -0600

    @1140 Cleanup logging.
---
 .../OverseerCollectionMessageHandler.java          |  6 +--
 .../apache/solr/cloud/overseer/SliceMutator.java   | 13 +++----
 .../apache/solr/cloud/overseer/ZkStateWriter.java  |  2 +-
 .../apache/solr/update/DefaultSolrCoreState.java   |  2 +-
 .../org/apache/solr/update/SolrIndexWriter.java    |  8 ++--
 .../src/java/org/apache/solr/update/UpdateLog.java |  2 +-
 .../solr/client/solrj/impl/Http2SolrClient.java    |  4 +-
 .../org/apache/solr/common/cloud/SolrZkClient.java | 43 +++++++++++-----------
 .../solr/common/util/SolrInternalHttpClient.java   |  2 +-
 9 files changed, 39 insertions(+), 43 deletions(-)

diff --git a/solr/core/src/java/org/apache/solr/cloud/api/collections/OverseerCollectionMessageHandler.java b/solr/core/src/java/org/apache/solr/cloud/api/collections/OverseerCollectionMessageHandler.java
index 980c47a..27a6b9f 100644
--- a/solr/core/src/java/org/apache/solr/cloud/api/collections/OverseerCollectionMessageHandler.java
+++ b/solr/core/src/java/org/apache/solr/cloud/api/collections/OverseerCollectionMessageHandler.java
@@ -254,7 +254,7 @@ public class OverseerCollectionMessageHandler implements OverseerMessageHandler,
     MDCLoggingContext.setCollection(message.getStr(COLLECTION));
     MDCLoggingContext.setShard(message.getStr(SHARD_ID_PROP));
     MDCLoggingContext.setReplica(message.getStr(REPLICA_PROP));
-    log.debug("OverseerCollectionMessageHandler.processMessage : {} , {}", operation, message);
+    if (log.isDebugEnabled()) log.debug("OverseerCollectionMessageHandler.processMessage : {} , {}", operation, message);
     ClusterState clusterState = overseer.getZkStateWriter().getClusterstate(false);
     @SuppressWarnings({"rawtypes"})
     NamedList results = new NamedList();
@@ -268,7 +268,7 @@ public class OverseerCollectionMessageHandler implements OverseerMessageHandler,
           throw new SolrException(ErrorCode.SERVER_ERROR, "CMD did not return a response:" + operation);
         }
 
-        log.info("Command returned clusterstate={} results={}", responce.clusterState, results);
+        if (log.isDebugEnabled()) log.debug("Command returned clusterstate={} results={}", responce.clusterState, results);
 
         if (responce.clusterState != null) {
           overseer.getZkStateWriter().enqueueUpdate(responce.clusterState, false);
@@ -279,7 +279,7 @@ public class OverseerCollectionMessageHandler implements OverseerMessageHandler,
         // nocommit consider
         if (responce != null && responce.asyncFinalRunner != null) {
           AddReplicaCmd.Response resp = responce.asyncFinalRunner.call();
-          log.info("Finalize after Command returned clusterstate={}", resp.clusterState);
+          if (log.isDebugEnabled()) log.debug("Finalize after Command returned clusterstate={}", resp.clusterState);
           if (resp.clusterState != null) {
             overseer.getZkStateWriter().enqueueUpdate(responce.clusterState, false);
             overseer.writePendingUpdates();
diff --git a/solr/core/src/java/org/apache/solr/cloud/overseer/SliceMutator.java b/solr/core/src/java/org/apache/solr/cloud/overseer/SliceMutator.java
index 9f17e28..df2a863 100644
--- a/solr/core/src/java/org/apache/solr/cloud/overseer/SliceMutator.java
+++ b/solr/core/src/java/org/apache/solr/cloud/overseer/SliceMutator.java
@@ -59,7 +59,7 @@ public class SliceMutator {
   }
 
   public ClusterState addReplica(ClusterState clusterState, ZkNodeProps message) {
-    log.info("createReplica() {} ", message);
+    if (log.isDebugEnabled()) log.debug("createReplica() {} ", message);
     String coll = message.getStr(ZkStateReader.COLLECTION_PROP);
     // if (!checkCollectionKeyExistence(message)) return ZkStateWriter.NO_OP;
     String slice = message.getStr(ZkStateReader.SHARD_ID_PROP);
@@ -88,7 +88,7 @@ public class SliceMutator {
 
   public ClusterState removeReplica(ClusterState clusterState, ZkNodeProps message) {
 
-    log.info("removeReplica(ClusterState clusterState={}, ZkNodeProps message={}) - start", clusterState, message);
+    if (log.isDebugEnabled()) log.debug("removeReplica(ClusterState clusterState={}, ZkNodeProps message={}) - start", clusterState, message);
 
     String coreName = message.getStr(ZkStateReader.REPLICA_PROP);
     if (coreName == null) {
@@ -149,7 +149,7 @@ public class SliceMutator {
       if (log.isDebugEnabled()) log.debug("examine for setting or unsetting as leader replica={}", replica);
 
       if (coreName.equals(replica.getName())) {
-        log.info("Set leader {}", replica.getName());
+        if (log.isDebugEnabled()) log.debug("Set leader {}", replica.getName());
         replica = new ReplicaMutator(cloudManager).setLeader(replica);
       } else if (replica.getBool("leader", false)) {
         if (log.isDebugEnabled()) log.debug("Unset leader");
@@ -164,7 +164,7 @@ public class SliceMutator {
     slice = new Slice(slice.getName(), newReplicas, slice.getProperties(), collectionName, (Replica.NodeNameToBaseUrl) cloudManager.getClusterStateProvider());
 
     clusterState = clusterState.copyWith(collectionName, CollectionMutator.updateSlice(collectionName, coll, slice));
-    log.info("setShardLeader {} {}", sliceName, clusterState);
+    if (log.isDebugEnabled()) log.debug("setShardLeader {} {}", sliceName, clusterState);
 
     return clusterState;
   }
@@ -175,7 +175,6 @@ public class SliceMutator {
     }
 
     String collectionName = message.getStr(ZkStateReader.COLLECTION_PROP);
-    log.info("Update shard state invoked for collection: " + collectionName + " with message: " + message);
 
     DocCollection collection = clusterState.getCollection(collectionName);
     Map<String, Slice> slicesCopy = new LinkedHashMap<>(collection.getSlicesMap());
@@ -188,7 +187,7 @@ public class SliceMutator {
       if (slice == null) {
         throw new RuntimeException("Overseer.updateShardState unknown slice: " + collectionName + " slice: " + key);
       }
-      log.info("Update shard state " + key + " to " + message.getStr(key));
+      if (log.isDebugEnabled()) log.debug("Update shard state " + key + " to " + message.getStr(key));
       Map<String, Object> props = slice.shallowCopy();
 
       if (Slice.State.getState(message.getStr(key)) == Slice.State.ACTIVE) {
@@ -205,7 +204,7 @@ public class SliceMutator {
     }
 
     ClusterState cs = clusterState.copyWith(collectionName, collection.copyWithSlices(slicesCopy));
-    log.info("updateShardState return clusterstate={}", cs);
+    if (log.isDebugEnabled()) log.debug("updateShardState return clusterstate={}", cs);
     return cs;
   }
 
diff --git a/solr/core/src/java/org/apache/solr/cloud/overseer/ZkStateWriter.java b/solr/core/src/java/org/apache/solr/cloud/overseer/ZkStateWriter.java
index 832c835..6f53432 100644
--- a/solr/core/src/java/org/apache/solr/cloud/overseer/ZkStateWriter.java
+++ b/solr/core/src/java/org/apache/solr/cloud/overseer/ZkStateWriter.java
@@ -343,7 +343,7 @@ public class ZkStateWriter {
         }
       }
     });
-    
+
     dirty = false;
     collectionsToWrite.clear();
 
diff --git a/solr/core/src/java/org/apache/solr/update/DefaultSolrCoreState.java b/solr/core/src/java/org/apache/solr/update/DefaultSolrCoreState.java
index 6103535..16b4cc6 100644
--- a/solr/core/src/java/org/apache/solr/update/DefaultSolrCoreState.java
+++ b/solr/core/src/java/org/apache/solr/update/DefaultSolrCoreState.java
@@ -103,7 +103,7 @@ public final class DefaultSolrCoreState extends SolrCoreState implements Recover
 
   private void closeIndexWriter(IndexWriterCloser closer) {
     try {
-      if (log.isInfoEnabled()) log.info("SolrCoreState ref count has reached 0 - closing IndexWriter");
+      if (log.isDebugEnabled()) log.debug("SolrCoreState ref count has reached 0 - closing IndexWriter");
       if (closer != null) {
         if (log.isDebugEnabled()) log.debug("closing IndexWriter with IndexWriterCloser");
 
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 ad4b875..2674487 100644
--- a/solr/core/src/java/org/apache/solr/update/SolrIndexWriter.java
+++ b/solr/core/src/java/org/apache/solr/update/SolrIndexWriter.java
@@ -393,19 +393,17 @@ public class SolrIndexWriter extends IndexWriter {
   }
 
   private void cleanup(String label) throws IOException {
+    numCloses.incrementAndGet();
     if (log.isDebugEnabled()) {
-      log.debug("cleanup() - start");
+      log.debug("SolrIndexWriter close {} numCloses={}", label, numCloses.get());
     }
-    numCloses.incrementAndGet();
-
-    log.info("SolrIndexWriter close {} numCloses={}", label, numCloses.get());
     try {
       if (infoStream != null) {
         ParWork.close(infoStream, true);
       }
 
       if (releaseDirectory) {
-        log.info("SolrIndexWriter release {}", directory);
+        if (log.isDebugEnabled()) log.debug("SolrIndexWriter release {}", directory);
         directoryFactory.release(directory);
       }
       if (solrMetricsContext != null) {
diff --git a/solr/core/src/java/org/apache/solr/update/UpdateLog.java b/solr/core/src/java/org/apache/solr/update/UpdateLog.java
index 2f8ea93..656bcc9 100644
--- a/solr/core/src/java/org/apache/solr/update/UpdateLog.java
+++ b/solr/core/src/java/org/apache/solr/update/UpdateLog.java
@@ -1468,7 +1468,7 @@ public class UpdateLog implements PluginInfoInitialized, SolrMetricProducer {
   }
 
   public void close(boolean committed, boolean deleteOnClose) {
-    log.info("Close UpdateLog committed={}, deleteOnClose={}", committed, deleteOnClose);
+    if (log.isDebugEnabled()) log.debug("Close UpdateLog committed={}, deleteOnClose={}", committed, deleteOnClose);
     this.isClosed = true;
     tlogLock.lock();
     try {
diff --git a/solr/solrj/src/java/org/apache/solr/client/solrj/impl/Http2SolrClient.java b/solr/solrj/src/java/org/apache/solr/client/solrj/impl/Http2SolrClient.java
index 29de64b..aff1ad0 100644
--- a/solr/solrj/src/java/org/apache/solr/client/solrj/impl/Http2SolrClient.java
+++ b/solr/solrj/src/java/org/apache/solr/client/solrj/impl/Http2SolrClient.java
@@ -275,7 +275,7 @@ public class Http2SolrClient extends SolrClient {
   }
 
   public void close() {
-    log.info("Closing {} closeClient={}", this.getClass().getSimpleName(), closeClient);
+    if (log.isDebugEnabled()) log.debug("Closing {} closeClient={}", this.getClass().getSimpleName(), closeClient);
    // assert closeTracker != null ? closeTracker.close() : true;
     asyncTracker.close();
     
@@ -286,7 +286,7 @@ public class Http2SolrClient extends SolrClient {
         log.error("Exception closing httpClient", e);
       }
     }
-    log.info("Done closing {}", this.getClass().getSimpleName());
+    if (log.isDebugEnabled()) log.debug("Done closing {}", this.getClass().getSimpleName());
     assert ObjectReleaseTracker.release(this);
   }
 
diff --git a/solr/solrj/src/java/org/apache/solr/common/cloud/SolrZkClient.java b/solr/solrj/src/java/org/apache/solr/common/cloud/SolrZkClient.java
index b7a607e..4bf892b 100644
--- a/solr/solrj/src/java/org/apache/solr/common/cloud/SolrZkClient.java
+++ b/solr/solrj/src/java/org/apache/solr/common/cloud/SolrZkClient.java
@@ -150,7 +150,7 @@ public class SolrZkClient implements Closeable {
 
   public SolrZkClient(String zkServerAddress, int zkClientTimeout, int clientConnectTimeout, final OnReconnect onReconnect, BeforeReconnect beforeReconnect, ZkACLProvider zkACLProvider, IsClosed higherLevelIsClosed) {
     assert ObjectReleaseTracker.track(this);
-    log.info("Creating new {} instance {}", SolrZkClient.class.getSimpleName(), this);
+    if (log.isDebugEnabled()) log.debug("Creating new {} instance {}", SolrZkClient.class.getSimpleName(), this);
     assert (closeTracker = new CloseTracker()) != null;
     this.zkServerAddress = zkServerAddress;
     this.higherLevelIsClosed = higherLevelIsClosed;
@@ -186,7 +186,7 @@ public class SolrZkClient implements Closeable {
   }
 
   public SolrZkClient start() {
-    log.info("Starting {} instance {}", SolrZkClient.class.getSimpleName(), this);
+    if (log.isDebugEnabled()) log.debug("Starting {} instance {}", SolrZkClient.class.getSimpleName(), this);
     try {
       connManager.start();
       connManager.waitForConnected(this.zkClientConnectTimeout);
@@ -214,14 +214,14 @@ public class SolrZkClient implements Closeable {
     String zkCredentialsProviderClassName = System.getProperty(ZK_CRED_PROVIDER_CLASS_NAME_VM_PARAM_NAME);
     if (!StringUtils.isEmpty(zkCredentialsProviderClassName)) {
       try {
-        log.info("Using ZkCredentialsProvider: {}", zkCredentialsProviderClassName);
+        if (log.isDebugEnabled()) log.debug("Using ZkCredentialsProvider: {}", zkCredentialsProviderClassName);
         return (ZkCredentialsProvider)Class.forName(zkCredentialsProviderClassName).getConstructor().newInstance();
       } catch (Throwable t) {
         // just ignore - go default
         log.warn("VM param zkCredentialsProvider does not point to a class implementing ZkCredentialsProvider and with a non-arg constructor", t);
       }
     }
-    log.info("Using default ZkCredentialsProvider");
+    if (log.isDebugEnabled()) log.debug("Using default ZkCredentialsProvider");
     return new DefaultZkCredentialsProvider();
   }
 
@@ -230,14 +230,14 @@ public class SolrZkClient implements Closeable {
     String zkACLProviderClassName = System.getProperty(ZK_ACL_PROVIDER_CLASS_NAME_VM_PARAM_NAME);
     if (!StringUtils.isEmpty(zkACLProviderClassName)) {
       try {
-        log.info("Using ZkACLProvider: {}", zkACLProviderClassName);
+        if (log.isDebugEnabled()) log.debug("Using ZkACLProvider: {}", zkACLProviderClassName);
         return (ZkACLProvider)Class.forName(zkACLProviderClassName).getConstructor().newInstance();
       } catch (Throwable t) {
         // just ignore - go default
         log.warn("VM param zkACLProvider does not point to a class implementing ZkACLProvider and with a non-arg constructor", t);
       }
     }
-    log.debug("Using default ZkACLProvider");
+    if (log.isDebugEnabled()) log.debug("Using default ZkACLProvider");
     return new DefaultZkACLProvider();
   }
 
@@ -316,11 +316,11 @@ public class SolrZkClient implements Closeable {
     ZooKeeper keeper = connManager.getKeeper();
     if (retryOnConnLoss) {
       Stat existsStat = zkCmdExecutor.retryOperation(() -> keeper.exists(path, null));
-      log.info("exists state return is {} {}", path, existsStat);
+      if (log.isDebugEnabled()) log.debug("exists state return is {} {}", path, existsStat);
       return existsStat != null;
     } else {
       Stat existsStat = keeper.exists(path, null);
-      log.info("exists state return is {} {}", path, existsStat);
+      if (log.isDebugEnabled()) log.debug("exists state return is {} {}", path, existsStat);
       return existsStat != null;
     }
   }
@@ -523,7 +523,7 @@ public class SolrZkClient implements Closeable {
   public void makePath(String path, byte[] data, CreateMode createMode,
       Watcher watcher, boolean failOnExists, boolean retryOnConnLoss, int skipPathParts) throws KeeperException, InterruptedException {
     ZooKeeper keeper = connManager.getKeeper();
-    log.info("makePath: {}", path);
+    if (log.isDebugEnabled()) log.debug("makePath: {}", path);
     boolean retry = true;
     if (path.startsWith("/")) {
       path = path.substring(1, path.length());
@@ -774,19 +774,19 @@ public class SolrZkClient implements Closeable {
   }
 
   public void delete(Collection<String> paths, boolean wait) {
-    log.info("delete paths {} wait={}", paths, wait);
+    if (log.isDebugEnabled()) log.debug("delete paths {} wait={}", paths, wait);
     CountDownLatch latch = null;
     if (wait) {
       latch = new CountDownLatch(paths.size());
     }
     for (String path : paths) {
-      log.info("process path={} connManager={}", path, connManager);
+      if (log.isDebugEnabled()) log.debug("process path={} connManager={}", path, connManager);
       ZooKeeper keeper = connManager.getKeeper();
-      log.info("keeper={}", keeper);
+      if (log.isDebugEnabled()) log.debug("keeper={}", keeper);
 
       CountDownLatch finalLatch = latch;
       keeper.delete(path, -1, (rc, path1, ctx) -> {
-        log.info("async delete resp rc={}, path1={}, ctx={}", rc, path1, ctx);
+        if (log.isDebugEnabled()) log.debug("async delete resp rc={}, path1={}, ctx={}", rc, path1, ctx);
         if (rc != 0) {
           log.error("got zk error {}", rc);
           final KeeperException.Code keCode = KeeperException.Code.get(rc);
@@ -795,21 +795,21 @@ public class SolrZkClient implements Closeable {
             if (log.isDebugEnabled()) log.debug("Problem removing zk node {}", path1);
           }
         }
-        log.info("done with latch countdown wait={}", wait);
+        if (log.isDebugEnabled()) log.debug("done with latch countdown wait={}", wait);
         if (wait) {
-          log.info("latch countdown");
+          if (log.isDebugEnabled()) log.debug("latch countdown");
           finalLatch.countDown();
         }
-        log.info("after wait &&  latch countdown");
+        if (log.isDebugEnabled()) log.debug("after wait &&  latch countdown");
       }, null);
     }
 
-    log.info("done with all paths, see if wait ... wait={}", wait);
+    if (log.isDebugEnabled()) log.debug("done with all paths, see if wait ... wait={}", wait);
     if (wait) {
       boolean success;
       try {
         success = latch.await(15, TimeUnit.SECONDS);
-        log.info("done waiting on latch, success={}", success);
+        if (log.isDebugEnabled()) log.debug("done waiting on latch, success={}", success);
       } catch (InterruptedException e) {
         ParWork.propagateInterrupt(e);
         log.error("", e);
@@ -873,8 +873,7 @@ public class SolrZkClient implements Closeable {
 
   public String mkdir(String path, byte[] data, CreateMode createMode) throws KeeperException {
     if (log.isDebugEnabled()) log.debug("mkdir path={}", path);
-    // nocommit
-    log.info("mkdir path={}", path);
+
 //    if (path.endsWith("/leader_elect")) {
 //      throw new IllegalStateException("");
 //    }
@@ -1017,7 +1016,7 @@ public class SolrZkClient implements Closeable {
     return returnString;
   }
   public void close() {
-    log.info("Closing {} instance {}", SolrZkClient.class.getSimpleName(), this);
+    if (log.isDebugEnabled()) log.debug("Closing {} instance {}", SolrZkClient.class.getSimpleName(), this);
 
     isClosed = true;
     connManager.close();
@@ -1131,7 +1130,7 @@ public class SolrZkClient implements Closeable {
   }
 
   public void clean(String path, Predicate<String> nodeFilter) throws InterruptedException, KeeperException {
-    log.info("clean path {}" + path);
+    if (log.isDebugEnabled()) log.debug("clean path {}" + path);
     ZkMaintenanceUtils.clean(this, path, nodeFilter);
   }
 
diff --git a/solr/solrj/src/java/org/apache/solr/common/util/SolrInternalHttpClient.java b/solr/solrj/src/java/org/apache/solr/common/util/SolrInternalHttpClient.java
index ea07778..616c5cb 100644
--- a/solr/solrj/src/java/org/apache/solr/common/util/SolrInternalHttpClient.java
+++ b/solr/solrj/src/java/org/apache/solr/common/util/SolrInternalHttpClient.java
@@ -18,7 +18,7 @@ public class SolrInternalHttpClient extends HttpClient {
 
   @Override
   protected void doStop() throws Exception {
-    log.info("Stopping {}", this.getClass().getSimpleName());
+    if (log.isDebugEnabled()) log.debug("Stopping {}", this.getClass().getSimpleName());
     super.doStop();
     assert ObjectReleaseTracker.release(this);
   }