# \`refresh=wait\_for\` taking unexpectedly long

**URL:** <https://discuss.elastic.co/t/refresh-wait-for-taking-unexpectedly-long/83691>\
**Category:** Elasticsearch\
**Created:** [April 26, 2017, 11:55am UTC](https://discuss.elastic.co/t/refresh-wait-for-taking-unexpectedly-long/83691 "2017-04-26T11:55:36Z")\
**Posts on this page:** 6\
**Page:** 1

<div class="post-metadata">

**Author:** ![\_markus](https://avatars.discourse-cdn.com/v4/letter/_/ecb155/32.png) [@\_markus](https://discuss.elastic.co/u/_markus)\
**Post date:** [April 26, 2017, 11:55am UTC](https://discuss.elastic.co/t/refresh-wait-for-taking-unexpectedly-long/83691/1 "2017-04-26T11:55:36Z")

</div>

I've started to use `wait_for` after we upgraded to 5.3 (from 1.5) for user-facing parts of the application which require that the next search returns the modified results.

The index refresh\_interval is set to 100ms . When I index e.g. 10 documents (in a batch request) and use different values for `refresh=`, this my current outcome

- `false` (or leaving out): 0.1s (basically: it's indexed async)
- `wait_for`: 4s
- `true`: 1.4s

I also tried to increase `refresh_interval` to 1s and use e.g. `refresh=true` but the timing didn't change.

It's unexpected to me that `refresh=wait_for` would take 4s here. 1.4s also isn't fast but that's an acceptable wait time for us currently.

Also, this are numbers from production from a write-heavy application. That's why I also never really saw this on dev environments which lack write-heavy nature.

I'm using elasticsearch-php client library and specifically all index operations happen via `\Elasticsearch\Client::bulk`:

- the `body` contains all the documents to be sent
- and `refresh` contains one of the values above

I thought that I only have to `wait_for` the `refresh_interval` of 100ms but obviously that assumption is flawed.

How does this work and what can I expect here? Can I improve `refresh=wait_for` performance without falling back to `refresh=true`?

thanks!

---

<div class="post-metadata">

**Author:** ![nik9000](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/nik9000/32/44947_2.png) [@nik9000](https://discuss.elastic.co/u/nik9000)\
**Post date:** [April 26, 2017, 2:09pm UTC](https://discuss.elastic.co/t/refresh-wait-for-taking-unexpectedly-long/83691/2 "2017-04-26T14:09:52Z")

</div>

> [@\_markus](#):
>
> false (or leaving out): 0.1s (basically: it's indexed async)

The translog is still fsynced unless you turned that off. But, yeah, the search data structures aren't built synchronously with your request.

> [@\_markus](#):
>
> I thought that I only have to wait\_for the refresh\_interval of 100ms but obviously that assumption is flawed.

Right. You have to wait for the actual refresh to finish. They might be scheduled to be kicked off every 100ms but it has to wait for a thread on the refresh pool (see [here](https://www.elastic.co/guide/en/elasticsearch/reference/current/modules-threadpool.html) for useful stuff like the size of the pool). And then the refresh has to actually finish. My guess, given that `refresh=true` finishes must faster than `refresh=wait_for`'s time + `refresh_interval` is that the refresh pool is stuffed. `refresh=true` uses the indexing thread pool for the refresh because it is synchronous with the indexing call, I believe. Can you have a look at the nodes stats and check to see if that thread pool has a queue?

> [@\_markus](#):
>
> How does this work and what can I expect here? Can I improve refresh=wait\_for performance without falling back to refresh=true?

My SWAG is that you should raise the refresh interval on indices that you don't use with `refresh=wait_for`. You could raise the size of the thread pool but I'm not sure what side effect that would have.

---

<div class="post-metadata">

**Author:** ![\_markus](https://avatars.discourse-cdn.com/v4/letter/_/ecb155/32.png) [@\_markus](https://discuss.elastic.co/u/_markus)\
**Post date:** [April 27, 2017, 5:22am UTC](https://discuss.elastic.co/t/refresh-wait-for-taking-unexpectedly-long/83691/3 "2017-04-27T05:22:47Z")

</div>

> [@nik9000](#):
>
> Can you have a look at the nodes stats and check to see if that thread pool has a queue?

Anything specific I should look out or? I see the `refresh` and `index` as well as the `bulk` pools:

```JSON
{
  "thread_pool": {
    "bulk": {
      "threads": 10,
      "queue": 0,
      "active": 0,
      "rejected": 0,
      "largest": 10,
      "completed": 29826938
    },
    "fetch_shard_started": {
      "threads": 0,
      "queue": 0,
      "active": 0,
      "rejected": 0,
      "largest": 0,
      "completed": 0
    },
    "fetch_shard_store": {
      "threads": 0,
      "queue": 0,
      "active": 0,
      "rejected": 0,
      "largest": 0,
      "completed": 0
    },
    "flush": {
      "threads": 1,
      "queue": 0,
      "active": 0,
      "rejected": 0,
      "largest": 5,
      "completed": 453
    },
    "force_merge": {
      "threads": 1,
      "queue": 0,
      "active": 0,
      "rejected": 0,
      "largest": 1,
      "completed": 13
    },
    "generic": {
      "threads": 4,
      "queue": 0,
      "active": 0,
      "rejected": 0,
      "largest": 4,
      "completed": 726806
    },
    "get": {
      "threads": 10,
      "queue": 0,
      "active": 0,
      "rejected": 0,
      "largest": 10,
      "completed": 304772
    },
    "index": {
      "threads": 10,
      "queue": 0,
      "active": 0,
      "rejected": 0,
      "largest": 10,
      "completed": 15074
    },
    "listener": {
      "threads": 5,
      "queue": 0,
      "active": 0,
      "rejected": 0,
      "largest": 5,
      "completed": 147613
    },
    "management": {
      "threads": 5,
      "queue": 0,
      "active": 1,
      "rejected": 0,
      "largest": 5,
      "completed": 6501816
    },
    "refresh": {
      "threads": 5,
      "queue": 0,
      "active": 1,
      "rejected": 0,
      "largest": 5,
      "completed": 30810420
    },
    "search": {
      "threads": 16,
      "queue": 0,
      "active": 0,
      "rejected": 0,
      "largest": 16,
      "completed": 30804051
    },
    "snapshot": {
      "threads": 0,
      "queue": 0,
      "active": 0,
      "rejected": 0,
      "largest": 0,
      "completed": 0
    },
    "warmer": {
      "threads": 5,
      "queue": 0,
      "active": 2,
      "rejected": 0,
      "largest": 5,
      "completed": 63761738
    },
    "watcher": {
      "threads": 0,
      "queue": 0,
      "active": 0,
      "rejected": 0,
      "largest": 0,
      "completed": 0
    }
  }
}

```

This snapshot is from right now and I guess there isn't much going on.

Would there be a benefit not using `_bulk` **all** the time?

The implementation can always index multiple documents (of the same type, in my case) at once and indexing a single document isn't a special case =\> just a `_bulk` with one document. However: the _majority_ of indexing requests deal with only a single document.

Looking at the node stats, this is easily reflected in the `completed` of `bulk` vs. `index` pool. TBH I'm surprised there are even ~15k `index.completed` because there's no code we've which performs such operations but maybe that's just something else (Kibana?).  
OTOH, when I read up your link about the pools, `index` and `bulk` have the same default configuration characteristics so this may be a dead end anyway.

> [@nik9000](#):
>
> My SWAG is that you should raise the refresh interval on indices that you don't use with refresh=wait\_for.

Thanks, I actually did that already in the meantime. Since yesterday I completely removed all `refresh=wait_for` and bumped the `refresh_interval` to 1s.

In certain areas, user interaction do now directly cause index requests with `refresh=true`. Since users are hard to control, this could be anything from 0 to 100 concurrently.

I expected this to to not go smooth, but I couldn't detect any real problems so far. CPU load is still stable (but more fluctuating; change was deployed around 14pm in that chart):

 ![](https://us1.discourse-cdn.com/elastic/original/3X/f/c/fc304bf9a5c474dc827ca47c4ca8bb80fb540e50.jpg)

Should I be more careful with too many concurrent index operations performing `refresh=true`?

Thank you very much so far!

---

<div class="post-metadata">

**Author:** ![nik9000](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/nik9000/32/44947_2.png) [@nik9000](https://discuss.elastic.co/u/nik9000)\
**Post date:** [April 27, 2017, 3:08pm UTC](https://discuss.elastic.co/t/refresh-wait-for-taking-unexpectedly-long/83691/4 "2017-04-27T15:08:39Z")

</div>

> [@\_markus](#):
>
> This snapshot is from right now and I guess there isn't much going on.

Looks like just about nothing. 1 active refresh thread and 2 active warmer threads.

One curious thing is that you have 30 million complete search tasks, 30 million complete refresh tasks, and 63 million complete warmer tasks. I'm honestly not sure if that is normal or not! Probably is. Can you get the index stats for warmers on the indices you are doing this wait\_for\_refresh for? I wonder how long they are taking.

It looks like warmers usually don't do a lot of work but if you are using nested documents then they will.

> [@\_markus](#):
>
> Would there be a benefit not using \_bulk all the time?

Just that \_bulk and \_index and separate thread pools with separate queues is all. I had an application that only used` _bulk` even if it had just one thing to update. I bumped the size of the bulk thread pool and everything was fine.

> [@\_markus](#):
>
> Should I be more careful with too many concurrent index operations performing refresh=true?

0-100 is probably not too big a deal. One issue you may have is that you'll end up with very small segments because of the forced refreshes so you'll see more load spent on merging. It might not matter. `refresh=wait_for` won't change the expected segment size.

---

<div class="post-metadata">

**Author:** ![\_markus](https://avatars.discourse-cdn.com/v4/letter/_/ecb155/32.png) [@\_markus](https://discuss.elastic.co/u/_markus)\
**Post date:** [April 27, 2017, 8:11pm UTC](https://discuss.elastic.co/t/refresh-wait-for-taking-unexpectedly-long/83691/5 "2017-04-27T20:11:43Z")

</div>

> [@nik9000](#):
>
> Can you get the index stats for warmers on the indices you are doing this wait\_for\_refresh for? I wonder how long they are taking.

Here they are; TBH not sure what this numbers should tell me (I mean, yes, the individual numbers are clear but I fail to see a conclusion here 😑 ):

```JSON
        "warmer": {
          "current": 1,
          "total": 1839115,
          "total_time_in_millis": 1062636977
        },

```

> [@](#):
>
> if you are using nested documents then they will.

Hmm, yes I'm using nested on two types. This nesting however is basically always like 1:1 (it doesn't contain multiple nested docs, at best always exactly one; at worst none).

Also I'm heavily using Parent/Child documents. This is absolutely required because we're storing posts and comments and we used to store comments directly inside posts but this wasn't really feasible with 100k comment threads ... 🙂

> [@](#):
>
> 0-100 is probably not too big a deal. One issue you may have is that you'll end up with very small segments because of the forced refreshes so you'll see more load spent on merging.

Currently I index with `refresh=true` directly (after the changes mentioned in the first post). I'm wondering the following:

- using this approach, I can hardly control how many `refresh=true` happen concurrently because the indexing has to be performed, no matter
- what if I separate `_bulk` from a manual `/_refresh` call
- and come up with a mechanism so it doesn't get executed e.g. more than once in `100ms`

As I understand it, no matter how many index operations I sent, when I sent `/_refresh` all of them will be made available for search so a manual but throttled `/_refresh` call could mean much more less stress on the system?

But TBH at the moment there's no identifiable bottlebeck and this may just be premature anyway.

Anyway, the only way to make an improvement from here on would be to find something which would reduce the ~1.4s when batch indexing 10 docs.

Thanks for your detailed responses (here and in the other thread), I learned so much from this!

---

<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:** [May 25, 2017, 8:13pm UTC](https://discuss.elastic.co/t/refresh-wait-for-taking-unexpectedly-long/83691/6 "2017-05-25T20:13:09Z")

</div>

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