From ac3aef8c667ad020f876328b49d7fbca16d7a706 Mon Sep 17 00:00:00 2001 From: "mergify[bot]" <37929162+mergify[bot]@users.noreply.github.com> Date: Mon, 2 Dec 2024 16:00:25 +0800 Subject: [PATCH] [Enhancement] Add pendingTime/netTime/netComputeTime to queryDetail (backport #53322) (#53377) Co-authored-by: satanson --- .../starrocks/common/profile/TimeWatcher.java | 5 +++ .../com/starrocks/common/profile/Tracer.java | 5 +++ .../starrocks/common/profile/TracerImpl.java | 6 +++ .../com/starrocks/common/profile/Tracers.java | 6 +++ .../java/com/starrocks/qe/QueryDetail.java | 28 +++++++++++++ .../java/com/starrocks/qe/StmtExecutor.java | 9 ++++ .../starrocks/qe/QueryDetailQueueTest.java | 41 +++++++++++-------- 7 files changed, 82 insertions(+), 18 deletions(-) diff --git a/fe/fe-core/src/main/java/com/starrocks/common/profile/TimeWatcher.java b/fe/fe-core/src/main/java/com/starrocks/common/profile/TimeWatcher.java index 6e3dc6f7111e4..cc806faf7974a 100644 --- a/fe/fe-core/src/main/java/com/starrocks/common/profile/TimeWatcher.java +++ b/fe/fe-core/src/main/java/com/starrocks/common/profile/TimeWatcher.java @@ -22,6 +22,7 @@ import java.util.LinkedHashMap; import java.util.List; import java.util.Map; +import java.util.Optional; import java.util.concurrent.TimeUnit; import java.util.stream.Collectors; @@ -42,6 +43,10 @@ public Timer scope(long time, String name) { return t; } + public Optional getTimer(String name) { + return Optional.ofNullable(timers.get(name)); + } + public List getAllTimerWithOrder() { return timers.values().stream().sorted(Comparator.comparingLong(o -> o.firstTimePoints)) .collect(Collectors.toList()); diff --git a/fe/fe-core/src/main/java/com/starrocks/common/profile/Tracer.java b/fe/fe-core/src/main/java/com/starrocks/common/profile/Tracer.java index 5732bfac5b242..ec180eb05ab78 100644 --- a/fe/fe-core/src/main/java/com/starrocks/common/profile/Tracer.java +++ b/fe/fe-core/src/main/java/com/starrocks/common/profile/Tracer.java @@ -18,6 +18,7 @@ import java.util.Collections; import java.util.List; +import java.util.Optional; import java.util.function.Function; public abstract class Tracer { @@ -71,4 +72,8 @@ public String printReasons() { public void toRuntimeProfile(RuntimeProfile parent) { } + + public Optional getSpecifiedTimer(String name) { + return Optional.empty(); + } } diff --git a/fe/fe-core/src/main/java/com/starrocks/common/profile/TracerImpl.java b/fe/fe-core/src/main/java/com/starrocks/common/profile/TracerImpl.java index c2c352232c64d..89b3b1187f495 100644 --- a/fe/fe-core/src/main/java/com/starrocks/common/profile/TracerImpl.java +++ b/fe/fe-core/src/main/java/com/starrocks/common/profile/TracerImpl.java @@ -20,6 +20,7 @@ import java.util.HashMap; import java.util.List; import java.util.Map; +import java.util.Optional; import java.util.TreeMap; import java.util.concurrent.TimeUnit; import java.util.function.Function; @@ -242,4 +243,9 @@ public void toRuntimeProfile(RuntimeProfile parent) { buildVars(parent); buildReasons(parent); } + + @Override + public Optional getSpecifiedTimer(String name) { + return watcher.getTimer(name); + } } diff --git a/fe/fe-core/src/main/java/com/starrocks/common/profile/Tracers.java b/fe/fe-core/src/main/java/com/starrocks/common/profile/Tracers.java index c9f09bc883247..ddba1ccbf2f2c 100644 --- a/fe/fe-core/src/main/java/com/starrocks/common/profile/Tracers.java +++ b/fe/fe-core/src/main/java/com/starrocks/common/profile/Tracers.java @@ -20,6 +20,7 @@ import org.apache.commons.lang3.StringUtils; import java.util.List; +import java.util.Optional; import java.util.function.Function; public class Tracers { @@ -258,6 +259,11 @@ public static void toRuntimeProfile(RuntimeProfile profile) { tracers.allTracer[1].toRuntimeProfile(profile); } + public static Optional getSpecifiedTimer(String name) { + Tracers tracers = THREAD_LOCAL.get(); + return tracers.allTracer[1].getSpecifiedTimer(name); + } + public static String getTrace(Mode mode) { switch (mode) { case TIMER: diff --git a/fe/fe-core/src/main/java/com/starrocks/qe/QueryDetail.java b/fe/fe-core/src/main/java/com/starrocks/qe/QueryDetail.java index 44dafcf821876..ae01413f78eb0 100644 --- a/fe/fe-core/src/main/java/com/starrocks/qe/QueryDetail.java +++ b/fe/fe-core/src/main/java/com/starrocks/qe/QueryDetail.java @@ -65,6 +65,10 @@ public enum QueryMemState { // default value will set to be minus one(-1). private long endTime; private long latency; + + private long pendingTime = -1; + private long netTime = -1; + private long netComputeTime = -1; private QueryMemState state; private String database; private String sql; @@ -207,6 +211,30 @@ public long getLatency() { return latency; } + public long getPendingTime() { + return pendingTime; + } + + public void setPendingTime(long pendingTime) { + this.pendingTime = pendingTime; + } + + public long getNetTime() { + return netTime; + } + + public void setNetTime(long netTime) { + this.netTime = netTime; + } + + public long getNetComputeTime() { + return netComputeTime; + } + + public void setNetComputeTime(long netComputeTime) { + this.netComputeTime = netComputeTime; + } + public void setState(QueryMemState state) { this.state = state; } diff --git a/fe/fe-core/src/main/java/com/starrocks/qe/StmtExecutor.java b/fe/fe-core/src/main/java/com/starrocks/qe/StmtExecutor.java index ee70c62a5d384..1bf8b07842da6 100644 --- a/fe/fe-core/src/main/java/com/starrocks/qe/StmtExecutor.java +++ b/fe/fe-core/src/main/java/com/starrocks/qe/StmtExecutor.java @@ -2860,6 +2860,15 @@ public void addFinishedQueryDetail() { } queryDetail.setEndTime(endTime); queryDetail.setLatency(elapseMs); + long pendingTime = ctx.getAuditEventBuilder().build().pendingTimeMs; + pendingTime = pendingTime < 0 ? 0 : pendingTime; + queryDetail.setPendingTime(pendingTime); + queryDetail.setNetTime(elapseMs - pendingTime); + long parseTime = Tracers.getSpecifiedTimer("Parser").map(Timer::getTotalTime).orElse(0L); + long planTime = Tracers.getSpecifiedTimer("Total").map(Timer::getTotalTime).orElse(0L); + long prepareTime = Tracers.getSpecifiedTimer("Prepare").map(Timer::getTotalTime).orElse(0L); + long deployTime = Tracers.getSpecifiedTimer("Deploy").map(Timer::getTotalTime).orElse(0L); + queryDetail.setNetComputeTime(elapseMs - parseTime - planTime - prepareTime - pendingTime - deployTime); queryDetail.setResourceGroupName(ctx.getResourceGroup() != null ? ctx.getResourceGroup().getName() : ""); // add execution statistics into queryDetail queryDetail.setReturnRows(ctx.getReturnRows()); diff --git a/fe/fe-core/src/test/java/com/starrocks/qe/QueryDetailQueueTest.java b/fe/fe-core/src/test/java/com/starrocks/qe/QueryDetailQueueTest.java index 9b72dc814cf54..38745eb5ba487 100644 --- a/fe/fe-core/src/test/java/com/starrocks/qe/QueryDetailQueueTest.java +++ b/fe/fe-core/src/test/java/com/starrocks/qe/QueryDetailQueueTest.java @@ -63,24 +63,29 @@ public void testQueryDetailQueue() { Gson gson = new Gson(); String jsonString = gson.toJson(queryDetails); - String queryDetailString = "[{\"eventTime\":" + startQueryDetail.getEventTime() + "," - + "\"queryId\":\"219a2d5443c542d4-8fc938db37c892e3\"," - + "\"isQuery\":false," - + "\"remoteIP\":\"127.0.0.1\"," - + "\"connId\":1," - + "\"startTime\":" + startQueryDetail.getStartTime() + ",\"endTime\":-1,\"latency\":-1," - + "\"state\":\"RUNNING\",\"database\":\"testDb\"," - + "\"sql\":\"select * from table1 limit 1\"," - + "\"user\":\"root\"," - + "\"scanRows\":100," - + "\"scanBytes\":10001," - + "\"returnRows\":1," - + "\"cpuCostNs\":1002," - + "\"memCostBytes\":100003," - + "\"spillBytes\":-1," - + "\"warehouse\":\"default_warehouse\"," - + "\"catalog\":\"default_catalog\"" - + "}]"; + String queryDetailString = "[{\"eventTime\":" + startQueryDetail.getEventTime() + "," + + "\"queryId\":\"219a2d5443c542d4-8fc938db37c892e3\"," + + "\"isQuery\":false," + + "\"remoteIP\":\"127.0.0.1\"," + + "\"connId\":1," + + "\"startTime\":" + startQueryDetail.getStartTime() + "," + + "\"endTime\":-1," + + "\"latency\":-1," + + "\"pendingTime\":-1," + + "\"netTime\":-1," + + "\"netComputeTime\":-1," + + "\"state\":\"RUNNING\"," + + "\"database\":\"testDb\"," + + "\"sql\":\"select * from table1 limit 1\"," + + "\"user\":\"root\"," + + "\"scanRows\":100," + + "\"scanBytes\":10001," + + "\"returnRows\":1," + + "\"cpuCostNs\":1002," + + "\"memCostBytes\":100003," + + "\"spillBytes\":-1," + + "\"warehouse\":\"default_warehouse\"," + + "\"catalog\":\"default_catalog\"}]"; Assert.assertEquals(jsonString, queryDetailString); queryDetails = QueryDetailQueue.getQueryDetailsAfterTime(startQueryDetail.getEventTime());