tez-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From rbalamo...@apache.org
Subject git commit: TEZ-1566. Reduce log verbosity (Rajesh Balamohan) (Cherry picked from commit 156e96dc3485dd94d97cd9623d273d8ac3fec32b)
Date Wed, 15 Oct 2014 01:13:48 GMT
Repository: tez
Updated Branches:
  refs/heads/branch-0.5 d6b21ed5a -> e710338c4


TEZ-1566. Reduce log verbosity  (Rajesh Balamohan)
(Cherry picked from commit 156e96dc3485dd94d97cd9623d273d8ac3fec32b)


Project: http://git-wip-us.apache.org/repos/asf/tez/repo
Commit: http://git-wip-us.apache.org/repos/asf/tez/commit/e710338c
Tree: http://git-wip-us.apache.org/repos/asf/tez/tree/e710338c
Diff: http://git-wip-us.apache.org/repos/asf/tez/diff/e710338c

Branch: refs/heads/branch-0.5
Commit: e710338c4ed88991b5520e33bdeeaf99aa011b04
Parents: d6b21ed
Author: Rajesh Balamohan <rbalamohan@apache.org>
Authored: Wed Oct 15 06:41:38 2014 +0530
Committer: Rajesh Balamohan <rbalamohan@apache.org>
Committed: Wed Oct 15 06:42:42 2014 +0530

----------------------------------------------------------------------
 CHANGES.txt                                            |  1 +
 .../src/main/resources/tez-container-log4j.properties  |  2 +-
 .../runtime/library/common/shuffle/impl/Fetcher.java   |  3 +--
 .../common/shuffle/impl/ShuffleInputEventHandler.java  |  9 ++++++---
 .../library/common/shuffle/impl/ShuffleScheduler.java  | 13 ++++++++-----
 .../tez/runtime/library/common/sort/impl/IFile.java    | 10 ++++++----
 .../library/common/sort/impl/PipelinedSorter.java      |  5 +++--
 .../runtime/library/shuffle/common/HttpConnection.java |  4 +++-
 .../runtime/library/shuffle/common/ShuffleUtils.java   |  8 ++++++--
 .../common/impl/ShuffleInputEventHandlerImpl.java      | 12 ++++++------
 10 files changed, 41 insertions(+), 26 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/tez/blob/e710338c/CHANGES.txt
----------------------------------------------------------------------
diff --git a/CHANGES.txt b/CHANGES.txt
index 7564746..1912946 100644
--- a/CHANGES.txt
+++ b/CHANGES.txt
@@ -17,6 +17,7 @@ ALL CHANGES:
   TEZ-1647. Issue with caching of events in VertexManager::onRootVertexInitialized.
   TEZ-1470. Recovery fails due to TaskAttemptFinishedEvent being recorded multiple times
for the same task.
   TEZ-1649. ShuffleVertexManager auto reduce parallelism can cause jobs to hang indefinitely.
+  TEZ-1566. Reduce log verbosity.
 
 Release 0.5.1: 2014-10-02
 

http://git-wip-us.apache.org/repos/asf/tez/blob/e710338c/tez-dag/src/main/resources/tez-container-log4j.properties
----------------------------------------------------------------------
diff --git a/tez-dag/src/main/resources/tez-container-log4j.properties b/tez-dag/src/main/resources/tez-container-log4j.properties
index 628d3b5..8a11f2d 100644
--- a/tez-dag/src/main/resources/tez-container-log4j.properties
+++ b/tez-dag/src/main/resources/tez-container-log4j.properties
@@ -28,7 +28,7 @@ log4j.appender.CLA=org.apache.tez.common.TezContainerLogAppender
 log4j.appender.CLA.containerLogDir=${yarn.app.container.log.dir}
 
 log4j.appender.CLA.layout=org.apache.log4j.PatternLayout
-log4j.appender.CLA.layout.ConversionPattern=%d{ISO8601} %p [%t] %c: %m%n
+log4j.appender.CLA.layout.ConversionPattern=%d{ISO8601} %p [%t] %c{2}: %m%n
 
 #
 # Event Counter Appender

http://git-wip-us.apache.org/repos/asf/tez/blob/e710338c/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/Fetcher.java
----------------------------------------------------------------------
diff --git a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/Fetcher.java
b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/Fetcher.java
index c29401b..83ded06 100644
--- a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/Fetcher.java
+++ b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/Fetcher.java
@@ -405,8 +405,7 @@ class Fetcher extends Thread {
       // Go!
       LOG.info("fetcher#" + id + " about to shuffle output of map " + 
                mapOutput.getAttemptIdentifier() + " decomp: " +
-               decompressedLength + " len: " + compressedLength + " to " +
-               mapOutput.getType());
+               decompressedLength + " len: " + compressedLength);
       if (mapOutput.getType() == Type.MEMORY) {
         ShuffleUtils.shuffleToMemory(mapOutput.getMemory(), input,
           (int) decompressedLength, (int) compressedLength, codec, ifileReadAhead,

http://git-wip-us.apache.org/repos/asf/tez/blob/e710338c/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/ShuffleInputEventHandler.java
----------------------------------------------------------------------
diff --git a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/ShuffleInputEventHandler.java
b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/ShuffleInputEventHandler.java
index bc68da9..2229231 100644
--- a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/ShuffleInputEventHandler.java
+++ b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/ShuffleInputEventHandler.java
@@ -80,7 +80,7 @@ public class ShuffleInputEventHandler {
       throw new TezUncheckedException("Unable to parse DataMovementEvent payload", e);
     } 
     int partitionId = dmEvent.getSourceIndex();
-    LOG.info("DataMovementEvent partitionId:" + partitionId + ", targetIndex: " + dmEvent.getTargetIndex()
+    LOG.info("DME srcIdx: " + partitionId + ", targetIdx: " + dmEvent.getTargetIndex()
         + ", attemptNum: " + dmEvent.getVersion() + ", payload: " + ShuffleUtils.stringify(shufflePayload));
     // TODO NEWTEZ See if this duration hack can be removed.
     int duration = shufflePayload.getRunDuration();
@@ -95,8 +95,11 @@ public class ShuffleInputEventHandler {
         if (emptyPartitionsBitSet.get(partitionId)) {
           InputAttemptIdentifier srcAttemptIdentifier =
               new InputAttemptIdentifier(dmEvent.getTargetIndex(), dmEvent.getVersion());
-          LOG.info("Source partition: " + partitionId + " did not generate any data. SrcAttempt:
["
-              + srcAttemptIdentifier + "]. Not fetching.");
+          if (LOG.isDebugEnabled()) {
+            LOG.debug(
+                "Source partition: " + partitionId + " did not generate any data. SrcAttempt:
["
+                    + srcAttemptIdentifier + "]. Not fetching.");
+          }
           scheduler.copySucceeded(srcAttemptIdentifier, null, 0, 0, 0, null);
           return;
         }

http://git-wip-us.apache.org/repos/asf/tez/blob/e710338c/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/ShuffleScheduler.java
----------------------------------------------------------------------
diff --git a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/ShuffleScheduler.java
b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/ShuffleScheduler.java
index 6874afb..3a15b65 100644
--- a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/ShuffleScheduler.java
+++ b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/shuffle/impl/ShuffleScheduler.java
@@ -426,9 +426,10 @@ class ShuffleScheduler {
       
       pendingHosts.remove(host);     
       host.markBusy();
-      
-      LOG.info("Assigning " + host + " with " + host.getNumKnownMapOutputs() + 
-               " to " + Thread.currentThread().getName());
+      if (LOG.isDebugEnabled()) {
+        LOG.debug("Assigning " + host + " with " + host.getNumKnownMapOutputs() +
+            " to " + Thread.currentThread().getName());
+      }
       shuffleStart.set(System.currentTimeMillis());
       
       return host;
@@ -490,8 +491,10 @@ class ShuffleScheduler {
       InputAttemptIdentifier id = dedupedItr.next().getValue();
       host.addKnownMap(id);
     }
-    LOG.info("assigned " + includedMaps + " of " + totalSize + " to " +
-             host + " to " + Thread.currentThread().getName());
+    if (LOG.isDebugEnabled()) {
+      LOG.debug("assigned " + includedMaps + " of " + totalSize + " to " +
+          host + " to " + Thread.currentThread().getName());
+    }
     return result;
   }
 

http://git-wip-us.apache.org/repos/asf/tez/blob/e710338c/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/sort/impl/IFile.java
----------------------------------------------------------------------
diff --git a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/sort/impl/IFile.java
b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/sort/impl/IFile.java
index 0085652..f075772 100644
--- a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/sort/impl/IFile.java
+++ b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/sort/impl/IFile.java
@@ -244,10 +244,12 @@ public class IFile {
       if (writtenRecordsCounter != null) {
         writtenRecordsCounter.increment(numRecordsWritten);
       }
-      LOG.info("Total keys written=" + numRecordsWritten + "; rleEnabled=" + rle + "; Savings"
+
-          "(due to multi-kv/rle)=" + totalKeySaving + "; number of RLEs written=" +
-          rleWritten + "; compressedLen=" + compressedBytesWritten + "; rawLen="
-          + decompressedBytesWritten);
+      if (LOG.isDebugEnabled()) {
+        LOG.debug("Total keys written=" + numRecordsWritten + "; rleEnabled=" + rle + ";
Savings" +
+            "(due to multi-kv/rle)=" + totalKeySaving + "; number of RLEs written=" +
+            rleWritten + "; compressedLen=" + compressedBytesWritten + "; rawLen="
+            + decompressedBytesWritten);
+      }
     }
 
     /**

http://git-wip-us.apache.org/repos/asf/tez/blob/e710338c/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/sort/impl/PipelinedSorter.java
----------------------------------------------------------------------
diff --git a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/sort/impl/PipelinedSorter.java
b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/sort/impl/PipelinedSorter.java
index 0a14946..afa2370 100644
--- a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/sort/impl/PipelinedSorter.java
+++ b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/common/sort/impl/PipelinedSorter.java
@@ -503,11 +503,12 @@ public class PipelinedSorter extends ExternalSorter {
     	this.comparator = comparator;
       ki = new byte[keymax];
       kj = new byte[keymax];
-      LOG.info("begin sorting Span"+index + " ("+length()+")");
+      long start = System.currentTimeMillis();
       if(length() > 1) {
         sorter.sort(this, 0, length(), nullProgressable);
       }
-      LOG.info("done sorting Span"+index);
+      LOG.info("done sorting span=" + index + ", length=" + length() + ", "
+          + "time=" + (System.currentTimeMillis() - start));
       return new SpanIterator(this);
     }
 

http://git-wip-us.apache.org/repos/asf/tez/blob/e710338c/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/HttpConnection.java
----------------------------------------------------------------------
diff --git a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/HttpConnection.java
b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/HttpConnection.java
index 1311a4f..3a2c34b 100644
--- a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/HttpConnection.java
+++ b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/HttpConnection.java
@@ -272,7 +272,9 @@ public class HttpConnection {
         readErrorStream(connection.getErrorStream());
       }
       if (connection != null && (disconnect || !httpConnParams.keepAlive)) {
-        LOG.info("Closing connection on " + logIdentifier);
+        if (LOG.isDebugEnabled()) {
+          LOG.debug("Closing connection on " + logIdentifier);
+        }
         connection.disconnect();
       }
     } catch (IOException e) {

http://git-wip-us.apache.org/repos/asf/tez/blob/e710338c/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/ShuffleUtils.java
----------------------------------------------------------------------
diff --git a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/ShuffleUtils.java
b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/ShuffleUtils.java
index 43326f6..f110ecd 100644
--- a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/ShuffleUtils.java
+++ b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/ShuffleUtils.java
@@ -224,12 +224,16 @@ public class ShuffleUtils {
   public static String stringify(DataMovementEventPayloadProto dmProto) {
     StringBuilder sb = new StringBuilder();
     sb.append("[");
-    sb.append("hasEmptyPartitions: ").append(dmProto.hasEmptyPartitions()).append(", ");
+    if (dmProto.hasEmptyPartitions()) {
+      sb.append("hasEmptyPartitions: ").append(dmProto.hasEmptyPartitions()).append(", ");
+    }
     sb.append("host: " + dmProto.getHost()).append(", ");
     sb.append("port: " + dmProto.getPort()).append(", ");
     sb.append("pathComponent: " + dmProto.getPathComponent()).append(", ");
     sb.append("runDuration: " + dmProto.getRunDuration()).append(", ");
-    sb.append("hasDataInEvent: " + dmProto.hasData());
+    if (dmProto.hasData()) {
+      sb.append(", ").append("hasDataInEvent: " + dmProto.hasData());
+    }
     sb.append("]");
     return sb.toString();
   }

http://git-wip-us.apache.org/repos/asf/tez/blob/e710338c/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/impl/ShuffleInputEventHandlerImpl.java
----------------------------------------------------------------------
diff --git a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/impl/ShuffleInputEventHandlerImpl.java
b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/impl/ShuffleInputEventHandlerImpl.java
index 2ac45d4..6d12228 100644
--- a/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/impl/ShuffleInputEventHandlerImpl.java
+++ b/tez-runtime-library/src/main/java/org/apache/tez/runtime/library/shuffle/common/impl/ShuffleInputEventHandlerImpl.java
@@ -97,10 +97,8 @@ public class ShuffleInputEventHandlerImpl implements ShuffleEventHandler
{
     }
     int srcIndex = dme.getSourceIndex();
     String hostIdentifier = shufflePayload.getHost() + ":" + shufflePayload.getPort();
-    LOG.info("Processing DataMovementEvent with srcIndex: "
-        + srcIndex + ", targetIndex: " + dme.getTargetIndex()
-        + ", attemptNum: " + dme.getVersion() + ", payload: "
-        + ShuffleUtils.stringify(shufflePayload));
+    LOG.info("DME srcIdx: " + srcIndex + ", targetIndex: " + dme.getTargetIndex()
+        + ", attemptNum: " + dme.getVersion() + ", payload: " + ShuffleUtils.stringify(shufflePayload));
 
     if (shufflePayload.hasEmptyPartitions()) {
       byte[] emptyPartitions = TezCommonUtils.decompressByteStringToByteArray(shufflePayload
@@ -109,8 +107,10 @@ public class ShuffleInputEventHandlerImpl implements ShuffleEventHandler
{
       if (emptyPartionsBitSet.get(srcIndex)) {
         InputAttemptIdentifier srcAttemptIdentifier = new InputAttemptIdentifier(dme.getTargetIndex(),
             dme.getVersion());
-        LOG.info("Source partition: " + srcIndex + " did not generate any data. SrcAttempt:
["
-            + srcAttemptIdentifier + "]. Not fetching.");
+        if (LOG.isDebugEnabled()) {
+          LOG.debug("Source partition: " + srcIndex + " did not generate any data. SrcAttempt:
["
+              + srcAttemptIdentifier + "]. Not fetching.");
+        }
         shuffleManager.addCompletedInputWithNoData(srcAttemptIdentifier);
         return;
       }


Mime
View raw message