You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@druid.apache.org by as...@apache.org on 2018/12/17 06:20:36 UTC

[incubator-druid] branch master updated: emit logs that are only useful for debugging at debug level (#6741)

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

asdf2014 pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/incubator-druid.git


The following commit(s) were added to refs/heads/master by this push:
     new 486c6f3  emit logs that are only useful for debugging at debug level (#6741)
486c6f3 is described below

commit 486c6f3cf9ca15ceb4da8be9351693fa128135c3
Author: Clint Wylie <cj...@gmail.com>
AuthorDate: Sun Dec 16 22:20:28 2018 -0800

    emit logs that are only useful for debugging at debug level (#6741)
    
    * make logs that are only useful for debugging be at debug level so log volume is much more chill
    
    * info level messages for total merge buffer allocated/free
    
    * more chill compaction logs
---
 .../druid/indexing/common/actions/SegmentInsertAction.java   |  3 ++-
 .../indexing/common/actions/SegmentMetadataUpdateAction.java |  2 +-
 .../druid/indexing/common/actions/SegmentNukeAction.java     |  2 +-
 .../common/actions/SegmentTransactionalInsertAction.java     |  2 +-
 .../src/main/java/org/apache/druid/segment/IndexMerger.java  | 12 ++++++++++--
 .../druid/server/coordinator/CuratorLoadQueuePeon.java       |  6 +++---
 .../apache/druid/server/coordinator/DruidCoordinator.java    |  2 +-
 .../apache/druid/server/coordinator/HttpLoadQueuePeon.java   |  4 ++--
 .../server/coordinator/helper/DruidCoordinatorBalancer.java  |  6 +++---
 .../coordinator/helper/DruidCoordinatorSegmentCompactor.java |  6 +++++-
 .../apache/druid/server/router/CoordinatorRuleManager.java   |  2 +-
 11 files changed, 30 insertions(+), 17 deletions(-)

diff --git a/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentInsertAction.java b/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentInsertAction.java
index c78aefe..42f74e5 100644
--- a/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentInsertAction.java
+++ b/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentInsertAction.java
@@ -27,6 +27,7 @@ import org.apache.druid.indexing.common.task.Task;
 import org.apache.druid.timeline.DataSegment;
 
 import java.util.Set;
+import java.util.stream.Collectors;
 
 /**
  * Insert segments into metadata storage. The segment versions must all be less than or equal to a lock held by
@@ -83,7 +84,7 @@ public class SegmentInsertAction implements TaskAction<Set<DataSegment>>
   public String toString()
   {
     return "SegmentInsertAction{" +
-           "segments=" + segments +
+           "segments=" + segments.stream().map(DataSegment::getIdentifier).collect(Collectors.joining(",")) +
            '}';
   }
 }
diff --git a/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentMetadataUpdateAction.java b/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentMetadataUpdateAction.java
index fd6f88a..4bb70a5 100644
--- a/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentMetadataUpdateAction.java
+++ b/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentMetadataUpdateAction.java
@@ -114,7 +114,7 @@ public class SegmentMetadataUpdateAction implements TaskAction<Void>
   public String toString()
   {
     return "SegmentMetadataUpdateAction{" +
-           "segments=" + segments +
+           "segments=" + segments.stream().map(DataSegment::getIdentifier).collect(Collectors.joining(",")) +
            '}';
   }
 }
diff --git a/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentNukeAction.java b/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentNukeAction.java
index ac5c286..db632a7 100644
--- a/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentNukeAction.java
+++ b/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentNukeAction.java
@@ -116,7 +116,7 @@ public class SegmentNukeAction implements TaskAction<Void>
   public String toString()
   {
     return "SegmentNukeAction{" +
-           "segments=" + segments +
+           "segments=" + segments.stream().map(DataSegment::getIdentifier).collect(Collectors.joining(",")) +
            '}';
   }
 }
diff --git a/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentTransactionalInsertAction.java b/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentTransactionalInsertAction.java
index ffc799b..3d733f9 100644
--- a/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentTransactionalInsertAction.java
+++ b/indexing-service/src/main/java/org/apache/druid/indexing/common/actions/SegmentTransactionalInsertAction.java
@@ -154,7 +154,7 @@ public class SegmentTransactionalInsertAction implements TaskAction<SegmentPubli
   public String toString()
   {
     return "SegmentInsertAction{" +
-           "segments=" + segments +
+           "segments=" + segments.stream().map(DataSegment::getIdentifier).collect(Collectors.joining(",")) +
            ", startMetadata=" + startMetadata +
            ", endMetadata=" + endMetadata +
            '}';
diff --git a/processing/src/main/java/org/apache/druid/segment/IndexMerger.java b/processing/src/main/java/org/apache/druid/segment/IndexMerger.java
index 4661b65..87466d2 100644
--- a/processing/src/main/java/org/apache/druid/segment/IndexMerger.java
+++ b/processing/src/main/java/org/apache/druid/segment/IndexMerger.java
@@ -397,6 +397,8 @@ public interface IndexMerger
     {
       pQueue = new PriorityQueue<>(dimValueLookups.length, NULLS_FIRST_PEEKING_COMPARATOR);
       conversions = new IntBuffer[dimValueLookups.length];
+
+      long mergeBufferTotalSize = 0;
       for (int i = 0; i < conversions.length; i++) {
         if (dimValueLookups[i] == null) {
           continue;
@@ -404,12 +406,14 @@ public interface IndexMerger
         Indexed<String> indexed = dimValueLookups[i];
         if (useDirect) {
           int allocationSize = indexed.size() * Integer.BYTES;
-          log.info("Allocating dictionary merging direct buffer with size[%,d]", allocationSize);
+          log.debug("Allocating dictionary merging direct buffer with size[%,d]", allocationSize);
+          mergeBufferTotalSize += allocationSize;
           final ByteBuffer conversionDirectBuffer = ByteBuffer.allocateDirect(allocationSize);
           conversions[i] = conversionDirectBuffer.asIntBuffer();
           directBufferAllocations.add(new Pair<>(conversionDirectBuffer, allocationSize));
         } else {
           conversions[i] = IntBuffer.allocate(indexed.size());
+          mergeBufferTotalSize += indexed.size();
         }
 
         final PeekingIterator<String> iter = Iterators.peekingIterator(
@@ -422,6 +426,7 @@ public interface IndexMerger
           pQueue.add(Pair.of(i, iter));
         }
       }
+      log.info("Allocated [%,d] bytes of dictionary merging direct buffers", mergeBufferTotalSize);
     }
 
     @Override
@@ -482,10 +487,13 @@ public interface IndexMerger
     @Override
     public void close()
     {
+      long mergeBufferTotalSize = 0;
       for (Pair<ByteBuffer, Integer> bufferAllocation : directBufferAllocations) {
-        log.info("Freeing dictionary merging direct buffer with size[%,d]", bufferAllocation.rhs);
+        log.debug("Freeing dictionary merging direct buffer with size[%,d]", bufferAllocation.rhs);
+        mergeBufferTotalSize += bufferAllocation.rhs;
         ByteBufferUtils.free(bufferAllocation.lhs);
       }
+      log.info("Freed [,%d] bytes of dictionary merging direct buffers", mergeBufferTotalSize);
     }
   }
 }
diff --git a/server/src/main/java/org/apache/druid/server/coordinator/CuratorLoadQueuePeon.java b/server/src/main/java/org/apache/druid/server/coordinator/CuratorLoadQueuePeon.java
index c790382..e097226 100644
--- a/server/src/main/java/org/apache/druid/server/coordinator/CuratorLoadQueuePeon.java
+++ b/server/src/main/java/org/apache/druid/server/coordinator/CuratorLoadQueuePeon.java
@@ -235,10 +235,10 @@ public class CuratorLoadQueuePeon extends LoadQueuePeon
 
     if (!segmentsToDrop.isEmpty()) {
       currentlyProcessing = segmentsToDrop.firstEntry().getValue();
-      log.info("Server[%s] dropping [%s]", basePath, currentlyProcessing.getSegmentIdentifier());
+      log.debug("Server[%s] dropping [%s]", basePath, currentlyProcessing.getSegmentIdentifier());
     } else if (!segmentsToLoad.isEmpty()) {
       currentlyProcessing = segmentsToLoad.firstEntry().getValue();
-      log.info("Server[%s] loading [%s]", basePath, currentlyProcessing.getSegmentIdentifier());
+      log.debug("Server[%s] loading [%s]", basePath, currentlyProcessing.getSegmentIdentifier());
     } else {
       return;
     }
@@ -386,7 +386,7 @@ public class CuratorLoadQueuePeon extends LoadQueuePeon
         );
         return;
       }
-      log.info(
+      log.debug(
           "Server[%s] done processing %s of segment [%s]",
           basePath,
           currentlyProcessing.getType() == LOAD ? "load" : "drop",
diff --git a/server/src/main/java/org/apache/druid/server/coordinator/DruidCoordinator.java b/server/src/main/java/org/apache/druid/server/coordinator/DruidCoordinator.java
index 8520683..be4f106 100644
--- a/server/src/main/java/org/apache/druid/server/coordinator/DruidCoordinator.java
+++ b/server/src/main/java/org/apache/druid/server/coordinator/DruidCoordinator.java
@@ -334,7 +334,7 @@ public class DruidCoordinator
 
   public void removeSegment(DataSegment segment)
   {
-    log.info("Removing Segment[%s]", segment);
+    log.info("Removing Segment[%s]", segment.getIdentifier());
     metadataSegmentManager.removeSegment(segment.getDataSource(), segment.getIdentifier());
   }
 
diff --git a/server/src/main/java/org/apache/druid/server/coordinator/HttpLoadQueuePeon.java b/server/src/main/java/org/apache/druid/server/coordinator/HttpLoadQueuePeon.java
index ef86d1e..a0641a2 100644
--- a/server/src/main/java/org/apache/druid/server/coordinator/HttpLoadQueuePeon.java
+++ b/server/src/main/java/org/apache/druid/server/coordinator/HttpLoadQueuePeon.java
@@ -223,7 +223,7 @@ public class HttpLoadQueuePeon extends LoadQueuePeon
                             handleResponseStatus(e.getRequest(), e.getStatus());
                             break;
                           case PENDING:
-                            log.info("Request[%s] is still pending on server[%s].", e.getRequest(), serverId);
+                            log.debug("Request[%s] is still pending on server[%s].", e.getRequest(), serverId);
                             break;
                           default:
                             scheduleNextRunImmediately = false;
@@ -521,7 +521,7 @@ public class HttpLoadQueuePeon extends LoadQueuePeon
 
     public void requestSucceeded()
     {
-      log.info(
+      log.debug(
           "Server[%s] Successfully processed segment[%s] request[%s].",
           serverId,
           segment.getIdentifier(),
diff --git a/server/src/main/java/org/apache/druid/server/coordinator/helper/DruidCoordinatorBalancer.java b/server/src/main/java/org/apache/druid/server/coordinator/helper/DruidCoordinatorBalancer.java
index 97589c9..129b453 100644
--- a/server/src/main/java/org/apache/druid/server/coordinator/helper/DruidCoordinatorBalancer.java
+++ b/server/src/main/java/org/apache/druid/server/coordinator/helper/DruidCoordinatorBalancer.java
@@ -155,11 +155,11 @@ public class DruidCoordinatorBalancer implements DruidCoordinatorHelper
             moveSegment(segmentToMoveHolder, destinationHolder.getServer(), params);
             moved++;
           } else {
-            log.info("Segment [%s] is 'optimally' placed.", segmentToMove.getIdentifier());
+            log.debug("Segment [%s] is 'optimally' placed.", segmentToMove.getIdentifier());
             unmoved++;
           }
         } else {
-          log.info(
+          log.debug(
               "No valid movement destinations for segment [%s].",
               segmentToMove.getIdentifier()
           );
@@ -207,7 +207,7 @@ public class DruidCoordinatorBalancer implements DruidCoordinatorHelper
     if (!toPeon.getSegmentsToLoad().contains(segmentToMove) &&
         (toServer.getSegment(segmentName) == null) &&
         new ServerHolder(toServer, toPeon).getAvailableSize() > segmentToMove.getSize()) {
-      log.info("Moving [%s] from [%s] to [%s]", segmentName, fromServer.getName(), toServer.getName());
+      log.debug("Moving [%s] from [%s] to [%s]", segmentName, fromServer.getName(), toServer.getName());
 
       LoadPeonCallback callback = null;
       try {
diff --git a/server/src/main/java/org/apache/druid/server/coordinator/helper/DruidCoordinatorSegmentCompactor.java b/server/src/main/java/org/apache/druid/server/coordinator/helper/DruidCoordinatorSegmentCompactor.java
index b029697..4067b3a 100644
--- a/server/src/main/java/org/apache/druid/server/coordinator/helper/DruidCoordinatorSegmentCompactor.java
+++ b/server/src/main/java/org/apache/druid/server/coordinator/helper/DruidCoordinatorSegmentCompactor.java
@@ -160,7 +160,11 @@ public class DruidCoordinatorSegmentCompactor implements DruidCoordinatorHelper
             config.getTuningConfig(),
             config.getTaskContext()
         );
-        LOG.info("Submitted a compactTask[%s] for segments[%s]", taskId, segmentsToCompact);
+        LOG.info(
+            "Submitted a compactTask[%s] for segments[%s]",
+            taskId,
+            segmentsToCompact.stream().map(DataSegment::getIdentifier).collect(Collectors.joining(","))
+        );
       } else if (segmentsToCompact.size() == 1) {
         throw new ISE("Found one segments[%s] to compact", segmentsToCompact);
       } else {
diff --git a/server/src/main/java/org/apache/druid/server/router/CoordinatorRuleManager.java b/server/src/main/java/org/apache/druid/server/router/CoordinatorRuleManager.java
index 1e9ea81..c8c3b56 100644
--- a/server/src/main/java/org/apache/druid/server/router/CoordinatorRuleManager.java
+++ b/server/src/main/java/org/apache/druid/server/router/CoordinatorRuleManager.java
@@ -156,7 +156,7 @@ public class CoordinatorRuleManager
           )
       );
 
-      log.info("Got [%,d] rules", newRules.size());
+      log.debug("Got [%,d] rules", newRules.size());
 
       rules.set(newRules);
     }


---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@druid.apache.org
For additional commands, e-mail: commits-help@druid.apache.org