Repository: tez Updated Branches: refs/heads/master d3011a9bc -> 30eaa1e47
TEZ-3379. Tez analyzer: Move sysout to log4j (rbalamohan) Project: http://git-wip-us.apache.org/repos/asf/tez/repo Commit: http://git-wip-us.apache.org/repos/asf/tez/commit/30eaa1e4 Tree: http://git-wip-us.apache.org/repos/asf/tez/tree/30eaa1e4 Diff: http://git-wip-us.apache.org/repos/asf/tez/diff/30eaa1e4 Branch: refs/heads/master Commit: 30eaa1e47f9bde5dc368ddb15e762049091f13bb Parents: d3011a9 Author: Rajesh Balamohan <[email protected]> Authored: Thu Jul 28 03:56:26 2016 +0530 Committer: Rajesh Balamohan <[email protected]> Committed: Thu Jul 28 03:56:26 2016 +0530 ---------------------------------------------------------------------- CHANGES.txt | 1 + .../tez/history/parser/ATSFileParser.java | 6 ++-- .../analyzer/plugins/CriticalPathAnalyzer.java | 30 +++++++++++--------- .../tez/analyzer/plugins/TezAnalyzerBase.java | 20 +++++++------ .../org/apache/tez/analyzer/utils/SVGUtils.java | 5 +++- 5 files changed, 36 insertions(+), 26 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/tez/blob/30eaa1e4/CHANGES.txt ---------------------------------------------------------------------- diff --git a/CHANGES.txt b/CHANGES.txt index 550087a..3d198fd 100644 --- a/CHANGES.txt +++ b/CHANGES.txt @@ -7,6 +7,7 @@ INCOMPATIBLE CHANGES ALL CHANGES: + TEZ-3379. Tez analyzer: Move sysout to log4j. TEZ-3376. Fix groupId generation to account for dagId starting with 1. TEZ-3359. Add granular log levels for HistoryLoggingService. TEZ-3374. Change TEZ_HISTORY_LOGGING_TIMELINE_NUM_DAGS_PER_GROUP conf key name. http://git-wip-us.apache.org/repos/asf/tez/blob/30eaa1e4/tez-plugins/tez-history-parser/src/main/java/org/apache/tez/history/parser/ATSFileParser.java ---------------------------------------------------------------------- diff --git a/tez-plugins/tez-history-parser/src/main/java/org/apache/tez/history/parser/ATSFileParser.java b/tez-plugins/tez-history-parser/src/main/java/org/apache/tez/history/parser/ATSFileParser.java index 89db976..b4f3df3 100644 --- a/tez-plugins/tez-history-parser/src/main/java/org/apache/tez/history/parser/ATSFileParser.java +++ b/tez-plugins/tez-history-parser/src/main/java/org/apache/tez/history/parser/ATSFileParser.java @@ -95,12 +95,12 @@ public class ATSFileParser extends BaseParser implements ATSData { //Process vertex information Preconditions.checkState(verticesJson != null, "Vertex json can not be null"); if (verticesJson != null) { - LOG.info("Started parsing vertex"); + LOG.debug("Started parsing vertex"); for (int i = 0; i < verticesJson.length(); i++) { VertexInfo vertexInfo = VertexInfo.create(verticesJson.getJSONObject(i)); vertexList.add(vertexInfo); } - LOG.info("Finished parsing vertex"); + LOG.debug("Finished parsing vertex"); } } @@ -195,7 +195,7 @@ public class ATSFileParser extends BaseParser implements ATSData { Enumeration<? extends ZipEntry> zipEntries = atsZipFile.entries(); while (zipEntries.hasMoreElements()) { ZipEntry zipEntry = zipEntries.nextElement(); - LOG.info("Processing " + zipEntry.getName()); + LOG.debug("Processing " + zipEntry.getName()); InputStream inputStream = atsZipFile.getInputStream(zipEntry); JSONObject jsonObject = readJson(inputStream); http://git-wip-us.apache.org/repos/asf/tez/blob/30eaa1e4/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/plugins/CriticalPathAnalyzer.java ---------------------------------------------------------------------- diff --git a/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/plugins/CriticalPathAnalyzer.java b/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/plugins/CriticalPathAnalyzer.java index 88c5134..2edce3e 100644 --- a/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/plugins/CriticalPathAnalyzer.java +++ b/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/plugins/CriticalPathAnalyzer.java @@ -47,9 +47,13 @@ import com.google.common.base.Preconditions; import com.google.common.base.Strings; import com.google.common.collect.Lists; import com.google.common.collect.Maps; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public class CriticalPathAnalyzer extends TezAnalyzerBase implements Analyzer { + private static final Logger LOG = LoggerFactory.getLogger(CriticalPathAnalyzer.class); + String succeededState = StringInterner.weakIntern(TaskAttemptState.SUCCEEDED.name()); String failedState = StringInterner.weakIntern(TaskAttemptState.FAILED.name()); @@ -138,7 +142,7 @@ public class CriticalPathAnalyzer extends TezAnalyzerBase implements Analyzer { } if (lastAttempt == null) { - System.out.println("Cannot find last attempt to finish in DAG " + dagInfo.getDagId()); + LOG.info("Cannot find last attempt to finish in DAG " + dagInfo.getDagId()); return; } @@ -162,7 +166,7 @@ public class CriticalPathAnalyzer extends TezAnalyzerBase implements Analyzer { outputDir = getConf().get(OUTPUT_DIR); } String outputFileName = outputDir + File.separator + dagInfo.getDagId() + ".svg"; - System.out.println("Writing output to: " + outputFileName); + LOG.info("Writing output to: " + outputFileName); svg.saveCriticalPathAsSVG(dagInfo, outputFileName, criticalPath); } @@ -259,7 +263,7 @@ public class CriticalPathAnalyzer extends TezAnalyzerBase implements Analyzer { for (TaskAttemptInfo a : t.getTaskAttempts()) { if (a.getTerminationCause().equals( TaskAttemptTerminationCause.INTERNAL_PREEMPTION.name())) { - System.out.println("Found preempted attempt " + a.getTaskAttemptId()); + LOG.debug("Found preempted attempt " + a.getTaskAttemptId()); preemptedAttempts.add(a); } } @@ -415,8 +419,7 @@ public class CriticalPathAnalyzer extends TezAnalyzerBase implements Analyzer { } } } - System.out - .println("DAG time taken: " + dagTime + " TotalAttemptTime: " + totalAttemptCriticalTime + LOG.debug("DAG time taken: " + dagTime + " TotalAttemptTime: " + totalAttemptCriticalTime + " DAG finish time: " + dag.getFinishTime() + " DAG start time: " + dagStartTime); } @@ -451,8 +454,7 @@ public class CriticalPathAnalyzer extends TezAnalyzerBase implements Analyzer { while (true) { Preconditions.checkState(currentAttempt != null); Preconditions.checkState(currentAttemptStopCriticalPathTime > 0); - System.out.println( - "Step: " + tempCP.size() + " Attempt: " + currentAttempt.getTaskAttemptId()); + LOG.debug("Step: " + tempCP.size() + " Attempt: " + currentAttempt.getTaskAttemptId()); currentStep = new CriticalPathStep(currentAttempt, EntityType.ATTEMPT); currentStep.stopCriticalPathTime = currentAttemptStopCriticalPathTime; @@ -501,13 +503,13 @@ public class CriticalPathAnalyzer extends TezAnalyzerBase implements Analyzer { // last data event was produced after the attempt was scheduled. use // data dependency // typically the case when scheduling ahead of time - System.out.println("Has data dependency"); + LOG.debug("Has data dependency"); if (!Strings.isNullOrEmpty(currentStepLastDataTA)) { // there is a valid data causal TA. Use it. nextAttemptId = currentStepLastDataTA; reason = CriticalPathDependency.DATA_DEPENDENCY; startCriticalPathTime = currentStepLastDataEventTime; - System.out.println("Using data dependency " + nextAttemptId); + LOG.debug("Using data dependency " + nextAttemptId); } else { // there is no valid data causal TA. This means data event came from the same vertex VertexInfo vertex = currentAttempt.getTaskInfo().getVertexInfo(); @@ -516,12 +518,12 @@ public class CriticalPathAnalyzer extends TezAnalyzerBase implements Analyzer { + "TA is null for " + currentAttempt.getTaskAttemptId()); nextAttemptId = null; reason = CriticalPathDependency.INIT_DEPENDENCY; - System.out.println("Using init dependency"); + LOG.debug("Using init dependency"); } } else { // attempt was scheduled after last data event. use scheduling dependency // typically happens for retries - System.out.println("Has scheduling dependency"); + LOG.debug("Has scheduling dependency"); if (!Strings.isNullOrEmpty(currentAttempt.getCreationCausalTA())) { // there is a scheduling causal TA. Use it. nextAttemptId = currentAttempt.getCreationCausalTA(); @@ -553,7 +555,7 @@ public class CriticalPathAnalyzer extends TezAnalyzerBase implements Analyzer { currentAttempt.getTaskInfo().getTaskId())); startCriticalPathTime = nextAttempt.getFinishTime(); } - System.out.println("Using scheduling dependency " + nextAttemptId); + LOG.debug("Using scheduling dependency " + nextAttemptId); } else { // there is no scheduling causal TA. if (!Strings.isNullOrEmpty(currentStepLastDataTA)) { @@ -565,7 +567,7 @@ public class CriticalPathAnalyzer extends TezAnalyzerBase implements Analyzer { long overhead = currentAttempt.getCreationTime() - currentStepLastDataEventTime; currentStep.notes .add("Initializer/VertexManager scheduling overhead " + SVGUtils.getTimeStr(overhead)); - System.out.println("Using data dependency " + nextAttemptId); + LOG.debug("Using data dependency " + nextAttemptId); } else { // there is no scheduling causal TA and no data event casual TA. // the vertex has external input that sent the last data events @@ -573,7 +575,7 @@ public class CriticalPathAnalyzer extends TezAnalyzerBase implements Analyzer { // or the vertex has no external inputs or edges nextAttemptId = null; reason = CriticalPathDependency.INIT_DEPENDENCY; - System.out.println("Using init dependency"); + LOG.debug("Using init dependency"); } } } http://git-wip-us.apache.org/repos/asf/tez/blob/30eaa1e4/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/plugins/TezAnalyzerBase.java ---------------------------------------------------------------------- diff --git a/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/plugins/TezAnalyzerBase.java b/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/plugins/TezAnalyzerBase.java index 73e731a..38254c8 100644 --- a/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/plugins/TezAnalyzerBase.java +++ b/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/plugins/TezAnalyzerBase.java @@ -40,9 +40,12 @@ import org.apache.tez.history.parser.SimpleHistoryParser; import org.apache.tez.history.parser.datamodel.DagInfo; import com.google.common.base.Preconditions; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public abstract class TezAnalyzerBase extends Configured implements Tool, Analyzer { + private static final Logger LOG = LoggerFactory.getLogger(TezAnalyzerBase.class); private static final String EVENT_FILE_NAME = "eventFileName"; private static final String OUTPUT_DIR = "outputDir"; @@ -176,7 +179,7 @@ public abstract class TezAnalyzerBase extends Configured implements Tool, Analyz String fileName = outputDir + File.separator + this.getClass().getName() + "_" + dagInfo.getDagId() + ".csv"; ((CSVResult) result).dumpToFile(fileName); - System.out.println("Saved results in " + fileName); + LOG.info("Saved results in " + fileName); } return 0; } @@ -193,21 +196,22 @@ public abstract class TezAnalyzerBase extends Configured implements Tool, Analyz } String format = formatBuilder.toString(); - StringBuilder separator = new StringBuilder(); + StringBuilder sep = new StringBuilder(); for (int i = 0; i < SEPARATOR_WIDTH; i++) { - separator.append("-"); + sep.append("-"); } - System.out.println(separator); - System.out.println(String.format(format.toString(), (String[]) headers)); - System.out.println(separator); + String separator = sep.toString(); + LOG.debug(separator); + LOG.debug(String.format(format.toString(), (String[]) headers)); + LOG.debug(separator); Iterator<String[]> recordsIterator = ((CSVResult) result).getRecordsIterator(); while (recordsIterator.hasNext()) { String line = String.format(format, (String[]) recordsIterator.next()); - System.out.println(line); + LOG.debug(line); } - System.out.println(separator); + LOG.debug(separator); } } } http://git-wip-us.apache.org/repos/asf/tez/blob/30eaa1e4/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/utils/SVGUtils.java ---------------------------------------------------------------------- diff --git a/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/utils/SVGUtils.java b/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/utils/SVGUtils.java index 78cb921..90acf3b 100644 --- a/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/utils/SVGUtils.java +++ b/tez-tools/analyzers/job-analyzer/src/main/java/org/apache/tez/analyzer/utils/SVGUtils.java @@ -25,6 +25,8 @@ import org.apache.tez.history.parser.datamodel.DagInfo; import org.apache.tez.history.parser.datamodel.TaskAttemptInfo; import com.google.common.base.Joiner; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import java.io.BufferedWriter; import java.io.IOException; @@ -35,6 +37,7 @@ import java.util.concurrent.TimeUnit; public class SVGUtils { + private static final Logger LOG = LoggerFactory.getLogger(SVGUtils.class); private static int MAX_DAG_RUNTIME = 0; private static final int SCREEN_WIDTH = 1800; @@ -167,7 +170,7 @@ public class SVGUtils { int launchTimeInterval = attempt.getStartTime() > 0 ? (int) (attempt.getStartTime() - dagStartTime) : 0; int finishTimeInterval = (int) (attempt.getFinishTime() - dagStartTime); - System.out.println(attempt.getTaskAttemptId() + " " + creationTimeInterval + " " + LOG.debug(attempt.getTaskAttemptId() + " " + creationTimeInterval + " " + allocationTimeInterval + " " + launchTimeInterval + " " + finishTimeInterval); StringBuilder title = new StringBuilder();
