IMPALA-4341: Add metadata load to planner timeline
This moves the timeline from the Analyzer GlobalState to the AnalysisContext
and AnalysisContext.AnalysisResult. When analysis needs to load metadata
about missing tables, it marks an event noting the start of metadata load.
Then, when metadata load completes (or times out), it marks an
event noting that metadata load completed (or timed out). Keeping the
timeline on the AnalysisContext means that it persists across attempts at
analysis. AnalysisContext.AnalysisResult has a reference to the timeline,
so that it persists past analyzeStmt and can be used for the rest of
the planning.
Here is an example output of the planner timeline after this change:
Planner Timeline: 4s371ms
- Metadata load started: 41.388ms (41.388ms)
- Metadata load finished: 4s260ms (4s219ms)
- Analysis finished: 4s296ms (35.693ms)
- Equivalence classes computed: 4s315ms (19.062ms)
- Single node plan created: 4s323ms (7.812ms)
- Runtime filters computed: 4s323ms (777.010us)
- Distributed plan created: 4s325ms (1.464ms)
- Planning finished: 4s371ms (46.697ms)
When there is no need to load metadata, the timeline looks like:
Planner Timeline: 13.695ms
- Analysis finished: 2.411ms (2.411ms)
- Equivalence classes computed: 2.653ms (241.733us)
- Single node plan created: 5.641ms (2.987ms)
- Runtime filters computed: 5.726ms (85.204us)
- Distributed plan created: 6.548ms (821.722us)
- Planning finished: 13.695ms (7.147ms)
Change-Id: I6f01a35e5f9f5007a0298acfc8e16da00ef99c6c
Reviewed-on: http://gerrit.cloudera.org:8080/5685
Reviewed-by: Marcel Kornacker <[email protected]>
Tested-by: Impala Public Jenkins
Project: http://git-wip-us.apache.org/repos/asf/incubator-impala/repo
Commit: http://git-wip-us.apache.org/repos/asf/incubator-impala/commit/5d028d93
Tree: http://git-wip-us.apache.org/repos/asf/incubator-impala/tree/5d028d93
Diff: http://git-wip-us.apache.org/repos/asf/incubator-impala/diff/5d028d93
Branch: refs/heads/master
Commit: 5d028d93b9b796af448c72396d99ccba43790f72
Parents: 44bb99a
Author: Joe McDonnell <[email protected]>
Authored: Wed Jan 11 13:41:00 2017 -0800
Committer: Impala Public Jenkins <[email protected]>
Committed: Thu Jan 12 03:54:15 2017 +0000
----------------------------------------------------------------------
.../java/org/apache/impala/analysis/AnalysisContext.java | 9 +++++++++
fe/src/main/java/org/apache/impala/analysis/Analyzer.java | 7 -------
fe/src/main/java/org/apache/impala/planner/Planner.java | 10 +++++-----
.../java/org/apache/impala/planner/SingleNodePlanner.java | 2 +-
fe/src/main/java/org/apache/impala/service/Frontend.java | 10 ++++++++--
5 files changed, 23 insertions(+), 15 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/5d028d93/fe/src/main/java/org/apache/impala/analysis/AnalysisContext.java
----------------------------------------------------------------------
diff --git a/fe/src/main/java/org/apache/impala/analysis/AnalysisContext.java
b/fe/src/main/java/org/apache/impala/analysis/AnalysisContext.java
index d57c25f..c74acc5 100644
--- a/fe/src/main/java/org/apache/impala/analysis/AnalysisContext.java
+++ b/fe/src/main/java/org/apache/impala/analysis/AnalysisContext.java
@@ -43,6 +43,7 @@ import org.apache.impala.rewrite.FoldConstantsRule;
import org.apache.impala.thrift.TAccessEvent;
import org.apache.impala.thrift.TLineageGraph;
import org.apache.impala.thrift.TQueryCtx;
+import org.apache.impala.util.EventSequence;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
@@ -60,6 +61,10 @@ public class AnalysisContext {
private final AuthorizationConfig authzConfig_;
private final ExprRewriter rewriter_;
+ // Timeline of important events in the planning process, used for debugging
+ // and profiling
+ private final EventSequence timeline_ = new EventSequence("Planner
Timeline");
+
// Set in analyze()
private AnalysisResult analysisResult_;
@@ -93,6 +98,7 @@ public class AnalysisContext {
static public class AnalysisResult {
private StatementBase stmt_;
private Analyzer analyzer_;
+ private EventSequence timeline_;
public boolean isAlterTableStmt() { return stmt_ instanceof
AlterTableStmt; }
public boolean isAlterViewStmt() { return stmt_ instanceof AlterViewStmt; }
@@ -332,6 +338,7 @@ public class AnalysisContext {
public StatementBase getStmt() { return stmt_; }
public Analyzer getAnalyzer() { return analyzer_; }
+ public EventSequence getTimeline() { return timeline_; }
public Set<TAccessEvent> getAccessEvents() { return
analyzer_.getAccessEvents(); }
public boolean requiresSubqueryRewrite() {
return analyzer_.containsSubquery() && !(stmt_ instanceof CreateViewStmt)
@@ -375,6 +382,7 @@ public class AnalysisContext {
if (analysisResult_.analyzer_ == null) {
analysisResult_.analyzer_ = new Analyzer(catalog_, queryCtx_,
authzConfig_);
}
+ analysisResult_.timeline_ = timeline_;
analysisResult_.stmt_ = (StatementBase) parser.parse().value;
if (analysisResult_.stmt_ == null) return;
@@ -583,4 +591,5 @@ public class AnalysisContext {
public AnalysisResult getAnalysisResult() { return analysisResult_; }
public Analyzer getAnalyzer() { return getAnalysisResult().getAnalyzer(); }
+ public EventSequence getTimeline() { return timeline_; }
}
http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/5d028d93/fe/src/main/java/org/apache/impala/analysis/Analyzer.java
----------------------------------------------------------------------
diff --git a/fe/src/main/java/org/apache/impala/analysis/Analyzer.java
b/fe/src/main/java/org/apache/impala/analysis/Analyzer.java
index 4d638a8..ca09b05 100644
--- a/fe/src/main/java/org/apache/impala/analysis/Analyzer.java
+++ b/fe/src/main/java/org/apache/impala/analysis/Analyzer.java
@@ -68,7 +68,6 @@ import org.apache.impala.thrift.TNetworkAddress;
import org.apache.impala.thrift.TQueryCtx;
import org.apache.impala.thrift.TQueryOptions;
import org.apache.impala.util.DisjointSet;
-import org.apache.impala.util.EventSequence;
import org.apache.impala.util.ListMap;
import org.apache.impala.util.TSessionStateUtil;
import org.slf4j.Logger;
@@ -303,10 +302,6 @@ public class Analyzer {
private final ExprRewriter constantFolder_ =
new ExprRewriter(FoldConstantsRule.INSTANCE);
- // Timeline of important events in the planning process, used for
debugging /
- // profiling
- private final EventSequence timeline = new EventSequence("Planner
Timeline");
-
public GlobalState(ImpaladCatalog catalog, TQueryCtx queryCtx,
AuthorizationConfig authzConfig) {
this.catalog = catalog;
@@ -2543,8 +2538,6 @@ public class Analyzer {
return res;
}
- public EventSequence getTimeline() { return globalState_.timeline; }
-
/**
* Assign all remaining unassigned slots to their own equivalence classes.
*/
http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/5d028d93/fe/src/main/java/org/apache/impala/planner/Planner.java
----------------------------------------------------------------------
diff --git a/fe/src/main/java/org/apache/impala/planner/Planner.java
b/fe/src/main/java/org/apache/impala/planner/Planner.java
index 297e9b2..b47a7b3 100644
--- a/fe/src/main/java/org/apache/impala/planner/Planner.java
+++ b/fe/src/main/java/org/apache/impala/planner/Planner.java
@@ -85,7 +85,7 @@ public class Planner {
SingleNodePlanner singleNodePlanner = new SingleNodePlanner(ctx_);
DistributedPlanner distributedPlanner = new DistributedPlanner(ctx_);
PlanNode singleNodePlan = singleNodePlanner.createSingleNodePlan();
- ctx_.getRootAnalyzer().getTimeline().markEvent("Single node plan created");
+ ctx_.getAnalysisResult().getTimeline().markEvent("Single node plan
created");
ArrayList<PlanFragment> fragments = null;
// Determine the maximum number of rows processed by any node in the plan
tree
@@ -116,7 +116,7 @@ public class Planner {
// Always compute filters, even if the BE won't always use all of them.
RuntimeFilterGenerator.generateRuntimeFilters(ctx_.getRootAnalyzer(),
singleNodePlan, ctx_.getQueryOptions().getMax_num_runtime_filters());
- ctx_.getRootAnalyzer().getTimeline().markEvent(
+ ctx_.getAnalysisResult().getTimeline().markEvent(
"Runtime filters computed");
}
@@ -174,7 +174,7 @@ public class Planner {
}
Collections.reverse(fragments);
- ctx_.getRootAnalyzer().getTimeline().markEvent("Distributed plan created");
+ ctx_.getAnalysisResult().getTimeline().markEvent("Distributed plan
created");
ColumnLineageGraph graph = ctx_.getRootAnalyzer().getColumnLineageGraph();
if (BackendConfig.INSTANCE.getComputeLineage() ||
RuntimeEnv.INSTANCE.isTestEnv()) {
@@ -217,7 +217,7 @@ public class Planner {
graph.computeLineageGraph(resultExprs, ctx_.getRootAnalyzer());
}
if (LOG.isTraceEnabled()) LOG.trace("lineage: " + graph.debugString());
- ctx_.getRootAnalyzer().getTimeline().markEvent("Lineage info computed");
+ ctx_.getAnalysisResult().getTimeline().markEvent("Lineage info
computed");
}
return fragments;
@@ -236,7 +236,7 @@ public class Planner {
// Only use one scanner thread per scan-node instance since intra-node
// parallelism is achieved via multiple fragment instances.
ctx_.getQueryOptions().setNum_scanner_threads(1);
- ctx_.getRootAnalyzer().getTimeline().markEvent("Parallel plans created");
+ ctx_.getAnalysisResult().getTimeline().markEvent("Parallel plans created");
return parallelPlans;
}
http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/5d028d93/fe/src/main/java/org/apache/impala/planner/SingleNodePlanner.java
----------------------------------------------------------------------
diff --git a/fe/src/main/java/org/apache/impala/planner/SingleNodePlanner.java
b/fe/src/main/java/org/apache/impala/planner/SingleNodePlanner.java
index 87ac427..ed43421 100644
--- a/fe/src/main/java/org/apache/impala/planner/SingleNodePlanner.java
+++ b/fe/src/main/java/org/apache/impala/planner/SingleNodePlanner.java
@@ -126,7 +126,7 @@ public class SingleNodePlanner {
// to detect empty result sets.
Analyzer analyzer = queryStmt.getAnalyzer();
analyzer.computeEquivClasses();
- analyzer.getTimeline().markEvent("Equivalence classes computed");
+ ctx_.getAnalysisResult().getTimeline().markEvent("Equivalence classes
computed");
// Mark slots referenced by output exprs as materialized, prior to
generating the
// plan tree.
http://git-wip-us.apache.org/repos/asf/incubator-impala/blob/5d028d93/fe/src/main/java/org/apache/impala/service/Frontend.java
----------------------------------------------------------------------
diff --git a/fe/src/main/java/org/apache/impala/service/Frontend.java
b/fe/src/main/java/org/apache/impala/service/Frontend.java
index d236cb1..eca8d65 100644
--- a/fe/src/main/java/org/apache/impala/service/Frontend.java
+++ b/fe/src/main/java/org/apache/impala/service/Frontend.java
@@ -904,12 +904,18 @@ public class Frontend {
// Only re-throw the AnalysisException if there were no missing
tables.
if (missingTbls.isEmpty()) throw e;
+ // Record that analysis needs table metadata
+ analysisCtx.getTimeline().markEvent("Metadata load started");
+
// Some tables/views were missing, request and wait for them to load.
if (!requestTblLoadAndWait(missingTbls,
MISSING_TBL_LOAD_WAIT_TIMEOUT_MS)) {
if (LOG.isTraceEnabled()) {
LOG.trace(String.format("Missing tables were not received in
%dms. Load " +
"request will be retried.",
MISSING_TBL_LOAD_WAIT_TIMEOUT_MS));
}
+ analysisCtx.getTimeline().markEvent("Metadata load timeout");
+ } else {
+ analysisCtx.getTimeline().markEvent("Metadata load finished");
}
}
}
@@ -1037,7 +1043,7 @@ public class Frontend {
throws ImpalaException {
// Analyze the statement
AnalysisContext.AnalysisResult analysisResult = analyzeStmt(queryCtx);
- EventSequence timeline = analysisResult.getAnalyzer().getTimeline();
+ EventSequence timeline = analysisResult.getTimeline();
timeline.markEvent("Analysis finished");
Preconditions.checkNotNull(analysisResult.getStmt());
TExecRequest result = new TExecRequest();
@@ -1150,7 +1156,7 @@ public class Frontend {
}
timeline.markEvent("Planning finished");
- result.setTimeline(analysisResult.getAnalyzer().getTimeline().toThrift());
+ result.setTimeline(analysisResult.getTimeline().toThrift());
return result;
}
