# How to track down slow Elasticsearch queries?

**URL:** <https://discuss.elastic.co/t/how-to-track-down-slow-elasticsearch-queries/169497>\
**Category:** Elasticsearch\
**Created:** [February 21, 2019, 10:28pm UTC](https://discuss.elastic.co/t/how-to-track-down-slow-elasticsearch-queries/169497 "2019-02-21T22:28:13Z")\
**Posts on this page:** 7\
**Page:** 1

<div class="post-metadata">

**Author:** ![rpm1984](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rpm1984/32/36595_2.png) [@rpm1984](https://discuss.elastic.co/u/rpm1984)\
**Post date:** [February 21, 2019, 10:28pm UTC](https://discuss.elastic.co/t/how-to-track-down-slow-elasticsearch-queries/169497/1 "2019-02-21T22:28:13Z")

</div>

Hi there,

I need some advice on how to diagnose slow Elasticseach queries.

**Setup**

- 2 node cluster in ElasticCloud (1 primary shard, 1 replica). note: ElasticCloud = no slowlog.
- Interacting with cluster via my Azure .NET Web App, using the NEST library

**Behaviour**

- Most response times for my web server are 50-80ms
- All query times in ES (e.g `took`) are \< 5ms.
- Network latency between my web server and ElasticCloud is about 15ms

**Problem**  
Sometimes, the response times jump between 100-200ms, but the `took` is still 1ms. I was able to replicate this behaviour on local too (using ElasticSearch docker).

Here's a trace from Fiddler i captured, which is the call to Elasticsearch from my app:

```
ClientConnected: 17:28:44.325
ClientBeginRequest: 17:34:34.953
GotRequestHeaders: 17:34:34.953
ClientDoneRequest: 17:34:34.953
Determine Gateway: 0ms
DNS Lookup: 0ms
TCP/IP Connect: 0ms
HTTPS Handshake: 0ms
ServerConnected: 17:34:27.538
FiddlerBeginRequest: 17:34:34.953
ServerGotRequest: 17:34:34.953
ServerBeginResponse: 17:34:35.171
GotResponseHeaders: 17:34:35.171
ServerDoneResponse: 17:34:35.172
ClientBeginResponse: 17:34:35.172
ClientDoneResponse: 17:34:35.178

```

So, above is saying the Elasticsearch cluster took 218ms to process the request. However the `took` is 1ms.

How can i track this slow request down? Clearly it's not the _query_ speed (since took is low), so it must be something in the cluster.

Any advice?

---

<div class="post-metadata">

**Author:** ![danielmitterdorfer](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/danielmitterdorfer/32/110510_2.png) [@danielmitterdorfer](https://discuss.elastic.co/u/danielmitterdorfer)\
**Post date:** [March 1, 2019, 10:20am UTC](https://discuss.elastic.co/t/how-to-track-down-slow-elasticsearch-queries/169497/2 "2019-03-01T10:20:23Z")

</div>

Hi,

the `took` timer only starts to tick once the search is ready to be processed so I wonder whether in your case you have a lot of requests queued up. As you mention, the slowlog would not be of any use because once the query is ready to be processed, it's executed quickly. I would start by checking the [node stats API](https://www.elastic.co/guide/en/elasticsearch/reference/current/cluster-nodes-stats.html) and watch the thread pools' queue lengths.

Daniel

---

<div class="post-metadata">

**Author:** ![rpm1984](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rpm1984/32/36595_2.png) [@rpm1984](https://discuss.elastic.co/u/rpm1984)\
**Post date:** [March 6, 2019, 4:59am UTC](https://discuss.elastic.co/t/how-to-track-down-slow-elasticsearch-queries/169497/3 "2019-03-06T04:59:33Z")

</div>

@danielmitterdorfer thanks for jumping in on this. much appreciated 🙂

If you check my Stackoverflow question i also raised with the same issue, you'll see all the stats from Kibana, including 'read threads': [https://stackoverflow.com/questions/54857104/how-to-track-down-slow-elasticsearch-queries](https://stackoverflow.com/questions/54857104/how-to-track-down-slow-elasticsearch-queries)

I assume this is the same stat as the one you're wanting from the node stats API? Also - that API would only ever give me a 'point in time' representation... which is hard to get during a load test, moreso since the 'slowness' only appears to occur for a few seconds.

So - does the StackOverflow pics i posted help in any way? or is there more stats i should provide/look into?

Many thanks again. Been stumped on this one for a while, so glad someone is helping me out 🙂

---

<div class="post-metadata">

**Author:** ![danielmitterdorfer](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/danielmitterdorfer/32/110510_2.png) [@danielmitterdorfer](https://discuss.elastic.co/u/danielmitterdorfer)\
**Post date:** [March 8, 2019, 11:54am UTC](https://discuss.elastic.co/t/how-to-track-down-slow-elasticsearch-queries/169497/4 "2019-03-08T11:54:06Z")

</div>

I had a look at the charts but nothing stands out immediately: GC is fine, also the `search` thread pool's queue never spikes although you might be fooled by the sampling frequency, I'd still double-check the raw numbers via the node stats API as I've suggested, especially the thread pool statistics. If that does not reveal anything I'd take a closer look at the network between your client and Elasticsearch.

---

<div class="post-metadata">

**Author:** ![rpm1984](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rpm1984/32/36595_2.png) [@rpm1984](https://discuss.elastic.co/u/rpm1984)\
**Post date:** [March 8, 2019, 9:03pm UTC](https://discuss.elastic.co/t/how-to-track-down-slow-elasticsearch-queries/169497/5 "2019-03-08T21:03:47Z")

</div>

K, I'll try the node stats API.

I don't believe it's the network. Proof of that is the Fiddler trace I captured. You can see full trace in Stack overflow question, but the pertinent part is this:

```auto
ServerGotRequest: 17:34:34.953 
ServerBeginResponse: 17:34:35.171 

```

So that's 200+ms for Elasticsearch to produce a response, eg not on the external network.

I'm wondering if it's an elastic cloud network issue? Between the ELB and the nodes etc?

Is there anywhere I can see traces of requests coming into the cluster, and going out?

---

<div class="post-metadata">

**Author:** ![rpm1984](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rpm1984/32/36595_2.png) [@rpm1984](https://discuss.elastic.co/u/rpm1984)\
**Post date:** [March 19, 2019, 4:41am UTC](https://discuss.elastic.co/t/how-to-track-down-slow-elasticsearch-queries/169497/6 "2019-03-19T04:41:46Z")

</div>

> [@danielmitterdorfer](#):
>
> I'd still double-check the raw numbers via the node stats API as I've suggested, especially the thread pool statistics.

@danielmitterdorfer

regarding the node stats API, what numbers should i be looking for?  
i'm guessing we're interested in this part:

```auto
"search" : {
          "threads" : 4,
          "queue" : 0,
          "active" : 0,
          "rejected" : 0,
          "largest" : 4,
          "completed" : 13020477
        },

```

Should i just be looking to make sure the `queue` is empty?

Also - isn't this just the same as the 'read threads' stat i posted in StackOverflow?

---

<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:** [April 16, 2019, 4:41am UTC](https://discuss.elastic.co/t/how-to-track-down-slow-elasticsearch-queries/169497/7 "2019-04-16T04:41:53Z")

</div>

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