# Groovy script execution occassionally "hangs"

**URL:** <https://discuss.elastic.co/t/groovy-script-execution-occassionally-hangs/182319>\
**Category:** Elasticsearch\
**Created:** [May 22, 2019, 8:22pm UTC](https://discuss.elastic.co/t/groovy-script-execution-occassionally-hangs/182319 "2019-05-22T20:22:10Z")\
**Posts on this page:** 2\
**Page:** 1

<div class="post-metadata">

**Author:** ![Bryan\_Warner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/bryan_warner/32/1225_2.png) [@Bryan\_Warner](https://discuss.elastic.co/u/Bryan_Warner)\
**Post date:** [May 22, 2019, 8:22pm UTC](https://discuss.elastic.co/t/groovy-script-execution-occassionally-hangs/182319/1 "2019-05-22T20:22:10Z")

</div>

**ES Version** : 2.4.6  
**Java Version** : openjdk version "1.8.0\_191"  
**OS** : Ubuntu 16.04.3 LTS  
**Node Stats** : 12 data nodes, 48 shards, ~1M parent docs, ~300M child docs  
**Index Refresh Interval** : 1s

Experiencing an odd issue and wanted to see if anyone could offer some insight on what the root issue might be. I've done preliminary research and the only issues I've seen relating to Groovy scripts is possibly memory leaks in 2.4 ([https://github.com/elastic/elasticsearch/issues/18079](https://github.com/elastic/elasticsearch/issues/18079)) and some possible Java CodeCache bug (see [https://bugs.openjdk.java.net/browse/JDK-8023191](https://bugs.openjdk.java.net/browse/JDK-8023191)). However, in our case, we are using indexed/parameterized scripts to avoid constant script recompilation.

Our document model is pretty simple and revolves around a parent/child relationship. The query in question targets the child documents of a single parent record (routed to that parent.id) along with a few standard filters (i.e. non-script query filters). The query returns typically in ~10-20 milliseconds and experiences no problems on subsequent executions

However, we also ask for a few aggregations in the search request using a **FILTERS** aggregation. One particular aggregation filter uses a script-query filter that basically filters out any matches where the comparison of two dates is less than a certain threshold (e.g. return `doc['a_date'].date.getMillis() - doc['b_date'].date.getMillis() <= parameterized_threshold`)

When adding in the aggregations to the original search request, it seems to work fine (and be very performant) up until about the ~5th subsequent request (and by that I mean if a user was to keep making the same request -- possibly with a different parent.id -- upon receiving the response, with no delay). On the ~5th request (again this is an approximation), the search request just hangs and doesn't return for about ~40-60 secs. And after looking at the **hot\_threads** isolated to the node I'm targeting, it hangs specifically inside GroovyScript.run:

```auto
       java.security.AccessController.doPrivileged(Native Method)
       org.elasticsearch.script.groovy.GroovyScriptEngineService$GroovyScript.run(GroovyScriptEngineService.java:278)
       org.elasticsearch.index.query.ScriptQueryParser$ScriptQuery$1$1.get(ScriptQueryParser.java:171)
       org.apache.lucene.search.RandomAccessWeight$1.matches(RandomAccessWeight.java:63)
       org.apache.lucene.search.Weight$DefaultBulkScorer.scoreAll(Weight.java:228)
       org.apache.lucene.search.Weight$DefaultBulkScorer.score(Weight.java:172)
       org.apache.lucene.search.BulkScorer.score(BulkScorer.java:39)
       org.apache.lucene.search.LRUQueryCache.cacheImpl(LRUQueryCache.java:422)
       org.apache.lucene.search.LRUQueryCache$CachingWrapperWeight.cache(LRUQueryCache.java:608)
       org.apache.lucene.search.LRUQueryCache$CachingWrapperWeight.scorer(LRUQueryCache.java:625)
       org.elasticsearch.indices.cache.query.IndicesQueryCache$CachingWeightWrapper.scorer(IndicesQueryCache.java:263)
       org.apache.lucene.search.BooleanWeight.scorer(BooleanWeight.java:389)
       org.apache.lucene.search.Weight.bulkScorer(Weight.java:135)
       org.apache.lucene.search.BooleanWeight.bulkScorer(BooleanWeight.java:370)
       org.apache.lucene.search.LRUQueryCache$CachingWrapperWeight.cache(LRUQueryCache.java:604)
       org.apache.lucene.search.LRUQueryCache$CachingWrapperWeight.scorer(LRUQueryCache.java:625)
       org.elasticsearch.indices.cache.query.IndicesQueryCache$CachingWeightWrapper.scorer(IndicesQueryCache.java:263)
       org.elasticsearch.search.aggregations.bucket.filters.FiltersAggregator.getLeafCollector(FiltersAggregator.java:90)
       org.elasticsearch.search.aggregations.AggregatorBase.getLeafCollector(AggregatorBase.java:132)
       org.elasticsearch.search.aggregations.AggregatorBase.getLeafCollector(AggregatorBase.java:38)
       org.apache.lucene.search.MultiCollector.getLeafCollector(MultiCollector.java:121)
       org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:812)

```

I've isolated the problem to the aggregation filter that applies the `script_query` - when removed from the aggregation request, the problem goes away (meaning I can't re-produce the problem after repeated executions). What's even more _bizarre_ is that the "hung" Groovy script appears even when there are no query matches ... meaning there is no data for the search request to aggregate!

My only conclusion right now is that the execution of the Groovy script is getting blocked by some GC or internal event like a cache-eviction event, but I can't verify that 100% at the moment. I did check various shard stats like `fielddata` cache on the shard I was targeting in my test and they seemed relatively stable (there does seem to be a large number of evictions for `query_cache` ... could that be related to the underlying problem???). However, we use scripts frequently in `function_score` queries and other `ValueSourceMetrics` aggregations with no apparent problems ... so my gut is that it's related to some underling nature of `script_query`

Shard stats:

```auto
store": {
    "size": "171.8gb",
    "size_in_bytes": 184534807270,
    "throttle_time": "0s",
    "throttle_time_in_millis": 0
  },
  "merges": {
    "current": 0,
    "current_docs": 0,
    "current_size": "0b",
    "current_size_in_bytes": 0,
    "total": 151463,
    "total_time": "4.3d",
    "total_time_in_millis": 379084042,
    "total_docs": 4128513473,
    "total_size": "1.4tb",
    "total_size_in_bytes": 1616384533860,
    "total_stopped_time": "0s",
    "total_stopped_time_in_millis": 0,
    "total_throttled_time": "2.5d",
    "total_throttled_time_in_millis": 219188827,
    "total_auto_throttle": "5mb",
    "total_auto_throttle_in_bytes": 5242880
  },
  "query_cache": {
    "memory_size": "206.6mb",
    "memory_size_in_bytes": 216649784,
    "total_count": 7766733200,
    "hit_count": 137685883,
    "miss_count": 7629047317,
    "cache_size": 733,
    "cache_count": 1098447,
    "evictions": 1097714
  },
  "fielddata": {
    "memory_size": "75.3mb",
    "memory_size_in_bytes": 79055664,
    "evictions": 0
  },
  "segments": {
    "count": 26,
    "memory": "402mb",
    "memory_in_bytes": 421545822,
    "terms_memory": "354.4mb",
    "terms_memory_in_bytes": 371677370,
    "stored_fields_memory": "35.3mb",
    "stored_fields_memory_in_bytes": 37068400,
    "term_vectors_memory": "0b",
    "term_vectors_memory_in_bytes": 0,
    "norms_memory": "62.4kb",
    "norms_memory_in_bytes": 63936,
    "doc_values_memory": "12.1mb",
    "doc_values_memory_in_bytes": 12736116,
    "index_writer_memory": "0b",
    "index_writer_memory_in_bytes": 0,
    "index_writer_max_memory": "512mb",
    "index_writer_max_memory_in_bytes": 536870912,
    "version_map_memory": "0b",
    "version_map_memory_in_bytes": 0,
    "fixed_bit_set": "33.5mb",
    "fixed_bit_set_memory_in_bytes": 35187432
  },

```

Any help or tips on where to look further would be greatly appreciated!

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [June 19, 2019, 8:22pm UTC](https://discuss.elastic.co/t/groovy-script-execution-occassionally-hangs/182319/2 "2019-06-19T20:22:11Z")

</div>

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.
