ElasticsearchUncaughtExceptionHandler OutOfMemoryError when running a cardinality query

[AMarthaller]

Elasticsearch version: 5.0.0

Plugins installed: []

JVM version: jre1.8.0_111

OS version: Windows Server 2016 Datacenter

Description of the problem including expected versus actual behavior:
When executing a cardinality query, all data nodes ran out of memory and died. I would expect the circuit breaker to kick in and stop the query.

Steps to reproduce:

1. A user created a Kibana visualization that did unique count of docvalue_1 over docvalue_2.
2. Kibana timed the query out after 30s but ES did not fare so well.

The data nodes (4) all have 28GB physical with half dedicated to ES.

-Xss1m
-Xms14g
-Xmx14g
 
bootstrap.memory_lock: true

The index has 12 shards. The index overall is 400GB with even distribution across the shards. Regardless of setup, my hope would be that running dangerous queries results in the circuit breaker kicking in before killing the nodes.

Provide logs (if relevant):
 
[2016-12-02T01:19:54,982][ERROR][o.e.b.ElasticsearchUncaughtExceptionHandler] [AI-DATA-01] fatal error in thread [elasticsearch[AI-DATA-01][search][T#4]], exiting
java.lang.OutOfMemoryError: Java heap space
               at org.elasticsearch.common.util.PageCacheRecycler$1.newInstance(PageCacheRecycler.java:99) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.common.util.PageCacheRecycler$1.newInstance(PageCacheRecycler.java:96) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.common.recycler.DequeRecycler.obtain(DequeRecycler.java:53) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.common.recycler.AbstractRecycler.obtain(AbstractRecycler.java:33) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.common.recycler.DequeRecycler.obtain(DequeRecycler.java:28) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.common.recycler.FilterRecycler.obtain(FilterRecycler.java:39) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.common.recycler.Recyclers$3.obtain(Recyclers.java:119) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.common.recycler.FilterRecycler.obtain(FilterRecycler.java:39) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.common.util.PageCacheRecycler.bytePage(PageCacheRecycler.java:147) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.common.util.AbstractBigArray.newBytePage(AbstractBigArray.java:112) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.common.util.BigByteArray.(BigByteArray.java:44) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.common.util.BigArrays.newByteArray(BigArrays.java:464) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.common.util.BigArrays.resize(BigArrays.java:488) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.common.util.BigArrays.grow(BigArrays.java:502) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.search.aggregations.metrics.cardinality.HyperLogLogPlusPlus.ensureCapacity(HyperLogLogPlusPlus.java:197) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.search.aggregations.metrics.cardinality.HyperLogLogPlusPlus.collect(HyperLogLogPlusPlus.java:232) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.search.aggregations.metrics.cardinality.CardinalityAggregator$DirectCollector.collect(CardinalityAggregator.java:198) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.search.aggregations.bucket.BucketsAggregator.collectExistingBucket(BucketsAggregator.java:80) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.search.aggregations.bucket.terms.GlobalOrdinalsStringTermsAggregator$2.collect(GlobalOrdinalsStringTermsAggregator.java:128) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.search.aggregations.LeafBucketCollector.collect(LeafBucketCollector.java:82) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.apache.lucene.search.MultiCollector$MultiLeafCollector.collect(MultiCollector.java:174) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
               at org.apache.lucene.search.Weight$DefaultBulkScorer.scoreAll(Weight.java:221) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
               at org.apache.lucene.search.Weight$DefaultBulkScorer.score(Weight.java:172) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
               at org.apache.lucene.search.BulkScorer.score(BulkScorer.java:39) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
               at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:669) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
               at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:473) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
               at org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:370) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:106) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.indices.IndicesService.lambda$loadIntoContext$17(IndicesService.java:1109) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.indices.IndicesService$$Lambda$1467/1254300496.load(Unknown Source) ~[?:?]
               at org.elasticsearch.indices.AbstractIndexShardCacheEntity.loadValue(AbstractIndexShardCacheEntity.java:73) ~[elasticsearch-5.0.0.jar:5.0.0]
               at org.elasticsearch.indices.IndicesRequestCache$Loader.load(IndicesRequestCache.java:148) ~[elasticsearch-5.0.0.jar:5.0.0]

[jpountz]

I would expect the circuit breaker to kick in and stop the query.

The circuit breaker is not perfect, and there are queries that cannot be stopped efficiently since they allocate most memory outside of the circuit breaker tracker, but a cardinality aggregation under a terms aggregation is the kind of query that should work well with the circuit breaker. Would you be able to share the whole search request?

[AMarthaller]

Here is the full query from Kibana.

POST /devices/device/_search
{
   "size": 0,
   "query": {
      "bool": {
         "must": [
            {
               "query_string": {
                  "query": "*",
                  "analyze_wildcard": true
               }
            },
            {
               "range": {
                  "StartTime": {
                     "gte": 1472923594387,
                     "lte": 1480703194388,
                     "format": "epoch_millis"
                  }
               }
            }
         ],
         "must_not": []
      }
   },
   "aggs": {
      "2": {
         "terms": {
            "field": "device",
            "size": 15,
            "order": {
               "1": "desc"
            }
         },
         "aggs": {
            "1": {
               "cardinality": {
                  "field": "Id"
               }
            }
         }
      }
   }
}

[Dyakovvn]

Hello! I have the same problem. I described it on the forum. When the precision_threshhold decreases to 100, the problem disappears. https://discuss.elastic.co/t/5-2-1-elasti-2-4-1/75357/28

[initialcontext]

I hit the same issue where a large cardinality query took down my datanodes with similar stack trace on ES 5.2.2. precision_threshold was default (I think 3000) at the time:

[2017-04-04T00:10:50,663][INFO ][o.e.m.j.JvmGcMonitorService] [prod-esreqdata01] [gc][607212] overhead, spent [394ms] collecting in the last [1s]
[2017-04-04T00:10:51,668][WARN ][o.e.m.j.JvmGcMonitorService] [prod-esreqdata01] [gc][607213] overhead, spent [778ms] collecting in the last [1s]
[2017-04-04T00:10:52,739][WARN ][o.e.m.j.JvmGcMonitorService] [prod-esreqdata01] [gc][607214] overhead, spent [834ms] collecting in the last [1s]
[2017-04-04T00:10:53,829][WARN ][o.e.m.j.JvmGcMonitorService] [prod-esreqdata01] [gc][607215] overhead, spent [866ms] collecting in the last [1s]
[2017-04-04T00:10:54,880][WARN ][o.e.m.j.JvmGcMonitorService] [prod-esreqdata01] [gc][607216] overhead, spent [830ms] collecting in the last [1s]
[2017-04-04T00:10:55,898][WARN ][o.e.m.j.JvmGcMonitorService] [prod-esreqdata01] [gc][607217] overhead, spent [800ms] collecting in the last [1s]
[2017-04-04T00:10:59,469][WARN ][o.e.m.j.JvmGcMonitorService] [prod-esreqdata01] [gc][607218] overhead, spent [3.3s] collecting in the last [3.5s]
[2017-04-04T00:11:02,521][WARN ][o.e.m.j.JvmGcMonitorService] [prod-esreqdata01] [gc][607219] overhead, spent [2.6s] collecting in the last [3s]
[2017-04-04T00:11:04,885][WARN ][o.e.m.j.JvmGcMonitorService] [prod-esreqdata01] [gc][607220] overhead, spent [2.3s] collecting in the last [2.3s]
[2017-04-04T00:11:09,888][WARN ][o.e.m.j.JvmGcMonitorService] [prod-esreqdata01] [gc][607221] overhead, spent [4.9s] collecting in the last [5s]
[2017-04-04T00:11:14,921][WARN ][o.e.m.j.JvmGcMonitorService] [prod-esreqdata01] [gc][607222] overhead, spent [5s] collecting in the last [5s]
[2017-04-04T00:11:20,792][ERROR][o.e.b.ElasticsearchUncaughtExceptionHandler] [prod-esreqdata01] fatal error in thread [elasticsearch[prod-esreqdata01][search][T#1]], exiting
java.lang.OutOfMemoryError: Java heap space
	at org.elasticsearch.common.util.PageCacheRecycler$1.newInstance(PageCacheRecycler.java:99) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.common.util.PageCacheRecycler$1.newInstance(PageCacheRecycler.java:96) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.common.recycler.DequeRecycler.obtain(DequeRecycler.java:53) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.common.recycler.AbstractRecycler.obtain(AbstractRecycler.java:33) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.common.recycler.DequeRecycler.obtain(DequeRecycler.java:28) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.common.recycler.FilterRecycler.obtain(FilterRecycler.java:39) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.common.recycler.Recyclers$3.obtain(Recyclers.java:119) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.common.recycler.FilterRecycler.obtain(FilterRecycler.java:39) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.common.util.PageCacheRecycler.bytePage(PageCacheRecycler.java:147) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.common.util.AbstractBigArray.newBytePage(AbstractBigArray.java:112) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.common.util.BigByteArray.<init>(BigByteArray.java:44) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.common.util.BigArrays.newByteArray(BigArrays.java:464) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.common.util.BigArrays.resize(BigArrays.java:488) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.common.util.BigArrays.grow(BigArrays.java:502) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.search.aggregations.metrics.cardinality.HyperLogLogPlusPlus.ensureCapacity(HyperLogLogPlusPlus.java:197) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.search.aggregations.metrics.cardinality.HyperLogLogPlusPlus.collect(HyperLogLogPlusPlus.java:232) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.search.aggregations.metrics.cardinality.CardinalityAggregator$OrdinalsCollector.postCollect(CardinalityAggregator.java:280) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.search.aggregations.metrics.cardinality.CardinalityAggregator.postCollectLastCollector(CardinalityAggregator.java:120) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.search.aggregations.metrics.cardinality.CardinalityAggregator.getLeafCollector(CardinalityAggregator.java:111) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.search.aggregations.AggregatorBase.getLeafCollector(AggregatorBase.java:149) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.search.aggregations.AggregatorBase.getLeafCollector(AggregatorBase.java:148) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.search.aggregations.AggregatorBase.getLeafCollector(AggregatorBase.java:41) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.apache.lucene.search.MultiCollector.getLeafCollector(MultiCollector.java:121) ~[lucene-core-6.4.1.jar:6.4.1 72f75b2503fa0aa4f0aff76d439874feb923bb0e - jpountz - 2017-02-01 14:43:32]
	at org.apache.lucene.search.FilterCollector.getLeafCollector(FilterCollector.java:40) ~[lucene-core-6.4.1.jar:6.4.1 72f75b2503fa0aa4f0aff76d439874feb923bb0e - jpountz - 2017-02-01 14:43:32]
	at org.elasticsearch.search.query.CancellableCollector.getLeafCollector(CancellableCollector.java:61) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:660) ~[lucene-core-6.4.1.jar:6.4.1 72f75b2503fa0aa4f0aff76d439874feb923bb0e - jpountz - 2017-02-01 14:43:32]
	at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:473) ~[lucene-core-6.4.1.jar:6.4.1 72f75b2503fa0aa4f0aff76d439874feb923bb0e - jpountz - 2017-02-01 14:43:32]
	at org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:379) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:106) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.indices.IndicesService.lambda$loadIntoContext$16(IndicesService.java:1108) ~[elasticsearch-5.2.2.jar:5.2.2]
	at org.elasticsearch.indices.IndicesService$$Lambda$1716/2035669851.accept(Unknown Source) ~[?:?]
	at org.elasticsearch.indices.IndicesService.lambda$cacheShardLevelResult$18(IndicesService.java:1189) ~[elasticsearch-5.2.2.jar:5.2.2]
[2017-04-04T00:18:15,117][INFO ][o.e.n.Node               ] [prod-esreqdata01] initializing ...

Our cluster is well resourced and handles large aggregations regularly (even setting aside that HyperLogLog isn't supposed to eat memory!) so I'm assuming we hit this bug.

[imotov]

Maybe we should revisit #19215

[jhejl2]

I'm facing the same problem. Is there any update to this issue?
Bad aggs query literally really kill the cluster.

To add more informations. Limiting circuit breakers do not prevent from OOM:

{
    "transient": {
        "indices.breaker.total.limit": "40%",
        "indices.breaker.fielddata.limit": "10%",
        "indices.breaker.request.limit": "10%",
        "network.breaker.inflight_requests.limit": "30%"
    }
}'

It is a 40 data + 3 master + 3 client nodes cluster, each with 64GB RAM (31g reserved for a heap) and at least 8 cores of Intel E3-1275 v5.
Yes, there's a lot of data there (~40TB in 2700 shards, lots of logs) and the visualize query aggs do not contain precision_threshold, but I still think that it shouldn't kill the cluster with one query.

Will lowering caches help? Currently I've got:

indices.memory.index_buffer_size: 30%
indices.memory.min_index_buffer_size: 96mb
indices.fielddata.cache.size: 15%
indices.queries.cache.size: 15%

[markharwood]

cc @elastic/es-search-aggs

[polyfractal]

After conferring with @jimczi, this issue is probably resolved now. The query in question was sorting by the cardinality, which was likely tripping the bug fixed in #24941.