You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@hive.apache.org by vi...@apache.org on 2018/04/25 18:07:41 UTC
hive git commit: HIVE-19133 : HS2 WebUI phase-wise performance
metrics not showing correctly (Bharathkrishna Guruvayoor Murali reviewed by
Zoltan Haindrich, Vihang Karajgaonkar)
Repository: hive
Updated Branches:
refs/heads/master da10aabe5 -> e89f98c44
HIVE-19133 : HS2 WebUI phase-wise performance metrics not showing correctly (Bharathkrishna Guruvayoor Murali reviewed by Zoltan Haindrich, Vihang Karajgaonkar)
Project: http://git-wip-us.apache.org/repos/asf/hive/repo
Commit: http://git-wip-us.apache.org/repos/asf/hive/commit/e89f98c4
Tree: http://git-wip-us.apache.org/repos/asf/hive/tree/e89f98c4
Diff: http://git-wip-us.apache.org/repos/asf/hive/diff/e89f98c4
Branch: refs/heads/master
Commit: e89f98c448d1c95bd92275575f2caa02537e8803
Parents: da10aab
Author: Bharathkrishna Guruvayoor Murali <bh...@cloudera.com>
Authored: Wed Apr 25 10:47:42 2018 -0700
Committer: Vihang Karajgaonkar <vi...@cloudera.com>
Committed: Wed Apr 25 10:47:48 2018 -0700
----------------------------------------------------------------------
.../apache/hadoop/hive/ql/log/PerfLogger.java | 2 --
.../hive/jdbc/miniHS2/TestHs2Metrics.java | 1 -
.../TestOperationLoggingAPIWithMr.java | 1 -
.../TestOperationLoggingAPIWithTez.java | 1 -
.../service/cli/session/TestQueryDisplay.java | 7 +++++++
.../java/org/apache/hadoop/hive/ql/Driver.java | 22 ++++++++------------
.../service/cli/operation/SQLOperation.java | 11 +++++-----
7 files changed, 21 insertions(+), 24 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/hive/blob/e89f98c4/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 c1e1b7f..3d6315c 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
@@ -51,14 +51,12 @@ public class PerfLogger {
public static final String SERIALIZE_PLAN = "serializePlan";
public static final String DESERIALIZE_PLAN = "deserializePlan";
public static final String CLONE_PLAN = "clonePlan";
- public static final String TASK = "task.";
public static final String RELEASE_LOCKS = "releaseLocks";
public static final String PRUNE_LISTING = "prune-listing";
public static final String PARTITION_RETRIEVING = "partition-retrieving";
public static final String PRE_HOOK = "PreHook.";
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 TEZ_COMPILER = "TezCompiler";
public static final String TEZ_SUBMIT_TO_RUNNING = "TezSubmitToRunningDag";
public static final String TEZ_BUILD_DAG = "TezBuildDag";
http://git-wip-us.apache.org/repos/asf/hive/blob/e89f98c4/itests/hive-unit/src/test/java/org/apache/hive/jdbc/miniHS2/TestHs2Metrics.java
----------------------------------------------------------------------
diff --git a/itests/hive-unit/src/test/java/org/apache/hive/jdbc/miniHS2/TestHs2Metrics.java b/itests/hive-unit/src/test/java/org/apache/hive/jdbc/miniHS2/TestHs2Metrics.java
index 0ec23e1..9686445 100644
--- a/itests/hive-unit/src/test/java/org/apache/hive/jdbc/miniHS2/TestHs2Metrics.java
+++ b/itests/hive-unit/src/test/java/org/apache/hive/jdbc/miniHS2/TestHs2Metrics.java
@@ -109,7 +109,6 @@ public class TestHs2Metrics {
MetricsTestUtils.verifyMetricsJson(json, MetricsTestUtils.TIMER, "api_hs2_sql_operation_PENDING", 1);
MetricsTestUtils.verifyMetricsJson(json, MetricsTestUtils.TIMER, "api_hs2_sql_operation_RUNNING", 1);
MetricsTestUtils.verifyMetricsJson(json, MetricsTestUtils.COUNTER, "hs2_completed_sql_operation_FINISHED", 1);
- MetricsTestUtils.verifyMetricsJson(json, MetricsTestUtils.TIMER, "api_Driver.run", 1);
//but there should be no more active calls.
MetricsTestUtils.verifyMetricsJson(json, MetricsTestUtils.COUNTER, "active_calls_api_semanticAnalyze", 0);
http://git-wip-us.apache.org/repos/asf/hive/blob/e89f98c4/itests/hive-unit/src/test/java/org/apache/hive/service/cli/operation/TestOperationLoggingAPIWithMr.java
----------------------------------------------------------------------
diff --git a/itests/hive-unit/src/test/java/org/apache/hive/service/cli/operation/TestOperationLoggingAPIWithMr.java b/itests/hive-unit/src/test/java/org/apache/hive/service/cli/operation/TestOperationLoggingAPIWithMr.java
index a6aa846..c7dade3 100644
--- a/itests/hive-unit/src/test/java/org/apache/hive/service/cli/operation/TestOperationLoggingAPIWithMr.java
+++ b/itests/hive-unit/src/test/java/org/apache/hive/service/cli/operation/TestOperationLoggingAPIWithMr.java
@@ -59,7 +59,6 @@ public class TestOperationLoggingAPIWithMr extends OperationLoggingAPITestBase {
expectedLogsPerformance = new String[]{
"<PERFLOG method=compile from=org.apache.hadoop.hive.ql.Driver>",
"<PERFLOG method=parse from=org.apache.hadoop.hive.ql.Driver>",
- "<PERFLOG method=Driver.run from=org.apache.hadoop.hive.ql.Driver>",
"<PERFLOG method=runTasks from=org.apache.hadoop.hive.ql.Driver>"
};
hiveConf = new HiveConf();
http://git-wip-us.apache.org/repos/asf/hive/blob/e89f98c4/itests/hive-unit/src/test/java/org/apache/hive/service/cli/operation/TestOperationLoggingAPIWithTez.java
----------------------------------------------------------------------
diff --git a/itests/hive-unit/src/test/java/org/apache/hive/service/cli/operation/TestOperationLoggingAPIWithTez.java b/itests/hive-unit/src/test/java/org/apache/hive/service/cli/operation/TestOperationLoggingAPIWithTez.java
index 388486d..28eeda1 100644
--- a/itests/hive-unit/src/test/java/org/apache/hive/service/cli/operation/TestOperationLoggingAPIWithTez.java
+++ b/itests/hive-unit/src/test/java/org/apache/hive/service/cli/operation/TestOperationLoggingAPIWithTez.java
@@ -49,7 +49,6 @@ public class TestOperationLoggingAPIWithTez extends OperationLoggingAPITestBase
expectedLogsPerformance = new String[]{
"<PERFLOG method=compile from=org.apache.hadoop.hive.ql.Driver>",
"<PERFLOG method=parse from=org.apache.hadoop.hive.ql.Driver>",
- "<PERFLOG method=Driver.run from=org.apache.hadoop.hive.ql.Driver>",
"from=org.apache.hadoop.hive.ql.exec.tez.monitoring.TezJobMonitor",
"org.apache.tez.common.counters.DAGCounter",
"NUM_SUCCEEDED_TASKS",
http://git-wip-us.apache.org/repos/asf/hive/blob/e89f98c4/itests/hive-unit/src/test/java/org/apache/hive/service/cli/session/TestQueryDisplay.java
----------------------------------------------------------------------
diff --git a/itests/hive-unit/src/test/java/org/apache/hive/service/cli/session/TestQueryDisplay.java b/itests/hive-unit/src/test/java/org/apache/hive/service/cli/session/TestQueryDisplay.java
index 22f953f..8b28e2d 100644
--- a/itests/hive-unit/src/test/java/org/apache/hive/service/cli/session/TestQueryDisplay.java
+++ b/itests/hive-unit/src/test/java/org/apache/hive/service/cli/session/TestQueryDisplay.java
@@ -20,6 +20,7 @@ package org.apache.hive.service.cli.session;
import org.apache.hadoop.hive.conf.HiveConf;
import org.apache.hadoop.hive.ql.QueryDisplay;
import org.apache.hadoop.hive.ql.QueryInfo;
+import org.apache.hadoop.hive.ql.log.PerfLogger;
import org.apache.hadoop.hive.ql.plan.api.StageType;
import org.apache.hadoop.hive.ql.session.SessionState;
import org.apache.hive.service.cli.OperationHandle;
@@ -182,6 +183,12 @@ public class TestQueryDisplay {
Assert.assertTrue(qDisplay1.getPerfLogStarts(QueryDisplay.Phase.COMPILATION).size() > 0);
Assert.assertTrue(qDisplay1.getPerfLogEnds(QueryDisplay.Phase.COMPILATION).size() > 0);
+ Assert.assertTrue(qDisplay1.getPerfLogStarts(QueryDisplay.Phase.COMPILATION).containsKey(PerfLogger.COMPILE));
+ Assert.assertFalse(qDisplay1.getPerfLogStarts(QueryDisplay.Phase.EXECUTION).containsKey(PerfLogger.COMPILE));
+ Assert.assertTrue(qDisplay1.getPerfLogStarts(QueryDisplay.Phase.EXECUTION).containsKey(PerfLogger.DRIVER_EXECUTE));
+ Assert.assertFalse(qDisplay1.getPerfLogStarts(QueryDisplay.Phase.COMPILATION)
+ .containsKey(PerfLogger.DRIVER_EXECUTE));
+
Assert.assertEquals(qDisplay1.getTaskDisplays().size(), 1);
QueryDisplay.TaskDisplay tInfo1 = qDisplay1.getTaskDisplays().get(0);
Assert.assertEquals(tInfo1.getTaskId(), "Stage-0");
http://git-wip-us.apache.org/repos/asf/hive/blob/e89f98c4/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 a35a215..4e8dbe2 100644
--- a/ql/src/java/org/apache/hadoop/hive/ql/Driver.java
+++ b/ql/src/java/org/apache/hadoop/hive/ql/Driver.java
@@ -489,8 +489,7 @@ public class Driver implements IDriver {
// interrupted, it should be set to true if the compile is called within another method like
// runInternal, which defers the close to the called in that method.
private void compile(String command, boolean resetTaskIds, boolean deferClose) throws CommandProcessorResponse {
- PerfLogger perfLogger = SessionState.getPerfLogger(true);
- perfLogger.PerfLogBegin(CLASS_NAME, PerfLogger.DRIVER_RUN);
+ PerfLogger perfLogger = SessionState.getPerfLogger();
perfLogger.PerfLogBegin(CLASS_NAME, PerfLogger.COMPILE);
lDrvState.stateLock.lock();
try {
@@ -660,7 +659,7 @@ public class Driver implements IDriver {
// get the output schema
schema = getSchema(sem, conf);
- plan = new QueryPlan(queryStr, sem, perfLogger.getStartTime(PerfLogger.DRIVER_RUN), queryId,
+ plan = new QueryPlan(queryStr, sem, queryDisplay.getQueryStartTime(), queryId,
queryState.getHiveOperation(), schema);
@@ -1650,7 +1649,7 @@ public class Driver implements IDriver {
metrics.incrementCounter(MetricsConstant.WAITING_COMPILE_OPS, 1);
}
- PerfLogger perfLogger = SessionState.getPerfLogger();
+ PerfLogger perfLogger = SessionState.getPerfLogger(true);
perfLogger.PerfLogBegin(CLASS_NAME, PerfLogger.WAIT_COMPILE);
final ReentrantLock compileLock = tryAcquireCompileLock(isParallelEnabled,
command);
@@ -1676,7 +1675,6 @@ public class Driver implements IDriver {
} finally {
compileLock.unlock();
}
-
//Save compile-time PerfLogging for WebUI.
//Execution-time Perf logs are done by either another thread's PerfLogger
//or a reset PerfLogger.
@@ -1784,19 +1782,18 @@ public class Driver implements IDriver {
throw createProcessorResponse(12);
}
- PerfLogger perfLogger = null;
-
if (!alreadyCompiled) {
// compile internal will automatically reset the perf logger
compileInternal(command, true);
- // then we continue to use this perf logger
- perfLogger = SessionState.getPerfLogger();
} 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));
+ plan.setQueryStartTime(queryDisplay.getQueryStartTime());
}
+
+ //Reset the PerfLogger so that it doesn't retain any previous values.
+ // Any value from compilation phase can be obtained through the map set in queryDisplay during compilation.
+ PerfLogger perfLogger = SessionState.getPerfLogger(true);
+
// the reason that we set the txn manager for the cxt here is because each
// query has its own ctx object. The txn mgr is shared across the
// same instance of Driver, which can run multiple queries.
@@ -1829,7 +1826,6 @@ public class Driver implements IDriver {
throw handleHiveException(e, 12);
}
- perfLogger.PerfLogEnd(CLASS_NAME, PerfLogger.DRIVER_RUN);
queryDisplay.setPerfLogStarts(QueryDisplay.Phase.EXECUTION, perfLogger.getStartTimes());
queryDisplay.setPerfLogEnds(QueryDisplay.Phase.EXECUTION, perfLogger.getEndTimes());
http://git-wip-us.apache.org/repos/asf/hive/blob/e89f98c4/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 5fc935b..85f92d2 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
@@ -263,8 +263,9 @@ public class SQLOperation extends ExecuteStatementOperation {
// 1) ThreadLocal Hive object needs to be set in background thread
// 2) The metastore client in Hive is associated with right user.
// 3) Current UGI will get used by metastore when metastore is in embedded mode
- Runnable work = new BackgroundWork(getCurrentUGI(), parentSession.getSessionHive(),
- SessionState.getPerfLogger(), SessionState.get(), asyncPrepare);
+ Runnable work =
+ new BackgroundWork(getCurrentUGI(), parentSession.getSessionHive(), SessionState.get(),
+ asyncPrepare);
try {
// This submit blocks if no background threads are available to run this operation
@@ -282,16 +283,14 @@ public class SQLOperation extends ExecuteStatementOperation {
private final class BackgroundWork implements Runnable {
private final UserGroupInformation currentUGI;
private final Hive parentHive;
- private final PerfLogger parentPerfLogger;
private final SessionState parentSessionState;
private final boolean asyncPrepare;
private BackgroundWork(UserGroupInformation currentUGI,
- Hive parentHive, PerfLogger parentPerfLogger,
+ Hive parentHive,
SessionState parentSessionState, boolean asyncPrepare) {
this.currentUGI = currentUGI;
this.parentHive = parentHive;
- this.parentPerfLogger = parentPerfLogger;
this.parentSessionState = parentSessionState;
this.asyncPrepare = asyncPrepare;
}
@@ -304,7 +303,7 @@ public class SQLOperation extends ExecuteStatementOperation {
Hive.set(parentHive);
// TODO: can this result in cross-thread reuse of session state?
SessionState.setCurrentSessionState(parentSessionState);
- PerfLogger.setPerfLogger(parentPerfLogger);
+ PerfLogger.setPerfLogger(SessionState.getPerfLogger());
LogUtils.registerLoggingContext(queryState.getConf());
try {
if (asyncPrepare) {