Repository: hive Updated Branches: refs/heads/master 041584557 -> 4f3c27cca
HIVE-14070: hive.tez.exec.print.summary=true returns wrong performance numbers on HS2 (Pengcheng Xiong, reviewed by Thejas M Nair, Sergey Shelukhin, Ashutosh Chauhan) Project: http://git-wip-us.apache.org/repos/asf/hive/repo Commit: http://git-wip-us.apache.org/repos/asf/hive/commit/4f3c27cc Tree: http://git-wip-us.apache.org/repos/asf/hive/tree/4f3c27cc Diff: http://git-wip-us.apache.org/repos/asf/hive/diff/4f3c27cc Branch: refs/heads/master Commit: 4f3c27cca796058ba4be79b00ba1ae919f26ac8a Parents: 0415845 Author: Pengcheng Xiong <[email protected]> Authored: Fri Jun 24 21:34:47 2016 -0700 Committer: Pengcheng Xiong <[email protected]> Committed: Fri Jun 24 21:34:47 2016 -0700 ---------------------------------------------------------------------- .../org/apache/hadoop/hive/ql/log/PerfLogger.java | 5 ++++- ql/src/java/org/apache/hadoop/hive/ql/Driver.java | 14 ++++++++------ .../apache/hadoop/hive/ql/exec/tez/TezJobMonitor.java | 2 +- .../hive/service/cli/operation/SQLOperation.java | 3 +++ 4 files changed, 16 insertions(+), 8 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/hive/blob/4f3c27cc/common/src/java/org/apache/hadoop/hive/ql/log/PerfLogger.java ---------------------------------------------------------------------- diff --git a/common/src/java/org/apache/hadoop/hive/ql/log/PerfLogger.java b/common/src/java/org/apache/hadoop/hive/ql/log/PerfLogger.java index 87b82f8..63d96be 100644 --- a/common/src/java/org/apache/hadoop/hive/ql/log/PerfLogger.java +++ b/common/src/java/org/apache/hadoop/hive/ql/log/PerfLogger.java @@ -62,7 +62,6 @@ public class PerfLogger { public static final String POST_HOOK = "PostHook."; public static final String FAILURE_HOOK = "FailureHook."; public static final String DRIVER_RUN = "Driver.run"; - public static final String TIME_TO_SUBMIT = "TimeToSubmit"; public static final String TEZ_COMPILER = "TezCompiler"; public static final String TEZ_SUBMIT_TO_RUNNING = "TezSubmitToRunningDag"; public static final String TEZ_BUILD_DAG = "TezBuildDag"; @@ -118,6 +117,10 @@ public class PerfLogger { return result; } + public static void setPerfLogger(PerfLogger resetPerfLogger) { + perfLogger.set(resetPerfLogger); + } + /** * Call this function when you start to measure time spent by a piece of code. * @param callerName the logging object to be used. http://git-wip-us.apache.org/repos/asf/hive/blob/4f3c27cc/ql/src/java/org/apache/hadoop/hive/ql/Driver.java ---------------------------------------------------------------------- diff --git a/ql/src/java/org/apache/hadoop/hive/ql/Driver.java b/ql/src/java/org/apache/hadoop/hive/ql/Driver.java index 2263192..d56295a 100644 --- a/ql/src/java/org/apache/hadoop/hive/ql/Driver.java +++ b/ql/src/java/org/apache/hadoop/hive/ql/Driver.java @@ -337,7 +337,8 @@ public class Driver implements CommandProcessor { * @return 0 for ok */ public int compile(String command, boolean resetTaskIds) { - PerfLogger perfLogger = SessionState.getPerfLogger(); + PerfLogger perfLogger = SessionState.getPerfLogger(true); + perfLogger.PerfLogBegin(CLASS_NAME, PerfLogger.DRIVER_RUN); perfLogger.PerfLogBegin(CLASS_NAME, PerfLogger.COMPILE); command = new VariableSubstitution(new HiveVariableSource() { @@ -1243,18 +1244,20 @@ public class Driver implements CommandProcessor { return createProcessorResponse(12); } - // Reset the perf logger - PerfLogger perfLogger = SessionState.getPerfLogger(true); - perfLogger.PerfLogBegin(CLASS_NAME, PerfLogger.DRIVER_RUN); - perfLogger.PerfLogBegin(CLASS_NAME, PerfLogger.TIME_TO_SUBMIT); + PerfLogger perfLogger = null; int ret; if (!alreadyCompiled) { + // compile internal will automatically reset the perf logger ret = compileInternal(command); + // then we continue to use this perf logger + perfLogger = SessionState.getPerfLogger(); if (ret != 0) { return createProcessorResponse(ret); } } else { + // reuse existing perf logger. + perfLogger = SessionState.getPerfLogger(); // Since we're reusing the compiled plan, we need to update its start time for current run plan.setQueryStartTime(perfLogger.getStartTime(PerfLogger.DRIVER_RUN)); } @@ -1551,7 +1554,6 @@ public class Driver implements CommandProcessor { driverCxt.addToRunnable(tsk); } - perfLogger.PerfLogEnd(CLASS_NAME, PerfLogger.TIME_TO_SUBMIT); perfLogger.PerfLogBegin(CLASS_NAME, PerfLogger.RUN_TASKS); // Loop while you either have tasks running, or tasks queued up while (!destroyed && driverCxt.isRunning()) { http://git-wip-us.apache.org/repos/asf/hive/blob/4f3c27cc/ql/src/java/org/apache/hadoop/hive/ql/exec/tez/TezJobMonitor.java ---------------------------------------------------------------------- diff --git a/ql/src/java/org/apache/hadoop/hive/ql/exec/tez/TezJobMonitor.java b/ql/src/java/org/apache/hadoop/hive/ql/exec/tez/TezJobMonitor.java index 838f320..5aab0e5 100644 --- a/ql/src/java/org/apache/hadoop/hive/ql/exec/tez/TezJobMonitor.java +++ b/ql/src/java/org/apache/hadoop/hive/ql/exec/tez/TezJobMonitor.java @@ -444,7 +444,7 @@ public class TezJobMonitor { // parse, analyze, optimize and compile long compile = perfLogger.getEndTime(PerfLogger.COMPILE) - - perfLogger.getStartTime(PerfLogger.DRIVER_RUN); + perfLogger.getStartTime(PerfLogger.COMPILE); console.printInfo(String.format(OPERATION_SUMMARY, "Compile Query", secondsFormat.format(compile / 1000.0) + "s")); http://git-wip-us.apache.org/repos/asf/hive/blob/4f3c27cc/service/src/java/org/apache/hive/service/cli/operation/SQLOperation.java ---------------------------------------------------------------------- diff --git a/service/src/java/org/apache/hive/service/cli/operation/SQLOperation.java b/service/src/java/org/apache/hive/service/cli/operation/SQLOperation.java index 3bf40eb..9cb5daf 100644 --- a/service/src/java/org/apache/hive/service/cli/operation/SQLOperation.java +++ b/service/src/java/org/apache/hive/service/cli/operation/SQLOperation.java @@ -54,6 +54,7 @@ import org.apache.hadoop.hive.ql.QueryState; import org.apache.hadoop.hive.ql.exec.ExplainTask; import org.apache.hadoop.hive.ql.exec.FetchTask; import org.apache.hadoop.hive.ql.exec.Task; +import org.apache.hadoop.hive.ql.log.PerfLogger; import org.apache.hadoop.hive.ql.metadata.Hive; import org.apache.hadoop.hive.ql.processors.CommandProcessorResponse; import org.apache.hadoop.hive.ql.session.OperationLog; @@ -282,6 +283,7 @@ public class SQLOperation extends ExecuteStatementOperation { // ThreadLocal Hive object needs to be set in background thread. // The metastore client in Hive is associated with right user. final Hive parentHive = parentSession.getSessionHive(); + final PerfLogger parentPerfLogger = SessionState.getPerfLogger(); // Current UGI will get used by metastore when metsatore is in embedded mode // So this needs to get passed to the new background thread final UserGroupInformation currentUGI = getCurrentUGI(); @@ -295,6 +297,7 @@ public class SQLOperation extends ExecuteStatementOperation { public Object run() throws HiveSQLException { Hive.set(parentHive); SessionState.setCurrentSessionState(parentSessionState); + PerfLogger.setPerfLogger(parentPerfLogger); // Set current OperationLog in this async thread for keeping on saving query log. registerCurrentOperationLog(); registerLoggingContext();
