You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@hive.apache.org by om...@apache.org on 2018/04/26 14:59:04 UTC

[40/50] [abbrv] hive git commit: HIVE-19133 : HS2 WebUI phase-wise performance metrics not showing correctly (Bharathkrishna Guruvayoor Murali reviewed by Zoltan Haindrich, Vihang Karajgaonkar)

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/storage-branch-2.6
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) {