# How to find out why a document get is slow?

**URL:** <https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203>\
**Category:** Elasticsearch\
**Created:** [January 30, 2017, 11:59am UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203 "2017-01-30T11:59:00Z")\
**Posts on this page:** 14\
**Page:** 1

<div class="post-metadata">

**Author:** ![Attila\_Nagy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/attila_nagy/32/46906_2.png) [@Attila\_Nagy](https://discuss.elastic.co/u/Attila_Nagy)\
**Post date:** [January 30, 2017, 11:59am UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203/1 "2017-01-30T11:59:00Z")

</div>

Hi,

After upgrading from 2.4 to 5.1.2, we can see a tremendous increase of response times in simple document gets (from java's get API over transport protocol).  
Previously -with 2.4-, the response times were in the range of few millisecs (1-5), now there are responses above 1-2 seconds, but only a few. The median seems to be OK.

The slow query doc says that there is no slow query logging for exact gets, just indexing and searches.  
So what's the preferred method of finding out why these get queries are slow?

---

<div class="post-metadata">

**Author:** ![spinscale](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/spinscale/32/25011_2.png) [@spinscale](https://discuss.elastic.co/u/spinscale)\
**Post date:** [January 31, 2017, 8:38am UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203/2 "2017-01-31T08:38:06Z")

</div>

Hey,

if you run the GET API, then no query is issued, so no slow query entry is being created. You can use the [hot threads API](https://www.elastic.co/guide/en/elasticsearch/reference/5.1/cluster-nodes-hot-threads.html) to check what causes high CPU usage.

Also [nodes stats APIs](https://www.elastic.co/guide/en/elasticsearch/reference/5.1/cluster-nodes-stats.html) might be worth taking a look (and comparing against your old system).

--Alex

---

<div class="post-metadata">

**Author:** ![Attila\_Nagy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/attila_nagy/32/46906_2.png) [@Attila\_Nagy](https://discuss.elastic.co/u/Attila_Nagy)\
**Post date:** [January 31, 2017, 9:57am UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203/3 "2017-01-31T09:57:47Z")

</div>

Hi,

Hot\_threads look like this:  
[http://pastebin.com/sntJza2s](http://pastebin.com/sntJza2s)  
node stats:  
[http://pastebin.com/gFfGTUXr](http://pastebin.com/gFfGTUXr)

Sadly, the upgrade was in-place, so I have no textual output for the old system.

Thanks,

---

<div class="post-metadata">

**Author:** ![spinscale](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/spinscale/32/25011_2.png) [@spinscale](https://discuss.elastic.co/u/spinscale)\
**Post date:** [January 31, 2017, 10:21am UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203/4 "2017-01-31T10:21:31Z")

</div>

Hey,

due to the amount of data I had only a quick look. You are spending a lot of time in warmers. to create parent child data structures. Why is that? Could you use [eager\_global\_ordinals](https://www.elastic.co/guide/en/elasticsearch/guide/current/preload-fielddata.html#eager-global-ordinals) instead?

--Alex

---

<div class="post-metadata">

**Author:** ![Attila\_Nagy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/attila_nagy/32/46906_2.png) [@Attila\_Nagy](https://discuss.elastic.co/u/Attila_Nagy)\
**Post date:** [January 31, 2017, 10:33am UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203/5 "2017-01-31T10:33:58Z")

</div>

Can I narrow this to at least an index, or mapping? We don't use parent child explicitly (I mean I don't know whether elasticsearch uses it internally somehow), although we've had a mapping where it was defined, but left unused.  
So I can't answer this question. It would be good to see in what index/mapping does this happen.

Also, in ES2.4 we couldn't see this behaviour (I don't have a hot\_threads dump, but the response times were quick). It started to appear with the upgrade to 5.1.2. Is there something, which has changed considerably in this area?

---

<div class="post-metadata">

**Author:** ![spinscale](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/spinscale/32/25011_2.png) [@spinscale](https://discuss.elastic.co/u/spinscale)\
**Post date:** [January 31, 2017, 11:29am UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203/6 "2017-01-31T11:29:38Z")

</div>

Hey,

wait, something is weird here. You said you are using Elasticsearch 5.1.2, but warmers were removed in 5.1. Are you sure you dont have another version running... I'm confused now 🙂

--Alex

---

<div class="post-metadata">

**Author:** ![Attila\_Nagy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/attila_nagy/32/46906_2.png) [@Attila\_Nagy](https://discuss.elastic.co/u/Attila_Nagy)\
**Post date:** [January 31, 2017, 11:34am UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203/7 "2017-01-31T11:34:26Z")

</div>

I have also found that strange, when I've checked the docs which said they were deprecated in 2.3.0.  
Here's what I have:

# curl -s '[http://localhost:9200/\_cat/nodes?v&h=v,id](http://localhost:9200/_cat/nodes?v&h=v,id)'

v id  
5.1.2 9YnN  
5.1.2 wzS5  
5.1.2 mTac  
5.1.2 -\_zl  
5.1.2 uZ2l  
5.1.2 Zhv2  
5.1.2 ebJt  
5.1.2 HEI1  
5.1.2 sPrn  
5.1.2 Gwgn  
5.1.2 USXH  
5.1.2 kxzX  
5.1.2 Cksl  
5.1.2 H3w1  
5.1.2 XdeO  
5.1.2 q8Wx  
5.1.2 1qbk  
5.1.2 X\_QX  
5.1.2 GauH  
5.1.2 43Gj  
5.1.2 1T6O  
5.1.2 Wyje  
5.1.2 b6L9  
5.1.2 HC5i  
5.1.2 g6XG  
5.1.2 BojW

BTW, the indexes were created in 2.x.

---

<div class="post-metadata">

**Author:** ![spinscale](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/spinscale/32/25011_2.png) [@spinscale](https://discuss.elastic.co/u/spinscale)\
**Post date:** [January 31, 2017, 11:45am UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203/8 "2017-01-31T11:45:33Z")

</div>

That looks good. You also said that you dont use parent-child. Elasticsearch does not use this unless it is configured explicitely. You can use the `_mapping` endpoint to get the mapping of all indices.

---

<div class="post-metadata">

**Author:** ![Attila\_Nagy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/attila_nagy/32/46906_2.png) [@Attila\_Nagy](https://discuss.elastic.co/u/Attila_Nagy)\
**Post date:** [January 31, 2017, 11:47am UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203/9 "2017-01-31T11:47:57Z")

</div>

I have a mapping defined with parent-child, but no documents were inserted with that.  
This is still in the index:

```
  "messages_29" : {
    "mappings" : {
      "message_search_helper" : {
        "dynamic" : "strict",
        "include_in_all" : false,
        "_parent" : {
          "type" : "message"
        },
        "_routing" : {
          "required" : true
        },
        "properties" : {
          "searchId" : {
            "type" : "long"
          }
        }
      },

```

But no docs are stored with it:

```
curl -s 'http://localhost:9200/messages_29/message_search_helper/_count' 
{"count":0,"_shards":{"total":1,"successful":1,"failed":0}}
```

---

<div class="post-metadata">

**Author:** ![Attila\_Nagy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/attila_nagy/32/46906_2.png) [@Attila\_Nagy](https://discuss.elastic.co/u/Attila_Nagy)\
**Post date:** [January 31, 2017, 3:45pm UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203/10 "2017-01-31T15:45:42Z")

</div>

BTW, I'm also confused. If there are no warmers, why do I see those in the hot\_threads output?

---

<div class="post-metadata">

**Author:** ![spinscale](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/spinscale/32/25011_2.png) [@spinscale](https://discuss.elastic.co/u/spinscale)\
**Post date:** [January 31, 2017, 5:12pm UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203/11 "2017-01-31T17:12:55Z")

</div>

Hey,

so there are still warmers for some tasks, like the parent/child handling. Can you delete that parent child index (it seems to be empty anyway) and see if those warmers and their CPU usage go away (just a guess here)?

Also, is there constant CPU usage by the warmers? Like all the time? Have you run a couple of more hot threads requests?

Deeply wondering how any warmers can consume CPU, but you dont have any indices with parent child, that contain data

--Alex

---

<div class="post-metadata">

**Author:** ![Attila\_Nagy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/attila_nagy/32/46906_2.png) [@Attila\_Nagy](https://discuss.elastic.co/u/Attila_Nagy)\
**Post date:** [February 1, 2017, 10:03am UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203/12 "2017-02-01T10:03:33Z")

</div>

Hi,

Sadly, we have other, valuable data in those indexes. But we will reindex those to see what changes.  
BTW, the same was the case with ES2.4 and there the performance was OK. Do you know about any changes which could cause this?

I will report back with the findings, when the indexes got reindexed.

---

<div class="post-metadata">

**Author:** ![Attila\_Nagy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/attila_nagy/32/46906_2.png) [@Attila\_Nagy](https://discuss.elastic.co/u/Attila_Nagy)\
**Post date:** [February 2, 2017, 1:40pm UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203/13 "2017-02-02T13:40:18Z")

</div>

By reindexing all indexes, things looks better. The warmers' high CPU usage has disappeared, now hot\_threads show only some merge tasks, or snapshot-related stuff (backups possibly).  
Also, after the reindex, extremely long get responses are gone, now I can see this for today:

```
       N Min Max Median Avg Stddev
x 89971255 0.255709 3056.4011 1.165522 2.5856993 17.446189

```

So it seems that parent-child mapping, which never had any doc caused some of the troubles.  
Thanks,

---

<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:** [March 2, 2017, 1:40pm UTC](https://discuss.elastic.co/t/how-to-find-out-why-a-document-get-is-slow/73203/14 "2017-03-02T13:40:27Z")

</div>

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