# Investigate high GC time when indexing **URL:** \ **Category:** Elasticsearch\ **Created:** [August 19, 2023, 2:44pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154 "2023-08-19T14:44:47Z")\ **Posts on this page:** 19\ **Page:** 1
**Author:** ![ktech007](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ktech007/32/124751_2.png) [@ktech007](https://discuss.elastic.co/u/ktech007)\ **Post date:** [August 19, 2023, 2:44pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/1 "2023-08-19T14:44:47Z")
Hello, I am looking for some advice as to why we are seeing a high GC time on our Elasticsearch cluster. On average, we see 5 - 8% of GC time across all the nodes. This is the setup we have: - 150 data nodes - 1000 primary shards and each has 2 replicas - each data node is receiving max up to 2k indexing calls, but avg is usually 200 - avg doc size = 3 kb - refresh\_interval = 10 sec - We provide the document id and an external version, so it is doing a lot of merges Initially, we thought it is due to the high indexing rate, but looking at this benchmark docs like this [Benchmarking and sizing your Elasticsearch cluster for logs and metrics | Elastic Blog](https://www.elastic.co/blog/benchmarking-and-sizing-your-elasticsearch-cluster-for-logs-and-metrics), it seems es should be able to handle the current load easily. So could it be: - as we provide our own document id, too many merges? - or our doc size is too big/too many fields and that takes time? - or it's probably some memory/heap misconfiguration? Our end goal is to bring down refresh\_interval to as low as possible, but a bit unsure with such a high GC. Any help would be greatly appreciated. ---
**Author:** ![Christian\_Dahlqvist](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/christian_dahlqvist/32/4617_2.png) [@Christian\_Dahlqvist](https://discuss.elastic.co/u/Christian_Dahlqvist)\ **Post date:** [August 19, 2023, 3:25pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/2 "2023-08-19T15:25:38Z")
Which version of Elasticsearch are you using? What is the specification of the data nodes with respect to CPU allocation, RAM and heap size? What type of storage are you using? What is your average shard size? How much data does each node hold? What is the full output of the [cluster stats APi](https://www.elastic.co/guide/en/elasticsearch/reference/7.17/cluster-stats.html)? > [@ktech007](#): > > each data node is receiving max up to 2k indexing calls, but avg is usually 200 Is this 2k bulk indexing requests per second? Would 2k indexing calls mean 300k indexing requests per second across the cluster? > [@ktech007](#): > > 1000 primary shards and each has 2 replicas Is this a single index or multiple indices? If multiple indices, how many indices can a single bulk indexing request cover? ---
**Author:** ![ktech007](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ktech007/32/124751_2.png) [@ktech007](https://discuss.elastic.co/u/ktech007)\ **Post date:** [August 19, 2023, 5:30pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/3 "2023-08-19T17:30:11Z")
Thanks @Christian_Dahlqvist for the response. Here are the answers: - _Which version of Elasticsearch are you using?_ - Elasticsearch version 7.10 - _What is the specification of the data nodes with respect to CPU allocation, RAM and heap size?_ - - heap: 27 gb/node - ram: 61.8gb/node - cpu allocation - Our usage is around 30 - 40%. I will back to you with the exact allocation soon. - _What is your average shard size?_ - 12 GB, 4.7 million docs - _How much data does each node hold?_ - 250 gb - _What type of storage are you using?_ - gp2 - _What is the full output of the cluster stats APi?_ - [stats.json · GitHub](https://gist.github.com/prachimg9/d24bd46dbc4f3e4cfe3d48e9c977fbf8) - _Is this 2k bulk indexing requests per second?_ - No, that is individual indexing count, but we use bulk indexing. Per node, we see max 2k/sec and avg 300/sec. For the entire cluster, we see max 30k/sec and avg 10k/sec. - _Is this a single index or multiple indices?_ - It is a single index ---
**Author:** ![Christian\_Dahlqvist](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/christian_dahlqvist/32/4617_2.png) [@Christian\_Dahlqvist](https://discuss.elastic.co/u/Christian_Dahlqvist)\ **Post date:** [August 19, 2023, 5:46pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/4 "2023-08-19T17:46:07Z")
> [@ktech007](#): > > _Which version of Elasticsearch are you using?_ - Elasticsearch version 7.10 This version is often used with third-party plugins, which naturally can affect heap usage and GC. Do you have any third-party plugins installed? > [@ktech007](#): > > _What type of storage are you using?_ - gp2 What is the size of gp2 storage per node? Small volumes can have very low IOPS which can cause performance issues. Given the number of shards in your index I would expect a lot of small writes to shards even if you use quite large bulk requests, which could overhead. The fact that you are updating and using your own IDs will also add a lot of reads. What does I/O performance look like if you run e.g. `iostat -x` on the data nodes? > "versions": [ > { > "bundled\_jdk": false, > "count": 165, > "using\_bundled\_jdk": null, > "version": "17.0.3", > } > ] The stats you provided shows that you seem to be using a JVM that is not officially supported according to the [official support matrix](https://www.elastic.co/support/matrix#matrix_jvm). Not sure if this could have any impact or special configuration considerations. ---
**Author:** ![ktech007](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ktech007/32/124751_2.png) [@ktech007](https://discuss.elastic.co/u/ktech007)\ **Post date:** [August 19, 2023, 6:14pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/5 "2023-08-19T18:14:58Z")
> [@Christian\_Dahlqvist](#): > > This version is often used with third-party plugins, which naturally can affect heap usage and GC. Do you have any third-party plugins installed? Ya, we have a few plugins installed. Is there a way to see what impact it could be having? > [@Christian\_Dahlqvist](#): > > What is the size of gp2 storage per node? 30 GB A few general questions: - Is there a max indexing rate per node/shard per sec? - With our current indexing rate, if we do change some configuration, would it be possible to have a very low refresh interval like 1 sec OR that is just too low for our volume? Could adding more data nodes help or splitting the cluster? - Does the number of fields in a doc impact GC? ---
**Author:** ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner)\ **Post date:** [August 19, 2023, 7:16pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/6 "2023-08-19T19:16:02Z")
> [@ktech007](#): > > Elasticsearch version 7.10 TBH the simplest piece of tuning advice we can offer is to use a newer version. 7.10.2 passed [EOL](https://www.elastic.co/support/eol) a long time ago, and there's been a lot of performance-related improvements in the ~2½ years since it was released, some of which I would expect to reduce the load on the GC. You could try using something like [async profiler](https://github.com/async-profiler/async-profiler) to understand where the time is being spent and/or what bits of the system are allocating the most heap objects (which directly contributes to GC pressure). Maybe that will point to problems in a particular plugin. 30k docs per sec does seem very low for such a large cluster. It very much depends on the details of the workload, but [at least some of the nightly benchmarks](https://elasticsearch-benchmarks.elastic.co/index.html#tracks/http-logs/nightly/default/90d) achieve several times that ingest rate using just 3 nodes running recent versions. ---
**Author:** ![ktech007](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ktech007/32/124751_2.png) [@ktech007](https://discuss.elastic.co/u/ktech007)\ **Post date:** [August 23, 2023, 9:33pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/7 "2023-08-23T21:33:46Z")
@DavidTurner @Christian_Dahlqvist wanted to follow up. We did some testing and analysis. For example: we set up an index with a lot of mapping properties like 10 - 12k and saw a huge increase in GC, up to 20%. Our heap is 27 GB. Based on a few use cases: - Do # of mappings in an index have an impact on GC or basically like how the heap is populated? - Is the heap somehow split between writes and reads? We are doing writes on this cluster (just for testing) and see around 50 - 60% heap used, but GC is so high, so wondering if something changed in es7? - Could the [indexing buffer setting](https://www.elastic.co/guide/en/elasticsearch/reference/7.17/indexing-buffer.html) impacting it somehow ? Like a 10% indices.memory.index\_buffer\_size means we are not flushing mesages to disk fast enough and the heap is getting filled up? Any help is appreciated as always. ---
**Author:** ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner)\ **Post date:** [August 24, 2023, 2:30pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/8 "2023-08-24T14:30:47Z")
- Mappings take up some amount of memory, yes. - Heap is not split between writes and reads. - The whole point of the indexing buffer is to _prevent_ heap from filling up. Did you try upgrading? Did you try async profiler? They were the two things I suggested would be most helpful. ---
**Author:** ![ktech007](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ktech007/32/124751_2.png) [@ktech007](https://discuss.elastic.co/u/ktech007)\ **Post date:** [August 24, 2023, 3:25pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/9 "2023-08-24T15:25:26Z")
We just finished upgrading to 7 a few months back, so we are a bit behind here. For the async profiler, I will try that next. I was setting up some use cases in our staging environment and had those questions. Thanks. ---
**Author:** ![ktech007](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ktech007/32/124751_2.png) [@ktech007](https://discuss.elastic.co/u/ktech007)\ **Post date:** [August 27, 2023, 4:16am UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/10 "2023-08-27T04:16:29Z")
@DavidTurner We did the async profiler for allocations on two clusters. The prod cluster has ~6% GC and QA cluster has 1% (not bad but just wanted to compare). There is no clear outlier, but the topmost caller is `org/apache/lucene/index/DefaultIndexingChain.flush` path. Here are some other stats: - prod cluster - [html file](https://drive.google.com/uc?export=download&id=1OGCxwgHMGLexPnUNtHSzmQ_p83Y6jnqm). - qa cluster, [html file](https://drive.google.com/uc?export=download&id=1uuj6hMYnSRf-FJElck6bq5G7aWje0Hxy). 27 GB, but has less volume and doc size. I will be digging in more, but if you have any advice, please let me know. Thanks. ---
**Author:** ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner)\ **Post date:** [August 27, 2023, 7:25am UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/11 "2023-08-27T07:25:16Z")
Thanks @ktech007, can you share the profiler options you used too? I think we want to see allocation profiles and wall-clock profiles, which are these? ---
**Author:** ![ktech007](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ktech007/32/124751_2.png) [@ktech007](https://discuss.elastic.co/u/ktech007)\ **Post date:** [August 27, 2023, 12:39pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/12 "2023-08-27T12:39:12Z")
> [@DavidTurner](#): > > can you share the profiler options you used too This is the allocation profile: `/opt/async-profiler/profiler.sh -e alloc -d 30 -f /tmp/foo.html {pid}`. Are there any specific options you would like for allocation and wall profile? ---
**Author:** ![ktech007](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ktech007/32/124751_2.png) [@ktech007](https://discuss.elastic.co/u/ktech007)\ **Post date:** [August 28, 2023, 3:20pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/13 "2023-08-28T15:20:23Z")
@DavidTurner , I have more data now. We ran the allocation profile (`/opt/async-profiler/profiler.sh -e alloc -d 30 `) and wall clock profile (`/opt/async-profiler/profiler.sh -e wall -t -i 5ms`) for two clusters that are seeing high GC. - Cluster 1 - [allocation profile](https://drive.google.com/uc?export=download&id=1dxnjXy_JxcsvUzCEYvssRPxEpdJn6ZLr), [wall clock profile](https://drive.google.com/uc?export=download&id=1iwgE8orlVld2xzm0u5DdCsZ2kTez_jD5) - 150 data nodes, 500 - 1000 requests/sec per node - Cluster 2 - [allocation profile](https://drive.google.com/uc?export=download&id=1Zy7ixsMmMxOpdmshHviqydFJzOndu8DO), [wall clock profile](https://drive.google.com/uc?export=download&id=1Uld8c0SMYhjHHroQ304KV0FxRfmL7X7Q) - 36 data nodes, ~100 individual requests per sec per node ---
**Author:** ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner)\ **Post date:** [August 28, 2023, 6:58pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/14 "2023-08-28T18:58:35Z")
These profiles indicate that the nodes are almost completely idle. There's no tuning needed here. ---
**Author:** ![ktech007](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ktech007/32/124751_2.png) [@ktech007](https://discuss.elastic.co/u/ktech007)\ **Post date:** [August 28, 2023, 7:11pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/15 "2023-08-28T19:11:11Z")
So I have an idea. I have been running some tests. Let's say an index has 3000 mappings and indexing doc with ~100 fields. If we are indexing documents with similar fields, GC is fine. But if I start indexing documents that all have very varied fields, GC starts to go high. Do you know if there is a cache or something we can adjust? ---
**Author:** ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner)\ **Post date:** [August 28, 2023, 7:28pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/16 "2023-08-28T19:28:12Z")
According to these profiles you're barely using your cluster at all. There's no need to worry about GC time here. ---
**Author:** ![ktech007](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ktech007/32/124751_2.png) [@ktech007](https://discuss.elastic.co/u/ktech007)\ **Post date:** [August 28, 2023, 7:38pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/17 "2023-08-28T19:38:57Z")
Ok, thank you. One last question, so high GC would basically impact indexing speed, right? We want to reduce our refresh\_interval but one of the concerns was high GC. Do you think it would be ok to reduce it? ---
**Author:** ![DavidTurner](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/davidturner/32/22453_2.png) [@DavidTurner](https://discuss.elastic.co/u/DavidTurner)\ **Post date:** [August 28, 2023, 7:42pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/18 "2023-08-28T19:42:54Z")
GC time doesn't look like it's having any impact on performance here. ---
**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\ **Post date:** [September 25, 2023, 7:43pm UTC](https://discuss.elastic.co/t/investigate-high-gc-time-when-indexing/341154/19 "2023-09-25T19:43:23Z")
This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.