# Query performance issue - need help to investigate

**URL:** https://discuss.elastic.co/t/query-performance-issue-need-help-to-investigate/38432
**Category:** Elasticsearch
**Created:** [January 5, 2016, 5:46pm UTC](https://discuss.elastic.co/t/query-performance-issue-need-help-to-investigate/38432 "2016-01-05T17:46:41Z")
**Posts on this page:** 10
**Page:** 1

<div class="post-metadata">

### Author: ![rkrombho](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rkrombho/32/3574_2.png) [@rkrombho](https://discuss.elastic.co/u/rkrombho)
#### Post date: [January 5, 2016, 5:46pm UTC](https://discuss.elastic.co/t/query-performance-issue-need-help-to-investigate/38432/1 "2016-01-05T17:46:41Z")

</div>

Hi Folks,

I could need some help in investigating a general performance issue that is going on on my ES 2.1.0 cluster.

First my problem: simple queries such as match\_all (default size: 10, no ordering) constantly take around **~2250ms** even on subsequent executions.  
This is on a single index with ~240,000,000 documents of pretty small document size (overall the index is ~50GB)  
This seem to be a general issue which of course slows down all other kinds of queries and probably aggregations.

Here are some details about my setup:

- Running Elasticsearch 2.1.0 on CentOS 6.7
- 4 Node Cluster (bare metal)
- 16GB Heap per instance with plenty of ram left for disk IO buffering
- Time-based indices (weekly) with each having ~240,000,000 documents and 50GB per index
- Each index got 2 shards with one replica (no routing)
- Configuration is pretty much default apart from `bootstrap.mlockall: true` and some recovery options set
- One storage path per instance (RAID10 spinning disks with pretty good read performance -700-800 MB/s for sequential reads)

While a match\_all query runs there is no noticable disk activity (probably because it is either cached in ES or in the OS cache for subsequent reads).  
Also I can not detect any spike in CPU usage.  
Heap utilization is quite stable at ~50-60% for all instances.

I got the HQ Plugin installed and the only thing which does not look healthy there are the following (from Index Activity):

- Search - Query: 67.41ms [query\_time\_in\_millis / query\_total]
- Search - Fetch: 29.75ms [fetch\_time\_in\_millis / fetch\_total]
- Get - Total: 10.32ms [get.time\_in\_millis / get.total]
- Get - Exists: 11.88ms [get.exists\_time\_in\_millis / get.exists\_total]
- Refresh: 3001.68ms [refresh.total\_time\_in\_millis / refresh.total]
- Flush: 4371.25ms [flush.total\_time\_in\_millis / flush.total]

To add: I only index once every week and am okay with the indexing performance (get 5000 docs per second with one single thread).  
From the numbers this looks like a disk IO problem but all my tests on disk IO look very good (just tested with `hdparm -tT` and reading a chunk of data with `dd`).  
Also as I mentioned this affects queries which are running multiple times and should be served from cache.

Can anyone help me to further investigate this?  
Are there any other useful ES metrics that I could look at?

---

<div class="post-metadata">

### Author: ![rkrombho](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rkrombho/32/3574_2.png) [@rkrombho](https://discuss.elastic.co/u/rkrombho)
#### Post date: [January 5, 2016, 5:47pm UTC](https://discuss.elastic.co/t/query-performance-issue-need-help-to-investigate/38432/2 "2016-01-05T17:47:12Z")

</div>

Also I tried to run a hot\_threads query while the simple `match_all` runs for 2.5 seconds and here are the two outstanding threads:

```
:::
Hot threads at 2016-01-05T17:28:12.147Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:
100.8% (503.7ms out of 500ms) cpu usage by thread 'elasticsearch[esnode-003][search][T#34]'
  7/10 snapshots sharing following 16 elements
    org.apache.lucene.search.Weight$DefaultBulkScorer.scoreAll(Weight.java:226)
    org.apache.lucene.search.Weight$DefaultBulkScorer.score(Weight.java:169)
    org.apache.lucene.search.BulkScorer.score(BulkScorer.java:39)
    org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:772)
    org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:486)
    org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:324)
    org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:106)
    org.elasticsearch.search.SearchService.loadOrExecuteQueryPhase(SearchService.java:363)
    org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:375)
    org.elasticsearch.search.action.SearchServiceTransportAction$SearchQueryTransportHandler.messageReceived(SearchServiceTransportAction.java:368)
    org.elasticsearch.search.action.SearchServiceTransportAction$SearchQueryTransportHandler.messageReceived(SearchServiceTransportAction.java:365)
    org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.doRun(MessageChannelHandler.java:299)
    org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
    java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    java.lang.Thread.run(Thread.java:745)
  3/10 snapshots sharing following 15 elements
    org.apache.lucene.search.Weight$DefaultBulkScorer.score(Weight.java:169)
    org.apache.lucene.search.BulkScorer.score(BulkScorer.java:39)
    org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:772)
    org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:486)
    org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:324)
    org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:106)
    org.elasticsearch.search.SearchService.loadOrExecuteQueryPhase(SearchService.java:363)
    org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:375)
    org.elasticsearch.search.action.SearchServiceTransportAction$SearchQueryTransportHandler.messageReceived(SearchServiceTransportAction.java:368)
    org.elasticsearch.search.action.SearchServiceTransportAction$SearchQueryTransportHandler.messageReceived(SearchServiceTransportAction.java:365)
    org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.doRun(MessageChannelHandler.java:299)
    org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
    java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    java.lang.Thread.run(Thread.java:745)
```

---

<div class="post-metadata">

### Author: ![rkrombho](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rkrombho/32/3574_2.png) [@rkrombho](https://discuss.elastic.co/u/rkrombho)
#### Post date: [January 5, 2016, 5:47pm UTC](https://discuss.elastic.co/t/query-performance-issue-need-help-to-investigate/38432/3 "2016-01-05T17:47:19Z")

</div>

```
::: 
Hot threads at 2016-01-05T17:28:12.148Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:
 
101.0% (504.8ms out of 500ms) cpu usage by thread 'elasticsearch[esnode-004][search][T#21]'
  9/10 snapshots sharing following 17 elements
    org.apache.lucene.search.TopScoreDocCollector$SimpleTopScoreDocCollector$1.collect(TopScoreDocCollector.java:64)
    org.apache.lucene.search.Weight$DefaultBulkScorer.scoreAll(Weight.java:226)
    org.apache.lucene.search.Weight$DefaultBulkScorer.score(Weight.java:169)
    org.apache.lucene.search.BulkScorer.score(BulkScorer.java:39)
    org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:772)
    org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:486)
    org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:324)
    org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:106)
    org.elasticsearch.search.SearchService.loadOrExecuteQueryPhase(SearchService.java:363)
    org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:375)
    org.elasticsearch.search.action.SearchServiceTransportAction$SearchQueryTransportHandler.messageReceived(SearchServiceTransportAction.java:368)
    org.elasticsearch.search.action.SearchServiceTransportAction$SearchQueryTransportHandler.messageReceived(SearchServiceTransportAction.java:365)
    org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.doRun(MessageChannelHandler.java:299)
    org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
    java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    java.lang.Thread.run(Thread.java:745)
  unique snapshot
    org.apache.lucene.search.Weight$DefaultBulkScorer.scoreAll(Weight.java:225)
    org.apache.lucene.search.Weight$DefaultBulkScorer.score(Weight.java:169)
    org.apache.lucene.search.BulkScorer.score(BulkScorer.java:39)
    org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:772)
    org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:486)
    org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:324)
    org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:106)
    org.elasticsearch.search.SearchService.loadOrExecuteQueryPhase(SearchService.java:363)
    org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:375)
    org.elasticsearch.search.action.SearchServiceTransportAction$SearchQueryTransportHandler.messageReceived(SearchServiceTransportAction.java:368)
    org.elasticsearch.search.action.SearchServiceTransportAction$SearchQueryTransportHandler.messageReceived(SearchServiceTransportAction.java:365)
    org.elasticsearch.transport.netty.MessageChannelHandler$RequestHandler.doRun(MessageChannelHandler.java:299)
    org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
    java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    java.lang.Thread.run(Thread.java:745)
```

---

<div class="post-metadata">

### Author: ![rkrombho](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rkrombho/32/3574_2.png) [@rkrombho](https://discuss.elastic.co/u/rkrombho)
#### Post date: [January 6, 2016, 12:24pm UTC](https://discuss.elastic.co/t/query-performance-issue-need-help-to-investigate/38432/4 "2016-01-06T12:24:05Z")

</div>

Another info: Restarting the cluster brings the simple match\_all query down to 1000ms which still seems very high. This seem to increase ofer time after we ran some more complicated queries and aggregation.

---

<div class="post-metadata">

### Author: ![jpountz](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jpountz/32/45836_2.png) [@jpountz](https://discuss.elastic.co/u/jpountz)
#### Post date: [January 6, 2016, 10:46pm UTC](https://discuss.elastic.co/t/query-performance-issue-need-help-to-investigate/38432/5 "2016-01-06T22:46:12Z")

</div>

The hot threads indicate that the execution of your match\_all query is cpu-bound. Elasticsearch 2.2 will bring some performance improvements to the match\_all query (see annotation R at [https://benchmarks.elastic.co/index.html#search\_times](https://benchmarks.elastic.co/index.html#search_times)).

Otherwise there isn't really anything you can do but buying faster hardware: it just takes time to visit all 240M matching documents.

---

<div class="post-metadata">

### 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: [January 6, 2016, 11:04pm UTC](https://discuss.elastic.co/t/query-performance-issue-need-help-to-investigate/38432/6 "2016-01-06T23:04:08Z")

</div>

Have you tried using a larger number of shards for each index?

---

<div class="post-metadata">

### Author: ![rkrombho](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rkrombho/32/3574_2.png) [@rkrombho](https://discuss.elastic.co/u/rkrombho)
#### Post date: [January 7, 2016, 7:48am UTC](https://discuss.elastic.co/t/query-performance-issue-need-help-to-investigate/38432/7 "2016-01-07T07:48:09Z")

</div>

Thanks for your responses!

@jpountz okay I get that but I don't understand why a `match_all` query would ever 'visit' all documents?  
Isn't is just like: please give me any 10 documents + the overall count (which I thought would be available without visiting all documents).  
The Threads seem to spend most time on `org.apache.lucene.search.Weight$DefaultBulkScorer.scoreAll(Weight.java:226)`.  
Without knowing the internals of the lucene api ... why is `match_all` scoring at all? ES Will anyway just return a static score or?  
Good to know about the upcoming improvement. Theoretically I don't have any business case for `match_all`.  
Was using is to measure if there may be a general issue with my cluster because I also see some other queries being very slow (e.g. an `ids` filter with 10 IDs taking 1,5-3 seconds).  
Will try to get a hot\_threads output of my other slow queries to see if this is the same issue.

@Christian_Dahlqvist not yet. Should I? You ask this because you think it may help to parallelize work and by that speed up the process?  
Including the replicas I already have one shard per ES instance.

---

<div class="post-metadata">

### 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: [January 7, 2016, 9:20am UTC](https://discuss.elastic.co/t/query-performance-issue-need-help-to-investigate/38432/8 "2016-01-07T09:20:42Z")

</div>

Having more shards should increase parallelism and ensure all nodes participate in the query. Query performance also tend to depend on shard size, so having a larger number of smaller shards may help performance. I would therefore recommend reindexing into an index with e.g. 8 shards and see if/how that affects performance.

Another benefit of having more shards is that it allows Elasticsearch to more evenly redistribute data on node failure.

---

<div class="post-metadata">

### Author: ![jpountz](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jpountz/32/45836_2.png) [@jpountz](https://discuss.elastic.co/u/jpountz)
#### Post date: [January 7, 2016, 9:22am UTC](https://discuss.elastic.co/t/query-performance-issue-need-help-to-investigate/38432/9 "2016-01-07T09:22:43Z")

</div>

> [@rkrombho](#):
>
> Isn't is just like: please give me any 10 documents + the overall count (which I thought would be available without visiting all documents).

Indeed match\_all could be optimized this way as the number of live documents is cached by the index. Elaseicsearch will do this already if you set size=0 [Optimize counts on simple queries. by jpountz · Pull Request #13037 · elastic/elasticsearch · GitHub](https://github.com/elastic/elasticsearch/pull/13037). I would like to generalize to more cases but this needs some changes if we want to keep the optimization manageable.

> [@rkrombho](#):
>
> why is match\_all scoring at all

This method actually means "collect all matching documents and give them a score". In the match\_all case however, giving a score is just a matter of returning a constant.

> [@rkrombho](#):
>
> Was using is to measure if there may be a general issue with my cluster because I also see some other queries being very slow (e.g. an ids filter with 10 IDs taking 1,5-3 seconds).Will try to get a hot\_threads output of my other slow queries to see if this is the same issue.

That is weird indeed. The hot threads wil help hopefully.

> [@rkrombho](#):
>
> You ask this because you think it may help to parallelize work and by that speed up the process?

Yes because Elasticsearch searches a given shard in a single thread (having replicas or not does not matter). However note that having more shards can also cause problems like less overall compression and more work for elasticsearch to manage all the shards, so you would need to find the sweet spot.

---

<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: [July 5, 2017, 11:26pm UTC](https://discuss.elastic.co/t/query-performance-issue-need-help-to-investigate/38432/10 "2017-07-05T23:26:29Z")

</div>


