-
Notifications
You must be signed in to change notification settings - Fork 25.4k
Expose more detailed profiling information #126525
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
Merged
Merged
Changes from 12 commits
Commits
Show all changes
14 commits
Select commit
Hold shift + click to select a range
0abaa7d
time span
idegtiarenko d96437b
expand profile object
idegtiarenko 5894155
upd
idegtiarenko 113c5aa
merge chunks and expose time in millis
idegtiarenko 16e359a
Allow calling method multiple times
idegtiarenko 09921ea
fix tests
idegtiarenko 55bc0b8
Merge branch 'main' into profiling
idegtiarenko 3683dc7
Merge branch 'main' into profiling
idegtiarenko 86913e2
Merge branch 'main' into profiling
idegtiarenko 2721a31
Merge branch 'main' into profiling
idegtiarenko 04dccd7
Merge branch 'main' into profiling
idegtiarenko f8a0102
Merge branch 'main' into profiling
idegtiarenko 61d03d5
serialize spans
idegtiarenko b0d15ef
Merge branch 'main' into profiling
idegtiarenko File filter
Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
There are no files selected for viewing
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -37,7 +37,6 @@ | |
import java.util.Objects; | ||
import java.util.Set; | ||
import java.util.concurrent.ConcurrentMap; | ||
import java.util.concurrent.TimeUnit; | ||
import java.util.function.BiFunction; | ||
import java.util.function.Predicate; | ||
import java.util.stream.Stream; | ||
|
@@ -67,17 +66,20 @@ public class EsqlExecutionInfo implements ChunkedToXContentObject, Writeable { | |
// Updates to the Cluster occur with the updateCluster method that given the key to map transforms an | ||
// old Cluster Object to a new Cluster Object with the remapping function. | ||
public final Map<String, Cluster> clusterInfo; | ||
private TimeValue overallTook; | ||
// whether the user has asked for CCS metadata to be in the JSON response (the overall took will always be present) | ||
private final boolean includeCCSMetadata; | ||
|
||
// fields that are not Writeable since they are only needed on the primary CCS coordinator | ||
private final transient Predicate<String> skipUnavailablePredicate; | ||
private final transient Long relativeStartNanos; // start time for an ESQL query for calculating took times | ||
private transient TimeValue planningTookTime; // time elapsed since start of query to calling ComputeService.execute | ||
private volatile boolean isPartial; // Does this request have partial results? | ||
private transient volatile boolean isStopped; // Have we received stop command? | ||
|
||
// start time for the ESQL query for calculating time spans relative to the beginning of the query | ||
private final transient TimeSpan.Builder relativeStart; | ||
private transient TimeSpan overallTimeSpan; | ||
private transient TimeSpan planningTimeSpan; // time elapsed since start of query to calling ComputeService.execute | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Okay, this actually need to be serialized in order to pass this information when executing query async |
||
private TimeValue overallTook; | ||
|
||
public EsqlExecutionInfo(boolean includeCCSMetadata) { | ||
this(Predicates.always(), includeCCSMetadata); // default all clusters to skip_unavailable=true | ||
} | ||
|
@@ -90,18 +92,17 @@ public EsqlExecutionInfo(Predicate<String> skipUnavailablePredicate, boolean inc | |
this.clusterInfo = ConcurrentCollections.newConcurrentMap(); | ||
this.skipUnavailablePredicate = skipUnavailablePredicate; | ||
this.includeCCSMetadata = includeCCSMetadata; | ||
this.relativeStartNanos = System.nanoTime(); | ||
this.relativeStart = TimeSpan.start(); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Should be always present on coordinating node |
||
} | ||
|
||
/** | ||
* For testing use with fromXContent parsing only | ||
* @param clusterInfo | ||
*/ | ||
EsqlExecutionInfo(ConcurrentMap<String, Cluster> clusterInfo, boolean includeCCSMetadata) { | ||
this.clusterInfo = clusterInfo; | ||
this.includeCCSMetadata = includeCCSMetadata; | ||
this.skipUnavailablePredicate = Predicates.always(); | ||
this.relativeStartNanos = null; | ||
this.relativeStart = null; | ||
} | ||
|
||
public EsqlExecutionInfo(StreamInput in) throws IOException { | ||
|
@@ -127,7 +128,7 @@ public EsqlExecutionInfo(StreamInput in) throws IOException { | |
} | ||
|
||
this.skipUnavailablePredicate = Predicates.always(); | ||
this.relativeStartNanos = null; | ||
this.relativeStart = null; | ||
} | ||
|
||
@Override | ||
|
@@ -150,31 +151,28 @@ public boolean includeCCSMetadata() { | |
return includeCCSMetadata; | ||
} | ||
|
||
public Long getRelativeStartNanos() { | ||
return relativeStartNanos; | ||
} | ||
|
||
/** | ||
* Call when ES|QL "planning" phase is complete and query execution (in ComputeService) is about to start. | ||
* Note this is currently only built for a single phase planning/execution model. When INLINESTATS | ||
* moves towards GA we may need to revisit this model. Currently, it should never be called more than once. | ||
*/ | ||
public void markEndPlanning() { | ||
assert planningTookTime == null : "markEndPlanning should only be called once"; | ||
assert relativeStartNanos != null : "Relative start time must be set when markEndPlanning is called"; | ||
planningTookTime = new TimeValue(System.nanoTime() - relativeStartNanos, TimeUnit.NANOSECONDS); | ||
assert planningTimeSpan == null : "markEndPlanning should only be called once"; | ||
assert relativeStart != null : "Relative start time must be set when markEndPlanning is called"; | ||
planningTimeSpan = relativeStart.stop(); | ||
} | ||
|
||
public TimeValue planningTookTime() { | ||
return planningTookTime; | ||
return planningTimeSpan != null ? planningTimeSpan.toTimeValue() : null; | ||
} | ||
|
||
/** | ||
* Call when ES|QL execution is complete in order to set the overall took time for an ES|QL query. | ||
*/ | ||
public void markEndQuery() { | ||
assert relativeStartNanos != null : "Relative start time must be set when markEndQuery is called"; | ||
overallTook = new TimeValue(System.nanoTime() - relativeStartNanos, TimeUnit.NANOSECONDS); | ||
assert relativeStart != null : "Relative start time must be set when markEndQuery is called"; | ||
overallTimeSpan = relativeStart.stop(); | ||
overallTook = overallTimeSpan.toTimeValue(); | ||
} | ||
|
||
// for testing only - use markEndQuery in production code | ||
|
@@ -190,11 +188,15 @@ public TimeValue overallTook() { | |
* How much time the query took since starting. | ||
*/ | ||
public TimeValue tookSoFar() { | ||
if (relativeStartNanos == null) { | ||
return new TimeValue(0); | ||
} else { | ||
return new TimeValue(System.nanoTime() - relativeStartNanos, TimeUnit.NANOSECONDS); | ||
} | ||
return relativeStart != null ? relativeStart.stop().toTimeValue() : TimeValue.ZERO; | ||
} | ||
|
||
public TimeSpan overallTimeSpan() { | ||
return overallTimeSpan; | ||
} | ||
|
||
public TimeSpan planningTimeSpan() { | ||
return planningTimeSpan; | ||
} | ||
|
||
public Set<String> clusterAliases() { | ||
|
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
77 changes: 77 additions & 0 deletions
77
x-pack/plugin/esql/src/main/java/org/elasticsearch/xpack/esql/action/TimeSpan.java
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,77 @@ | ||
/* | ||
* Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one | ||
* or more contributor license agreements. Licensed under the Elastic License | ||
* 2.0; you may not use this file except in compliance with the Elastic License | ||
* 2.0. | ||
*/ | ||
|
||
package org.elasticsearch.xpack.esql.action; | ||
|
||
import org.elasticsearch.common.io.stream.StreamInput; | ||
import org.elasticsearch.common.io.stream.StreamOutput; | ||
import org.elasticsearch.common.io.stream.Writeable; | ||
import org.elasticsearch.core.TimeValue; | ||
import org.elasticsearch.xcontent.ToXContentObject; | ||
import org.elasticsearch.xcontent.XContentBuilder; | ||
|
||
import java.io.IOException; | ||
|
||
import static org.elasticsearch.core.TimeValue.timeValueNanos; | ||
|
||
/** | ||
* THis class is used to capture a duration of some process, including start and stop point int time. | ||
*/ | ||
public record TimeSpan(long startMillis, long startNanos, long stopMillis, long stopNanos) implements Writeable, ToXContentObject { | ||
|
||
public static TimeSpan readFrom(StreamInput in) throws IOException { | ||
return new TimeSpan(in.readVLong(), in.readVLong(), in.readVLong(), in.readVLong()); | ||
} | ||
|
||
@Override | ||
public void writeTo(StreamOutput out) throws IOException { | ||
out.writeVLong(startMillis); | ||
out.writeVLong(startNanos); | ||
out.writeVLong(stopMillis); | ||
out.writeVLong(stopNanos); | ||
} | ||
|
||
@Override | ||
public XContentBuilder toXContent(XContentBuilder builder, Params params) throws IOException { | ||
builder.startObject(); | ||
builder.timestampFieldsFromUnixEpochMillis("start_millis", "start", startMillis); | ||
builder.timestampFieldsFromUnixEpochMillis("stop_millis", "stop", stopMillis); | ||
if (builder.humanReadable()) { | ||
builder.field("took_time", toTimeValue()); | ||
} | ||
builder.field("took_millis", durationInMillis()); | ||
builder.field("took_nanos", durationInNanos()); | ||
builder.endObject(); | ||
return builder; | ||
} | ||
|
||
public TimeValue toTimeValue() { | ||
return timeValueNanos(stopNanos - startNanos); | ||
} | ||
|
||
public long durationInMillis() { | ||
return stopMillis - startMillis; | ||
} | ||
|
||
public long durationInNanos() { | ||
return stopNanos - startNanos; | ||
} | ||
|
||
public static Builder start() { | ||
return new Builder(); | ||
} | ||
|
||
public static class Builder { | ||
|
||
private final long startMillis = System.currentTimeMillis(); | ||
private final long startNanos = System.nanoTime(); | ||
|
||
public TimeSpan stop() { | ||
return new TimeSpan(startMillis, startNanos, System.currentTimeMillis(), System.nanoTime()); | ||
} | ||
} | ||
} |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Moved down and converted to
TimeSpan
s