This is an automated email from the ASF dual-hosted git repository.
morrysnow pushed a commit to branch branch-3.1
in repository https://gitbox.apache.org/repos/asf/doris.git
The following commit(s) were added to refs/heads/branch-3.1 by this push:
new 69cd720fc13 branch-3.1: [opt](profile) optimize timer in profile
#51327 (#52409)
69cd720fc13 is described below
commit 69cd720fc13700da1e5d1ac9d38c533700587d56
Author: morrySnow <[email protected]>
AuthorDate: Fri Jun 27 15:19:19 2025 +0800
branch-3.1: [opt](profile) optimize timer in profile #51327 (#52409)
Cherry-picked #51327
---
.../doris/common/profile/RuntimeProfile.java | 4 +-
.../doris/common/profile/SummaryProfile.java | 107 ++++++++-------------
.../org/apache/doris/nereids/NereidsPlanner.java | 5 +-
.../org/apache/doris/planner/OriginalPlanner.java | 6 --
.../apache/doris/planner/SingleNodePlanner.java | 3 -
.../main/java/org/apache/doris/qe/Coordinator.java | 17 ++--
.../java/org/apache/doris/qe/StmtExecutor.java | 7 +-
7 files changed, 60 insertions(+), 89 deletions(-)
diff --git
a/fe/fe-core/src/main/java/org/apache/doris/common/profile/RuntimeProfile.java
b/fe/fe-core/src/main/java/org/apache/doris/common/profile/RuntimeProfile.java
index 1369cfaef2f..5d54d36ae2a 100644
---
a/fe/fe-core/src/main/java/org/apache/doris/common/profile/RuntimeProfile.java
+++
b/fe/fe-core/src/main/java/org/apache/doris/common/profile/RuntimeProfile.java
@@ -415,8 +415,8 @@ public class RuntimeProfile {
try {
for (String key : this.infoStringsDisplayOrder) {
builder.append(prefix);
- if
(SummaryProfile.EXECUTION_SUMMARY_KEYS_IDENTATION.containsKey(key)) {
- for (int i = 0; i <
SummaryProfile.EXECUTION_SUMMARY_KEYS_IDENTATION.get(key); i++) {
+ if
(SummaryProfile.EXECUTION_SUMMARY_KEYS_INDENTATION.containsKey(key)) {
+ for (int i = 0; i <
SummaryProfile.EXECUTION_SUMMARY_KEYS_INDENTATION.get(key); i++) {
builder.append(" ");
}
}
diff --git
a/fe/fe-core/src/main/java/org/apache/doris/common/profile/SummaryProfile.java
b/fe/fe-core/src/main/java/org/apache/doris/common/profile/SummaryProfile.java
index bf286d263a2..6c6dcbecdfd 100644
---
a/fe/fe-core/src/main/java/org/apache/doris/common/profile/SummaryProfile.java
+++
b/fe/fe-core/src/main/java/org/apache/doris/common/profile/SummaryProfile.java
@@ -77,10 +77,6 @@ public class SummaryProfile {
public static final String EXECUTED_BY_FRONTEND = "Executed By Frontend";
// Execution Summary
public static final String EXECUTION_SUMMARY_PROFILE_NAME = "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 INIT_SCAN_NODE_TIME = "Init Scan Node Time";
public static final String FINALIZE_SCAN_NODE_TIME = "Finalize Scan Node
Time";
public static final String GET_SPLITS_TIME = "Get Splits Time";
@@ -96,6 +92,7 @@ public class SummaryProfile {
public static final String WAIT_FETCH_RESULT_TIME = "Wait and Fetch Result
Time";
public static final String FETCH_RESULT_TIME = "Fetch Result Time";
public static final String WRITE_RESULT_TIME = "Write Result Time";
+ public static final String GET_META_VERSION_TIME = "Get Meta Version Time";
public static final String GET_PARTITION_VERSION_TIME = "Get Partition
Version Time";
public static final String GET_PARTITION_VERSION_COUNT = "Get Partition
Version Count";
public static final String GET_PARTITION_VERSION_BY_HAS_DATA_COUNT = "Get
Partition Version Count (hasData)";
@@ -110,9 +107,9 @@ public class SummaryProfile {
public static final String NEREIDS_COLLECT_TABLE_PARTITION_TIME = "Nereids
Collect Table Partition Time";
public static final String NEREIDS_OPTIMIZE_TIME = "Nereids Optimize Time";
public static final String NEREIDS_TRANSLATE_TIME = "Nereids Translate
Time";
- public static final String NEREIDS_DISTRIBUTE_TIME = "Nereids Distribute
Time";
- public static final String NEREIDS_GARBAGE_COLLECT_TIME = "Nereids
GarbageCollect Time";
- public static final String NEREIDS_BE_FOLD_CONST_TIME = "Nereids
BeFoldConst Time";
+ public static final String DISTRIBUTE_TIME = "Distribute Time";
+ public static final String NEREIDS_GARBAGE_COLLECT_TIME = "Garbage Collect
During Plan Time";
+ public static final String NEREIDS_BE_FOLD_CONST_TIME = "Nereids Fold
Const By BE Time";
public static final String FRAGMENT_COMPRESSED_SIZE = "Fragment Compressed
Size";
public static final String FRAGMENT_RPC_COUNT = "Fragment RPC Count";
@@ -145,24 +142,25 @@ public class SummaryProfile {
// The display order of execution summary items.
public static final ImmutableList<String> EXECUTION_SUMMARY_KEYS =
ImmutableList.of(
+ WORKLOAD_GROUP,
PARSE_SQL_TIME,
+ PLAN_TIME,
+ NEREIDS_GARBAGE_COLLECT_TIME,
NEREIDS_LOCK_TABLE_TIME,
NEREIDS_ANALYSIS_TIME,
NEREIDS_REWRITE_TIME,
+ NEREIDS_BE_FOLD_CONST_TIME,
+ NEREIDS_COLLECT_TABLE_PARTITION_TIME,
NEREIDS_OPTIMIZE_TIME,
NEREIDS_TRANSLATE_TIME,
- WORKLOAD_GROUP,
- ANALYSIS_TIME,
- PLAN_TIME,
- JOIN_REORDER_TIME,
- CREATE_SINGLE_NODE_TIME,
- QUERY_DISTRIBUTED_TIME,
INIT_SCAN_NODE_TIME,
FINALIZE_SCAN_NODE_TIME,
GET_SPLITS_TIME,
GET_PARTITIONS_TIME,
GET_PARTITION_FILES_TIME,
CREATE_SCAN_RANGE_TIME,
+ DISTRIBUTE_TIME,
+ GET_META_VERSION_TIME,
GET_PARTITION_VERSION_TIME,
GET_PARTITION_VERSION_BY_HAS_DATA_COUNT,
GET_PARTITION_VERSION_COUNT,
@@ -189,21 +187,25 @@ public class SummaryProfile {
TRANSACTION_COMMIT_TIME,
SYSTEM_MESSAGE,
EXECUTED_BY_FRONTEND,
- NEREIDS_BE_FOLD_CONST_TIME,
- NEREIDS_GARBAGE_COLLECT_TIME,
SPLITS_ASSIGNMENT_WEIGHT
);
// Ident of each item. Default is 0, which doesn't need to present in this
Map.
// Please set this map for new profile items if they need ident.
- public static ImmutableMap<String, Integer>
EXECUTION_SUMMARY_KEYS_IDENTATION
+ public static ImmutableMap<String, Integer>
EXECUTION_SUMMARY_KEYS_INDENTATION
= ImmutableMap.<String, Integer>builder()
- .put(JOIN_REORDER_TIME, 1)
- .put(CREATE_SINGLE_NODE_TIME, 1)
- .put(QUERY_DISTRIBUTED_TIME, 1)
- .put(INIT_SCAN_NODE_TIME, 1)
- .put(FINALIZE_SCAN_NODE_TIME, 1)
- .put(GET_SPLITS_TIME, 2)
+ .put(NEREIDS_GARBAGE_COLLECT_TIME, 1)
+ .put(NEREIDS_LOCK_TABLE_TIME, 1)
+ .put(NEREIDS_ANALYSIS_TIME, 1)
+ .put(NEREIDS_REWRITE_TIME, 1)
+ .put(NEREIDS_COLLECT_TABLE_PARTITION_TIME, 1)
+ .put(NEREIDS_OPTIMIZE_TIME, 1)
+ .put(NEREIDS_TRANSLATE_TIME, 1)
+ .put(INIT_SCAN_NODE_TIME, 2)
+ .put(FINALIZE_SCAN_NODE_TIME, 2)
+ .put(GET_SPLITS_TIME, 3)
+ .put(DISTRIBUTE_TIME, 1)
+ .put(NEREIDS_BE_FOLD_CONST_TIME, 2)
.put(GET_PARTITIONS_TIME, 3)
.put(GET_PARTITION_FILES_TIME, 3)
.put(CREATE_SCAN_RANGE_TIME, 2)
@@ -256,22 +258,11 @@ public class SummaryProfile {
private long nereidsGarbageCollectionTime = -1;
@SerializedName(value = "nereidsBeFoldConstTime")
private long nereidsBeFoldConstTime = 0;
- private long nereidsDistributeFinishTime = -1;
+ @SerializedName(value = "distributeFinishTime")
+ private long distributeFinishTime = -1;
// timestamp of query begin
@SerializedName(value = "queryBeginTime")
private long queryBeginTime = -1;
- // Analysis end time
- @SerializedName(value = "queryAnalysisFinishTime")
- private long queryAnalysisFinishTime = -1;
- // Join reorder end time
- @SerializedName(value = "queryJoinReorderFinishTime")
- private long queryJoinReorderFinishTime = -1;
- // Create single node plan end time
- @SerializedName(value = "queryCreateSingleNodeFinishTime")
- private long queryCreateSingleNodeFinishTime = -1;
- // Create distribute plan end time
- @SerializedName(value = "queryDistributedFinishTime")
- private long queryDistributedFinishTime = -1;
@SerializedName(value = "initScanNodeStartTime")
private long initScanNodeStartTime = -1;
@SerializedName(value = "initScanNodeFinishTime")
@@ -450,6 +441,8 @@ public class SummaryProfile {
private void updateExecutionSummaryProfile() {
executionSummaryProfile.addInfoString(PARSE_SQL_TIME,
getPrettyParseSqlTime());
+ executionSummaryProfile.addInfoString(PLAN_TIME,
+ getPrettyTime(queryPlanFinishTime, parseSqlFinishTime,
TUnit.TIME_MS));
executionSummaryProfile.addInfoString(NEREIDS_LOCK_TABLE_TIME,
getPrettyNereidsLockTableTime());
executionSummaryProfile.addInfoString(NEREIDS_ANALYSIS_TIME,
getPrettyNereidsAnalysisTime());
executionSummaryProfile.addInfoString(NEREIDS_REWRITE_TIME,
getPrettyNereidsRewriteTime());
@@ -457,19 +450,9 @@ public class SummaryProfile {
getPrettyNereidsCollectTablePartitionTime());
executionSummaryProfile.addInfoString(NEREIDS_OPTIMIZE_TIME,
getPrettyNereidsOptimizeTime());
executionSummaryProfile.addInfoString(NEREIDS_TRANSLATE_TIME,
getPrettyNereidsTranslateTime());
- executionSummaryProfile.addInfoString(NEREIDS_DISTRIBUTE_TIME,
getPrettyNereidsDistributeTime());
+ executionSummaryProfile.addInfoString(DISTRIBUTE_TIME,
getPrettyDistributeTime());
executionSummaryProfile.addInfoString(NEREIDS_GARBAGE_COLLECT_TIME,
getPrettyNereidsGarbageCollectionTime());
executionSummaryProfile.addInfoString(NEREIDS_BE_FOLD_CONST_TIME,
getPrettyNereidsBeFoldConstTime());
- executionSummaryProfile.addInfoString(ANALYSIS_TIME,
- getPrettyTime(queryAnalysisFinishTime, queryBeginTime,
TUnit.TIME_MS));
- executionSummaryProfile.addInfoString(PLAN_TIME,
- getPrettyTime(queryPlanFinishTime, queryAnalysisFinishTime,
TUnit.TIME_MS));
- executionSummaryProfile.addInfoString(JOIN_REORDER_TIME,
- getPrettyTime(queryJoinReorderFinishTime,
queryAnalysisFinishTime, TUnit.TIME_MS));
- executionSummaryProfile.addInfoString(CREATE_SINGLE_NODE_TIME,
- getPrettyTime(queryCreateSingleNodeFinishTime,
queryJoinReorderFinishTime, TUnit.TIME_MS));
- executionSummaryProfile.addInfoString(QUERY_DISTRIBUTED_TIME,
- getPrettyTime(queryDistributedFinishTime,
queryCreateSingleNodeFinishTime, TUnit.TIME_MS));
executionSummaryProfile.addInfoString(INIT_SCAN_NODE_TIME,
getPrettyTime(initScanNodeFinishTime, initScanNodeStartTime,
TUnit.TIME_MS));
executionSummaryProfile.addInfoString(FINALIZE_SCAN_NODE_TIME,
@@ -505,6 +488,7 @@ public class SummaryProfile {
setTransactionSummary();
if (Config.isCloudMode()) {
+ executionSummaryProfile.addInfoString(GET_META_VERSION_TIME,
getPrettyGetMetaVersionTime());
executionSummaryProfile.addInfoString(GET_PARTITION_VERSION_TIME,
getPrettyGetPartitionVersionTime());
executionSummaryProfile.addInfoString(GET_PARTITION_VERSION_COUNT,
getPrettyGetPartitionVersionCount());
executionSummaryProfile.addInfoString(GET_PARTITION_VERSION_BY_HAS_DATA_COUNT,
@@ -585,26 +569,14 @@ public class SummaryProfile {
this.nereidsBeFoldConstTime += beFoldConstTimeOnce;
}
- public void setNereidsDistributeTime() {
- this.nereidsDistributeFinishTime = TimeUtils.getStartTimeMs();
+ public void setDistributeTime() {
+ this.distributeFinishTime = TimeUtils.getStartTimeMs();
}
public void setQueryBeginTime(long queryBeginTime) {
this.queryBeginTime = queryBeginTime;
}
- public void setQueryAnalysisFinishTime() {
- this.queryAnalysisFinishTime = TimeUtils.getStartTimeMs();
- }
-
- public void setQueryJoinReorderFinishTime() {
- this.queryJoinReorderFinishTime = TimeUtils.getStartTimeMs();
- }
-
- public void setCreateSingleNodeFinishTime() {
- this.queryCreateSingleNodeFinishTime = TimeUtils.getStartTimeMs();
- }
-
public void setInitScanNodeStartTime() {
this.initScanNodeStartTime = TimeUtils.getStartTimeMs();
}
@@ -641,10 +613,6 @@ public class SummaryProfile {
this.createScanRangeFinishTime = TimeUtils.getStartTimeMs();
}
- public void setQueryDistributedFinishTime() {
- this.queryDistributedFinishTime = TimeUtils.getStartTimeMs();
- }
-
public void setQueryPlanFinishTime() {
if (queryPlanFinishTime == -1) {
this.queryPlanFinishTime = TimeUtils.getStartTimeMs();
@@ -824,7 +792,7 @@ public class SummaryProfile {
}
public String getPrettyNereidsLockTableTime() {
- return getPrettyTime(nereidsLockTableFinishTime, parseSqlStartTime,
TUnit.TIME_MS);
+ return getPrettyTime(nereidsLockTableFinishTime, parseSqlFinishTime,
TUnit.TIME_MS);
}
public String getPrettyNereidsAnalysisTime() {
@@ -858,8 +826,13 @@ public class SummaryProfile {
return RuntimeProfile.printCounter(nereidsBeFoldConstTime,
TUnit.TIME_MS);
}
- public String getPrettyNereidsDistributeTime() {
- return getPrettyTime(nereidsDistributeFinishTime,
nereidsTranslateFinishTime, TUnit.TIME_MS);
+ public String getPrettyDistributeTime() {
+ return getPrettyTime(distributeFinishTime, nereidsTranslateFinishTime,
TUnit.TIME_MS);
+ }
+
+ private String getPrettyGetMetaVersionTime() {
+ long getMetaVersionTime = getPartitionVersionTime +
getTableVersionTime;
+ return getPrettyTime(getMetaVersionTime, 0, TUnit.TIME_MS);
}
private String getPrettyGetPartitionVersionTime() {
diff --git
a/fe/fe-core/src/main/java/org/apache/doris/nereids/NereidsPlanner.java
b/fe/fe-core/src/main/java/org/apache/doris/nereids/NereidsPlanner.java
index a405edf3efd..9949835af41 100644
--- a/fe/fe-core/src/main/java/org/apache/doris/nereids/NereidsPlanner.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/nereids/NereidsPlanner.java
@@ -382,7 +382,6 @@ public class NereidsPlanner extends Planner {
}
if (statementContext.getConnectContext().getExecutor() != null) {
-
statementContext.getConnectContext().getExecutor().getSummaryProfile().setQueryAnalysisFinishTime();
statementContext.getConnectContext().getExecutor().getSummaryProfile().setNereidsAnalysisTime();
}
}
@@ -545,7 +544,7 @@ public class NereidsPlanner extends Planner {
distributedPlans = new DistributePlanner(fragments).plan();
if (statementContext.getConnectContext().getExecutor() != null) {
-
statementContext.getConnectContext().getExecutor().getSummaryProfile().setNereidsDistributeTime();
+
statementContext.getConnectContext().getExecutor().getSummaryProfile().setDistributeTime();
}
}
@@ -733,7 +732,7 @@ public class NereidsPlanner extends Planner {
if (distributedPlans != null && !distributedPlans.isEmpty()) {
plan += "========== DISTRIBUTED PLAN "
- +
getTimeMetricString(SummaryProfile::getPrettyNereidsDistributeTime) + "
==========\n";
+ +
getTimeMetricString(SummaryProfile::getPrettyDistributeTime) + " ==========\n";
plan +=
DistributedPlan.toString(Lists.newArrayList(distributedPlans.values())) +
"\n\n";
}
plan += mvSummary;
diff --git
a/fe/fe-core/src/main/java/org/apache/doris/planner/OriginalPlanner.java
b/fe/fe-core/src/main/java/org/apache/doris/planner/OriginalPlanner.java
index 8d2ed4a4926..5371774989f 100644
--- a/fe/fe-core/src/main/java/org/apache/doris/planner/OriginalPlanner.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/planner/OriginalPlanner.java
@@ -163,9 +163,6 @@ 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) {
@@ -219,9 +216,6 @@ 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.
diff --git
a/fe/fe-core/src/main/java/org/apache/doris/planner/SingleNodePlanner.java
b/fe/fe-core/src/main/java/org/apache/doris/planner/SingleNodePlanner.java
index 693d9ede950..bc162f952fa 100644
--- a/fe/fe-core/src/main/java/org/apache/doris/planner/SingleNodePlanner.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/planner/SingleNodePlanner.java
@@ -290,9 +290,6 @@ public class SingleNodePlanner {
Preconditions.checkState(stmt instanceof SetOperationStmt);
root = createSetOperationPlan((SetOperationStmt) stmt, analyzer,
newDefaultOrderByLimit, sqlSelectLimit);
}
- 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;
diff --git a/fe/fe-core/src/main/java/org/apache/doris/qe/Coordinator.java
b/fe/fe-core/src/main/java/org/apache/doris/qe/Coordinator.java
index d05fb4e3694..8496c6d4160 100644
--- a/fe/fe-core/src/main/java/org/apache/doris/qe/Coordinator.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/qe/Coordinator.java
@@ -609,15 +609,20 @@ public class Coordinator implements CoordInterface {
}
protected void processFragmentAssignmentAndParams() throws Exception {
- // prepare information
- prepare();
- // compute Fragment Instance
- computeScanRangeAssignment();
+ try {
+ // prepare information
+ prepare();
+ // compute Fragment Instance
+ computeScanRangeAssignment();
- computeFragmentExecParams();
+ computeFragmentExecParams();
+ } finally {
+ if (context != null && context.getExecutor() != null) {
+ context.getExecutor().getSummaryProfile().setDistributeTime();
+ }
+ }
}
-
public TPipelineFragmentParams getStreamLoadPlan() throws Exception {
processFragmentAssignmentAndParams();
diff --git a/fe/fe-core/src/main/java/org/apache/doris/qe/StmtExecutor.java
b/fe/fe-core/src/main/java/org/apache/doris/qe/StmtExecutor.java
index 29d9f4574ad..90b51123771 100644
--- a/fe/fe-core/src/main/java/org/apache/doris/qe/StmtExecutor.java
+++ b/fe/fe-core/src/main/java/org/apache/doris/qe/StmtExecutor.java
@@ -832,8 +832,10 @@ public class StmtExecutor {
} catch (Exception e) {
LOG.warn("Nereids plan query failed:\n{}",
originStmt.originStmt, e);
throw new NereidsException(new
AnalysisException(e.getMessage(), e));
+ } finally {
+ profile.getSummaryProfile().setQueryPlanFinishTime();
}
- profile.getSummaryProfile().setQueryPlanFinishTime();
+
handleQueryWithRetry(queryId);
}
}
@@ -861,7 +863,9 @@ public class StmtExecutor {
}
List<StatementBase> statements;
try {
+
getProfile().getSummaryProfile().setParseSqlStartTime(System.currentTimeMillis());
statements = new NereidsParser().parseSQL(originStmt.originStmt,
context.getSessionVariable());
+
getProfile().getSummaryProfile().setParseSqlFinishTime(System.currentTimeMillis());
} catch (Exception e) {
throw new ParseException("Nereids parse failed. " +
e.getMessage());
}
@@ -1546,7 +1550,6 @@ public class StmtExecutor {
}
}
}
- profile.getSummaryProfile().setQueryAnalysisFinishTime();
planner = new OriginalPlanner(analyzer);
if (parsedStmt instanceof QueryStmt || parsedStmt instanceof
InsertStmt) {
planner.plan(parsedStmt, tQueryOptions);
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
