diff --git a/core/src/main/java/org/elasticsearch/search/profile/aggregation/InternalAggregationProfileTree.java b/core/src/main/java/org/elasticsearch/search/profile/aggregation/InternalAggregationProfileTree.java index f367595c84c87..f3e66c1a9fda9 100644 --- a/core/src/main/java/org/elasticsearch/search/profile/aggregation/InternalAggregationProfileTree.java +++ b/core/src/main/java/org/elasticsearch/search/profile/aggregation/InternalAggregationProfileTree.java @@ -32,10 +32,16 @@ protected AggregationProfileBreakdown createProfileBreakdown() { @Override protected String getTypeFromElement(Aggregator element) { + + // 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(); + } if (element instanceof MultiBucketAggregatorWrapper) { - return ((MultiBucketAggregatorWrapper) element).getWrappedClass().getName(); + return ((MultiBucketAggregatorWrapper) element).getWrappedClass().getSimpleName(); } - return element.getClass().getName(); + return element.getClass().getSimpleName(); } @Override diff --git a/core/src/main/java/org/elasticsearch/search/profile/aggregation/ProfilingAggregator.java b/core/src/main/java/org/elasticsearch/search/profile/aggregation/ProfilingAggregator.java index d96fbe0d86697..522910e0ab9eb 100644 --- a/core/src/main/java/org/elasticsearch/search/profile/aggregation/ProfilingAggregator.java +++ b/core/src/main/java/org/elasticsearch/search/profile/aggregation/ProfilingAggregator.java @@ -110,4 +110,8 @@ public void postCollection() throws IOException { delegate.postCollection(); } + @Override + public String toString() { + return delegate.toString(); + } } diff --git a/core/src/main/java/org/elasticsearch/search/profile/query/InternalQueryProfileTree.java b/core/src/main/java/org/elasticsearch/search/profile/query/InternalQueryProfileTree.java index 013b7d3a506cd..6a69ea968f0bd 100644 --- a/core/src/main/java/org/elasticsearch/search/profile/query/InternalQueryProfileTree.java +++ b/core/src/main/java/org/elasticsearch/search/profile/query/InternalQueryProfileTree.java @@ -41,6 +41,11 @@ protected QueryProfileBreakdown createProfileBreakdown() { @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(); } diff --git a/core/src/test/java/org/elasticsearch/search/profile/aggregation/AggregationProfilerIT.java b/core/src/test/java/org/elasticsearch/search/profile/aggregation/AggregationProfilerIT.java index 9914938854d03..e0cc63beeab4c 100644 --- a/core/src/test/java/org/elasticsearch/search/profile/aggregation/AggregationProfilerIT.java +++ b/core/src/test/java/org/elasticsearch/search/profile/aggregation/AggregationProfilerIT.java @@ -100,7 +100,7 @@ public void testSimpleProfile() { 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 void testMultiLevelProfile() { 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 histoBreakdown = histoAggResult.getTimeBreakdown(); @@ -154,7 +154,7 @@ public void testMultiLevelProfile() { 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 termsBreakdown = termsAggResult.getTimeBreakdown(); @@ -171,7 +171,7 @@ public void testMultiLevelProfile() { 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 avgBreakdown = termsAggResult.getTimeBreakdown(); @@ -207,7 +207,7 @@ public void testMultiLevelProfileBreadthFirst() { 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 histoBreakdown = histoAggResult.getTimeBreakdown(); @@ -224,7 +224,7 @@ public void testMultiLevelProfileBreadthFirst() { 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 termsBreakdown = termsAggResult.getTimeBreakdown(); @@ -241,7 +241,7 @@ public void testMultiLevelProfileBreadthFirst() { 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 avgBreakdown = termsAggResult.getTimeBreakdown(); @@ -277,7 +277,7 @@ public void testDiversifiedAggProfile() { 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 histoBreakdown = diversifyAggResult.getTimeBreakdown(); @@ -294,7 +294,7 @@ public void testDiversifiedAggProfile() { 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 termsBreakdown = maxAggResult.getTimeBreakdown(); @@ -338,7 +338,7 @@ public void testComplexProfile() { 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 histoBreakdown = histoAggResult.getTimeBreakdown(); @@ -355,7 +355,7 @@ public void testComplexProfile() { 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 tagsBreakdown = tagsAggResult.getTimeBreakdown(); @@ -372,7 +372,7 @@ public void testComplexProfile() { 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 avgBreakdown = tagsAggResult.getTimeBreakdown(); @@ -389,7 +389,7 @@ public void testComplexProfile() { 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 maxBreakdown = tagsAggResult.getTimeBreakdown(); @@ -406,7 +406,7 @@ public void testComplexProfile() { 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 stringsBreakdown = stringsAggResult.getTimeBreakdown(); @@ -423,7 +423,7 @@ public void testComplexProfile() { 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 void testComplexProfile() { 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 void testComplexProfile() { 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 void testComplexProfile() { 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 void testComplexProfile() { 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(); diff --git a/docs/reference/search/profile.asciidoc b/docs/reference/search/profile.asciidoc index f18dab54ccefb..c864c643c8f6b 100644 --- a/docs/reference/search/profile.asciidoc +++ b/docs/reference/search/profile.asciidoc @@ -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/] - -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. +// TESTRESPONSE[s/(?<=[" ])\d+(\.\d+)?/$body.$_path/] +// TESTRESPONSE[s/"id": "\[P6-vulHtQRWuD4YnubWb7A\]\[test\]\[0\]"/"id": $body.profile.shards.0.id/] -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. +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 `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