This is an automated email from the ASF dual-hosted git repository.
sankarh pushed a commit to branch branch-3
in repository https://gitbox.apache.org/repos/asf/hive.git
The following commit(s) were added to refs/heads/branch-3 by this push:
new 63e6941abb2 HIVE-27378: Backport HIVE-19133 : HS2 WebUI phase-wise
performance metrics not showing correctly (Bharathkrishna Guruvayoor Murali
reviewed by Zoltan Haindrich, Vihang Karajgaonkar)
63e6941abb2 is described below
commit 63e6941abb20626dd273d30ba7061a88ae3cfe02
Author: Diksha628 <43694846+diksha...@users.noreply.github.com>
AuthorDate: Tue Jun 6 12:23:14 2023 +0530
HIVE-27378: Backport HIVE-19133 : HS2 WebUI phase-wise performance metrics
not showing correctly (Bharathkrishna Guruvayoor Murali reviewed by Zoltan
Haindrich, Vihang Karajgaonkar)
Signed-off-by: Sankar Hariappan <sank...@apache.org>
Closes (#4358)
---
.../org/apache/hadoop/hive/ql/log/PerfLogger.java | 2 --
.../apache/hive/jdbc/miniHS2/TestHs2Metrics.java | 1 -
.../operation/TestOperationLoggingAPIWithMr.java | 1 -
.../operation/TestOperationLoggingAPIWithTez.java | 1 -
.../hive/service/cli/session/TestQueryDisplay.java | 7 +++++++
ql/src/java/org/apache/hadoop/hive/ql/Driver.java | 22 +++++++++-------------
.../hive/service/cli/operation/SQLOperation.java | 11 +++++------
7 files changed, 21 insertions(+), 24 deletions(-)
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 764a832e281..65745f211d0 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";
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 0ec23e1c1e1..9686445f2b2 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);
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 a6aa84629af..c7dade3874a 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();
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 388486d9702..28eeda18a1a 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",
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 28948a9ce78..8b2a85d9625 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;
@@ -153,6 +154,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");
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 d6cdc355a39..89762d95800 100644
--- a/ql/src/java/org/apache/hadoop/hive/ql/Driver.java
+++ b/ql/src/java/org/apache/hadoop/hive/ql/Driver.java
@@ -504,8 +504,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 {
@@ -683,7 +682,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);
// save the optimized sql for the explain
plan.setOptimizedQueryString(ctx.getOptimizedSql());
@@ -1836,7 +1835,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);
@@ -1862,7 +1861,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.
@@ -1970,19 +1968,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.
@@ -2058,7 +2055,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());
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 f2a262d3d46..36df57e40c7 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
@@ -268,8 +268,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
@@ -287,16 +288,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;
}
@@ -309,7 +308,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) {
