This is an automated email from the ASF dual-hosted git repository. yiguolei pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/doris.git
The following commit(s) were added to refs/heads/master by this push: new fb78807430 [Exec](Profile) Register to Fetch Result time and Write Result time in FE to debug (#14832) fb78807430 is described below commit fb78807430115b635c16d1510a04d81bb3e2ee98 Author: HappenLee <happen...@hotmail.com> AuthorDate: Tue Dec 6 14:32:18 2022 +0800 [Exec](Profile) Register to Fetch Result time and Write Result time in FE to debug (#14832) --- .../doris/common/util/QueryPlannerProfile.java | 30 ++++++++++++++++++++-- .../java/org/apache/doris/qe/StmtExecutor.java | 8 ++++++ 2 files changed, 36 insertions(+), 2 deletions(-) diff --git a/fe/fe-core/src/main/java/org/apache/doris/common/util/QueryPlannerProfile.java b/fe/fe-core/src/main/java/org/apache/doris/common/util/QueryPlannerProfile.java index 6ea3efa560..df5ae5aee2 100644 --- a/fe/fe-core/src/main/java/org/apache/doris/common/util/QueryPlannerProfile.java +++ b/fe/fe-core/src/main/java/org/apache/doris/common/util/QueryPlannerProfile.java @@ -30,7 +30,11 @@ public class QueryPlannerProfile { public static final String KEY_ANALYSIS = "Analysis Time"; public static final String KEY_PLAN = "Plan Time"; public static final String KEY_SCHEDULE = "Schedule Time"; - public static final String KEY_FETCH = "Wait and Fetch Result Time"; + public static final String KEY_WAIT_AND_FETCH = "Wait and Fetch Result Time"; + + public static final String KEY_FETCH = "Fetch Result Time"; + + public static final String KEY_WRITE = "Write Result Time"; // timestamp of query begin private long queryBeginTime = -1; @@ -43,6 +47,12 @@ public class QueryPlannerProfile { // Query result fetch end time private long queryFetchResultFinishTime = -1; + private long tempStarTime = -1; + + private long queryFetchResultConsumeTime = 0; + + private long queryWriteResultConsumeTime = 0; + public void setQueryBeginTime() { this.queryBeginTime = TimeUtils.getStartTime(); } @@ -63,6 +73,18 @@ public class QueryPlannerProfile { this.queryFetchResultFinishTime = TimeUtils.getStartTime(); } + public void setTempStartTime() { + this.tempStarTime = TimeUtils.getStartTime(); + } + + public void freshFetchResultConsumeTime() { + this.queryFetchResultConsumeTime += TimeUtils.getStartTime() - tempStarTime; + } + + public void freshWriteResultConsumeTime() { + this.queryWriteResultConsumeTime += TimeUtils.getStartTime() - tempStarTime; + } + public long getQueryBeginTime() { return queryBeginTime; } @@ -99,6 +121,10 @@ public class QueryPlannerProfile { plannerProfile.addInfoString(KEY_ANALYSIS, getPrettyQueryAnalysisFinishTime()); plannerProfile.addInfoString(KEY_PLAN, getPrettyQueryPlanFinishTime()); plannerProfile.addInfoString(KEY_SCHEDULE, getPrettyQueryScheduleFinishTime()); - plannerProfile.addInfoString(KEY_FETCH, getPrettyQueryFetchResultFinishTime()); + plannerProfile.addInfoString(KEY_FETCH, + RuntimeProfile.printCounter(queryFetchResultConsumeTime, TUnit.TIME_NS)); + plannerProfile.addInfoString(KEY_WRITE, + RuntimeProfile.printCounter(queryWriteResultConsumeTime, TUnit.TIME_NS)); + plannerProfile.addInfoString(KEY_WAIT_AND_FETCH, getPrettyQueryFetchResultFinishTime()); } } 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 f06fcbb1ec..a4a8c44496 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 @@ -1135,12 +1135,19 @@ public class StmtExecutor implements ProfileWriter { Span fetchResultSpan = context.getTracer().spanBuilder("fetch result").setParent(Context.current()).startSpan(); try (Scope scope = fetchResultSpan.makeCurrent()) { while (true) { + // register the fetch result time. + plannerProfile.setTempStartTime(); batch = coord.getNext(); + plannerProfile.freshFetchResultConsumeTime(); + // for outfile query, there will be only one empty batch send back with eos flag if (batch.getBatch() != null) { if (cacheAnalyzer != null) { cacheAnalyzer.copyRowBatch(batch); } + + // register send field result time. + plannerProfile.setTempStartTime(); // For some language driver, getting error packet after fields packet // will be recognized as a success result // so We need to send fields after first batch arrived @@ -1155,6 +1162,7 @@ public class StmtExecutor implements ProfileWriter { for (ByteBuffer row : batch.getBatch().getRows()) { channel.sendOnePacket(row); } + plannerProfile.freshWriteResultConsumeTime(); context.updateReturnRows(batch.getBatch().getRows().size()); } if (batch.isEos()) { --------------------------------------------------------------------- To unsubscribe, e-mail: commits-unsubscr...@doris.apache.org For additional commands, e-mail: commits-h...@doris.apache.org