svn commit: r1294492 - in /hive/trunk/ql/src/java/org/apache/hadoop/hive/ql: Driver.java QueryPlan.java log/PerfLogger.java

[na...@apache.org]

Author: namit
Date: Tue Feb 28 07:14:33 2012
New Revision: 1294492

URL: http://svn.apache.org/viewvc?rev=1294492&view=rev
Log:
HIVE-2823 Add logging of total run time in Driver
(Kevin Wilfong via namit)


Modified:
    hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/Driver.java
    hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/QueryPlan.java
    hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/log/PerfLogger.java

Modified: hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/Driver.java
URL: http://svn.apache.org/viewvc/hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/Driver.java?rev=1294492&r1=1294491&r2=1294492&view=diff
==============================================================================
--- hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/Driver.java (original)
+++ hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/Driver.java Tue Feb 28 07:14:33 2012
@@ -442,7 +442,7 @@ public class Driver implements CommandPr
       // validate the plan
       sem.validate();
 
-      plan = new QueryPlan(command, sem);
+      plan = new QueryPlan(command, sem, perfLogger.getStartTime(PerfLogger.DRIVER_RUN));
       // initialize FetchTask right here
       if (plan.getFetchTask() != null) {
         plan.getFetchTask().initialize(conf, plan, null);
@@ -886,7 +886,8 @@ public class Driver implements CommandPr
     errorMessage = null;
     SQLState = null;
     // Reset the perf logger
-    PerfLogger.getPerfLogger(true);
+    PerfLogger perfLogger = PerfLogger.getPerfLogger(true);
+    perfLogger.PerfLogBegin(LOG, PerfLogger.DRIVER_RUN);
 
     int ret = compile(command);
     if (ret != 0) {
@@ -939,7 +940,9 @@ public class Driver implements CommandPr
 
     //if needRequireLock is false, the release here will do nothing because there is no lock
     releaseLocks(ctx.getHiveLocks());
-    PerfLogger.getPerfLogger().close(LOG, plan);
+
+    perfLogger.PerfLogEnd(LOG, PerfLogger.DRIVER_RUN);
+    perfLogger.close(LOG, plan);
     return new CommandProcessorResponse(ret);
   }
 

Modified: hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/QueryPlan.java
URL: http://svn.apache.org/viewvc/hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/QueryPlan.java?rev=1294492&r1=1294491&r2=1294492&view=diff
==============================================================================
--- hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/QueryPlan.java (original)
+++ hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/QueryPlan.java Tue Feb 28 07:14:33 2012
@@ -90,10 +90,12 @@ public class QueryPlan implements Serial
 
   private QueryProperties queryProperties;
 
+  private transient Long queryStartTime;
+
   public QueryPlan() {
   }
 
-  public QueryPlan(String queryString, BaseSemanticAnalyzer sem) {
+  public QueryPlan(String queryString, BaseSemanticAnalyzer sem, Long startTime) {
     this.queryString = queryString;
 
     rootTasks = new ArrayList<Task<? extends Serializable>>();
@@ -113,6 +115,7 @@ public class QueryPlan implements Serial
     done = new HashSet<String>();
     started = new HashSet<String>();
     queryProperties = sem.getQueryProperties();
+    queryStartTime = startTime;
   }
 
   public String getQueryStr() {
@@ -744,4 +747,12 @@ public class QueryPlan implements Serial
   public QueryProperties getQueryProperties() {
     return queryProperties;
   }
+
+  public Long getQueryStartTime() {
+    return queryStartTime;
+  }
+
+  public void setQueryStartTime(Long queryStartTime) {
+    this.queryStartTime = queryStartTime;
+  }
 }

Modified: hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/log/PerfLogger.java
URL: http://svn.apache.org/viewvc/hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/log/PerfLogger.java?rev=1294492&r1=1294491&r2=1294492&view=diff
==============================================================================
--- hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/log/PerfLogger.java (original)
+++ hive/trunk/ql/src/java/org/apache/hadoop/hive/ql/log/PerfLogger.java Tue Feb 28 07:14:33 2012
@@ -45,10 +45,12 @@ public class PerfLogger {
   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";
 
   protected static final ThreadLocal<PerfLogger> perfLogger = new ThreadLocal<PerfLogger>();
 
-  protected final Map<String, Long> perfKeyMaps = new HashMap<String, Long>();
+  protected final Map<String, Long> startTimes = new HashMap<String, Long>();
+  protected final Map<String, Long> endTimes = new HashMap<String, Long>();
 
   static final private Log LOG = LogFactory.getLog(PerfLogger.class.getName());
 
@@ -95,7 +97,7 @@ public class PerfLogger {
   public void PerfLogBegin(Log _log, String method) {
     long startTime = System.currentTimeMillis();
     _log.info("<PERFLOG method=" + method + ">");
-    perfKeyMaps.put(method, new Long(startTime));
+    startTimes.put(method, new Long(startTime));
   }
 
   /**
@@ -105,9 +107,12 @@ public class PerfLogger {
    * @return long duration  the difference between now and startTime, or -1 if startTime is null
    */
   public long PerfLogEnd(Log _log, String method) {
-    Long startTime = perfKeyMaps.get(method);
+    Long startTime = startTimes.get(method);
     long endTime = System.currentTimeMillis();
     long duration = -1;
+
+    endTimes.put(method, new Long(endTime));
+
     StringBuilder sb = new StringBuilder("</PERFLOG method=").append(method);
     if (startTime != null) {
       sb.append(" start=").append(startTime);
@@ -131,4 +136,12 @@ public class PerfLogger {
   public void close(Log _log, QueryPlan queryPlan) {
 
   }
+
+  public Long getStartTime(String method) {
+    return startTimes.get(method);
+  }
+
+  public Long getEndTime(String method) {
+    return endTimes.get(method);
+  }
 }