# Nested aggregation of 7 documents takes 1 min **URL:** \ **Category:** Elasticsearch\ **Created:** [February 4, 2020, 1:48pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823 "2020-02-04T13:48:38Z")\ **Posts on this page:** 20\ **Page:** 1
**Author:** ![naoko](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/naoko/32/11822_2.png) [@naoko](https://discuss.elastic.co/u/naoko)\ **Post date:** [February 4, 2020, 1:48pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/1 "2020-02-04T13:48:38Z")
I have the following query where 1. query will return 7 hits and if execute without agg, it complete in 62ms. 2. removing nested "hour\_bucket" agg will complete in 180ms 3. but executing nested aggs takes about 1 min is the query below the only aggregate against 7 documents only or doing something else? Is there any way to improve? mapping ```auto { "user_id":{"type":"keyword"}, "connected":{"type":"keyword"}, "start_time":{"type":"date","format":"yyyyMMddHHmmss.SSS"}, "record_id": {"type":"keyword"} } ``` query: `my-index/_search?size=0` ```auto { "query": { "bool": { "filter": [] } }, "aggs": { "users": { "terms": { "size": 2147483647, "field": "user_id" }, "aggs": { "hour_buckets": { "aggs": { "Missed": { "filter": { "bool": { "must_not": { "term": { "connected": "Yes" } } } }, "aggs": { "Missed": { "sum": { "field": "inbound" } } } }, "Answered": { "filter": { "term": { "connected": "Yes" } }, "aggs": { "Answered": { "value_count": { "field": "record_id" } } } } }, "terms": { "min_doc_count": 0, "script": "doc['start_time'].date.hourOfDay", "size": 24 } } } } } } ``` ---
**Author:** ![Christian\_Dahlqvist](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/christian_dahlqvist/32/4617_2.png) [@Christian\_Dahlqvist](https://discuss.elastic.co/u/Christian_Dahlqvist)\ **Post date:** [February 4, 2020, 2:03pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/2 "2020-02-04T14:03:20Z")
Try setting the size field in the terms aggregation to something more reasonable and see if that makes any difference. ---
**Author:** ![naoko](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/naoko/32/11822_2.png) [@naoko](https://discuss.elastic.co/u/naoko)\ **Post date:** [February 4, 2020, 2:16pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/3 "2020-02-04T14:16:30Z")
@Christian_Dahlqvist, thank you for your advice. I set changed size value from `2147483647` to `10,000`, `1,000`, and `100` but still took 54-56 seconds. Anything else I can try? ---
**Author:** ![Mark\_Harwood](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/mark_harwood/32/10538_2.png) [@Mark\_Harwood](https://discuss.elastic.co/u/Mark_Harwood)\ **Post date:** [February 4, 2020, 2:40pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/4 "2020-02-04T14:40:09Z")
> [@naoko](#): > > Anything else I can try? We could speculate but next I'd try dropping different sub-branches of the `hour_bucket ` aggregation to identify any hotspots. ---
**Author:** ![naoko](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/naoko/32/11822_2.png) [@naoko](https://discuss.elastic.co/u/naoko)\ **Post date:** [February 4, 2020, 2:57pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/5 "2020-02-04T14:57:55Z")
@Mark_Harwood, I did. I dropped "Missed" only and "Answered" only but no change (53 seconds plus). It only changes when I drop the entire "aggs" of "hour\_buckets" (75 ms). Do you know if ES is doing agg of resulting query of 7 hits? It certainly doesn't seem so (I'm only guessing from how long it takes to complete agg). I also try to add range filter in query clause to "Answered" and "Missed" filter but no change there either (56 seconds with an additional filter within nested agg. ---
**Author:** ![Mark\_Harwood](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/mark_harwood/32/10538_2.png) [@Mark\_Harwood](https://discuss.elastic.co/u/Mark_Harwood)\ **Post date:** [February 4, 2020, 3:04pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/6 "2020-02-04T15:04:34Z")
> [@naoko](#): > > I dropped "Missed" only and "Answered" only What happens if you drop both, leaving only the scripted `terms` agg? I'd have expected script execution times to be a multiple of the number of matching docs, not the number of docs in the index. ---
**Author:** ![naoko](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/naoko/32/11822_2.png) [@naoko](https://discuss.elastic.co/u/naoko)\ **Post date:** [February 4, 2020, 3:11pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/7 "2020-02-04T15:11:22Z")
@Mark_Harwood, when I drop both and leaving only the scripted "terms" agg took 56 seconds so culprit seems to be this one? Based on your expectation (script execution times to be a multiple of the number of matching docs and not the number of docs in the index), it should be still fast as there are only 7 matching docs 🤔 ---
**Author:** ![Mark\_Harwood](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/mark_harwood/32/10538_2.png) [@Mark\_Harwood](https://discuss.elastic.co/u/Mark_Harwood)\ **Post date:** [February 4, 2020, 3:16pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/8 "2020-02-04T15:16:41Z")
> [@naoko](#): > > it should be still fast as there are only 7 matching docs Agreed. Each of these 7 docs only has one user and one timestamp, right? Otherwise a doc with arrays full of user ids would create many user buckets. ---
**Author:** ![naoko](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/naoko/32/11822_2.png) [@naoko](https://discuss.elastic.co/u/naoko)\ **Post date:** [February 4, 2020, 3:43pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/9 "2020-02-04T15:43:43Z")
@Mark_Harwood, correct. Each of these 7 docs only has one user and one field called "start\_time". When I changed "script" to "field" and picked some keyword field in "terms" and execution time was 41 ms. But I can now confirm your expectation. We store data in multiple indices (create daily) and I query individually. `/day1_index/` total doc in index: 2,913,609 match: 0 docs execution time: 45 ms `/day2_index/` total doc in index: 2,878,023 match: 2 docs execution time: 20 seconds `/day3_index/` total doc in index: 2,906,909 match: 5 docs execution time: 50 seconds So the question is why the script execution is so slow... Any idea? ---
**Author:** ![Mark\_Harwood](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/mark_harwood/32/10538_2.png) [@Mark\_Harwood](https://discuss.elastic.co/u/Mark_Harwood)\ **Post date:** [February 4, 2020, 4:06pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/10 "2020-02-04T16:06:40Z")
Hmm. Can you get a [hot threads dump](https://www.elastic.co/guide/en/elasticsearch/reference/current/cluster-nodes-hot-threads.html) while the slow query is running? Another thing to try is to see if it is scripting in general or the combination of dates and scripts - can you try get the script to return a keyword field like the record\_id and time that? ---
**Author:** ![naoko](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/naoko/32/11822_2.png) [@naoko](https://discuss.elastic.co/u/naoko)\ **Post date:** [February 4, 2020, 4:25pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/11 "2020-02-04T16:25:13Z")
It appears to be script in general. I changed from `"doc['start_time'].date.hourOfDay"` to `"doc['record_id']"` and took 56 seconds (no change). I also changed to `"doc['start_time'].date.hour"` and this one took 28 seconds. Not good enough but much improvement... Below is the hot threads dump after at 15 seconds mark of the query in question execution. the dump is located here: [https://drive.google.com/file/d/1jZQJLd2vWYi-U3-c9AE-ftN1N9jTDkoV/view?usp=sharing](https://drive.google.com/file/d/1jZQJLd2vWYi-U3-c9AE-ftN1N9jTDkoV/view?usp=sharing) ---
**Author:** ![Mark\_Harwood](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/mark_harwood/32/10538_2.png) [@Mark\_Harwood](https://discuss.elastic.co/u/Mark_Harwood)\ **Post date:** [February 4, 2020, 5:11pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/12 "2020-02-04T17:11:51Z")
Thanks for this. The hot threads look like monitoring activity is hammering the CPU so there may be some contention there. Do you have something calling the stats API aggressively? Our own monitoring services can be behind this so you might want to dial back the frequency of checks in the [settings](https://www.elastic.co/guide/en/elasticsearch/reference/current/monitoring-settings.html). > [@naoko](#): > > `"doc['record_id']"` and took 56 seconds Putting aside the monitoring overheads, this may have taken time for different reasons - it could be loading global ordinals so can you run this terms aggregation on the record\_id field and add the [execution\_hint](https://www.elastic.co/guide/en/elasticsearch/reference/current/search-aggregations-bucket-terms-aggregation.html#search-aggregations-bucket-terms-aggregation-execution-hint) setting to be "map" and time that? Also, what version of elasticsearch are you running? There was an [issue](https://github.com/elastic/elasticsearch/issues/35754#issuecomment-455419860) with logging deprecation warnings around use of joda time which got [fixed](https://github.com/elastic/elasticsearch/pull/38780) around 6.7/7.2 ---
**Author:** ![naoko](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/naoko/32/11822_2.png) [@naoko](https://discuss.elastic.co/u/naoko)\ **Post date:** [February 4, 2020, 6:24pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/13 "2020-02-04T18:24:31Z")
The version of elasticsearch is 6.8.2. So sounds like the version we run have the "fix" in. Adding `"execution_hint": "map"` to `"script": "doc['record_id']"` did not change the execution time. I ran `/usr/share/elasticsearch/bin/elasticsearch-plugin list` but nothing was returned. So monitoring does not seems to be enabled ☹ I hope I have not exhausted the options yet... I saw one suggestion to store "hour of the day" separately to aggregate but the question still remains why only 7 matched record script term aggregation would take nearly one minute. @Mark_Harwood, sorry for taking up your time... last question - it appears that `getHour` and `getHourOfDay` seems to result in the same result but I could not find documentation to validate. Do you know if that is the case? Thank you, ---
**Author:** ![Mark\_Harwood](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/mark_harwood/32/10538_2.png) [@Mark\_Harwood](https://discuss.elastic.co/u/Mark_Harwood)\ **Post date:** [February 4, 2020, 7:27pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/14 "2020-02-04T19:27:54Z")
> [@naoko](#): > > it appears that `getHour` and `getHourOfDay` seems to result in the same result Not sure about that but it should be in the reference docs. > [@naoko](#): > > Adding `"execution_hint": "map"` to `"script": "doc['record_id']"` did not change the execution time. I meant for that test to be done on the terms agg without a script - so with ‘“field” : “record\_id”’ instead > [@naoko](#): > > So monitoring does not seems to be enabled ☹ Maybe you have something else gathering stats through the stats api? ---
**Author:** ![naoko](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/naoko/32/11822_2.png) [@naoko](https://discuss.elastic.co/u/naoko)\ **Post date:** [February 4, 2020, 7:36pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/15 "2020-02-04T19:36:38Z")
> [@Mark\_Harwood](#): > > I meant for that test to be done on the terms agg without a script - so with ‘“field” : “record\_id”’ instead Oh sorry, yes I have done it without script and it completed in 117 ms. So definitely script is the culprit. ---
**Author:** ![Mark\_Harwood](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/mark_harwood/32/10538_2.png) [@Mark\_Harwood](https://discuss.elastic.co/u/Mark_Harwood)\ **Post date:** [February 4, 2020, 7:40pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/16 "2020-02-04T19:40:13Z")
Ok - so maybe it’s CPU contention with all the stats gathering stuff we saw in the hot threads dump. Are these nodes running hot when you’re not busy doing these scripted queries? ---
**Author:** ![naoko](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/naoko/32/11822_2.png) [@naoko](https://discuss.elastic.co/u/naoko)\ **Post date:** [February 4, 2020, 8:01pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/17 "2020-02-04T20:01:22Z")
I checked hot dump when running query and not running query. When not running query, all node's cpu usage is near 1%. As soon as I run the query, 2 nodes hits over 80% and it is clear that running my script ```auto 84.0% (419.7ms out of 500ms) cpu usage by thread 'elasticsearch[analytics-elastic12-s01][search][T#5]' 10/10 snapshots sharing following 31 elements java.security.AccessController.doPrivileged(Native Method) org.elasticsearch.index.fielddata.ScriptDocValues.deprecated(ScriptDocValues.java:126) org.elasticsearch.index.fielddata.ScriptDocValues$Dates.getDate(ScriptDocValues.java:277) java.lang.invoke.LambdaForm$DMH/1144748369.invokeSpecial_L_L(LambdaForm$DMH) java.lang.invoke.LambdaForm$BMH/1608103523.reinvoke(LambdaForm$BMH) java.lang.invoke.LambdaForm$MH/379110473.delegate(LambdaForm$MH) java.lang.invoke.LambdaForm$MH/1293090980.guard(LambdaForm$MH) java.lang.invoke.LambdaForm$MH/1242711236.linkToCallSite(LambdaForm$MH) org.elasticsearch.painless.PainlessScript$Script.execute(doc['start_time'].date.getHour():18) org.elasticsearch.painless.ScriptImpl.run(ScriptImpl.java:104) org.elasticsearch.search.aggregations.support.values.ScriptBytesValues.advanceExact(ScriptBytesValues.java:56) org.elasticsearch.search.aggregations.bucket.terms.StringTermsAggregator.buildAggregation(StringTermsAggregator.java:119) org.elasticsearch.search.aggregations.AggregatorFactory$MultiBucketAggregatorWrapper.buildAggregation(AggregatorFactory.java:151) org.elasticsearch.search.aggregations.bucket.BestBucketsDeferringCollector$2.buildAggregation(BestBucketsDeferringCollector.java:213) org.elasticsearch.search.aggregations.bucket.BucketsAggregator.bucketAggregations(BucketsAggregator.java:141) org.elasticsearch.search.aggregations.bucket.terms.GlobalOrdinalsStringTermsAggregator.buildAggregation(GlobalOrdinalsStringTermsAggregator.java:238) org.elasticsearch.search.aggregations.AggregationPhase.execute(AggregationPhase.java:130) org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:120) org.elasticsearch.search.SearchService.loadOrExecuteQueryPhase(SearchService.java:350) org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:394) org.elasticsearch.search.SearchService.access$100(SearchService.java:126) org.elasticsearch.search.SearchService$2.onResponse(SearchService.java:359) org.elasticsearch.search.SearchService$2.onResponse(SearchService.java:355) org.elasticsearch.search.SearchService$4.doRun(SearchService.java:1107) org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) org.elasticsearch.common.util.concurrent.TimedRunnable.doRun(TimedRunnable.java:41) org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:751) org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) java.lang.Thread.run(Thread.java:748) ``` note: I did find the getHour vs getHourOfDay doc. this [Shared API for package java.time | Painless Scripting Language [7.5] | Elastic](https://www.elastic.co/guide/en/elasticsearch/painless/7.5/painless-api-reference-shared-java-time.html) takes you to func def and they are identical. in fact, it says > `getHourOfDay()` should be replaced with `getHour()` here [Breaking changes in 7.0 | Elasticsearch Guide [7.5] | Elastic](https://www.elastic.co/guide/en/elasticsearch/reference/7.5/breaking-changes-7.0.html) ---
**Author:** ![Mark\_Harwood](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/mark_harwood/32/10538_2.png) [@Mark\_Harwood](https://discuss.elastic.co/u/Mark_Harwood)\ **Post date:** [February 4, 2020, 8:18pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/18 "2020-02-04T20:18:44Z")
I see references to field data and deprecation - can you share the full mapping for the date field? ---
**Author:** ![naoko](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/naoko/32/11822_2.png) [@naoko](https://discuss.elastic.co/u/naoko)\ **Post date:** [February 4, 2020, 8:25pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/19 "2020-02-04T20:25:38Z")
Yes, so I switched to `getHour()` from `getHourOfDay()` which for some reason cut the time to half (from 60 sec to 30 sec). Here is the mapping of index ```auto { "app-20200201" : { "mappings" : { "app" : { "properties" : { "answer_time" : { "type" : "date", "format" : "yyyyMMddHHmmss.SSS" }, "area_code_location" : { "type" : "keyword" }, "call_duration_seconds" : { "type" : "integer", "null_value" : 0 }, "call_recording_result" : { "type" : "keyword" }, "called_area_code" : { "type" : "keyword" }, "called_number" : { "type" : "keyword" }, "called_number_state" : { "type" : "keyword" }, "calling_area_code" : { "type" : "keyword" }, "calling_number" : { "type" : "keyword" }, "calling_number_state" : { "type" : "keyword" }, "connected" : { "type" : "keyword" }, "customer_area_code" : { "type" : "keyword" }, "customer_area_code_state" : { "type" : "keyword" }, "customer_number" : { "type" : "keyword" }, "direction" : { "type" : "keyword" }, "end_time" : { "type" : "date", "format" : "yyyyMMddHHmmss.SSS" }, "enterprise_id" : { "type" : "keyword" }, "external" : { "type" : "integer" }, "group_id" : { "type" : "keyword" }, "inbound" : { "type" : "integer" }, "inbound_duration_seconds" : { "type" : "integer", "null_value" : 0 }, "internal" : { "type" : "integer" }, "international_duration_seconds" : { "type" : "integer", "null_value" : 0 }, "international_outbound" : { "type" : "integer" }, "local_call_id" : { "type" : "keyword" }, "other_party_name" : { "type" : "keyword" }, "outbound" : { "type" : "integer" }, "outbound_duration_seconds" : { "type" : "integer", "null_value" : 0 }, "record_id" : { "type" : "keyword" }, "redirection_reason" : { "type" : "keyword" }, "related_call_id" : { "type" : "keyword" }, "related_call_id_reason" : { "type" : "keyword" }, "remote_call_id" : { "type" : "keyword" }, "remote_user_id" : { "type" : "keyword" }, "returned_id" : { "type" : "keyword" }, "start_time" : { "type" : "date", "format" : "yyyyMMddHHmmss.SSS" }, "talk_duration_seconds" : { "type" : "integer", "null_value" : 0 }, "tollfree_duration_seconds" : { "type" : "integer", "null_value" : 0 }, "tollfree_inbound" : { "type" : "integer" }, "user_area_code" : { "type" : "keyword" }, "user_id" : { "type" : "keyword" }, "user_number" : { "type" : "keyword" }, "user_type" : { "type" : "keyword" } } } } } } ``` ---
**Author:** ![Mark\_Harwood](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/mark_harwood/32/10538_2.png) [@Mark\_Harwood](https://discuss.elastic.co/u/Mark_Harwood)\ **Post date:** [February 4, 2020, 8:55pm UTC](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823/20 "2020-02-04T20:55:30Z")
> [@naoko](#): > > which for some reason cut the time to half (from 60 sec to 30 sec). Using non-deprecated methods will avoid logging warnings about use of deprecated features. Reading the docs you linked to it looks [like you need to access the date field using the “value” property](https://www.elastic.co/guide/en/elasticsearch/reference/7.5/breaking-changes-7.0.html#breaking_70_scripting_changes) [Next page](https://discuss.elastic.co/t/nested-aggregation-of-7-documents-takes-1-min/217823.md?page=2)