[#1201] improvement: only invoking LOG.debug when LOG.isDebugEnabled(…

…) is true (#1217)

### What changes were proposed in this pull request?

Improve invoking LOG.debug when LOG.isDebugEnabled() is true .

### Why are the changes needed?

Fix: #1201

### Does this PR introduce _any_ user-facing change?

No.

### How was this patch tested?
No

cli/src/main/java/org/apache/uniffle/client/RestClientImpl.java

@@ -97,7 +97,9 @@ private String doRequest(URI uri, String authHeader, RequestBuilder requestBuild
       }
       HttpUriRequest httpRequest = requestBuilder.setUri(uri).build();
 
-      LOG.debug("Executing {} request: {}", httpRequest.getMethod(), uri);
+      if (LOG.isDebugEnabled()) {
+        LOG.debug("Executing {} request: {}", httpRequest.getMethod(), uri);
+      }
 
       ResponseHandler<String> responseHandler =
           resp -> {
@@ -112,7 +114,9 @@ private String doRequest(URI uri, String authHeader, RequestBuilder requestBuild
           };
 
       response = httpclient.execute(httpRequest, responseHandler);
-      LOG.debug("Response: {}", response);
+      if (LOG.isDebugEnabled()) {
+        LOG.debug("Response: {}", response);
+      }
     } catch (ConnectException | ConnectTimeoutException | NoHttpResponseException e) {
       throw new UniffleRestException("Api request failed for " + uri.toString(), e);
     } catch (UniffleRestException rethrow) {

client-mr/core/src/main/java/org/apache/hadoop/mapred/SortWriteBuffer.java

@@ -140,13 +140,15 @@ public int compare(Record<K> o1, Record<K> o2) {
 
   private boolean compact(int lastIndex, int lastOffset, int dataLength) {
     if (lastIndex != currentIndex) {
-      LOG.debug(
-          "compact lastIndex {}, currentIndex {}, lastOffset {} currentOffset {} dataLength {}",
-          lastIndex,
-          currentIndex,
-          lastOffset,
-          currentOffset,
-          dataLength);
+      if (LOG.isDebugEnabled()) {
+        LOG.debug(
+            "compact lastIndex {}, currentIndex {}, lastOffset {} currentOffset {} dataLength {}",
+            lastIndex,
+            currentIndex,
+            lastOffset,
+            currentOffset,
+            dataLength);
+      }
       WrappedBuffer buffer = new WrappedBuffer(lastOffset + dataLength);
       // copy data
       int offset = 0;

client-mr/core/src/main/java/org/apache/hadoop/mapred/SortWriteBufferManager.java

@@ -181,7 +181,9 @@ public void addRecord(int partitionId, K key, V value) throws IOException, Inter
     if (length > maxMemSize) {
       throw new RssException("record is too big");
     }
-    LOG.debug("memoryUsedSize {} increase {}", memoryUsedSize, length);
+    if (LOG.isDebugEnabled()) {
+      LOG.debug("memoryUsedSize {} increase {}", memoryUsedSize, length);
+    }
     memoryUsedSize.addAndGet(length);
     if (buffer.getDataLength() > maxBufferSize) {
       if (waitSendBuffers.remove(buffer)) {
@@ -255,7 +257,9 @@ public void run() {
             } finally {
               try {
                 memoryLock.lock();
-                LOG.debug("memoryUsedSize {} decrease {}", memoryUsedSize, size);
+                if (LOG.isDebugEnabled()) {
+                  LOG.debug("memoryUsedSize {} decrease {}", memoryUsedSize, size);
+                }
                 memoryUsedSize.addAndGet(-size);
                 inSendListBytes.addAndGet(-size);
                 full.signalAll();

client-mr/core/src/main/java/org/apache/hadoop/mapreduce/task/reduce/RssEventFetcher.java

@@ -159,7 +159,9 @@ public void acceptMapCompletionEvents() throws IOException {
               maxEventsToFetch,
               (org.apache.hadoop.mapred.TaskAttemptID) reduce);
       events = update.getMapTaskCompletionEvents();
-      LOG.debug("Got " + events.length + " map completion events from " + fromEventIdx);
+      if (LOG.isDebugEnabled()) {
+        LOG.debug("Got " + events.length + " map completion events from " + fromEventIdx);
+      }
 
       assert !update.shouldReset() : "Unexpected legacy state";
 

client-mr/core/src/main/java/org/apache/hadoop/mapreduce/task/reduce/RssRemoteMergeManagerImpl.java

@@ -207,30 +207,34 @@ public synchronized MapOutput<K, V> reserve(TaskAttemptID mapId, long requestedS
       throws IOException {
     // we disable OnDisk MapOutput to avoid merging disk immediate data
     if (usedMemory > memoryLimit) {
+      if (LOG.isDebugEnabled()) {
+        LOG.debug(
+            mapId
+                + ": Stalling shuffle since usedMemory ("
+                + usedMemory
+                + ") is greater than memoryLimit ("
+                + memoryLimit
+                + ")."
+                + " CommitMemory is ("
+                + commitMemory
+                + ")");
+      }
+      return null;
+    }
+
+    // Allow the in-memory shuffle to progress
+    if (LOG.isDebugEnabled()) {
       LOG.debug(
           mapId
-              + ": Stalling shuffle since usedMemory ("
+              + ": Proceeding with shuffle since usedMemory ("
               + usedMemory
-              + ") is greater than memoryLimit ("
+              + ") is lesser than memoryLimit ("
               + memoryLimit
               + ")."
-              + " CommitMemory is ("
+              + "CommitMemory is ("
               + commitMemory
               + ")");
-      return null;
     }
-
-    // Allow the in-memory shuffle to progress
-    LOG.debug(
-        mapId
-            + ": Proceeding with shuffle since usedMemory ("
-            + usedMemory
-            + ") is lesser than memoryLimit ("
-            + memoryLimit
-            + ")."
-            + "CommitMemory is ("
-            + commitMemory
-            + ")");
     usedMemory += requestedSize;
     // use this rss merger as the callback
     return new InMemoryMapOutput<K, V>(jobConf, mapId, this, (int) requestedSize, codec, true);

client-spark/common/src/main/java/org/apache/spark/shuffle/writer/WriteBufferManager.java

@@ -216,16 +216,18 @@ private List<ShuffleBlockInfo> insertIntoBuffer(
         sentBlocks.add(createShuffleBlock(partitionId, wb));
         copyTime += wb.getCopyTime();
         buffers.remove(partitionId);
-        LOG.debug(
-            "Single buffer is full for shuffleId["
-                + shuffleId
-                + "] partition["
-                + partitionId
-                + "] with memoryUsed["
-                + wb.getMemoryUsed()
-                + "], dataLength["
-                + wb.getDataLength()
-                + "]");
+        if (LOG.isDebugEnabled()) {
+          LOG.debug(
+              "Single buffer is full for shuffleId["
+                  + shuffleId
+                  + "] partition["
+                  + partitionId
+                  + "] with memoryUsed["
+                  + wb.getMemoryUsed()
+                  + "], dataLength["
+                  + wb.getDataLength()
+                  + "]");
+        }
       }
     } else {
       // The true of hasRequested means the former partitioned buffer has been flushed, that is
@@ -401,12 +403,14 @@ public List<AddBlockEvent> buildBlockEvents(List<ShuffleBlockInfo> shuffleBlockI
       shuffleBlockInfosPerEvent.add(sbi);
       // split shuffle data according to the size
       if (totalSize > sendSizeLimit) {
-        LOG.debug(
-            "Build event with "
-                + shuffleBlockInfosPerEvent.size()
-                + " blocks and "
-                + totalSize
-                + " bytes");
+        if (LOG.isDebugEnabled()) {
+          LOG.debug(
+              "Build event with "
+                  + shuffleBlockInfosPerEvent.size()
+                  + " blocks and "
+                  + totalSize
+                  + " bytes");
+        }
         // Use final temporary variables for closures
         final long memoryUsedTemp = memoryUsed;
         final List<ShuffleBlockInfo> shuffleBlocksTemp = shuffleBlockInfosPerEvent;
@@ -424,12 +428,14 @@ public List<AddBlockEvent> buildBlockEvents(List<ShuffleBlockInfo> shuffleBlockI
       }
     }
     if (!shuffleBlockInfosPerEvent.isEmpty()) {
-      LOG.debug(
-          "Build event with "
-              + shuffleBlockInfosPerEvent.size()
-              + " blocks and "
-              + totalSize
-              + " bytes");
+      if (LOG.isDebugEnabled()) {
+        LOG.debug(
+            "Build event with "
+                + shuffleBlockInfosPerEvent.size()
+                + " blocks and "
+                + totalSize
+                + " bytes");
+      }
       // Use final temporary variables for closures
       final long memoryUsedTemp = memoryUsed;
       final List<ShuffleBlockInfo> shuffleBlocksTemp = shuffleBlockInfosPerEvent;

client-tez/src/main/java/org/apache/tez/common/TezClassLoader.java

@@ -70,11 +70,13 @@ public static TezClassLoader getInstance() {
   }
 
   public static void setupTezClassLoader() {
-    LOG.debug(
-        "Setting up TezClassLoader: thread: {}, current thread classloader: {} system classloader: {}",
-        Thread.currentThread().getId(),
-        Thread.currentThread().getContextClassLoader(),
-        ClassLoader.getSystemClassLoader());
+    if (LOG.isDebugEnabled()) {
+      LOG.debug(
+          "Setting up TezClassLoader: thread: {}, current thread classloader: {} system classloader: {}",
+          Thread.currentThread().getId(),
+          Thread.currentThread().getContextClassLoader(),
+          ClassLoader.getSystemClassLoader());
+    }
     Thread.currentThread().setContextClassLoader(INSTANCE);
   }
 

client-tez/src/main/java/org/apache/tez/dag/app/RssDAGAppMaster.java

@@ -204,7 +204,9 @@ public static void initAndStartRSSClient(final RssDAGAppMaster appMaster, Config
         () -> {
           try {
             appMaster.getShuffleWriteClient().sendAppHeartbeat(strAppAttemptId, heartbeatTimeout);
-            LOG.debug("Finish send heartbeat to coordinator and servers");
+            if (LOG.isDebugEnabled()) {
+              LOG.debug("Finish send heartbeat to coordinator and servers");
+            }
           } catch (Exception e) {
             LOG.warn("Fail to send heartbeat to coordinator and servers", e);
           }

client-tez/src/main/java/org/apache/tez/runtime/library/common/sort/buffer/WriteBufferManager.java

@@ -270,7 +270,9 @@ public void run() {
             } finally {
               try {
                 memoryLock.lock();
-                LOG.debug("memoryUsedSize {} decrease {}", memoryUsedSize, size);
+                if (LOG.isDebugEnabled()) {
+                  LOG.debug("memoryUsedSize {} decrease {}", memoryUsedSize, size);
+                }
                 memoryUsedSize.addAndGet(-size);
                 inSendListBytes.addAndGet(-size);
                 full.signalAll();

client/src/main/java/org/apache/uniffle/client/impl/ShuffleWriteClientImpl.java

@@ -228,7 +228,9 @@ private boolean sendShuffleDataAsync(
                     if (defectiveServers != null) {
                       defectiveServers.remove(ssi);
                     }
-                    LOG.debug("{} successfully.", logMsg);
+                    if (LOG.isDebugEnabled()) {
+                      LOG.debug("{} successfully.", logMsg);
+                    }
                   } else {
                     if (defectiveServers != null) {
                       defectiveServers.add(ssi);

common/src/main/java/org/apache/uniffle/common/filesystem/HadoopFilesystemProvider.java

@@ -60,7 +60,9 @@ public static FileSystem getFilesystem(String user, Path path, Configuration con
     }
 
     if (fileSystem instanceof LocalFileSystem) {
-      LOGGER.debug("{} is local file system", path);
+      if (LOGGER.isDebugEnabled()) {
+        LOGGER.debug("{} is local file system", path);
+      }
       return ((LocalFileSystem) fileSystem).getRawFileSystem();
     }
 

common/src/main/java/org/apache/uniffle/common/netty/client/TransportClientFactory.java

@@ -215,7 +215,9 @@ public void initChannel(SocketChannel ch) {
     TransportClient client = clientRef.get();
     assert client != null : "Channel future completed successfully with null client";
 
-    logger.debug("Connection to {} successful", address);
+    if (logger.isDebugEnabled()) {
+      logger.debug("Connection to {} successful", address);
+    }
 
     return client;
   }

common/src/main/java/org/apache/uniffle/common/netty/handle/TransportRequestHandler.java

@@ -45,12 +45,16 @@ public void exceptionCaught(Throwable cause) {
 
   @Override
   public void channelActive() {
-    logger.debug("channelActive: {}", reverseClient.getSocketAddress());
+    if (logger.isDebugEnabled()) {
+      logger.debug("channelActive: {}", reverseClient.getSocketAddress());
+    }
   }
 
   @Override
   public void channelInactive() {
-    logger.debug("channelInactive: {}", reverseClient.getSocketAddress());
+    if (logger.isDebugEnabled()) {
+      logger.debug("channelInactive: {}", reverseClient.getSocketAddress());
+    }
   }
 
   @Override

coordinator/src/main/java/org/apache/uniffle/coordinator/CoordinatorGrpcService.java

@@ -175,7 +175,9 @@ public void heartbeat(
             .setRetMsg("")
             .setStatus(StatusCode.SUCCESS)
             .build();
-    LOG.debug("Got heartbeat from {}", serverNode);
+    if (LOG.isDebugEnabled()) {
+      LOG.debug("Got heartbeat from {}", serverNode);
+    }
     responseObserver.onNext(response);
     responseObserver.onCompleted();
   }
@@ -214,7 +216,9 @@ public void appHeartbeat(
       AppHeartBeatRequest request, StreamObserver<AppHeartBeatResponse> responseObserver) {
     String appId = request.getAppId();
     coordinatorServer.getApplicationManager().refreshAppId(appId);
-    LOG.debug("Got heartbeat from application: {}", appId);
+    if (LOG.isDebugEnabled()) {
+      LOG.debug("Got heartbeat from application: {}", appId);
+    }
     AppHeartBeatResponse response =
         AppHeartBeatResponse.newBuilder().setRetMsg("").setStatus(StatusCode.SUCCESS).build();
 
@@ -235,7 +239,9 @@ public void registerApplicationInfo(
     String appId = request.getAppId();
     String user = request.getUser();
     coordinatorServer.getApplicationManager().registerApplicationInfo(appId, user);
-    LOG.debug("Got a registered application info: {}", appId);
+    if (LOG.isDebugEnabled()) {
+      LOG.debug("Got a registered application info: {}", appId);
+    }
     ApplicationInfoResponse response =
         ApplicationInfoResponse.newBuilder().setRetMsg("").setStatus(StatusCode.SUCCESS).build();
 

coordinator/src/main/java/org/apache/uniffle/coordinator/access/checker/AccessCandidatesChecker.java

@@ -81,7 +81,9 @@ public AccessCandidatesChecker(AccessManager accessManager) throws Exception {
       LOG.error(msg);
       throw new RssException(msg);
     }
-    LOG.debug("Load candidates: {}", String.join(";", candidates.get()));
+    if (LOG.isDebugEnabled()) {
+      LOG.debug("Load candidates: {}", String.join(";", candidates.get()));
+    }
 
     int updateIntervalS =
         conf.getInteger(CoordinatorConf.COORDINATOR_ACCESS_CANDIDATES_UPDATE_INTERVAL_SEC);
@@ -96,7 +98,9 @@ public AccessCheckResult check(AccessInfo accessInfo) {
     String accessId = accessInfo.getAccessId().trim();
     if (!candidates.get().contains(accessId)) {
       String msg = String.format("Denied by AccessCandidatesChecker, accessInfo[%s].", accessInfo);
-      LOG.debug("Candidates is {}, {}", candidates.get(), msg);
+      if (LOG.isDebugEnabled()) {
+        LOG.debug("Candidates is {}, {}", candidates.get(), msg);
+      }
       CoordinatorMetrics.counterTotalCandidatesDeniedRequest.inc();
       return new AccessCheckResult(false, msg);
     }
@@ -119,7 +123,9 @@ private void updateAccessCandidates() {
         if (lastCandidatesUpdateMS.get() != lastModifiedMS) {
           updateAccessCandidatesInternal();
           lastCandidatesUpdateMS.set(lastModifiedMS);
-          LOG.debug("Load candidates: {}", String.join(";", candidates.get()));
+          if (LOG.isDebugEnabled()) {
+            LOG.debug("Load candidates: {}", String.join(";", candidates.get()));
+          }
         }
       } else {
         LOG.warn("Candidates file not found.");