This is an automated email from the ASF dual-hosted git repository.
morrysnow pushed a commit to branch branch-3.0
in repository https://gitbox.apache.org/repos/asf/doris.git
The following commit(s) were added to refs/heads/branch-3.0 by this push:
new e13a3e9e8cf [Impl](Nereids) add nereids gc cost time and be fold const
cost time to profile (#42007) (#42518)
e13a3e9e8cf is described below
commit e13a3e9e8cfe7704df17f3735b19b2fc3f409cae
Author: LiBinfeng <[email protected]>
AuthorDate: Tue Oct 29 11:36:37 2024 +0800
[Impl](Nereids) add nereids gc cost time and be fold const cost time to
profile (#42007) (#42518)
pick from master #42007
add Nereids GarbageCollect Time and Nereids BeFoldConst Time to profile
---
.../doris/common/profile/SummaryProfile.java | 24 ++++++++++++++++++++++
.../org/apache/doris/nereids/NereidsPlanner.java | 16 +++++++++++++++
.../expression/rules/FoldConstantRuleOnBE.java | 8 +++++++-
.../suites/query_profile/test_profile.groovy | 16 +++++++++++++++
4 files changed, 63 insertions(+), 1 deletion(-)
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 8356bc34a13..323566c5161 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
@@ -102,6 +102,8 @@ public class SummaryProfile {
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 FRAGMENT_COMPRESSED_SIZE = "Fragment Compressed
Size";
public static final String FRAGMENT_RPC_COUNT = "Fragment RPC Count";
@@ -229,6 +231,10 @@ public class SummaryProfile {
private long nereidsOptimizeFinishTime = -1;
@SerializedName(value = "nereidsTranslateFinishTime")
private long nereidsTranslateFinishTime = -1;
+ @SerializedName(value = "nereidsGarbageCollectionTime")
+ private long nereidsGarbageCollectionTime = -1;
+ @SerializedName(value = "nereidsBeFoldConstTime")
+ private long nereidsBeFoldConstTime = 0;
private long nereidsDistributeFinishTime = -1;
// timestamp of query begin
@SerializedName(value = "queryBeginTime")
@@ -408,6 +414,8 @@ public class SummaryProfile {
executionSummaryProfile.addInfoString(NEREIDS_OPTIMIZE_TIME,
getPrettyNereidsOptimizeTime());
executionSummaryProfile.addInfoString(NEREIDS_TRANSLATE_TIME,
getPrettyNereidsTranslateTime());
executionSummaryProfile.addInfoString(NEREIDS_DISTRIBUTE_TIME,
getPrettyNereidsDistributeTime());
+ 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,
@@ -513,6 +521,14 @@ public class SummaryProfile {
this.nereidsTranslateFinishTime = TimeUtils.getStartTimeMs();
}
+ public void setNereidsGarbageCollectionTime(long
nereidsGarbageCollectionTime) {
+ this.nereidsGarbageCollectionTime = nereidsGarbageCollectionTime;
+ }
+
+ public void sumBeFoldTime(long beFoldConstTimeOnce) {
+ this.nereidsBeFoldConstTime += beFoldConstTimeOnce;
+ }
+
public void setNereidsDistributeTime() {
this.nereidsDistributeFinishTime = TimeUtils.getStartTimeMs();
}
@@ -765,6 +781,14 @@ public class SummaryProfile {
return getPrettyTime(nereidsTranslateFinishTime,
nereidsOptimizeFinishTime, TUnit.TIME_MS);
}
+ public String getPrettyNereidsGarbageCollectionTime() {
+ return RuntimeProfile.printCounter(nereidsGarbageCollectionTime,
TUnit.TIME_MS);
+ }
+
+ public String getPrettyNereidsBeFoldConstTime() {
+ return RuntimeProfile.printCounter(nereidsBeFoldConstTime,
TUnit.TIME_MS);
+ }
+
public String getPrettyNereidsDistributeTime() {
return getPrettyTime(nereidsDistributeFinishTime,
nereidsTranslateFinishTime, TUnit.TIME_MS);
}
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 3ef68969455..4acae7164f8 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
@@ -82,6 +82,8 @@ import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import java.io.IOException;
+import java.lang.management.GarbageCollectorMXBean;
+import java.lang.management.ManagementFactory;
import java.nio.ByteBuffer;
import java.util.ArrayList;
import java.util.List;
@@ -187,6 +189,7 @@ public class NereidsPlanner extends Planner {
ExplainLevel explainLevel, boolean showPlanProcess,
Consumer<Plan> lockCallback) {
try {
+ long beforePlanGcTime = getGarbageCollectionTime();
if (plan instanceof LogicalSqlCache) {
rewrittenPlan = analyzedPlan = plan;
LogicalSqlCache logicalSqlCache = (LogicalSqlCache) plan;
@@ -214,6 +217,10 @@ public class NereidsPlanner extends Planner {
try (Lock lock = new Lock(plan, cascadesContext)) {
Plan resultPlan = planWithoutLock(plan, explainLevel,
showPlanProcess, requireProperties);
lockCallback.accept(resultPlan);
+ if (statementContext.getConnectContext().getExecutor() !=
null) {
+
statementContext.getConnectContext().getExecutor().getSummaryProfile()
+
.setNereidsGarbageCollectionTime(getGarbageCollectionTime() - beforePlanGcTime);
+ }
return resultPlan;
}
} finally {
@@ -536,6 +543,15 @@ public class NereidsPlanner extends Planner {
}
}
+ private long getGarbageCollectionTime() {
+ List<GarbageCollectorMXBean> gcMxBeans =
ManagementFactory.getGarbageCollectorMXBeans();
+ long initialGCTime = 0;
+ for (GarbageCollectorMXBean gcBean : gcMxBeans) {
+ initialGCTime += gcBean.getCollectionTime();
+ }
+ return initialGCTime;
+ }
+
/**
* getting hints explain string, which specified by enumerate and show in
lists
* @param hints hint map recorded in statement context
diff --git
a/fe/fe-core/src/main/java/org/apache/doris/nereids/rules/expression/rules/FoldConstantRuleOnBE.java
b/fe/fe-core/src/main/java/org/apache/doris/nereids/rules/expression/rules/FoldConstantRuleOnBE.java
index fc6112834a0..dedd1b35bd7 100644
---
a/fe/fe-core/src/main/java/org/apache/doris/nereids/rules/expression/rules/FoldConstantRuleOnBE.java
+++
b/fe/fe-core/src/main/java/org/apache/doris/nereids/rules/expression/rules/FoldConstantRuleOnBE.java
@@ -268,7 +268,6 @@ public class FoldConstantRuleOnBE implements
ExpressionPatternRuleFactory {
private static Map<String, Expression> evalOnBE(Map<String, Map<String,
TExpr>> paramMap,
Map<String, Expression> constMap, ConnectContext context) {
-
Map<String, Expression> resultMap = new HashMap<>();
try {
List<Long> backendIds =
Env.getCurrentSystemInfo().getAllBackendIds(true);
@@ -300,7 +299,14 @@ public class FoldConstantRuleOnBE implements
ExpressionPatternRuleFactory {
Future<PConstantExprResult> future =
BackendServiceProxy.getInstance().foldConstantExpr(brpcAddress,
tParams);
+ long beFoldStartTime = 0L;
+ if (context.getSessionVariable().enableProfile()) {
+ beFoldStartTime = TimeUtils.getStartTimeMs();
+ }
PConstantExprResult result = future.get(5, TimeUnit.SECONDS);
+ if (context.getExecutor() != null &&
context.getSessionVariable().enableProfile()) {
+
context.getExecutor().getSummaryProfile().sumBeFoldTime(TimeUtils.getStartTimeMs()
- beFoldStartTime);
+ }
if (result.getStatus().getStatusCode() == 0) {
for (Entry<String, InternalService.PExprResultMap> e :
result.getExprResultMapMap().entrySet()) {
diff --git a/regression-test/suites/query_profile/test_profile.groovy
b/regression-test/suites/query_profile/test_profile.groovy
index a40aef615d9..913a15ecb27 100644
--- a/regression-test/suites/query_profile/test_profile.groovy
+++ b/regression-test/suites/query_profile/test_profile.groovy
@@ -79,6 +79,22 @@ suite('test_profile') {
}
assertTrue(isRecorded)
+ sql "set enable_nereids_planner=true"
+ sql "set enable_fallback_to_original_planner=false"
+
+ int randomInt = Math.random() * 2000000000
+ profile("test_profile_time_${randomInt}") {
+ run {
+ sql "/* test_profile_time_${randomInt} */ select ${randomInt} from
test_profile"
+ }
+
+ check { profileString, exception ->
+ log.info(profileString)
+ assertTrue(profileString.contains("Nereids GarbageCollect Time"))
+ assertTrue(profileString.contains("Nereids BeFoldConst Time"))
+ }
+ }
+
sql """ SET enable_profile = false """
sql """ DROP TABLE IF EXISTS test_profile """
}
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
