mirror of
https://github.com/honeymoose/OpenSearch.git
synced 2025-02-22 21:05:23 +00:00
Fix profiling naming issues (#27133)
Some code-paths use anonymous classes (such as NonCollectingAggregator in terms agg), which messes up the display name of the profiler. If we encounter an anonymous class, we need to grab the super's name. Another naming issue was that ProfileAggs were not delegating to the wrapped agg's name for toString(), leading to ugly display. This PR also fixes up the profile documentation. Some of the examples were executing against empty indices, which shows different profile results than a populated index (and made for confusing examples). Finally, I switched the agg display names from the fully qualified name to the simple name, so that it's similar to how the query profiles work. Closes #26405
This commit is contained in:
parent
766d29e7cf
commit
6e9e07d6f8
@ -32,10 +32,16 @@ public class InternalAggregationProfileTree extends AbstractInternalProfileTree<
|
||||
|
||||
@Override
|
||||
protected String getTypeFromElement(Aggregator element) {
|
||||
if (element instanceof MultiBucketAggregatorWrapper) {
|
||||
return ((MultiBucketAggregatorWrapper) element).getWrappedClass().getName();
|
||||
|
||||
// Anonymous classes (such as NonCollectingAggregator in TermsAgg) won't have a name,
|
||||
// we need to get the super class
|
||||
if (element.getClass().getSimpleName().isEmpty() == true) {
|
||||
return element.getClass().getSuperclass().getSimpleName();
|
||||
}
|
||||
return element.getClass().getName();
|
||||
if (element instanceof MultiBucketAggregatorWrapper) {
|
||||
return ((MultiBucketAggregatorWrapper) element).getWrappedClass().getSimpleName();
|
||||
}
|
||||
return element.getClass().getSimpleName();
|
||||
}
|
||||
|
||||
@Override
|
||||
|
@ -110,4 +110,8 @@ public class ProfilingAggregator extends Aggregator {
|
||||
delegate.postCollection();
|
||||
}
|
||||
|
||||
@Override
|
||||
public String toString() {
|
||||
return delegate.toString();
|
||||
}
|
||||
}
|
||||
|
@ -41,6 +41,11 @@ final class InternalQueryProfileTree extends AbstractInternalProfileTree<QueryPr
|
||||
|
||||
@Override
|
||||
protected String getTypeFromElement(Query query) {
|
||||
// Anonymous classes won't have a name,
|
||||
// we need to get the super class
|
||||
if (query.getClass().getSimpleName().isEmpty() == true) {
|
||||
return query.getClass().getSuperclass().getSimpleName();
|
||||
}
|
||||
return query.getClass().getSimpleName();
|
||||
}
|
||||
|
||||
|
@ -100,7 +100,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
ProfileResult histoAggResult = aggProfileResultsList.get(0);
|
||||
assertThat(histoAggResult, notNullValue());
|
||||
assertThat(histoAggResult.getQueryName(),
|
||||
equalTo("org.elasticsearch.search.aggregations.bucket.histogram.HistogramAggregator"));
|
||||
equalTo("HistogramAggregator"));
|
||||
assertThat(histoAggResult.getLuceneDescription(), equalTo("histo"));
|
||||
assertThat(histoAggResult.getProfiledChildren().size(), equalTo(0));
|
||||
assertThat(histoAggResult.getTime(), greaterThan(0L));
|
||||
@ -137,7 +137,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
ProfileResult histoAggResult = aggProfileResultsList.get(0);
|
||||
assertThat(histoAggResult, notNullValue());
|
||||
assertThat(histoAggResult.getQueryName(),
|
||||
equalTo("org.elasticsearch.search.aggregations.bucket.histogram.HistogramAggregator"));
|
||||
equalTo("HistogramAggregator"));
|
||||
assertThat(histoAggResult.getLuceneDescription(), equalTo("histo"));
|
||||
assertThat(histoAggResult.getTime(), greaterThan(0L));
|
||||
Map<String, Long> histoBreakdown = histoAggResult.getTimeBreakdown();
|
||||
@ -154,7 +154,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
|
||||
ProfileResult termsAggResult = histoAggResult.getProfiledChildren().get(0);
|
||||
assertThat(termsAggResult, notNullValue());
|
||||
assertThat(termsAggResult.getQueryName(), equalTo(GlobalOrdinalsStringTermsAggregator.class.getName()));
|
||||
assertThat(termsAggResult.getQueryName(), equalTo(GlobalOrdinalsStringTermsAggregator.class.getSimpleName()));
|
||||
assertThat(termsAggResult.getLuceneDescription(), equalTo("terms"));
|
||||
assertThat(termsAggResult.getTime(), greaterThan(0L));
|
||||
Map<String, Long> termsBreakdown = termsAggResult.getTimeBreakdown();
|
||||
@ -171,7 +171,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
|
||||
ProfileResult avgAggResult = termsAggResult.getProfiledChildren().get(0);
|
||||
assertThat(avgAggResult, notNullValue());
|
||||
assertThat(avgAggResult.getQueryName(), equalTo(AvgAggregator.class.getName()));
|
||||
assertThat(avgAggResult.getQueryName(), equalTo(AvgAggregator.class.getSimpleName()));
|
||||
assertThat(avgAggResult.getLuceneDescription(), equalTo("avg"));
|
||||
assertThat(avgAggResult.getTime(), greaterThan(0L));
|
||||
Map<String, Long> avgBreakdown = termsAggResult.getTimeBreakdown();
|
||||
@ -207,7 +207,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
ProfileResult histoAggResult = aggProfileResultsList.get(0);
|
||||
assertThat(histoAggResult, notNullValue());
|
||||
assertThat(histoAggResult.getQueryName(),
|
||||
equalTo("org.elasticsearch.search.aggregations.bucket.histogram.HistogramAggregator"));
|
||||
equalTo("HistogramAggregator"));
|
||||
assertThat(histoAggResult.getLuceneDescription(), equalTo("histo"));
|
||||
assertThat(histoAggResult.getTime(), greaterThan(0L));
|
||||
Map<String, Long> histoBreakdown = histoAggResult.getTimeBreakdown();
|
||||
@ -224,7 +224,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
|
||||
ProfileResult termsAggResult = histoAggResult.getProfiledChildren().get(0);
|
||||
assertThat(termsAggResult, notNullValue());
|
||||
assertThat(termsAggResult.getQueryName(), equalTo(GlobalOrdinalsStringTermsAggregator.class.getName()));
|
||||
assertThat(termsAggResult.getQueryName(), equalTo(GlobalOrdinalsStringTermsAggregator.class.getSimpleName()));
|
||||
assertThat(termsAggResult.getLuceneDescription(), equalTo("terms"));
|
||||
assertThat(termsAggResult.getTime(), greaterThan(0L));
|
||||
Map<String, Long> termsBreakdown = termsAggResult.getTimeBreakdown();
|
||||
@ -241,7 +241,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
|
||||
ProfileResult avgAggResult = termsAggResult.getProfiledChildren().get(0);
|
||||
assertThat(avgAggResult, notNullValue());
|
||||
assertThat(avgAggResult.getQueryName(), equalTo(AvgAggregator.class.getName()));
|
||||
assertThat(avgAggResult.getQueryName(), equalTo(AvgAggregator.class.getSimpleName()));
|
||||
assertThat(avgAggResult.getLuceneDescription(), equalTo("avg"));
|
||||
assertThat(avgAggResult.getTime(), greaterThan(0L));
|
||||
Map<String, Long> avgBreakdown = termsAggResult.getTimeBreakdown();
|
||||
@ -277,7 +277,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
ProfileResult diversifyAggResult = aggProfileResultsList.get(0);
|
||||
assertThat(diversifyAggResult, notNullValue());
|
||||
assertThat(diversifyAggResult.getQueryName(),
|
||||
equalTo(DiversifiedOrdinalsSamplerAggregator.class.getName()));
|
||||
equalTo(DiversifiedOrdinalsSamplerAggregator.class.getSimpleName()));
|
||||
assertThat(diversifyAggResult.getLuceneDescription(), equalTo("diversify"));
|
||||
assertThat(diversifyAggResult.getTime(), greaterThan(0L));
|
||||
Map<String, Long> histoBreakdown = diversifyAggResult.getTimeBreakdown();
|
||||
@ -294,7 +294,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
|
||||
ProfileResult maxAggResult = diversifyAggResult.getProfiledChildren().get(0);
|
||||
assertThat(maxAggResult, notNullValue());
|
||||
assertThat(maxAggResult.getQueryName(), equalTo(MaxAggregator.class.getName()));
|
||||
assertThat(maxAggResult.getQueryName(), equalTo(MaxAggregator.class.getSimpleName()));
|
||||
assertThat(maxAggResult.getLuceneDescription(), equalTo("max"));
|
||||
assertThat(maxAggResult.getTime(), greaterThan(0L));
|
||||
Map<String, Long> termsBreakdown = maxAggResult.getTimeBreakdown();
|
||||
@ -338,7 +338,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
ProfileResult histoAggResult = aggProfileResultsList.get(0);
|
||||
assertThat(histoAggResult, notNullValue());
|
||||
assertThat(histoAggResult.getQueryName(),
|
||||
equalTo("org.elasticsearch.search.aggregations.bucket.histogram.HistogramAggregator"));
|
||||
equalTo("HistogramAggregator"));
|
||||
assertThat(histoAggResult.getLuceneDescription(), equalTo("histo"));
|
||||
assertThat(histoAggResult.getTime(), greaterThan(0L));
|
||||
Map<String, Long> histoBreakdown = histoAggResult.getTimeBreakdown();
|
||||
@ -355,7 +355,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
|
||||
ProfileResult tagsAggResult = histoAggResult.getProfiledChildren().get(0);
|
||||
assertThat(tagsAggResult, notNullValue());
|
||||
assertThat(tagsAggResult.getQueryName(), equalTo(GlobalOrdinalsStringTermsAggregator.class.getName()));
|
||||
assertThat(tagsAggResult.getQueryName(), equalTo(GlobalOrdinalsStringTermsAggregator.class.getSimpleName()));
|
||||
assertThat(tagsAggResult.getLuceneDescription(), equalTo("tags"));
|
||||
assertThat(tagsAggResult.getTime(), greaterThan(0L));
|
||||
Map<String, Long> tagsBreakdown = tagsAggResult.getTimeBreakdown();
|
||||
@ -372,7 +372,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
|
||||
ProfileResult avgAggResult = tagsAggResult.getProfiledChildren().get(0);
|
||||
assertThat(avgAggResult, notNullValue());
|
||||
assertThat(avgAggResult.getQueryName(), equalTo(AvgAggregator.class.getName()));
|
||||
assertThat(avgAggResult.getQueryName(), equalTo(AvgAggregator.class.getSimpleName()));
|
||||
assertThat(avgAggResult.getLuceneDescription(), equalTo("avg"));
|
||||
assertThat(avgAggResult.getTime(), greaterThan(0L));
|
||||
Map<String, Long> avgBreakdown = tagsAggResult.getTimeBreakdown();
|
||||
@ -389,7 +389,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
|
||||
ProfileResult maxAggResult = tagsAggResult.getProfiledChildren().get(1);
|
||||
assertThat(maxAggResult, notNullValue());
|
||||
assertThat(maxAggResult.getQueryName(), equalTo(MaxAggregator.class.getName()));
|
||||
assertThat(maxAggResult.getQueryName(), equalTo(MaxAggregator.class.getSimpleName()));
|
||||
assertThat(maxAggResult.getLuceneDescription(), equalTo("max"));
|
||||
assertThat(maxAggResult.getTime(), greaterThan(0L));
|
||||
Map<String, Long> maxBreakdown = tagsAggResult.getTimeBreakdown();
|
||||
@ -406,7 +406,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
|
||||
ProfileResult stringsAggResult = histoAggResult.getProfiledChildren().get(1);
|
||||
assertThat(stringsAggResult, notNullValue());
|
||||
assertThat(stringsAggResult.getQueryName(), equalTo(GlobalOrdinalsStringTermsAggregator.class.getName()));
|
||||
assertThat(stringsAggResult.getQueryName(), equalTo(GlobalOrdinalsStringTermsAggregator.class.getSimpleName()));
|
||||
assertThat(stringsAggResult.getLuceneDescription(), equalTo("strings"));
|
||||
assertThat(stringsAggResult.getTime(), greaterThan(0L));
|
||||
Map<String, Long> stringsBreakdown = stringsAggResult.getTimeBreakdown();
|
||||
@ -423,7 +423,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
|
||||
avgAggResult = stringsAggResult.getProfiledChildren().get(0);
|
||||
assertThat(avgAggResult, notNullValue());
|
||||
assertThat(avgAggResult.getQueryName(), equalTo(AvgAggregator.class.getName()));
|
||||
assertThat(avgAggResult.getQueryName(), equalTo(AvgAggregator.class.getSimpleName()));
|
||||
assertThat(avgAggResult.getLuceneDescription(), equalTo("avg"));
|
||||
assertThat(avgAggResult.getTime(), greaterThan(0L));
|
||||
avgBreakdown = stringsAggResult.getTimeBreakdown();
|
||||
@ -440,7 +440,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
|
||||
maxAggResult = stringsAggResult.getProfiledChildren().get(1);
|
||||
assertThat(maxAggResult, notNullValue());
|
||||
assertThat(maxAggResult.getQueryName(), equalTo(MaxAggregator.class.getName()));
|
||||
assertThat(maxAggResult.getQueryName(), equalTo(MaxAggregator.class.getSimpleName()));
|
||||
assertThat(maxAggResult.getLuceneDescription(), equalTo("max"));
|
||||
assertThat(maxAggResult.getTime(), greaterThan(0L));
|
||||
maxBreakdown = stringsAggResult.getTimeBreakdown();
|
||||
@ -457,7 +457,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
|
||||
tagsAggResult = stringsAggResult.getProfiledChildren().get(2);
|
||||
assertThat(tagsAggResult, notNullValue());
|
||||
assertThat(tagsAggResult.getQueryName(), equalTo(GlobalOrdinalsStringTermsAggregator.class.getName()));
|
||||
assertThat(tagsAggResult.getQueryName(), equalTo(GlobalOrdinalsStringTermsAggregator.class.getSimpleName()));
|
||||
assertThat(tagsAggResult.getLuceneDescription(), equalTo("tags"));
|
||||
assertThat(tagsAggResult.getTime(), greaterThan(0L));
|
||||
tagsBreakdown = tagsAggResult.getTimeBreakdown();
|
||||
@ -474,7 +474,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
|
||||
avgAggResult = tagsAggResult.getProfiledChildren().get(0);
|
||||
assertThat(avgAggResult, notNullValue());
|
||||
assertThat(avgAggResult.getQueryName(), equalTo(AvgAggregator.class.getName()));
|
||||
assertThat(avgAggResult.getQueryName(), equalTo(AvgAggregator.class.getSimpleName()));
|
||||
assertThat(avgAggResult.getLuceneDescription(), equalTo("avg"));
|
||||
assertThat(avgAggResult.getTime(), greaterThan(0L));
|
||||
avgBreakdown = tagsAggResult.getTimeBreakdown();
|
||||
@ -491,7 +491,7 @@ public class AggregationProfilerIT extends ESIntegTestCase {
|
||||
|
||||
maxAggResult = tagsAggResult.getProfiledChildren().get(1);
|
||||
assertThat(maxAggResult, notNullValue());
|
||||
assertThat(maxAggResult.getQueryName(), equalTo(MaxAggregator.class.getName()));
|
||||
assertThat(maxAggResult.getQueryName(), equalTo(MaxAggregator.class.getSimpleName()));
|
||||
assertThat(maxAggResult.getLuceneDescription(), equalTo("max"));
|
||||
assertThat(maxAggResult.getTime(), greaterThan(0L));
|
||||
maxBreakdown = tagsAggResult.getTimeBreakdown();
|
||||
|
@ -1,7 +1,7 @@
|
||||
[[search-profile]]
|
||||
== Profile API
|
||||
|
||||
WARNING: The Profile API is a debugging tool and adds signficant overhead to search execution.
|
||||
WARNING: The Profile API is a debugging tool and adds significant overhead to search execution.
|
||||
|
||||
The Profile API provides detailed timing information about the execution of individual components
|
||||
in a search request. It gives the user insight into how search requests are executed at a low level so that
|
||||
@ -17,11 +17,11 @@ Any `_search` request can be profiled by adding a top-level `profile` parameter:
|
||||
|
||||
[source,js]
|
||||
--------------------------------------------------
|
||||
GET /_search
|
||||
GET /twitter/_search
|
||||
{
|
||||
"profile": true,<1>
|
||||
"query" : {
|
||||
"match" : { "message" : "message number" }
|
||||
"match" : { "message" : "some number" }
|
||||
}
|
||||
}
|
||||
--------------------------------------------------
|
||||
@ -58,7 +58,7 @@ This will yield the following result:
|
||||
"query": [
|
||||
{
|
||||
"type": "BooleanQuery",
|
||||
"description": "message:message message:number",
|
||||
"description": "message:some message:number",
|
||||
"time_in_nanos": "1873811",
|
||||
"breakdown": {
|
||||
"score": 51306,
|
||||
@ -77,7 +77,7 @@ This will yield the following result:
|
||||
"children": [
|
||||
{
|
||||
"type": "TermQuery",
|
||||
"description": "message:message",
|
||||
"description": "message:some",
|
||||
"time_in_nanos": "391943",
|
||||
"breakdown": {
|
||||
"score": 28776,
|
||||
@ -230,13 +230,13 @@ The overall structure of this query tree will resemble your original Elasticsear
|
||||
"query": [
|
||||
{
|
||||
"type": "BooleanQuery",
|
||||
"description": "message:message message:number",
|
||||
"description": "message:some message:number",
|
||||
"time_in_nanos": "1873811",
|
||||
"breakdown": {...}, <1>
|
||||
"children": [
|
||||
{
|
||||
"type": "TermQuery",
|
||||
"description": "message:message",
|
||||
"description": "message:some",
|
||||
"time_in_nanos": "391943",
|
||||
"breakdown": {...}
|
||||
},
|
||||
@ -291,7 +291,7 @@ The `breakdown` component lists detailed timing statistics about low-level Lucen
|
||||
"advance_count": 0
|
||||
}
|
||||
--------------------------------------------------
|
||||
// TESTRESPONSE[s/^/{\n"took": $body.took,\n"timed_out": $body.timed_out,\n"_shards": $body._shards,\n"hits": $body.hits,\n"profile": {\n"shards": [ {\n"id": "$body.$_path",\n"searches": [{\n"query": [{\n"type": "BooleanQuery",\n"description": "message:message message:number",\n"time_in_nanos": $body.$_path,/]
|
||||
// TESTRESPONSE[s/^/{\n"took": $body.took,\n"timed_out": $body.timed_out,\n"_shards": $body._shards,\n"hits": $body.hits,\n"profile": {\n"shards": [ {\n"id": "$body.$_path",\n"searches": [{\n"query": [{\n"type": "BooleanQuery",\n"description": "message:some message:number",\n"time_in_nanos": $body.$_path,/]
|
||||
// TESTRESPONSE[s/}$/},\n"children": $body.$_path}],\n"rewrite_time": $body.$_path, "collector": $body.$_path}], "aggregations": []}]}}/]
|
||||
// TESTRESPONSE[s/(?<=[" ])\d+(\.\d+)?/$body.$_path/]
|
||||
|
||||
@ -469,35 +469,25 @@ value is cumulative and contains the total time for all queries being rewritten.
|
||||
|
||||
==== A more complex example
|
||||
|
||||
//////////////////////////
|
||||
|
||||
[source,js]
|
||||
--------------------------------------------------
|
||||
PUT test
|
||||
{"settings": {"index.number_of_shards": 1, "number_of_replicas": 0}}
|
||||
-------------------------------------------------
|
||||
// CONSOLE
|
||||
|
||||
//////////////////////////
|
||||
|
||||
To demonstrate a slightly more complex query and the associated results, we can profile the following query:
|
||||
|
||||
[source,js]
|
||||
--------------------------------------------------
|
||||
GET /test/_search
|
||||
GET /twitter/_search
|
||||
{
|
||||
"profile": true,
|
||||
"query": {
|
||||
"term": {
|
||||
"message": {
|
||||
"value": "search"
|
||||
"user": {
|
||||
"value": "test"
|
||||
}
|
||||
}
|
||||
},
|
||||
"aggs": {
|
||||
"my_scoped_agg": {
|
||||
"terms": {
|
||||
"field": "level"
|
||||
"field": "likes"
|
||||
}
|
||||
},
|
||||
"my_global_agg": {
|
||||
@ -505,21 +495,21 @@ GET /test/_search
|
||||
"aggs": {
|
||||
"my_level_agg": {
|
||||
"terms": {
|
||||
"field": "level"
|
||||
"field": "likes"
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"post_filter": {
|
||||
"term": {
|
||||
"tag": "elastic"
|
||||
"match": {
|
||||
"message": "some"
|
||||
}
|
||||
}
|
||||
}
|
||||
--------------------------------------------------
|
||||
// CONSOLE
|
||||
// TEST[s/GET \/test\/_search/GET \/test\/_search\?filter_path=profile.shards.id,profile.shards.searches/]
|
||||
// TEST[s/_search/_search\?filter_path=profile.shards.id,profile.shards.searches,profile.shards.aggregations/]
|
||||
// TEST[continued]
|
||||
|
||||
This example has:
|
||||
@ -544,7 +534,7 @@ And the response:
|
||||
"query": [
|
||||
{
|
||||
"type": "TermQuery",
|
||||
"description": "my_field:foo",
|
||||
"description": "message:some",
|
||||
"time_in_nanos": "409456",
|
||||
"breakdown": {
|
||||
"score": 0,
|
||||
@ -563,7 +553,7 @@ And the response:
|
||||
},
|
||||
{
|
||||
"type": "TermQuery",
|
||||
"description": "message:search",
|
||||
"description": "user:test",
|
||||
"time_in_nanos": "303702",
|
||||
"breakdown": {
|
||||
"score": 0,
|
||||
@ -606,7 +596,7 @@ And the response:
|
||||
]
|
||||
},
|
||||
{
|
||||
"name": "BucketCollector: [[org.elasticsearch.search.profile.aggregation.ProfilingAggregator@222b076, org.elasticsearch.search.profile.aggregation.ProfilingAggregator@3000ab31]]",
|
||||
"name": "BucketCollector: [[my_scoped_agg, my_global_agg]]",
|
||||
"reason": "aggregation",
|
||||
"time_in_nanos": 8273
|
||||
}
|
||||
@ -616,21 +606,24 @@ And the response:
|
||||
}
|
||||
]
|
||||
}
|
||||
]
|
||||
],
|
||||
"aggregations": [...] <1>
|
||||
}
|
||||
]
|
||||
}
|
||||
}
|
||||
--------------------------------------------------
|
||||
// TESTRESPONSE[s/"aggregations": \[\.\.\.\]/"aggregations": $body.$_path/]
|
||||
// TESTRESPONSE[s/\.\.\.//]
|
||||
// TESTRESPONSE[s/: (\-)?[0-9]+/: $body.$_path/]
|
||||
// TESTRESPONSE[s/: "[^"]*"/: $body.$_path/]
|
||||
// TESTRESPONSE[s/(?<=[" ])\d+(\.\d+)?/$body.$_path/]
|
||||
// TESTRESPONSE[s/"id": "\[P6-vulHtQRWuD4YnubWb7A\]\[test\]\[0\]"/"id": $body.profile.shards.0.id/]
|
||||
<1> The ``"aggregations"` portion has been omitted because it will be covered in the next section
|
||||
|
||||
As you can see, the output is significantly verbose from before. All the major portions of the query are
|
||||
represented:
|
||||
|
||||
1. The first `TermQuery` (message:search) represents the main `term` query
|
||||
2. The second `TermQuery` (my_field:foo) represents the `post_filter` query
|
||||
1. The first `TermQuery` (user:test) represents the main `term` query
|
||||
2. The second `TermQuery` (message:some) represents the `post_filter` query
|
||||
|
||||
The Collector tree is fairly straightforward, showing how a single CancellableCollector wraps a MultiCollector
|
||||
which also wraps a FilteredCollector to execute the post_filter (and in turn wraps the normal scoring SimpleCollector),
|
||||
@ -651,7 +644,7 @@ Due to this dynamic, per-segment rewriting, the clean tree structure becomes dis
|
||||
"lineage" showing how one query rewrites into the next. At present time, all we can do is apologize, and suggest you
|
||||
collapse the details for that query's children if it is too confusing. Luckily, all the timing statistics are correct,
|
||||
just not the physical layout in the response, so it is sufficient to just analyze the top-level MultiTermQuery and
|
||||
ignore it's children if you find the details too tricky to interpret.
|
||||
ignore its children if you find the details too tricky to interpret.
|
||||
|
||||
Hopefully this will be fixed in future iterations, but it is a tricky problem to solve and still in-progress :)
|
||||
|
||||
@ -659,45 +652,49 @@ Hopefully this will be fixed in future iterations, but it is a tricky problem to
|
||||
|
||||
==== `aggregations` Section
|
||||
|
||||
//////////////////////////
|
||||
|
||||
[source,js]
|
||||
--------------------------------------------------
|
||||
PUT house-prices
|
||||
{"settings": {"index.number_of_shards": 1, "number_of_replicas": 0}}
|
||||
-------------------------------------------------
|
||||
// CONSOLE
|
||||
|
||||
//////////////////////////
|
||||
|
||||
The `aggregations` section contains detailed timing of the aggregation tree executed by a particular shard.
|
||||
The overall structure of this aggregation tree will resemble your original Elasticsearch request. Let's consider
|
||||
the following example aggregations request:
|
||||
The overall structure of this aggregation tree will resemble your original Elasticsearch request. Let's
|
||||
execute the previous query again and look at the aggregation profile this time:
|
||||
|
||||
[source,js]
|
||||
--------------------------------------------------
|
||||
GET /house-prices/_search
|
||||
GET /twitter/_search
|
||||
{
|
||||
"profile": true,
|
||||
"size": 0,
|
||||
"query": {
|
||||
"term": {
|
||||
"user": {
|
||||
"value": "test"
|
||||
}
|
||||
}
|
||||
},
|
||||
"aggs": {
|
||||
"property_type": {
|
||||
"my_scoped_agg": {
|
||||
"terms": {
|
||||
"field": "propertyType"
|
||||
},
|
||||
"field": "likes"
|
||||
}
|
||||
},
|
||||
"my_global_agg": {
|
||||
"global": {},
|
||||
"aggs": {
|
||||
"avg_price": {
|
||||
"avg": {
|
||||
"field": "price"
|
||||
"my_level_agg": {
|
||||
"terms": {
|
||||
"field": "likes"
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"post_filter": {
|
||||
"match": {
|
||||
"message": "some"
|
||||
}
|
||||
}
|
||||
}
|
||||
--------------------------------------------------
|
||||
// CONSOLE
|
||||
// TEST[s/GET \/house-prices\/_search/GET \/house-prices\/_search\?filter_path=profile.shards.aggregations/]
|
||||
// TEST[s/_search/_search\?filter_path=profile.shards.aggregations/]
|
||||
// TEST[continued]
|
||||
|
||||
Which yields the following aggregation profile output
|
||||
@ -705,39 +702,53 @@ Which yields the following aggregation profile output
|
||||
[source,js]
|
||||
--------------------------------------------------
|
||||
{
|
||||
"profile": {
|
||||
"shards": [
|
||||
"profile" : {
|
||||
"shards" : [
|
||||
{
|
||||
...
|
||||
"aggregations": [
|
||||
"aggregations" : [
|
||||
{
|
||||
"type": "org.elasticsearch.search.aggregations.bucket.terms.TermsAggregatorFactory$1",
|
||||
"description": "property_type",
|
||||
"time_in_nanos": 26234,
|
||||
"breakdown": {
|
||||
"reduce": 0,
|
||||
"build_aggregation": 817,
|
||||
"build_aggregation_count": 1,
|
||||
"initialize": 25415,
|
||||
"initialize_count": 1,
|
||||
"reduce_count": 0,
|
||||
"collect": 0,
|
||||
"collect_count": 0
|
||||
"type" : "LongTermsAggregator",
|
||||
"description" : "my_scoped_agg",
|
||||
"time_in_nanos" : 195386,
|
||||
"breakdown" : {
|
||||
"reduce" : 0,
|
||||
"build_aggregation" : 81171,
|
||||
"build_aggregation_count" : 1,
|
||||
"initialize" : 22753,
|
||||
"initialize_count" : 1,
|
||||
"reduce_count" : 0,
|
||||
"collect" : 91456,
|
||||
"collect_count" : 4
|
||||
}
|
||||
},
|
||||
{
|
||||
"type" : "GlobalAggregator",
|
||||
"description" : "my_global_agg",
|
||||
"time_in_nanos" : 190430,
|
||||
"breakdown" : {
|
||||
"reduce" : 0,
|
||||
"build_aggregation" : 59990,
|
||||
"build_aggregation_count" : 1,
|
||||
"initialize" : 29619,
|
||||
"initialize_count" : 1,
|
||||
"reduce_count" : 0,
|
||||
"collect" : 100815,
|
||||
"collect_count" : 4
|
||||
},
|
||||
"children": [
|
||||
"children" : [
|
||||
{
|
||||
"type": "org.elasticsearch.search.aggregations.metrics.avg.AvgAggregator",
|
||||
"description": "avg_price",
|
||||
"time_in_nanos": 5610,
|
||||
"breakdown": {
|
||||
"reduce": 0,
|
||||
"build_aggregation": 0,
|
||||
"build_aggregation_count": 0,
|
||||
"initialize": 5609,
|
||||
"initialize_count": 1,
|
||||
"reduce_count": 0,
|
||||
"collect": 0,
|
||||
"collect_count": 0
|
||||
"type" : "LongTermsAggregator",
|
||||
"description" : "my_level_agg",
|
||||
"time_in_nanos" : 160329,
|
||||
"breakdown" : {
|
||||
"reduce" : 0,
|
||||
"build_aggregation" : 55712,
|
||||
"build_aggregation_count" : 1,
|
||||
"initialize" : 10559,
|
||||
"initialize_count" : 1,
|
||||
"reduce_count" : 0,
|
||||
"collect" : 94052,
|
||||
"collect_count" : 4
|
||||
}
|
||||
}
|
||||
]
|
||||
@ -749,17 +760,15 @@ Which yields the following aggregation profile output
|
||||
}
|
||||
--------------------------------------------------
|
||||
// TESTRESPONSE[s/\.\.\.//]
|
||||
// TESTRESPONSE[s/: (\-)?[0-9]+/: $body.$_path/]
|
||||
// TESTRESPONSE[s/(?<=[" ])\d+(\.\d+)?/$body.$_path/]
|
||||
// TESTRESPONSE[s/"id": "\[P6-vulHtQRWuD4YnubWb7A\]\[test\]\[0\]"/"id": $body.profile.shards.0.id/]
|
||||
|
||||
From the profile structure we can see our `property_type` terms aggregation which is internally represented by the
|
||||
`GlobalOrdinalsStringTermsAggregator` class and the sub aggregator `avg_price` which is internally represented by the `AvgAggregator` class. The `type` field displays the class used internally to represent the aggregation. The `description` field displays the name of the aggregation.
|
||||
From the profile structure we can see that the `my_scoped_agg` is internally being run as a `LongTermsAggregator` (because the field it is
|
||||
aggregating, `likes`, is a numeric field). At the same level, we see a `GlobalAggregator` which comes from `my_global_agg`. That
|
||||
aggregation then has a child `LongTermsAggregator` which from the second terms aggregation on `likes`.
|
||||
|
||||
The `time_in_nanos` field shows that it took ~4 seconds for the entire aggregation to execute. The recorded time is inclusive
|
||||
of all children.
|
||||
|
||||
The `breakdown` field will give detailed stats about how the time was spent, we'll look at
|
||||
that in a moment. Finally, the `children` array lists any sub-aggregations that may be present. Because we have an `avg_price` aggregation as a sub-aggregation to the `property_type` aggregation we see it listed as a child of the `property_type` aggregation. the two aggregation outputs have identical information (type, time,
|
||||
breakdown, etc). Children are allowed to have their own children.
|
||||
The `time_in_nanos` field shows the time executed by each aggregation, and is inclusive of all children. While the overall time is useful,
|
||||
the `breakdown` field will give detailed stats about how the time was spent.
|
||||
|
||||
===== Timing Breakdown
|
||||
|
||||
|
Loading…
x
Reference in New Issue
Block a user