[feature](profile) Add important time of legacy planner to profile (#20602)

Add important time in planning process. Add time points of:
// Join reorder end time
queryJoinReorderFinishTime means time after analyze and before join reorder
// Create single node plan end time
queryCreateSingleNodeFinishTime means time after join reorder and before finish create single node plan
// Create distribute plan end time
queryDistributedFinishTime means time after create single node plan and before finish create distributed node plan
This commit is contained in:
LiBinfeng
2023-07-06 15:36:25 +08:00
committed by GitHub
parent bb3b6770b5
commit 068fe44493
3 changed files with 54 additions and 1 deletions

View File

@ -51,6 +51,9 @@ public class SummaryProfile {
// Execution Summary
public static final String ANALYSIS_TIME = "Analysis Time";
public static final String JOIN_REORDER_TIME = "JoinReorder Time";
public static final String CREATE_SINGLE_NODE_TIME = "CreateSingleNode Time";
public static final String QUERY_DISTRIBUTED_TIME = "QueryDistributed Time";
public static final String PLAN_TIME = "Plan Time";
public static final String SCHEDULE_TIME = "Schedule Time";
public static final String FETCH_RESULT_TIME = "Fetch Result Time";
@ -71,6 +74,12 @@ public class SummaryProfile {
private long queryBeginTime = -1;
// Analysis end time
private long queryAnalysisFinishTime = -1;
// Join reorder end time
private long queryJoinReorderFinishTime = -1;
// Create single node plan end time
private long queryCreateSingleNodeFinishTime = -1;
// Create distribute plan end time
private long queryDistributedFinishTime = -1;
// Plan end time
private long queryPlanFinishTime = -1;
// Fragment schedule and send end time
@ -113,6 +122,9 @@ public class SummaryProfile {
private void updateExecutionSummaryProfile() {
executionSummaryProfile.addInfoString(ANALYSIS_TIME, getPrettyQueryAnalysisFinishTime());
executionSummaryProfile.addInfoString(JOIN_REORDER_TIME, getPrettyQueryJoinReorderFinishTime());
executionSummaryProfile.addInfoString(CREATE_SINGLE_NODE_TIME, getPrettyCreateSingleNodeFinishTime());
executionSummaryProfile.addInfoString(QUERY_DISTRIBUTED_TIME, getPrettyQueryDistributedFinishTime());
executionSummaryProfile.addInfoString(PLAN_TIME, getPrettyQueryPlanFinishTime());
executionSummaryProfile.addInfoString(SCHEDULE_TIME, getPrettyQueryScheduleFinishTime());
executionSummaryProfile.addInfoString(FETCH_RESULT_TIME,
@ -130,6 +142,18 @@ public class SummaryProfile {
this.queryAnalysisFinishTime = TimeUtils.getStartTimeMs();
}
public void setQueryJoinReorderFinishTime() {
this.queryJoinReorderFinishTime = TimeUtils.getStartTimeMs();
}
public void setCreateSingleNodeFinishTime() {
this.queryCreateSingleNodeFinishTime = TimeUtils.getStartTimeMs();
}
public void setQueryDistributedFinishTime() {
this.queryDistributedFinishTime = TimeUtils.getStartTimeMs();
}
public void setQueryPlanFinishTime() {
this.queryPlanFinishTime = TimeUtils.getStartTimeMs();
}
@ -253,6 +277,27 @@ public class SummaryProfile {
return RuntimeProfile.printCounter(queryAnalysisFinishTime - queryBeginTime, TUnit.TIME_MS);
}
private String getPrettyQueryJoinReorderFinishTime() {
if (queryAnalysisFinishTime == -1 || queryJoinReorderFinishTime == -1) {
return "N/A";
}
return RuntimeProfile.printCounter(queryJoinReorderFinishTime - queryAnalysisFinishTime, TUnit.TIME_MS);
}
private String getPrettyCreateSingleNodeFinishTime() {
if (queryJoinReorderFinishTime == -1 || queryCreateSingleNodeFinishTime == -1) {
return "N/A";
}
return RuntimeProfile.printCounter(queryCreateSingleNodeFinishTime - queryJoinReorderFinishTime, TUnit.TIME_MS);
}
private String getPrettyQueryDistributedFinishTime() {
if (queryCreateSingleNodeFinishTime == -1 || queryDistributedFinishTime == -1) {
return "N/A";
}
return RuntimeProfile.printCounter(queryDistributedFinishTime - queryCreateSingleNodeFinishTime, TUnit.TIME_MS);
}
private String getPrettyQueryPlanFinishTime() {
if (queryAnalysisFinishTime == -1 || queryPlanFinishTime == -1) {
return "N/A";

View File

@ -164,9 +164,11 @@ public class OriginalPlanner extends Planner {
plannerContext = new PlannerContext(analyzer, queryStmt, queryOptions, statement);
singleNodePlanner = new SingleNodePlanner(plannerContext);
PlanNode singleNodePlan = singleNodePlanner.createSingleNodePlan();
if (ConnectContext.get().getExecutor() != null) {
ConnectContext.get().getExecutor().getSummaryProfile().setCreateSingleNodeFinishTime();
}
ProjectPlanner projectPlanner = new ProjectPlanner(analyzer);
projectPlanner.projectSingleNodePlan(queryStmt.getResultExprs(), singleNodePlan);
if (statement instanceof InsertStmt) {
InsertStmt insertStmt = (InsertStmt) statement;
insertStmt.prepareExpressions();
@ -220,6 +222,9 @@ public class OriginalPlanner extends Planner {
distributedPlanner = new DistributedPlanner(plannerContext);
fragments = distributedPlanner.createPlanFragments(singleNodePlan);
}
if (ConnectContext.get().getExecutor() != null) {
ConnectContext.get().getExecutor().getSummaryProfile().setQueryDistributedFinishTime();
}
// Push sort node down to the bottom of olapscan.
// Because the olapscan must be in the end. So get the last two nodes.

View File

@ -277,6 +277,9 @@ public class SingleNodePlanner {
Preconditions.checkState(stmt instanceof SetOperationStmt);
root = createSetOperationPlan((SetOperationStmt) stmt, analyzer, newDefaultOrderByLimit);
}
if (ConnectContext.get().getExecutor() != null) {
ConnectContext.get().getExecutor().getSummaryProfile().setQueryJoinReorderFinishTime();
}
// Avoid adding a sort node if the sort tuple has no materialized slots.
boolean sortHasMaterializedSlots = false;