# Suspect GC sync'ed between nodes cause simultaneous performance hit **URL:** \ **Category:** Elasticsearch\ **Created:** [March 15, 2011, 3:24am UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093 "2011-03-15T03:24:16Z")\ **Posts on this page:** 15\ **Page:** 1
**Author:** ![David\_Taylor](https://avatars.discourse-cdn.com/v4/letter/d/d78d45/32.png) [@David\_Taylor](https://discuss.elastic.co/u/David_Taylor)\ **Post date:** [March 15, 2011, 3:24am UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/1 "2011-03-15T03:24:16Z")
Hi there, We're noticing occasional slow-downs in New Relic, with transactions slowed by waiting on elastic search. According to our monitoring, garbage collection appears to be spiking at the time of the slow-down. I've attached some graphs showing the JVM GC count on each server and both at the same time. GC count (and time) gradually increase (as you'd expect)... but with spikes occurring, typically 4-8 hours apart. These spikes occur simultaneously on both nodes. Can someone help me understand what is happening when these GC spikes occur, why they occur simultaneously, and what we can do to mitigate/eliminate the impact (eg, do they have to do whatever it is they're doing simultaneously)? Thanks! Cheers, David. ---
**Author:** ![kimchy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kimchy/32/44952_2.png) [@kimchy](https://discuss.elastic.co/u/kimchy)\ **Post date:** [March 15, 2011, 7:19am UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/2 "2011-03-15T07:19:28Z")
There isn't a way to control when a GC occurs, but we can try and understand why they occur. How do you monitor the GC count? It would be interesting to know which type of GC spiked, the ParNew or the CMS (if you are using the node stats, then you will see it there). Some basic questions: - What operating system are you using? - Which JVM version are you using? - How much memory is allocated to the JVM? - Do you see in elasticsearch log a log statement indicating a GC has run, and the time it took? Also, can you check the node stats and check the field cache and filter cache memory size? Do they increase? Does the filter cache occupies a lot of memory? What might happen every 4-8 hours in terms of the system? Is there something that might create such load? One such reason can be if you provide a front facing web site, and allow to paginate through all the results (which might be really big resultset), and a search crawler might do that. -shay.banon On Tuesday, March 15, 2011 at 5:24 AM, David Taylor wrote: Hi there, > We're noticing occasional slow-downs in New Relic, with transactions slowed by waiting on Elasticsearch. According to our monitoring, garbage collection appears to be spiking at the time of the slow-down. > > I've attached some graphs showing the JVM GC count on each server and both at the same time. GC count (and time) gradually increase (as you'd expect)... but with spikes occurring, typically 4-8 hours apart. These spikes occur simultaneously on both nodes. > > Can someone help me understand what is happening when these GC spikes occur, why they occur simultaneously, and what we can do to mitigate/eliminate the impact (eg, do they have to do whatever it is they're doing simultaneously)? > > Thanks! > > Cheers, > David. > > Attachments: > > - elastic\_search\_gc\_count\_both.png > > - elastic\_search\_gc\_count\_es1.png > > - elastic\_search\_gc\_count\_es2.png ---
**Author:** ![ppearcy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ppearcy/32/980_2.png) [@ppearcy](https://discuss.elastic.co/u/ppearcy)\ **Post date:** [March 15, 2011, 5:07pm UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/3 "2011-03-15T17:07:05Z")
FYI, our GC performance issues were fixed up by enabling mlockall from ES. On Mar 15, 1:19 am, Shay Banon [shay.ba...@elasticsearch.com](mailto:shay.ba...@elasticsearch.com) wrote: > There isn't a way to control when a GC occurs, but we can try and understand why they occur. How do you monitor the GC count? It would be interesting to know which type of GC spiked, the ParNew or the CMS (if you are using the node stats, then you will see it there). > > Some basic questions: > > - What operating system are you using? > - Which JVM version are you using? > - How much memory is allocated to the JVM? > - Do you see in elasticsearch log a log statement indicating a GC has run, and the time it took? > > Also, can you check the node stats and check the field cache and filter cache memory size? Do they increase? Does the filter cache occupies a lot of memory? > > What might happen every 4-8 hours in terms of the system? Is there something that might create such load? One such reason can be if you provide a front facing web site, and allow to paginate through all the results (which might be really big resultset), and a search crawler might do that. > > -shay.banonOn Tuesday, March 15, 2011 at 5:24 AM, David Taylor wrote: > > Hi there, > > > We're noticing occasional slow-downs in New Relic, with transactions slowed by waiting on Elasticsearch. According to our monitoring, garbage collection appears to be spiking at the time of the slow-down. > > > I've attached some graphs showing the JVM GC count on each server and both at the same time. GC count (and time) gradually increase (as you'd expect)... but with spikes occurring, typically 4-8 hours apart. These spikes occur simultaneously on both nodes. > > > Can someone help me understand what is happening when these GC spikes occur, why they occur simultaneously, and what we can do to mitigate/eliminate the impact (eg, do they have to do whatever it is they're doing simultaneously)? > > > Thanks! > > > Cheers, > > David. > > > Attachments: > > > > - elastic\_search\_gc\_count\_both.png > > > - elastic\_search\_gc\_count\_es1.png > > > - elastic\_search\_gc\_count\_es2.png ---
**Author:** ![Brad\_Birnbaum](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/brad_birnbaum/32/3255_2.png) [@Brad\_Birnbaum](https://discuss.elastic.co/u/Brad_Birnbaum)\ **Post date:** [March 15, 2011, 6:22pm UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/4 "2011-03-15T18:22:40Z")
Shay, is this something that you recommend On Tue, Mar 15, 2011 at 1:07 PM, Paul [ppearcy@gmail.com](mailto:ppearcy@gmail.com) wrote: > FYI, our GC performance issues were fixed up by enabling mlockall from > ES. > > On Mar 15, 1:19 am, Shay Banon [shay.ba...@elasticsearch.com](mailto:shay.ba...@elasticsearch.com) wrote: > > > There isn't a way to control when a GC occurs, but we can try and > > understand why they occur. How do you monitor the GC count? It would be > > interesting to know which type of GC spiked, the ParNew or the CMS (if you > > are using the node stats, then you will see it there). > > > > Some basic questions: > > > > - What operating system are you using? > > - Which JVM version are you using? > > - How much memory is allocated to the JVM? > > - Do you see in elasticsearch log a log statement indicating a GC has > > run, and the time it took? > > > > Also, can you check the node stats and check the field cache and filter > > cache memory size? Do they increase? Does the filter cache occupies a lot of > > memory? > > > > What might happen every 4-8 hours in terms of the system? Is there > > something that might create such load? One such reason can be if you provide > > a front facing web site, and allow to paginate through all the results > > (which might be really big resultset), and a search crawler might do that. > > > > -shay.banonOn Tuesday, March 15, 2011 at 5:24 AM, David Taylor wrote: > > > > Hi there, > > > > > We're noticing occasional slow-downs in New Relic, with transactions > > > slowed by waiting on Elasticsearch. According to our monitoring, garbage > > > collection appears to be spiking at the time of the slow-down. > > > > > I've attached some graphs showing the JVM GC count on each server and > > > both at the same time. GC count (and time) gradually increase (as you'd > > > expect)... but with spikes occurring, typically 4-8 hours apart. These > > > spikes occur simultaneously on both nodes. > > > > > Can someone help me understand what is happening when these GC spikes > > > occur, why they occur simultaneously, and what we can do to > > > mitigate/eliminate the impact (eg, do they have to do whatever it is they're > > > doing simultaneously)? > > > > > Thanks! > > > > > Cheers, > > > David. > > > > > Attachments: > > > > > > - elastic\_search\_gc\_count\_both.png > > > > > - elastic\_search\_gc\_count\_es1.png > > > > > - elastic\_search\_gc\_count\_es2.png -- Brad Birnbaum CTO, Assistly [brad@assistly.com](mailto:brad@assistly.com) m: 516-308-2286 ---
**Author:** ![kimchy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kimchy/32/44952_2.png) [@kimchy](https://discuss.elastic.co/u/kimchy)\ **Post date:** [March 15, 2011, 7:24pm UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/5 "2011-03-15T19:24:10Z")
Yes, using mlockall is recommended, just to be on hte safe side of not allowing to OS to ever swap the ES process to disk. Make sure though that ulimits are set properly to allow to lock the amount of memory allocated to ES, and that MIN and MAX mem have the same value. On Tuesday, March 15, 2011 at 8:22 PM, Brad Birnbaum wrote: > Shay, is this something that you recommend > > On Tue, Mar 15, 2011 at 1:07 PM, Paul [ppearcy@gmail.com](mailto:ppearcy@gmail.com) wrote: > > > FYI, our GC performance issues were fixed up by enabling mlockall from > > ES. > > > > On Mar 15, 1:19 am, Shay Banon [shay.ba...@elasticsearch.com](mailto:shay.ba...@elasticsearch.com) wrote: > > > > > There isn't a way to control when a GC occurs, but we can try and understand why they occur. How do you monitor the GC count? It would be interesting to know which type of GC spiked, the ParNew or the CMS (if you are using the node stats, then you will see it there). > > > > > > Some basic questions: > > > > > > - What operating system are you using? > > > - Which JVM version are you using? > > > - How much memory is allocated to the JVM? > > > - Do you see in elasticsearch log a log statement indicating a GC has run, and the time it took? > > > > > > Also, can you check the node stats and check the field cache and filter cache memory size? Do they increase? Does the filter cache occupies a lot of memory? > > > > > > What might happen every 4-8 hours in terms of the system? Is there something that might create such load? One such reason can be if you provide a front facing web site, and allow to paginate through all the results (which might be really big resultset), and a search crawler might do that. > > > > > > -shay.banonOn Tuesday, March 15, 2011 at 5:24 AM, David Taylor wrote: > > > > > > Hi there, > > > > > > > We're noticing occasional slow-downs in New Relic, with transactions slowed by waiting on Elasticsearch. According to our monitoring, garbage collection appears to be spiking at the time of the slow-down. > > > > > > > I've attached some graphs showing the JVM GC count on each server and both at the same time. GC count (and time) gradually increase (as you'd expect)... but with spikes occurring, typically 4-8 hours apart. These spikes occur simultaneously on both nodes. > > > > > > > Can someone help me understand what is happening when these GC spikes occur, why they occur simultaneously, and what we can do to mitigate/eliminate the impact (eg, do they have to do whatever it is they're doing simultaneously)? > > > > > > > Thanks! > > > > > > > Cheers, > > > > David. > > > > > > > Attachments: > > > > > > > > - elastic\_search\_gc\_count\_both.png > > > > > > > - elastic\_search\_gc\_count\_es1.png > > > > > > > - elastic\_search\_gc\_count\_es2.png > > -- > Brad Birnbaum > CTO, Assistly > [brad@assistly.com](mailto:brad@assistly.com) m: 516-308-2286 ---
**Author:** ![David\_Taylor](https://avatars.discourse-cdn.com/v4/letter/d/d78d45/32.png) [@David\_Taylor](https://discuss.elastic.co/u/David_Taylor)\ **Post date:** [March 15, 2011, 10:35pm UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/6 "2011-03-15T22:35:48Z")
On Tue, Mar 15, 2011 at 6:19 PM, Shay Banon [shay.banon@elasticsearch.com](mailto:shay.banon@elasticsearch.com)wrote: > There isn't a way to control when a GC occurs, but we can try and > understand why they occur. How do you monitor the GC count? It would be > interesting to know which type of GC spiked, the ParNew or the CMS (if you > are using the node stats, then you will see it there). Hi Shay, We're using [http://localhost:9200/\_cluster/health](http://localhost:9200/_cluster/health) to pull out jvm-\>gc-\>collection\_count for each node. The graphs I attached show those counts for each node and side-by-side for both nodes. > Some basic questions: > > - What operating system are you using? We're using Ubuntu 10.10 (Maverick) x64, running on EC2 m1.large instances. - Which JVM version are you using? > java version "1.6.0\_23" Java(TM) SE Runtime Environment (build 1.6.0\_23-b05) Java HotSpot(TM) 64-Bit Server VM (build 19.0-b09, mixed mode) > - How much memory is allocated to the JVM? We're using the service wrapper with: set.default.ES\_MIN\_MEM=8192 set.default.ES\_MAX\_MEM=8192 wrapper.java.initmemory=%ES\_MIN\_MEM% wrapper.java.maxmemory=%ES\_MAX\_MEM% > - Do you see in elasticsearch log a log statement indicating a GC has run, > and the time it took? No, we have GC logging disabled in production, so we're inferring that rapid increases in GC counts indicate the times that GC has run. Also, can you check the node stats and check the field cache and filter > cache memory size? Do they increase? Does the filter cache occupies a lot of > memory? I noticed different memory sizes between the nodes, but I assume that can simply be due to how they're used? There are a high number of evictions on the master node. However, I checked these stats yesterday and today, more than 12 hours apart, and the evictions have not changed (4,605 yesterday and still 4,605 today): "nodes" : { "UMi0Q32TTNOt14Fjwd-oUA" : { "name" : "Black Tom Cassidy", "indices" : { "store\_size" : "3.4gb", "store\_size\_in\_bytes" : 3709373643, "field\_cache\_evictions" : 4605, "field\_cache\_size" : "190.4mb", "field\_cache\_size\_in\_bytes" : 199713560, "filter\_cache\_size" : "6.5gb", "filter\_cache\_size\_in\_bytes" : 7019021448 }, . . . "nb\_CvB7wTSqrEt928agjnA" : { "name" : "X-Man", "indices" : { "store\_size" : "4.7gb", "store\_size\_in\_bytes" : 5063162525, "field\_cache\_evictions" : 0, "field\_cache\_size" : "247.1mb", "field\_cache\_size\_in\_bytes" : 259161452, "filter\_cache\_size" : "2.5gb", "filter\_cache\_size\_in\_bytes" : 2788778984 }, > What might happen every 4-8 hours in terms of the system? Is there > something that might create such load? One such reason can be if you provide > a front facing web site, and allow to paginate through all the results > (which might be really big resultset), and a search crawler might do that. That's a very good question. The period between each GC run (or, at least, what I'm assuming is a GC run) varies. I can't see any cron jobs that would cause it and I wouldn't expect to with the varying times. I'll check the logs for search crawlers around those times and I'll ask the guys if they have any ideas. Thanks for your help, Shay. Cheers, David. On Tuesday, March 15, 2011 at 5:24 AM, David Taylor wrote: > Hi there, > > We're noticing occasional slow-downs in New Relic, with transactions slowed > by waiting on Elasticsearch. According to our monitoring, garbage > collection appears to be spiking at the time of the slow-down. > > I've attached some graphs showing the JVM GC count on each server and both > at the same time. GC count (and time) gradually increase (as you'd > expect)... but with spikes occurring, typically 4-8 hours apart. These > spikes occur simultaneously on both nodes. > > Can someone help me understand what is happening when these GC spikes > occur, why they occur simultaneously, and what we can do to > mitigate/eliminate the impact (eg, do they have to do whatever it is they're > doing simultaneously)? > > Thanks! > > Cheers, > David. > > Attachments: > > - elastic\_search\_gc\_count\_both.png > - elastic\_search\_gc\_count\_es1.png > - elastic\_search\_gc\_count\_es2.png ---
**Author:** ![David\_Taylor](https://avatars.discourse-cdn.com/v4/letter/d/d78d45/32.png) [@David\_Taylor](https://discuss.elastic.co/u/David_Taylor)\ **Post date:** [March 15, 2011, 11:00pm UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/7 "2011-03-15T23:00:47Z")
Hi Shay, I read [Elasticsearch Platform — Find real-time answers at scale | Elastic](http://www.elasticsearch.org/guide/reference/setup/installation.html) and can see that it's to prevent the process being swapped out. However, I'm not clear, what effect does this have on GC? Presumably the address space is still the same size and GC still needs to occur. Thanks! ps. We aim not to use swap and make sure we have more memory than needs to be allocated. Cheers, David. On Wed, Mar 16, 2011 at 6:24 AM, Shay Banon [shay.banon@elasticsearch.com](mailto:shay.banon@elasticsearch.com)wrote: > Yes, using mlockall is recommended, just to be on hte safe side of not > allowing to OS to ever swap the ES process to disk. Make sure though that > ulimits are set properly to allow to lock the amount of memory allocated to > ES, and that MIN and MAX mem have the same value. > > On Tuesday, March 15, 2011 at 8:22 PM, Brad Birnbaum wrote: > > Shay, is this something that you recommend > > On Tue, Mar 15, 2011 at 1:07 PM, Paul [ppearcy@gmail.com](mailto:ppearcy@gmail.com) wrote: > > FYI, our GC performance issues were fixed up by enabling mlockall from > ES. > > On Mar 15, 1:19 am, Shay Banon [shay.ba...@elasticsearch.com](mailto:shay.ba...@elasticsearch.com) wrote: > > > There isn't a way to control when a GC occurs, but we can try and > > understand why they occur. How do you monitor the GC count? It would be > > interesting to know which type of GC spiked, the ParNew or the CMS (if you > > are using the node stats, then you will see it there). > > > > Some basic questions: > > > > - What operating system are you using? > > - Which JVM version are you using? > > - How much memory is allocated to the JVM? > > - Do you see in elasticsearch log a log statement indicating a GC has > > run, and the time it took? > > > > Also, can you check the node stats and check the field cache and filter > > cache memory size? Do they increase? Does the filter cache occupies a lot of > > memory? > > > > What might happen every 4-8 hours in terms of the system? Is there > > something that might create such load? One such reason can be if you provide > > a front facing web site, and allow to paginate through all the results > > (which might be really big resultset), and a search crawler might do that. > > > > -shay.banonOn Tuesday, March 15, 2011 at 5:24 AM, David Taylor wrote: > > > > Hi there, > > > > > We're noticing occasional slow-downs in New Relic, with transactions > > > slowed by waiting on Elasticsearch. According to our monitoring, garbage > > > collection appears to be spiking at the time of the slow-down. > > > > > I've attached some graphs showing the JVM GC count on each server and > > > both at the same time. GC count (and time) gradually increase (as you'd > > > expect)... but with spikes occurring, typically 4-8 hours apart. These > > > spikes occur simultaneously on both nodes. > > > > > Can someone help me understand what is happening when these GC spikes > > > occur, why they occur simultaneously, and what we can do to > > > mitigate/eliminate the impact (eg, do they have to do whatever it is they're > > > doing simultaneously)? > > > > > Thanks! > > > > > Cheers, > > > David. > > > > > Attachments: > > > > > > - elastic\_search\_gc\_count\_both.png > > > > > - elastic\_search\_gc\_count\_es1.png > > > > > - elastic\_search\_gc\_count\_es2.png > > -- > > Brad Birnbaum > > CTO, Assistly > > [brad@assistly.com](mailto:brad@assistly.com) m: 516-308-2286 ---
**Author:** ![kimchy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kimchy/32/44952_2.png) [@kimchy](https://discuss.elastic.co/u/kimchy)\ **Post date:** [March 15, 2011, 11:01pm UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/8 "2011-03-15T23:01:08Z")
I have a sneaky suspicion based on the node stats that it might be because of excessive filter caching. Which version are you using? In 0.15.2, I fixed a wrong double caching of filters when using filter facets. Where do you typically use filters? And what type of filters do you use? On Wednesday, March 16, 2011 at 12:35 AM, David Taylor wrote: On Tue, Mar 15, 2011 at 6:19 PM, Shay Banon [shay.banon@elasticsearch.com](mailto:shay.banon@elasticsearch.com) wrote: > > There isn't a way to control when a GC occurs, but we can try and understand why they occur. How do you monitor the GC count? It would be interesting to know which type of GC spiked, the ParNew or the CMS (if you are using the node stats, then you will see it there). > > Hi Shay, > > We're using [http://localhost:9200/\_cluster/health](http://localhost:9200/_cluster/health) to pull out jvm-\>gc-\>collection\_count for each node. The graphs I attached show those counts for each node and side-by-side for both nodes. > > > Some basic questions: > > > > - What operating system are you using? > > We're using Ubuntu 10.10 (Maverick) x64, running on EC2 m1.large instances. > > > - Which JVM version are you using? > > java version "1.6.0\_23" > Java(TM) SE Runtime Environment (build 1.6.0\_23-b05) > Java HotSpot(TM) 64-Bit Server VM (build 19.0-b09, mixed mode) > > - How much memory is allocated to the JVM? > > We're using the service wrapper with: > > set.default.ES\_MIN\_MEM=8192 > set.default.ES\_MAX\_MEM=8192 > > wrapper.java.initmemory=%ES\_MIN\_MEM% > wrapper.java.maxmemory=%ES\_MAX\_MEM% > > - Do you see in elasticsearch log a log statement indicating a GC has run, and the time it took? > > No, we have GC logging disabled in production, so we're inferring that rapid increases in GC counts indicate the times that GC has run. > > Also, can you check the node stats and check the field cache and filter cache memory size? Do they increase? Does the filter cache occupies a lot of memory? > > I noticed different memory sizes between the nodes, but I assume that can simply be due to how they're used? > > There are a high number of evictions on the master node. However, I checked these stats yesterday and today, more than 12 hours apart, and the evictions have not changed (4,605 yesterday and still 4,605 today): > > "nodes" : { > "UMi0Q32TTNOt14Fjwd-oUA" : { > "name" : "Black Tom Cassidy", > "indices" : { > "store\_size" : "3.4gb", > "store\_size\_in\_bytes" : 3709373643, > "field\_cache\_evictions" : 4605, > "field\_cache\_size" : "190.4mb", > "field\_cache\_size\_in\_bytes" : 199713560, > "filter\_cache\_size" : "6.5gb", > "filter\_cache\_size\_in\_bytes" : 7019021448 > }, > > . . . > "nb\_CvB7wTSqrEt928agjnA" : { > "name" : "X-Man", > "indices" : { > "store\_size" : "4.7gb", > "store\_size\_in\_bytes" : 5063162525, > "field\_cache\_evictions" : 0, > "field\_cache\_size" : "247.1mb", > "field\_cache\_size\_in\_bytes" : 259161452, > "filter\_cache\_size" : "2.5gb", > "filter\_cache\_size\_in\_bytes" : 2788778984 > }, > > > What might happen every 4-8 hours in terms of the system? Is there something that might create such load? One such reason can be if you provide a front facing web site, and allow to paginate through all the results (which might be really big resultset), and a search crawler might do that. > > That's a very good question. The period between each GC run (or, at least, what I'm assuming is a GC run) varies. I can't see any cron jobs that would cause it and I wouldn't expect to with the varying times. > > I'll check the logs for search crawlers around those times and I'll ask the guys if they have any ideas. > > Thanks for your help, Shay. > > Cheers, > David. > > > On Tuesday, March 15, 2011 at 5:24 AM, David Taylor wrote: > > > > > Hi there, > > > > > > We're noticing occasional slow-downs in New Relic, with transactions slowed by waiting on Elasticsearch. According to our monitoring, garbage collection appears to be spiking at the time of the slow-down. > > > > > > I've attached some graphs showing the JVM GC count on each server and both at the same time. GC count (and time) gradually increase (as you'd expect)... but with spikes occurring, typically 4-8 hours apart. These spikes occur simultaneously on both nodes. > > > > > > Can someone help me understand what is happening when these GC spikes occur, why they occur simultaneously, and what we can do to mitigate/eliminate the impact (eg, do they have to do whatever it is they're doing simultaneously)? > > > > > > Thanks! > > > > > > Cheers, > > > David. > > > > > > Attachments: > > > > > > - elastic\_search\_gc\_count\_both.png > > > > > > - elastic\_search\_gc\_count\_es1.png > > > > > > - elastic\_search\_gc\_count\_es2.png ---
**Author:** ![kimchy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kimchy/32/44952_2.png) [@kimchy](https://discuss.elastic.co/u/kimchy)\ **Post date:** [March 15, 2011, 11:02pm UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/9 "2011-03-15T23:02:39Z")
Yes, the same GC needs to occur even when swap is used, but, because of the nature of a VM, swapping it can result in much longer GC runs. On Wednesday, March 16, 2011 at 1:00 AM, David Taylor wrote: > Hi Shay, > > I read [Elasticsearch Platform — Find real-time answers at scale | Elastic](http://www.elasticsearch.org/guide/reference/setup/installation.html) and can see that it's to prevent the process being swapped out. However, I'm not clear, what effect does this have on GC? Presumably the address space is still the same size and GC still needs to occur. > > Thanks! > > ps. We aim not to use swap and make sure we have more memory than needs to be allocated. > > Cheers, > David. > > On Wed, Mar 16, 2011 at 6:24 AM, Shay Banon [shay.banon@elasticsearch.com](mailto:shay.banon@elasticsearch.com) wrote: > > > Yes, using mlockall is recommended, just to be on hte safe side of not allowing to OS to ever swap the ES process to disk. Make sure though that ulimits are set properly to allow to lock the amount of memory allocated to ES, and that MIN and MAX mem have the same value. > > On Tuesday, March 15, 2011 at 8:22 PM, Brad Birnbaum wrote: > > > > > Shay, is this something that you recommend > > > > > > On Tue, Mar 15, 2011 at 1:07 PM, Paul [ppearcy@gmail.com](mailto:ppearcy@gmail.com) wrote: > > > > > > > FYI, our GC performance issues were fixed up by enabling mlockall from > > > > ES. > > > > > > > > On Mar 15, 1:19 am, Shay Banon [shay.ba...@elasticsearch.com](mailto:shay.ba...@elasticsearch.com) wrote: > > > > > > > > > There isn't a way to control when a GC occurs, but we can try and understand why they occur. How do you monitor the GC count? It would be interesting to know which type of GC spiked, the ParNew or the CMS (if you are using the node stats, then you will see it there). > > > > > > > > > > Some basic questions: > > > > > > > > > > - What operating system are you using? > > > > > - Which JVM version are you using? > > > > > - How much memory is allocated to the JVM? > > > > > - Do you see in elasticsearch log a log statement indicating a GC has run, and the time it took? > > > > > > > > > > Also, can you check the node stats and check the field cache and filter cache memory size? Do they increase? Does the filter cache occupies a lot of memory? > > > > > > > > > > What might happen every 4-8 hours in terms of the system? Is there something that might create such load? One such reason can be if you provide a front facing web site, and allow to paginate through all the results (which might be really big resultset), and a search crawler might do that. > > > > > > > > > > -shay.banonOn Tuesday, March 15, 2011 at 5:24 AM, David Taylor wrote: > > > > > > > > > > Hi there, > > > > > > > > > > > We're noticing occasional slow-downs in New Relic, with transactions slowed by waiting on Elasticsearch. According to our monitoring, garbage collection appears to be spiking at the time of the slow-down. > > > > > > > > > > > I've attached some graphs showing the JVM GC count on each server and both at the same time. GC count (and time) gradually increase (as you'd expect)... but with spikes occurring, typically 4-8 hours apart. These spikes occur simultaneously on both nodes. > > > > > > > > > > > Can someone help me understand what is happening when these GC spikes occur, why they occur simultaneously, and what we can do to mitigate/eliminate the impact (eg, do they have to do whatever it is they're doing simultaneously)? > > > > > > > > > > > Thanks! > > > > > > > > > > > Cheers, > > > > > > David. > > > > > > > > > > > Attachments: > > > > > > > > > > > > - elastic\_search\_gc\_count\_both.png > > > > > > > > > > > - elastic\_search\_gc\_count\_es1.png > > > > > > > > > > > - elastic\_search\_gc\_count\_es2.png > > > > > > -- > > > Brad Birnbaum > > > CTO, Assistly > > > [brad@assistly.com](mailto:brad@assistly.com) m: 516-308-2286 ---
**Author:** ![David\_Taylor](https://avatars.discourse-cdn.com/v4/letter/d/d78d45/32.png) [@David\_Taylor](https://discuss.elastic.co/u/David_Taylor)\ **Post date:** [March 15, 2011, 11:22pm UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/10 "2011-03-15T23:22:48Z")
Hi Shay, We're using 0.14.2. About the filters, I have no idea, I'll get back to you on that. 🙂 Thanks. Cheers, David. On Wed, Mar 16, 2011 at 10:01 AM, Shay Banon [shay.banon@elasticsearch.com](mailto:shay.banon@elasticsearch.com)wrote: > I have a sneaky suspicion based on the node stats that it might be > because of excessive filter caching. Which version are you using? In 0.15.2, > I fixed a wrong double caching of filters when using filter facets. > > Where do you typically use filters? And what type of filters do you use? > > On Wednesday, March 16, 2011 at 12:35 AM, David Taylor wrote: > > On Tue, Mar 15, 2011 at 6:19 PM, Shay Banon [shay.banon@elasticsearch.com](mailto:shay.banon@elasticsearch.com)wrote: > > There isn't a way to control when a GC occurs, but we can try and > understand why they occur. How do you monitor the GC count? It would be > interesting to know which type of GC spiked, the ParNew or the CMS (if you > are using the node stats, then you will see it there). > > Hi Shay, > > We're using [http://localhost:9200/\_cluster/health](http://localhost:9200/_cluster/health) to pull out > jvm-\>gc-\>collection\_count for each node. The graphs I attached show those > counts for each node and side-by-side for both nodes. > > > Some basic questions: > > > > - What operating system are you using? > > We're using Ubuntu 10.10 (Maverick) x64, running on EC2 m1.large instances. > > - Which JVM version are you using? > > > > > java version "1.6.0\_23" > Java(TM) SE Runtime Environment (build 1.6.0\_23-b05) > Java HotSpot(TM) 64-Bit Server VM (build 19.0-b09, mixed mode) > > > - How much memory is allocated to the JVM? > > We're using the service wrapper with: > > set.default.ES\_MIN\_MEM=8192 > set.default.ES\_MAX\_MEM=8192 > wrapper.java.initmemory=%ES\_MIN\_MEM% > wrapper.java.maxmemory=%ES\_MAX\_MEM% > > > - Do you see in elasticsearch log a log statement indicating a GC has run, > > and the time it took? > > No, we have GC logging disabled in production, so we're inferring that > rapid increases in GC counts indicate the times that GC has run. > > Also, can you check the node stats and check the field cache and filter > > > cache memory size? Do they increase? Does the filter cache occupies a lot of > > memory? > > I noticed different memory sizes between the nodes, but I assume that can > simply be due to how they're used? > > There are a high number of evictions on the master node. However, I > checked these stats yesterday and today, more than 12 hours apart, and the > evictions have not changed (4,605 yesterday and still 4,605 today): > > "nodes" : { > "UMi0Q32TTNOt14Fjwd-oUA" : { > "name" : "Black Tom Cassidy", > "indices" : { > "store\_size" : "3.4gb", > "store\_size\_in\_bytes" : 3709373643, > "field\_cache\_evictions" : 4605, > "field\_cache\_size" : "190.4mb", > "field\_cache\_size\_in\_bytes" : 199713560, > "filter\_cache\_size" : "6.5gb", > "filter\_cache\_size\_in\_bytes" : 7019021448 > }, > . . . > "nb\_CvB7wTSqrEt928agjnA" : { > "name" : "X-Man", > "indices" : { > "store\_size" : "4.7gb", > "store\_size\_in\_bytes" : 5063162525, > "field\_cache\_evictions" : 0, > "field\_cache\_size" : "247.1mb", > "field\_cache\_size\_in\_bytes" : 259161452, > "filter\_cache\_size" : "2.5gb", > "filter\_cache\_size\_in\_bytes" : 2788778984 > }, > > What might happen every 4-8 hours in terms of the system? Is there > something that might create such load? One such reason can be if you provide > a front facing web site, and allow to paginate through all the results > (which might be really big resultset), and a search crawler might do that. > > That's a very good question. The period between each GC run (or, at least, > what I'm assuming is a GC run) varies. I can't see any cron jobs that would > cause it and I wouldn't expect to with the varying times. > > I'll check the logs for search crawlers around those times and I'll ask the > guys if they have any ideas. > > Thanks for your help, Shay. > > Cheers, > David. > > On Tuesday, March 15, 2011 at 5:24 AM, David Taylor wrote: > > > Hi there, > > > > We're noticing occasional slow-downs in New Relic, with transactions > > slowed by waiting on Elasticsearch. According to our monitoring, garbage > > collection appears to be spiking at the time of the slow-down. > > > > I've attached some graphs showing the JVM GC count on each server and both > > at the same time. GC count (and time) gradually increase (as you'd > > expect)... but with spikes occurring, typically 4-8 hours apart. These > > spikes occur simultaneously on both nodes. > > > > Can someone help me understand what is happening when these GC spikes > > occur, why they occur simultaneously, and what we can do to > > mitigate/eliminate the impact (eg, do they have to do whatever it is they're > > doing simultaneously)? > > > > Thanks! > > > > Cheers, > > David. > > > > Attachments: > > > > - elastic\_search\_gc\_count\_both.png > > - elastic\_search\_gc\_count\_es1.png > > - elastic\_search\_gc\_count\_es2.png ---
**Author:** ![David\_Taylor](https://avatars.discourse-cdn.com/v4/letter/d/d78d45/32.png) [@David\_Taylor](https://discuss.elastic.co/u/David_Taylor)\ **Post date:** [March 16, 2011, 12:09am UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/11 "2011-03-16T00:09:28Z")
On Wed, Mar 16, 2011 at 9:35 AM, David Taylor [david.taylor@assistly.com](mailto:david.taylor@assistly.com)wrote: > There are a high number of evictions on the master node. However, I > checked these stats yesterday and today, more than 12 hours apart, and the > evictions have not changed (4,605 yesterday and still 4,605 today): > > "nodes" : { > "UMi0Q32TTNOt14Fjwd-oUA" : { > "name" : "Black Tom Cassidy", > "indices" : { > "store\_size" : "3.4gb", > "store\_size\_in\_bytes" : 3709373643, > "field\_cache\_evictions" : 4605, > "field\_cache\_size" : "190.4mb", > "field\_cache\_size\_in\_bytes" : 199713560, > "filter\_cache\_size" : "6.5gb", > "filter\_cache\_size\_in\_bytes" : 7019021448 > }, > . . . > "nb\_CvB7wTSqrEt928agjnA" : { > "name" : "X-Man", > "indices" : { > "store\_size" : "4.7gb", > "store\_size\_in\_bytes" : 5063162525, > "field\_cache\_evictions" : 0, > "field\_cache\_size" : "247.1mb", > "field\_cache\_size\_in\_bytes" : 259161452, > "filter\_cache\_size" : "2.5gb", > "filter\_cache\_size\_in\_bytes" : 2788778984 > }, Some additional info on the above. The filter cache size on the master has increased by a factor of 10 since yesterday (it was approximately 640mb yesterday, not it's 6.5gb). Cheers, David. ---
**Author:** ![kimchy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kimchy/32/44952_2.png) [@kimchy](https://discuss.elastic.co/u/kimchy)\ **Post date:** [March 16, 2011, 12:16am UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/12 "2011-03-16T00:16:42Z")
Right. Information on where you use filters and what type of filters will help. The fact that its the master node, btw, has no affect. Its just shards allocated on nodes, and search being executed on them, the master plays no specific role here. On Wednesday, March 16, 2011 at 2:09 AM, David Taylor wrote: > On Wed, Mar 16, 2011 at 9:35 AM, David Taylor [david.taylor@assistly.com](mailto:david.taylor@assistly.com) wrote: > > > There are a high number of evictions on the master node. However, I checked these stats yesterday and today, more than 12 hours apart, and the evictions have not changed (4,605 yesterday and still 4,605 today): > > > > "nodes" : { > > "UMi0Q32TTNOt14Fjwd-oUA" : { > > "name" : "Black Tom Cassidy", > > "indices" : { > > "store\_size" : "3.4gb", > > "store\_size\_in\_bytes" : 3709373643, > > "field\_cache\_evictions" : 4605, > > "field\_cache\_size" : "190.4mb", > > "field\_cache\_size\_in\_bytes" : 199713560, > > "filter\_cache\_size" : "6.5gb", > > "filter\_cache\_size\_in\_bytes" : 7019021448 > > }, > > > > . . . > > "nb\_CvB7wTSqrEt928agjnA" : { > > "name" : "X-Man", > > "indices" : { > > "store\_size" : "4.7gb", > > "store\_size\_in\_bytes" : 5063162525, > > "field\_cache\_evictions" : 0, > > "field\_cache\_size" : "247.1mb", > > "field\_cache\_size\_in\_bytes" : 259161452, > > "filter\_cache\_size" : "2.5gb", > > "filter\_cache\_size\_in\_bytes" : 2788778984 > > }, > > Some additional info on the above. The filter cache size on the master has increased by a factor of 10 since yesterday (it was approximately 640mb yesterday, not it's 6.5gb). > > Cheers, > David. ---
**Author:** ![David\_Taylor](https://avatars.discourse-cdn.com/v4/letter/d/d78d45/32.png) [@David\_Taylor](https://discuss.elastic.co/u/David_Taylor)\ **Post date:** [March 16, 2011, 3:54am UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/13 "2011-03-16T03:54:01Z")
Hi Shay, Filters are used by our web application. They are only available to authenticated users, so they can't be triggered by search crawlers. We're using filtered facets. Cheers, David. On Wed, Mar 16, 2011 at 11:16 AM, Shay Banon [shay.banon@elasticsearch.com](mailto:shay.banon@elasticsearch.com)wrote: > Right. Information on where you use filters and what type of filters will > help. The fact that its the master node, btw, has no affect. Its just shards > allocated on nodes, and search being executed on them, the master plays no > specific role here. > > On Wednesday, March 16, 2011 at 2:09 AM, David Taylor wrote: > > On Wed, Mar 16, 2011 at 9:35 AM, David Taylor [david.taylor@assistly.com](mailto:david.taylor@assistly.com)wrote: > > There are a high number of evictions on the master node. However, I > checked these stats yesterday and today, more than 12 hours apart, and the > evictions have not changed (4,605 yesterday and still 4,605 today): > > "nodes" : { > "UMi0Q32TTNOt14Fjwd-oUA" : { > "name" : "Black Tom Cassidy", > "indices" : { > "store\_size" : "3.4gb", > "store\_size\_in\_bytes" : 3709373643, > "field\_cache\_evictions" : 4605, > "field\_cache\_size" : "190.4mb", > "field\_cache\_size\_in\_bytes" : 199713560, > "filter\_cache\_size" : "6.5gb", > "filter\_cache\_size\_in\_bytes" : 7019021448 > }, > . . . > "nb\_CvB7wTSqrEt928agjnA" : { > "name" : "X-Man", > "indices" : { > "store\_size" : "4.7gb", > "store\_size\_in\_bytes" : 5063162525, > "field\_cache\_evictions" : 0, > "field\_cache\_size" : "247.1mb", > "field\_cache\_size\_in\_bytes" : 259161452, > "filter\_cache\_size" : "2.5gb", > "filter\_cache\_size\_in\_bytes" : 2788778984 > }, > > Some additional info on the above. The filter cache size on the master has > increased by a factor of 10 since yesterday (it was approximately 640mb > yesterday, not it's 6.5gb). > > Cheers, > David. ---
**Author:** ![kimchy](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/kimchy/32/44952_2.png) [@kimchy](https://discuss.elastic.co/u/kimchy)\ **Post date:** [March 16, 2011, 6:03am UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/14 "2011-03-16T06:03:52Z")
On Wednesday, March 16, 2011 at 5:54 AM, David Taylor wrote: Hi Shay, > Filters are used by our web application. They are only available to authenticated users, so they can't be triggered by search crawlers. > This sounds reasonable. > > We're using filtered facets. > Which filters? > > Cheers, > David. > > On Wed, Mar 16, 2011 at 11:16 AM, Shay Banon [shay.banon@elasticsearch.com](mailto:shay.banon@elasticsearch.com) wrote: > > > Right. Information on where you use filters and what type of filters will help. The fact that its the master node, btw, has no affect. Its just shards allocated on nodes, and search being executed on them, the master plays no specific role here. > > On Wednesday, March 16, 2011 at 2:09 AM, David Taylor wrote: > > > > > On Wed, Mar 16, 2011 at 9:35 AM, David Taylor [david.taylor@assistly.com](mailto:david.taylor@assistly.com) wrote: > > > > > > > There are a high number of evictions on the master node. However, I checked these stats yesterday and today, more than 12 hours apart, and the evictions have not changed (4,605 yesterday and still 4,605 today): > > > > > > > > "nodes" : { > > > > "UMi0Q32TTNOt14Fjwd-oUA" : { > > > > "name" : "Black Tom Cassidy", > > > > "indices" : { > > > > "store\_size" : "3.4gb", > > > > "store\_size\_in\_bytes" : 3709373643, > > > > "field\_cache\_evictions" : 4605, > > > > "field\_cache\_size" : "190.4mb", > > > > "field\_cache\_size\_in\_bytes" : 199713560, > > > > "filter\_cache\_size" : "6.5gb", > > > > "filter\_cache\_size\_in\_bytes" : 7019021448 > > > > }, > > > > > > > > . . . > > > > "nb\_CvB7wTSqrEt928agjnA" : { > > > > "name" : "X-Man", > > > > "indices" : { > > > > "store\_size" : "4.7gb", > > > > "store\_size\_in\_bytes" : 5063162525, > > > > "field\_cache\_evictions" : 0, > > > > "field\_cache\_size" : "247.1mb", > > > > "field\_cache\_size\_in\_bytes" : 259161452, > > > > "filter\_cache\_size" : "2.5gb", > > > > "filter\_cache\_size\_in\_bytes" : 2788778984 > > > > }, > > > > > > Some additional info on the above. The filter cache size on the master has increased by a factor of 10 since yesterday (it was approximately 640mb yesterday, not it's 6.5gb). > > > > > > Cheers, > > > David. ---
**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\ **Post date:** [July 6, 2017, 4:09am UTC](https://discuss.elastic.co/t/suspect-gc-synced-between-nodes-cause-simultaneous-performance-hit/4093/15 "2017-07-06T04:09:58Z")