# Indexing performance degrading over time **URL:** \ **Category:** Elasticsearch\ **Created:** [January 27, 2016, 12:30pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229 "2016-01-27T12:30:27Z")\ **Posts on this page:** 20\ **Page:** 2
**Author:** ![rusty](https://avatars.discourse-cdn.com/v4/letter/r/f17d59/32.png) [@rusty](https://discuss.elastic.co/u/rusty)\ **Post date:** [February 8, 2016, 11:36am UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/21 "2016-02-08T11:36:26Z")
Michael thank you for answer. We'll definitely try the defaults and share results. Some words about our case: we are making logs storage with search capabilities on almost all key-metrics. All kind of logs have different retention policy (from 1 to 14 month) so we decided to use daily indexes and remove old indexes by using curator app. All indexes are append only. As we don't need sorting and aggregations we disable doc\_values and enable best\_compression as this is big cost saver (30-50% reduce of storage requirements compared to ES 1.7). We use the settings from 1.7.x as they were efficient enough and expect only trouble with terms\_in\_memory. But to our surprise got slowdown in indexing speed. > It's best to set shard count for an index only as large as is really needed to > > 1. ensure you never hit the 2.1B per-shard doc limit, and > 2. get enough search time concurrency for your search QPS needs. Setting it higher just adds risk of indexing slowdown when some nodes in your cluster are overloaded... 1. Yes, we are using this limit in shard number calculation (\<=50Gbyte for shard size and less than 2B document in index, and number of shard should be equal or less than node count just not to get hot point then on one node is more shard than on others) 2. Ok, It's the next step. > Finally, your output from free seems to show that only ~27 > GB is available as buffer cache? Somehow your processes are using up > the other 101 GB of RAM? You should try to leave ~50% or more for the > OS to cache the hot blocks from the index. We have 2 instances of Elasticsearch on one bare-metal server: 61GB is for Elasticsearch (30.5 + 30.5), 4 GB reserved for our app that loads data (it can use up to 30GB). We'll try to minimize memory for our app to free up more memory for Elasticsearch. ---
**Author:** ![ivank](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ivank/32/7595_2.png) [@ivank](https://discuss.elastic.co/u/ivank)\ **Post date:** [February 8, 2016, 4:43pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/22 "2016-02-08T16:43:00Z")
But still, why is there one node overloaded? Is it normal that one node has large bulk queue (according to gifs)? We tested id generator and it distributes docs to shards normally. Bulks are sending to master nodes, so they have to split into bulks for concrete shards, so every data node must have approx. equal shard bulks and consequently uniform load on all nodes. Am I right? > "index.store.type": "niofs" We think that `mmapfs`, which is included to `default_fs`, will use too large heap with time. ---
**Author:** ![mikemccand](https://avatars.discourse-cdn.com/v4/letter/m/f04885/32.png) [@mikemccand](https://discuss.elastic.co/u/mikemccand)\ **Post date:** [February 9, 2016, 12:43am UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/23 "2016-02-09T00:43:11Z")
> [@ivank](#): > > We think that mmapfs, which is included to default\_fs, will use too large heap with time. That is unfortunately a persistent myth: MMapDirectory does not increase heap usage, despite how horrifying the output from "top" or "ps" might seem. Have a look at Uwe's blog post to understand why: [http://blog.thetaphi.de/2012/07/use-lucenes-mmapdirectory-on-64bit.html](http://blog.thetaphi.de/2012/07/use-lucenes-mmapdirectory-on-64bit.html) ---
**Author:** ![mikemccand](https://avatars.discourse-cdn.com/v4/letter/m/f04885/32.png) [@mikemccand](https://discuss.elastic.co/u/mikemccand)\ **Post date:** [February 9, 2016, 12:48am UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/24 "2016-02-09T00:48:19Z")
> [@ivank](#): > > But still, why is there one node overloaded? Is it normal that one node has large bulk queue (according to gifs)? Maybe that one node has less free RAM than others and it becomes the bottleneck? Maybe the node restart frees up the RAM for a while until processes take it away from the OS? ---
**Author:** ![ivank](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ivank/32/7595_2.png) [@ivank](https://discuss.elastic.co/u/ivank)\ **Post date:** [February 11, 2016, 6:08pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/25 "2016-02-11T18:08:54Z")
OK, we removed some settings from templates, and it gave some positive effect (as I see it), but nothing changed with single overloaded nodes. I have tried to manually move shards from overloaded node to anothers (previously forbidden to cluster to rebalance) and bulks have been much increased (as on gif for 70M). It seems that it repeats with new indices for the next day. So, it really seems overloaded node is bottleneck for bulks. Also we tried to stop loading data for some time. We waited until all bulks are processed and continued to upload data... and overloaded node came back... For now, we stopped to load main part of data. All nodes does nothing now as expected, except... overloaded node. I'm confusing... what does this ES's node? this machine has 30-40 avg load, 30 bulk threads and 80-100 in queue. `top` shows 2000-3000% cpu for ES process while second one on the same machine is ok and does nothing. That instance itself reports that it uses 80-90% cpu. Hot threads: [http://pastebin.com/Gtfbk2Mg](http://pastebin.com/Gtfbk2Mg) What does it mean? ---
**Author:** ![mikemccand](https://avatars.discourse-cdn.com/v4/letter/m/f04885/32.png) [@mikemccand](https://discuss.elastic.co/u/mikemccand)\ **Post date:** [February 12, 2016, 4:16pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/26 "2016-02-12T16:16:50Z")
Hmm your hot threads output on that "still busy even after stopping bulk indexing" node is unhealthy, with nearly all threads doing this: ```auto 97.7% (976.8ms out of 1s) cpu usage by thread 'elasticsearch[test_data_11-d2][bulk][T#7]' 10/10 snapshots sharing following 22 elements java.lang.ThreadLocal$ThreadLocalMap.expungeStaleEntry(Unknown Source) java.lang.ThreadLocal$ThreadLocalMap.remove(Unknown Source) java.lang.ThreadLocal$ThreadLocalMap.access$200(Unknown Source) java.lang.ThreadLocal.remove(Unknown Source) java.util.concurrent.locks.ReentrantReadWriteLock$Sync.tryReleaseShared(Unknown Source) java.util.concurrent.locks.AbstractQueuedSynchronizer.releaseShared(Unknown Source) java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.unlock(Unknown Source) org.elasticsearch.common.util.concurrent.ReleasableLock.close(ReleasableLock.java:49) org.elasticsearch.index.engine.InternalEngine.create(InternalEngine.java:365) org.elasticsearch.index.shard.IndexShard.create(IndexShard.java:531) org.elasticsearch.index.engine.Engine$Create.execute(Engine.java:810) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnReplica(TransportShardBulkAction.java:476) org.elasticsearch.action.bulk.TransportShardBulkAction.shardOperationOnReplica(TransportShardBulkAction.java:69) ``` It's as if you have waaay too many `ThreadLocal` instances and these threads are stuck walking through all of them pruning the now unreferenced ones. Which Java version are you using? Do you still have any settings increasing e.g. thread pool sizes? ---
**Author:** ![ivank](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ivank/32/7595_2.png) [@ivank](https://discuss.elastic.co/u/ivank)\ **Post date:** [February 12, 2016, 6:44pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/27 "2016-02-12T18:44:23Z")
Sounds strange... We use JRE version 1.8.0\_66. We didn't touch any settings except removed from templates which became default: ```auto index.merge.policy.floor_segment index.merge.policy.max_merged_segment index.merge.scheduler.* index.translog.flush_threshold_size index.store.type ``` So, it seems that that node stopped to do such strange things when new (for today) indices have been created, and cluster worked fine today - up to 90M docs/5 min. But now I see again that one node (on another machine) have permanent queue of ~200 bulks, but seems it doesn't delay others for now. All ES's nodes have almost the same environment and I don't see what may be the cause for this queue. Will see what will happen on this weekend. ---
**Author:** ![mikemccand](https://avatars.discourse-cdn.com/v4/letter/m/f04885/32.png) [@mikemccand](https://discuss.elastic.co/u/mikemccand)\ **Post date:** [February 12, 2016, 8:54pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/28 "2016-02-12T20:54:28Z")
Hmm what settings remain? Do you launch ES with a different number of cores than it would have detected via Java's Runtime APIs? These hot threads are very bad, a smoking gun. We need to understand why you're hitting them ... I think it must be either a bug somewhere, or an extreme setting tickling something bad. ---
**Author:** ![jprante](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jprante/32/44941_2.png) [@jprante](https://discuss.elastic.co/u/jprante)\ **Post date:** [February 12, 2016, 9:58pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/29 "2016-02-12T21:58:06Z")
My observation is, a lock of class ` java.util.concurrent.locks.ReentrantReadWriteLock` is passed to `new ReleasableLock(...)`, and `ReleasableLock` uses `ThreadLocal`. `ReentrantReadWriteLock` of JDK is also using `ThreadLocal` internally. I think the `getReadHoldCount()` issue of `ReentrantReadWriteLock` [http://bugs.java.com/bugdatabase/view\_bug.do?bug\_id=6625724](http://bugs.java.com/bugdatabase/view_bug.do?bug_id=6625724) can not be underestimated. Quoting > The maintainers of ReentrantReadWriteLock now regret having added this extra overhead. Unfortunately, we cannot withdraw support for this, since we added the public getReadHoldCount method. It could be worth to replace `java.util.concurrent.locks.ReentrantReadWriteLock` in favor of a customized class that does not make use of ThreadLocal. Maybe ReleasableLock should be reorganized at the same time, too, as it looks like a wrapper around `java.util.concurrent.locks.ReentrantReadWriteLock`. ---
**Author:** ![mikemccand](https://avatars.discourse-cdn.com/v4/letter/m/f04885/32.png) [@mikemccand](https://discuss.elastic.co/u/mikemccand)\ **Post date:** [February 13, 2016, 3:26pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/30 "2016-02-13T15:26:31Z")
Are you running java with assertion enabled for Elasticsearch classes? The `ReleasableLock` only uses `ThreadLocal` if assertions are enabled. That said, I don't think this nor the JVM bug @jprante cited ought to matter here (and I would rather not fork JDK classes into ES), because we limit the number of unique threads based on the bulk and index thread pools, which ought to limit the size of the backing map used by `ThreadLocal`. @ivank would it be possible to capture a heap dump of the "node still busy after bulk indexing stopped" while its hot threads are reclaiming `ThreadLocal`s? This could help understand why that backing map has so many entries... ---
**Author:** ![ivank](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ivank/32/7595_2.png) [@ivank](https://discuss.elastic.co/u/ivank)\ **Post date:** [February 15, 2016, 2:46pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/31 "2016-02-15T14:46:19Z")
We specified 8 cores (as it turned out, it is wrong) > os.processors: 8 but it's less, not greater... `Runtime.availableProcessors()` returns expected 32 cores. > The ReleasableLock only uses ThreadLocal if assertions are enabled. We don't use `-ea` at all. > a heap dump of the "node still busy after bulk indexing stopped" First, we need to see again such node, but we don't at the moment. Second, I don't think we can transfer such big dump... We are trying to reproduce problem with overloaded node (which had no entries with `ThreadLocalMap.expungeStaleEntry`, just normal bulk) on our small cluster (4x data nodes, 4 masters), but we cant ☹ And I don't think we can reproduce `ThreadLocalMap.expungeStaleEntry` at all. If we could, we would take dump of such instance, of course. ---
**Author:** ![ivank](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ivank/32/7595_2.png) [@ivank](https://discuss.elastic.co/u/ivank)\ **Post date:** [February 15, 2016, 3:58pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/32 "2016-02-15T15:58:03Z")
Hmm, I see we made a mistake, there is just `processors` setting, right? If so, each of the two instances used 32 processors by default instead of 16? Or they are detecting each other on the same machine? ---
**Author:** ![mikemccand](https://avatars.discourse-cdn.com/v4/letter/m/f04885/32.png) [@mikemccand](https://discuss.elastic.co/u/mikemccand)\ **Post date:** [February 15, 2016, 4:21pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/33 "2016-02-15T16:21:49Z")
Yes, it's just `processors`, and I don't think the nodes will detect they are sharing the same cpu(s) and divide the processors in half. So, yes, it sounds like you had two nodes on one box, each thinking it had 32 cores to work with. But I would be surprised if this led to the hot threads you saw (trying to clear out `ThreadLocal` instances from expired threads). It seems like something is making an excessive number of `ThreadLocal` instances somewhere... ---
**Author:** ![ivank](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ivank/32/7595_2.png) [@ivank](https://discuss.elastic.co/u/ivank)\ **Post date:** [March 3, 2016, 3:54pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/34 "2016-03-03T15:54:06Z")
So, we have reduced available number of proccessors for ES, plus increased shard count for large indices and set some template settings to default - all it gave positive effect, but one overloaded node still remains, because of which cluster performance slows down with time... We also tried to use `node` client type to send bulks directly to shards. Initially, nodes become overloaded in turn, but now we have one all this day. `hot_threads` on overloaded node shows now stacktrace above with `java.lang.ThreadLocal$ThreadLocalMap.expungeStaleEntry` in almost all snapshots in bulk threads. I have done heap dump and started `jhat` on it to view it in browser (we cant pick out this dump because it is on remote machine). So, I have looked at tables in `ThreadLocalMap`s, and they have sizes 2^14 and 2^15. Table is sparsed, but some ranges is big (up to 4000 elements). Non-null elements are WeakReference to null (the same WeakReference object is referenced in many other indices). Also I saw one weak ref to HashMap, but I think that there is more WR's with nulls . What does this mean all? What can I post here, were should I look in dump? ---
**Author:** ![ivank](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ivank/32/7595_2.png) [@ivank](https://discuss.elastic.co/u/ivank)\ **Post date:** [March 4, 2016, 11:39am UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/35 "2016-03-04T11:39:49Z")
@mikemccand, could you look at this, please? ---
**Author:** ![mikemccand](https://avatars.discourse-cdn.com/v4/letter/m/f04885/32.png) [@mikemccand](https://discuss.elastic.co/u/mikemccand)\ **Post date:** [March 4, 2016, 2:22pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/36 "2016-03-04T14:22:09Z")
Hi @ivank, Can you run `jstack ` and post the result, on the hung node? This will show all thread names and what they are up to. Can you also run [https://github.com/elastic/elasticsearch-support-diagnostics](https://github.com/elastic/elasticsearch-support-diagnostics) and post somewhere? This pulls more detailed stats from the cluster. ---
**Author:** ![ivank](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ivank/32/7595_2.png) [@ivank](https://discuss.elastic.co/u/ivank)\ **Post date:** [March 4, 2016, 4:35pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/37 "2016-03-04T16:35:30Z")
Hi! Glad to see you again! Yeah, I did such stack dump, but it shows another stack trace then hot threads, and without `ThreadLocalMap.expungeStaleEntry` on top. I think I can do that on next week + we have to modify output from provided utility, of course. ---
**Author:** ![Arun\_Agarwal](https://avatars.discourse-cdn.com/v4/letter/a/59ef9b/32.png) [@Arun\_Agarwal](https://discuss.elastic.co/u/Arun_Agarwal)\ **Post date:** [March 6, 2016, 8:16pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/38 "2016-03-06T20:16:03Z")
Hey i have been seeing the same issue for a while, do you suggest to open a new discussion or can i put in the data i have here I see the cpu going to 95+% with hot threads on 66.6% (332.9ms out of 500ms) cpu usage by thread 'elasticsearch[host][search][T#25]' 10/10 snapshots sharing following 14 elements java.lang.ThreadLocal$ThreadLocalMap.expungeStaleEntry(ThreadLocal.java:617) java.lang.ThreadLocal$ThreadLocalMap.remove(ThreadLocal.java:499) java.lang.ThreadLocal$ThreadLocalMap.access$200(ThreadLocal.java:298) java.lang.ThreadLocal.remove(ThreadLocal.java:222) if i increase the refresh interval from 30s to 60s the cpu seems to come down, but when i revert it back the cpu on the host starts increasing and stays there until i send a sudo kill -QUIT {pid} and everything comes back to normal ---
**Author:** ![Arun\_Agarwal](https://avatars.discourse-cdn.com/v4/letter/a/59ef9b/32.png) [@Arun\_Agarwal](https://discuss.elastic.co/u/Arun_Agarwal)\ **Post date:** [March 9, 2016, 11:59pm UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/39 "2016-03-09T23:59:22Z")
This issue resolved itself when i added clients to handle the routing logic and disable http on data nodes. But we still have the some host stuck in the above state until i go and do a sudo kill -QUIT ---
**Author:** ![rusty](https://avatars.discourse-cdn.com/v4/letter/r/f17d59/32.png) [@rusty](https://discuss.elastic.co/u/rusty)\ **Post date:** [March 10, 2016, 8:07am UTC](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229/40 "2016-03-10T08:07:19Z")
@Arun_Agarwal hi, you are welcome to share you case and details. Which ES version do you use? @mikemccand Right now we found temporary solution - restart of stalled ES instance, this solves the problem for a while (6-24 hours) and then the issue occures again. Another changes we've tried: 1. increase shard number (this increase througput a little) 2. replace transport client with node client (decrease network overhead) 3. change `refresh_interval` to 60s but this does not change the things. A little later @ivank will share `jstack` and support diagnostics, we have a trouble with NDA, so need to change sensetive data (ip, index and field names) and this slows things a lot. [Previous page](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229.md?page=1) [Next page](https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229.md?page=3)