# GC spending too much time on elastic injest node **URL:** \ **Category:** Elasticsearch\ **Created:** [October 31, 2017, 2:39pm UTC](https://discuss.elastic.co/t/gc-spending-too-much-time-on-elastic-injest-node/105903 "2017-10-31T14:39:44Z")\ **Posts on this page:** 3\ **Page:** 1
**Author:** ![Zeeshan\_Alam](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/zeeshan_alam/32/94298_2.png) [@Zeeshan\_Alam](https://discuss.elastic.co/u/Zeeshan_Alam)\ **Post date:** [October 31, 2017, 2:39pm UTC](https://discuss.elastic.co/t/gc-spending-too-much-time-on-elastic-injest-node/105903/1 "2017-10-31T14:39:44Z")
Hi All, I am running elastic 5.5 and my set up is having 3 client node, [data: false, master:false] and I am sending bulk request of 15000 from Logstash to client nodes. I have: **3 Master** **3 Client** **10 Data** **1 Logstash** I am getting these GC logs and then the client node is not responding and hence my cronjob is restarting the elastic process: ``` [2017-10-31T10:18:06,109][WARN][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][348] overhead, spent [619ms] collecting in the last [1s] [2017-10-31T10:18:07,225][WARN][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][349] overhead, spent [877ms] collecting in the last [1.1s] [2017-10-31T10:18:08,527][WARN][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][350] overhead, spent [1.1s] collecting in the last [1.3s] [2017-10-31T10:18:09,577][WARN][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][351] overhead, spent [864ms] collecting in the last [1s] [2017-10-31T10:18:10,748][WARN][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][352] overhead, spent [965ms] collecting in the last [1.1s] [2017-10-31T10:18:11,749][WARN][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][353] overhead, spent [845ms] collecting in the last [1s] [2017-10-31T10:18:12,750][INFO][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][354] overhead, spent [403ms] collecting in the last [1s] [2017-10-31T10:18:20,922][INFO][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][362] overhead, spent [360ms] collecting in the last [1.1s] [2017-10-31T10:18:22,934][INFO][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][364] overhead, spent [255ms] collecting in the last [1s] [2017-10-31T10:18:23,935][INFO][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][365] overhead, spent [401ms] collecting in the last [1s] [2017-10-31T10:18:24,936][INFO][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][366] overhead, spent [323ms] collecting in the last [1s] [2017-10-31T10:18:36,107][INFO][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][old][370][4] duration [7.2s], collections [1]/[8s], total [7.2s]/[7.3s], memory [14.2gb]->[13.9gb]/[14.9gb], all_pools {[young] [25.9mb]->[5.9mb]/[399.4mb]}{[survivor] [49.8mb]->[0b]/[49.8mb]}{[old] [14.1gb]->[13.9gb]/[14.5gb]} [2017-10-31T10:18:36,108][WARN][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][370] overhead, spent [7.2s] collecting in the last [8s] [2017-10-31T10:18:46,756][INFO][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][old][375][6] duration [6s], collections [1]/[6.6s], total [6s]/[13.4s], memory [14.6gb]->[14.5gb]/[14.9gb], all_pools {[young] [286.8mb]->[32.7mb]/[399.4mb]}{[survivor] [49.8mb]->[0b]/[49.8mb]}{[old] [14.3gb]->[14.5gb]/[14.5gb]} [2017-10-31T10:18:46,758][WARN][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][375] overhead, spent [6.2s] collecting in the last [6.6s] [2017-10-31T10:18:52,991][INFO][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][old][376][7] duration [6s], collections [1]/[6.2s], total [6s]/[19.4s], memory [14.5gb]->[14.8gb]/[14.9gb], all_pools {[young] [32.7mb]->[389.4mb]/[399.4mb]}{[survivor] [0b]->[0b]/[49.8mb]}{[old] [14.5gb]->[14.5gb]/[14.5gb]} [2017-10-31T10:18:52,991][WARN][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][376] overhead, spent [6s] collecting in the last [6.2s] [2017-10-31T10:19:01,204][INFO][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][old][377][8] duration [8.1s], collections [1]/[8.2s], total [8.1s]/[27.6s], memory [14.8gb]->[14.9gb]/[14.9gb], all_pools {[young] [389.4mb]->[399.4mb]/[399.4mb]}{[survivor] [0b]->[44.1mb]/[49.8mb]}{[old] [14.5gb]->[14.5gb]/[14.5gb]} [2017-10-31T10:19:01,204][WARN][o.e.m.j.JvmGcMonitorService] [client-esinjest1] [gc][377] overhead, spent [8.1s] collecting in the last [8.2s] ``` Here is my **heap** details from `jmap -heap` ``` Heap Configuration: MinHeapFreeRatio = 40 MaxHeapFreeRatio = 70 MaxHeapSize = 16106127360 (15360.0MB) NewSize = 523436032 (499.1875MB) MaxNewSize = 523436032 (499.1875MB) OldSize = 15582691328 (14860.8125MB) NewRatio = 2 SurvivorRatio = 8 MetaspaceSize = 21807104 (20.796875MB) CompressedClassSpaceSize = 1073741824 (1024.0MB) MaxMetaspaceSize = 17592186044415 MB G1HeapRegionSize = 0 (0.0MB) Heap Usage: New Generation (Eden + 1 Survivor Space): capacity = 471138304 (449.3125MB) used = 355704016 (339.2257843017578MB) free = 115434288 (110.08671569824219MB) 75.49885309261545% used Eden Space: capacity = 418840576 (399.4375MB) used = 303406288 (289.3507843017578MB) free = 115434288 (110.08671569824219MB) 72.43956421261345% used From Space: capacity = 52297728 (49.875MB) used = 52297728 (49.875MB) free = 0 (0.0MB) 100.0% used To Space: capacity = 52297728 (49.875MB) used = 0 (0.0MB) free = 52297728 (49.875MB) 0.0% used concurrent mark-sweep generation: capacity = 15582691328 (14860.8125MB) used = 9416535272 (8980.307838439941MB) free = 6166156056 (5880.504661560059MB) 60.4294538972209% used 16820 interned Strings occupying 2487936 bytes. ``` ---
**Author:** ![Zeeshan\_Alam](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/zeeshan_alam/32/94298_2.png) [@Zeeshan\_Alam](https://discuss.elastic.co/u/Zeeshan_Alam)\ **Post date:** [October 31, 2017, 2:51pm UTC](https://discuss.elastic.co/t/gc-spending-too-much-time-on-elastic-injest-node/105903/2 "2017-10-31T14:51:21Z")
Heap Histogram: ``` num #instances #bytes class name ---------------------------------------------- 1: 1778028 9096304592 [B 2: 631785 72002248 [I 3: 1263904 59104952 [Ljava.lang.Object; 4: 1338437 58393192 [C 5: 837308 46889248 org.elasticsearch.search.aggregations.bucket.terms.StringTerms$Bucket 6: 1833157 43995768 java.util.ArrayList 7: 1282186 30772464 java.lang.String 8: 1226539 29436936 org.apache.lucene.util.BytesRef 9: 531366 25505568 java.nio.HeapByteBuffer 10: 318411 25472880 org.elasticsearch.search.aggregations.bucket.terms.StringTerms 11: 518632 24894336 org.elasticsearch.search.aggregations.metrics.cardinality.HyperLogLogPlusPlus 12: 521897 20875880 org.elasticsearch.common.util.BigArrays$ByteArrayWrapper 13: 518632 20745280 org.elasticsearch.common.util.BigArrays$IntArrayWrapper 14: 518632 20745280 org.elasticsearch.search.aggregations.metrics.cardinality.HyperLogLogPlusPlus$Hashset 15: 841696 20200704 org.elasticsearch.search.aggregations.InternalAggregations 16: 1088436 17414976 java.util.concurrent.atomic.AtomicBoolean 17: 518634 16596288 org.apache.lucene.util.LongBitSet 18: 518632 16596224 org.elasticsearch.search.aggregations.metrics.cardinality.InternalCardinality 19: 557155 13371720 java.util.LinkedList$Node 20: 526560 12683344 [J 21: 279160 8933120 java.util.LinkedList 22: 518632 8298112 org.elasticsearch.search.aggregations.metrics.cardinality.HyperLogLogPlusPlus$OpenBitSet 23: 247598 7923136 java.util.HashMap$Node 24: 141651 5666040 java.util.TreeMap$Entry 25: 103954 4989792 org.joda.time.format.DateTimeFormatter 26: 59324 4749648 [S 27: 50486 4574960 [Ljava.util.HashMap$Node; 28: 278461 4455376 org.elasticsearch.search.aggregations.bucket.terms.InternalOrder$CompoundOrder 29: 78943 2595280 [Lorg.elasticsearch.search.aggregations.bucket.terms.StringTerms$Bucket; 30: 104786 2514864 java.util.Arrays$ArrayList 31: 43240 2075520 java.util.HashMap 32: 29531 1653736 java.util.stream.ReferencePipeline$Head 33: 20432 1307648 java.util.concurrent.ConcurrentHashMap 34: 25624 1229952 java.util.TreeMap 35: 18490 1183360 java.util.regex.Matcher 36: 10713 1176256 java.lang.Class 37: 45591 1094184 org.apache.lucene.util.SetOnce 38: 26678 1067120 java.util.TreeMap$KeySpliterator 39: 16556 1059584 java.util.stream.ReferencePipeline$2 40: 32884 1052288 java.util.TreeMap$EntryIterator 41: 15610 999040 java.util.stream.ReferencePipeline$5 42: 28286 905152 java.util.concurrent.ConcurrentHashMap$Node 43: 4882 898288 com.fasterxml.jackson.core.json.UTF8StreamJsonParser 44: 21561 862440 java.util.HashMap$KeyIterator 45: 21011 840440 java.util.HashMap$ValueIterator 46: 25952 830464 org.elasticsearch.common.joda.FormatDateTimeFormatter 47: 33898 813552 java.util.Collections$SetFromMap 48: 23398 748736 java.util.AbstractList$Itr 49: 15073 723504 com.fasterxml.jackson.core.json.JsonReadContext 50: 8920 713600 io.netty.buffer.PooledHeapByteBuf 51: 12380 693280 com.carrotsearch.hppc.ObjectObjectHashMap 52: 20721 663072 java.util.Collections$UnmodifiableSortedMap 53: 20263 648416 org.elasticsearch.common.settings.Settings 54: 26707 643080 [Lorg.joda.time.format.InternalParser; 55: 15610 624400 org.elasticsearch.common.settings.Settings$FilteredMap 56: 15495 619800 io.netty.buffer.UnpooledSlicedByteBuf 57: 18928 605696 org.elasticsearch.transport.netty4.ByteBufBytesReference 58: 6650 585200 java.lang.reflect.Method 59: 4824 578880 org.elasticsearch.action.index.IndexRequest 60: 17824 570368 org.joda.time.format.DateTimeFormatterBuilder$Composite 61: 19586 566256 [Ljava.lang.String; 62: 13672 546880 java.util.IdentityHashMap 63: 12915 516600 io.netty.buffer.UnpooledDuplicatedByteBuf 64: 15610 499520 java.util.stream.ReduceOps$8 65: 15610 499520 java.util.stream.ReduceOps$8ReducingSink 66: 15610 499520 org.elasticsearch.common.settings.Settings$FilteredMap$1$1 67: 30675 490800 java.util.Collections$UnmodifiableMap$UnmodifiableEntrySet$UnmodifiableEntry 68: 20276 486624 java.util.concurrent.ConcurrentHashMap$KeySetView 69: 19658 471792 java.lang.Long 70: 14291 457312 io.netty.handler.codec.CodecOutputList 71: 7847 439432 com.carrotsearch.hppc.IntObjectHashMap 72: 17874 428976 java.util.Collections$UnmodifiableMap$UnmodifiableEntrySet$1 73: 17786 428768 [Lorg.joda.time.format.InternalPrinter; 74: 12906 412992 org.elasticsearch.transport.netty4.ByteBufStreamInput 75: 5678 408816 java.util.regex.Pattern 76: 3924 408096 org.elasticsearch.cluster.metadata.IndexMetaData 77: 47 407536 [D 78: 12581 402592 org.apache.lucene.search.FieldDoc 79: 16556 397344 java.util.stream.ReferencePipeline$2$1 80: 15610 374640 java.util.stream.ReferencePipeline$5$1 81: 15610 374640 org.elasticsearch.common.settings.Settings$FilteredMap$1 82: 9312 372480 java.util.HashMap$EntryIterator 83: 11583 370656 java.lang.NumberFormatException 84: 6490 363440 java.lang.invoke.MemberName 85: 14823 360936 ``` ---
**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\ **Post date:** [November 28, 2017, 2:52pm UTC](https://discuss.elastic.co/t/gc-spending-too-much-time-on-elastic-injest-node/105903/3 "2017-11-28T14:52:02Z")
This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.