Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Expose query starting time #23113

Merged
merged 2 commits into from
Aug 26, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -277,6 +277,7 @@ private static QueryStats immediateFailureQueryStats()
new Duration(0, MILLISECONDS),
new Duration(0, MILLISECONDS),
new Duration(0, MILLISECONDS),
new Duration(0, MILLISECONDS),
sopel39 marked this conversation as resolved.
Show resolved Hide resolved
0,
0,
0,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -209,6 +209,7 @@ public void queryImmediateFailureEvent(BasicQueryInfo queryInfo, ExecutionFailur
Optional.empty(),
Optional.empty(),
Optional.empty(),
Optional.empty(),
0,
0,
0,
Expand Down Expand Up @@ -317,6 +318,7 @@ private QueryStatistics createQueryStatistics(QueryInfo queryInfo)
Optional.of(ofMillis(queryStats.getAnalysisTime().toMillis())),
Optional.of(ofMillis(queryStats.getPlanningTime().toMillis())),
Optional.of(ofMillis(queryStats.getPlanningCpuTime().toMillis())),
Optional.of(ofMillis(queryStats.getStartingTime().toMillis())),
Optional.of(ofMillis(queryStats.getExecutionTime().toMillis())),
Optional.of(ofMillis(queryStats.getInputBlockedTime().toMillis())),
Optional.of(ofMillis(queryStats.getFailedInputBlockedTime().toMillis())),
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -825,6 +825,7 @@ private QueryStats getQueryStats(Optional<StageInfo> rootStage, List<StageInfo>
queryStateTimer.getAnalysisTime(),
queryStateTimer.getPlanningTime(),
queryStateTimer.getPlanningCpuTime(),
queryStateTimer.getStartingTime(),
queryStateTimer.getFinishingTime(),

totalTasks,
Expand Down Expand Up @@ -1435,6 +1436,7 @@ private static QueryStats pruneQueryStats(QueryStats queryStats)
queryStats.getAnalysisTime(),
queryStats.getPlanningTime(),
queryStats.getPlanningCpuTime(),
queryStats.getStartingTime(),
queryStats.getFinishingTime(),
queryStats.getTotalTasks(),
queryStats.getRunningTasks(),
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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<>();

Expand All @@ -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<>();
Expand Down Expand Up @@ -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()
Expand All @@ -123,6 +126,7 @@ public void beginRunning()
private void beginRunning(long now)
{
beginStarting(now, currentThreadCpuTime());
startingTime.compareAndSet(null, nanosSince(beginStartingNanos, now));
}

public void beginFinishing()
Expand Down Expand Up @@ -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);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -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");
Expand Down Expand Up @@ -410,6 +413,12 @@ public Duration getPlanningCpuTime()
return planningCpuTime;
}

@JsonProperty
public Duration getStartingTime()
{
return startingTime;
}

@JsonProperty
public Duration getFinishingTime()
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -181,6 +181,7 @@ public QueryInfo getFullQueryInfo()

new Duration(100, NANOSECONDS),
new Duration(150, NANOSECONDS),
new Duration(160, NANOSECONDS),
new Duration(200, NANOSECONDS),

9,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -192,6 +192,7 @@ public class TestQueryStats

new Duration(100, NANOSECONDS),
new Duration(150, NANOSECONDS),
new Duration(160, NANOSECONDS),
new Duration(200, NANOSECONDS),

9,
Expand Down Expand Up @@ -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);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down
6 changes: 6 additions & 0 deletions core/trino-spi/pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -235,6 +235,12 @@
<old>method void io.trino.spi.eventlistener.QueryStatistics::&lt;init&gt;(java.time.Duration, java.time.Duration, java.time.Duration, java.time.Duration, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, long, long, long, long, long, long, long, long, long, long, long, long, long, long, long, long, double, double, java.util.List&lt;io.trino.spi.eventlistener.StageGcStatistics&gt;, int, boolean, java.util.List&lt;io.trino.spi.eventlistener.StageCpuDistribution&gt;, java.util.List&lt;io.trino.spi.eventlistener.StageOutputBufferUtilization&gt;, java.util.function.Supplier&lt;java.util.List&lt;java.lang.String&gt;&gt;, java.util.List&lt;io.trino.spi.eventlistener.QueryPlanOptimizerStatistics&gt;, java.util.Optional&lt;java.lang.String&gt;)</old>
<new>method void io.trino.spi.eventlistener.QueryStatistics::&lt;init&gt;(java.time.Duration, java.time.Duration, java.time.Duration, java.time.Duration, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, long, long, long, long, long, long, long, long, long, long, long, long, long, long, long, long, double, double, java.util.List&lt;io.trino.spi.eventlistener.StageGcStatistics&gt;, int, boolean, java.util.List&lt;io.trino.spi.eventlistener.StageCpuDistribution&gt;, java.util.List&lt;io.trino.spi.eventlistener.StageOutputBufferUtilization&gt;, java.util.List&lt;io.trino.spi.eventlistener.StageTaskStatistics&gt;, java.util.function.Supplier&lt;java.util.List&lt;java.lang.String&gt;&gt;, java.util.List&lt;io.trino.spi.eventlistener.QueryPlanOptimizerStatistics&gt;, java.util.Optional&lt;java.lang.String&gt;)</new>
</item>
<item>
<ignore>true</ignore>
<code>java.method.numberOfParametersChanged</code>
<old>method void io.trino.spi.eventlistener.QueryStatistics::&lt;init&gt;(java.time.Duration, java.time.Duration, java.time.Duration, java.time.Duration, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, long, long, long, long, long, long, long, long, long, long, long, long, long, long, long, long, double, double, java.util.List&lt;io.trino.spi.eventlistener.StageGcStatistics&gt;, int, boolean, java.util.List&lt;io.trino.spi.eventlistener.StageCpuDistribution&gt;, java.util.List&lt;io.trino.spi.eventlistener.StageOutputBufferUtilization&gt;, java.util.List&lt;io.trino.spi.eventlistener.StageTaskStatistics&gt;, java.util.function.Supplier&lt;java.util.List&lt;java.lang.String&gt;&gt;, java.util.List&lt;io.trino.spi.eventlistener.QueryPlanOptimizerStatistics&gt;, java.util.Optional&lt;java.lang.String&gt;)</old>
<new>method void io.trino.spi.eventlistener.QueryStatistics::&lt;init&gt;(java.time.Duration, java.time.Duration, java.time.Duration, java.time.Duration, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, java.util.Optional&lt;java.time.Duration&gt;, long, long, long, long, long, long, long, long, long, long, long, long, long, long, long, long, double, double, java.util.List&lt;io.trino.spi.eventlistener.StageGcStatistics&gt;, int, boolean, java.util.List&lt;io.trino.spi.eventlistener.StageCpuDistribution&gt;, java.util.List&lt;io.trino.spi.eventlistener.StageOutputBufferUtilization&gt;, java.util.List&lt;io.trino.spi.eventlistener.StageTaskStatistics&gt;, java.util.function.Supplier&lt;java.util.List&lt;java.lang.String&gt;&gt;, java.util.List&lt;io.trino.spi.eventlistener.QueryPlanOptimizerStatistics&gt;, java.util.Optional&lt;java.lang.String&gt;)</new>
</item>
<item>
<code>java.method.numberOfParametersChanged</code>
<old>method io.trino.spi.predicate.SortedRangeSet io.trino.spi.predicate.SortedRangeSet::fromJson(io.trino.spi.type.Type, boolean[], io.trino.spi.block.Block)</old>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,7 @@ public class QueryStatistics
private final Optional<Duration> analysisTime;
private final Optional<Duration> planningTime;
private final Optional<Duration> planningCpuTime;
private final Optional<Duration> startingTime;
private final Optional<Duration> executionTime;
private final Optional<Duration> inputBlockedTime;
private final Optional<Duration> failedInputBlockedTime;
Expand Down Expand Up @@ -100,6 +101,7 @@ public QueryStatistics(
Optional<Duration> analysisTime,
Optional<Duration> planningTime,
Optional<Duration> planningCpuTime,
Optional<Duration> startingTime,
Optional<Duration> executionTime,
Optional<Duration> inputBlockedTime,
Optional<Duration> failedInputBlockedTime,
Expand Down Expand Up @@ -145,6 +147,7 @@ public QueryStatistics(
analysisTime,
planningTime,
planningCpuTime,
startingTime,
executionTime,
inputBlockedTime,
failedInputBlockedTime,
Expand Down Expand Up @@ -191,6 +194,7 @@ public QueryStatistics(
Optional<Duration> analysisTime,
Optional<Duration> planningTime,
Optional<Duration> planningCpuTime,
Optional<Duration> startingTime,
Optional<Duration> executionTime,
Optional<Duration> inputBlockedTime,
Optional<Duration> failedInputBlockedTime,
Expand Down Expand Up @@ -235,6 +239,7 @@ public QueryStatistics(
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.executionTime = requireNonNull(executionTime, "executionTime is null");
this.inputBlockedTime = requireNonNull(inputBlockedTime, "inputBlockedTime is null");
this.failedInputBlockedTime = requireNonNull(failedInputBlockedTime, "failedInputBlockedTime is null");
Expand Down Expand Up @@ -330,6 +335,12 @@ public Optional<Duration> getPlanningCpuTime()
return planningCpuTime;
}

@JsonProperty
public Optional<Duration> getStartingTime()
{
return startingTime;
}

@JsonProperty
public Optional<Duration> getExecutionTime()
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -166,6 +166,7 @@ final class TestHttpEventListener
Optional.empty(),
Optional.empty(),
Optional.empty(),
Optional.empty(),
0L,
0L,
0L,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -136,6 +136,7 @@ final class TestHttpServerEventListener
Optional.empty(),
Optional.empty(),
Optional.empty(),
Optional.empty(),
0L,
0L,
0L,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -131,6 +131,7 @@ private TestUtils()
Optional.empty(),
Optional.empty(),
Optional.empty(),
Optional.empty(),
0L,
0L,
0L,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -137,6 +137,7 @@ public void queryCompleted(QueryCompletedEvent event)
stats.getAnalysisTime().map(Duration::toMillis).orElse(0L),
stats.getPlanningTime().map(Duration::toMillis).orElse(0L),
stats.getPlanningCpuTime().map(Duration::toMillis).orElse(0L),
stats.getStartingTime().map(Duration::toMillis).orElse(0L),
stats.getExecutionTime().map(Duration::toMillis).orElse(0L),
stats.getInputBlockedTime().map(Duration::toMillis).orElse(0L),
stats.getFailedInputBlockedTime().map(Duration::toMillis).orElse(0L),
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -63,6 +63,7 @@ public interface QueryDao
" analysis_time_millis BIGINT NOT NULL,\n" +
" planning_time_millis BIGINT NOT NULL,\n" +
" planning_cpu_time_millis BIGINT NOT NULL,\n" +
" starting_time_millis BIGINT NOT NULL,\n" +
" execution_time_millis BIGINT NOT NULL,\n" +
" input_blocked_time_millis BIGINT NOT NULL,\n" +
" failed_input_blocked_time_millis BIGINT NOT NULL,\n" +
Expand Down Expand Up @@ -135,6 +136,7 @@ public interface QueryDao
" analysis_time_millis,\n" +
" planning_time_millis,\n" +
" planning_cpu_time_millis,\n" +
" starting_time_millis,\n" +
" execution_time_millis,\n" +
" input_blocked_time_millis,\n" +
" failed_input_blocked_time_millis,\n" +
Expand Down Expand Up @@ -204,6 +206,7 @@ public interface QueryDao
" :analysisTimeMillis,\n" +
" :planningTimeMillis,\n" +
" :planningCpuTimeMillis,\n" +
" :startingTimeMillis,\n" +
" :executionTimeMillis,\n" +
" :inputBlockedTimeMillis,\n" +
" :failedInputBlockedTimeMillis,\n" +
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -74,6 +74,7 @@ public class QueryEntity
private final long analysisTimeMillis;
private final long planningTimeMillis;
private final long planningCpuTimeMillis;
private final long startingTimeMillis;
private final long executionTimeMillis;
private final long inputBlockedTimeMillis;
private final long failedInputBlockedTimeMillis;
Expand Down Expand Up @@ -147,6 +148,7 @@ public QueryEntity(
long analysisTimeMillis,
long planningTimeMillis,
long planningCpuTimeMillis,
long startingTimeMillis,
long executionTimeMillis,
long inputBlockedTimeMillis,
long failedInputBlockedTimeMillis,
Expand Down Expand Up @@ -215,6 +217,7 @@ public QueryEntity(
this.analysisTimeMillis = analysisTimeMillis;
this.planningTimeMillis = planningTimeMillis;
this.planningCpuTimeMillis = planningCpuTimeMillis;
this.startingTimeMillis = startingTimeMillis;
this.executionTimeMillis = executionTimeMillis;
this.inputBlockedTimeMillis = inputBlockedTimeMillis;
this.failedInputBlockedTimeMillis = failedInputBlockedTimeMillis;
Expand Down Expand Up @@ -460,6 +463,11 @@ public long getPlanningCpuTimeMillis()
return planningCpuTimeMillis;
}

public long getStartingTimeMillis()
{
return startingTimeMillis;
}

public long getExecutionTimeMillis()
{
return executionTimeMillis;
Expand Down
Loading
Loading