Expose query starting time

Reported query start time is computed after call to SplitSourceFactory#createSplitSources, and that method may take a lot of time for some connectors.
trinodb · Aug 26, 2024 · 36609d2 · 36609d2
1 parent aa5a6ca
commit 36609d2
Show file tree

Hide file tree

Showing 8 changed files with 26 additions and 0 deletions.
diff --git a/core/trino-main/src/main/java/io/trino/dispatcher/FailedDispatchQuery.java b/core/trino-main/src/main/java/io/trino/dispatcher/FailedDispatchQuery.java
@@ -277,6 +277,7 @@ private static QueryStats immediateFailureQueryStats()
                 new Duration(0, MILLISECONDS),
                 new Duration(0, MILLISECONDS),
                 new Duration(0, MILLISECONDS),
+                new Duration(0, MILLISECONDS),
                 0,
                 0,
                 0,

diff --git a/core/trino-main/src/main/java/io/trino/execution/QueryStateMachine.java b/core/trino-main/src/main/java/io/trino/execution/QueryStateMachine.java
@@ -825,6 +825,7 @@ private QueryStats getQueryStats(Optional<StageInfo> rootStage, List<StageInfo>
                 queryStateTimer.getAnalysisTime(),
                 queryStateTimer.getPlanningTime(),
                 queryStateTimer.getPlanningCpuTime(),
+                queryStateTimer.getStartingTime(),
                 queryStateTimer.getFinishingTime(),
 
                 totalTasks,
@@ -1435,6 +1436,7 @@ private static QueryStats pruneQueryStats(QueryStats queryStats)
                 queryStats.getAnalysisTime(),
                 queryStats.getPlanningTime(),
                 queryStats.getPlanningCpuTime(),
+                queryStats.getStartingTime(),
                 queryStats.getFinishingTime(),
                 queryStats.getTotalTasks(),
                 queryStats.getRunningTasks(),

diff --git a/core/trino-main/src/main/java/io/trino/execution/QueryStateTimer.java b/core/trino-main/src/main/java/io/trino/execution/QueryStateTimer.java
@@ -40,6 +40,7 @@ class QueryStateTimer
     private final AtomicReference<Long> beginDispatchingNanos = new AtomicReference<>();
     private final AtomicReference<Long> beginPlanningNanos = new AtomicReference<>();
     private final AtomicReference<Long> beginPlanningCpuNanos = new AtomicReference<>();
+    private final AtomicReference<Long> beginStartingNanos = new AtomicReference<>();
     private final AtomicReference<Long> beginFinishingNanos = new AtomicReference<>();
     private final AtomicReference<Long> endNanos = new AtomicReference<>();
 
@@ -49,6 +50,7 @@ class QueryStateTimer
     private final AtomicReference<Duration> executionTime = new AtomicReference<>();
     private final AtomicReference<Duration> planningTime = new AtomicReference<>();
     private final AtomicReference<Duration> planningCpuTime = new AtomicReference<>();
+    private final AtomicReference<Duration> startingTime = new AtomicReference<>();
     private final AtomicReference<Duration> finishingTime = new AtomicReference<>();
 
     private final AtomicReference<Long> beginAnalysisNanos = new AtomicReference<>();
@@ -113,6 +115,7 @@ private void beginStarting(long now, long cpuNow)
         beginPlanning(now, cpuNow);
         planningTime.compareAndSet(null, nanosSince(beginPlanningNanos, now));
         planningCpuTime.compareAndSet(null, nanosSince(beginPlanningCpuNanos, cpuNow));
+        beginStartingNanos.compareAndSet(null, now);
     }
 
     public void beginRunning()
@@ -123,6 +126,7 @@ public void beginRunning()
     private void beginRunning(long now)
     {
         beginStarting(now, currentThreadCpuTime());
+        startingTime.compareAndSet(null, nanosSince(beginStartingNanos, now));
     }
 
     public void beginFinishing()
@@ -240,6 +244,11 @@ public Duration getPlanningCpuTime()
         return getDuration(planningCpuTime, beginPlanningCpuNanos);
     }
 
+    public Duration getStartingTime()
+    {
+        return getDuration(startingTime, beginStartingNanos);
+    }
+
     public Duration getFinishingTime()
     {
         return getDuration(finishingTime, beginFinishingNanos);

diff --git a/core/trino-main/src/main/java/io/trino/execution/QueryStats.java b/core/trino-main/src/main/java/io/trino/execution/QueryStats.java
@@ -53,6 +53,7 @@ public class QueryStats
     private final Duration analysisTime;
     private final Duration planningTime;
     private final Duration planningCpuTime;
+    private final Duration startingTime;
     private final Duration finishingTime;
 
     private final int totalTasks;
@@ -147,6 +148,7 @@ public QueryStats(
             @JsonProperty("analysisTime") Duration analysisTime,
             @JsonProperty("planningTime") Duration planningTime,
             @JsonProperty("planningCpuTime") Duration planningCpuTime,
+            @JsonProperty("startingTime") Duration startingTime,
             @JsonProperty("finishingTime") Duration finishingTime,
 
             @JsonProperty("totalTasks") int totalTasks,
@@ -239,6 +241,7 @@ public QueryStats(
         this.analysisTime = requireNonNull(analysisTime, "analysisTime is null");
         this.planningTime = requireNonNull(planningTime, "planningTime is null");
         this.planningCpuTime = requireNonNull(planningCpuTime, "planningCpuTime is null");
+        this.startingTime = requireNonNull(startingTime, "startingTime is null");
         this.finishingTime = requireNonNull(finishingTime, "finishingTime is null");
 
         checkArgument(totalTasks >= 0, "totalTasks is negative");
@@ -410,6 +413,12 @@ public Duration getPlanningCpuTime()
         return planningCpuTime;
     }
 
+    @JsonProperty
+    public Duration getStartingTime()
+    {
+        return startingTime;
+    }
+
     @JsonProperty
     public Duration getFinishingTime()
     {

diff --git a/core/trino-main/src/test/java/io/trino/execution/MockManagedQueryExecution.java b/core/trino-main/src/test/java/io/trino/execution/MockManagedQueryExecution.java
@@ -181,6 +181,7 @@ public QueryInfo getFullQueryInfo()
 
                         new Duration(100, NANOSECONDS),
                         new Duration(150, NANOSECONDS),
+                        new Duration(160, NANOSECONDS),
                         new Duration(200, NANOSECONDS),
 
                         9,

diff --git a/core/trino-main/src/test/java/io/trino/execution/TestQueryStats.java b/core/trino-main/src/test/java/io/trino/execution/TestQueryStats.java
@@ -192,6 +192,7 @@ public class TestQueryStats
 
             new Duration(100, NANOSECONDS),
             new Duration(150, NANOSECONDS),
+            new Duration(160, NANOSECONDS),
             new Duration(200, NANOSECONDS),
 
             9,
@@ -305,6 +306,7 @@ public static void assertExpectedQueryStats(QueryStats actual)
 
         assertThat(actual.getPlanningTime()).isEqualTo(new Duration(100, NANOSECONDS));
         assertThat(actual.getPlanningCpuTime()).isEqualTo(new Duration(150, NANOSECONDS));
+        assertThat(actual.getStartingTime()).isEqualTo(new Duration(160, NANOSECONDS));
         assertThat(actual.getFinishingTime()).isEqualTo(new Duration(200, NANOSECONDS));
 
         assertThat(actual.getTotalTasks()).isEqualTo(9);

diff --git a/core/trino-main/src/test/java/io/trino/server/TestBasicQueryInfo.java b/core/trino-main/src/test/java/io/trino/server/TestBasicQueryInfo.java
@@ -68,6 +68,7 @@ public void testConstructor()
                                 new Duration(9, MINUTES),
                                 new Duration(99, SECONDS),
                                 new Duration(1, SECONDS),
+                                new Duration(2, SECONDS),
                                 new Duration(12, MINUTES),
                                 13,
                                 14,

diff --git a/core/trino-main/src/test/java/io/trino/server/TestQueryStateInfo.java b/core/trino-main/src/test/java/io/trino/server/TestQueryStateInfo.java
@@ -120,6 +120,7 @@ private QueryInfo createQueryInfo(String queryId, QueryState state, String query
                         new Duration(10, MINUTES),
                         new Duration(11, MINUTES),
                         new Duration(1, SECONDS),
+                        new Duration(2, SECONDS),
                         new Duration(12, MINUTES),
                         13,
                         14,