title: Too much Full GC happening in CMS
body: <p>I'm observing frequent GC including Full GC in my java application under load off 100 clients making a web service call which return a JSON of 21KB (compressed size) to client. Uncompressed JSON will be around 200 KB. Beacause of frequent GC, I'm observing huge latency of 2.6 seconds. Here the JVM option used for the load test</p>
  
  <pre><code>-Xloggc:/mnt/apache-tomcat-7.0.29/logs/gc.log -XX:+UseConcMarkSweepGC -XX:+UseCompressedOops -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintTenuringDistribution -XX:+PrintTenuringDistribution -XX:+UseParNewGC -Xms5048M  -XX:MaxTenuringThreshold=2 -XX:SoftRefLRUPolicyMSPerMB=73 -Djava.net.preferIPv4Stack=true -server -XX:NewRatio=4 -XX:SurvivorRatio=8 
  </code></pre>
  
  <p>I'm using AWS xLarge instance with 4vCPU and 15 MB RAM.</p>
  
  <p>Here are the GCl logs produced by the process</p>
  
  <pre><code> 249.988: [GC 249.988: [ParNew
  2163 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
  2164 - age   1:   83821968 bytes,   83821968 total
  2165 - age   2:   20181408 bytes,  104003376 total
  2166 : 896337K-&gt;103360K(930432K), 0.0409860 secs] 4453729K-&gt;3663260K(5065792K), 0.0412220 secs] [Times: user=0.16 sys=0.00, real=0.04 secs]
  
  2167 250.051: [GC 250.051: [ParNew
  2168 Desired survivor size 52920320 bytes, new threshold 2 (max 2)
  2169 - age   1:   24997144 bytes,   24997144 total
  
  2170 : 185613K-&gt;82956K(930432K), 0.0620620 secs] 3745513K-&gt;3744426K(5065792K), 0.0622810 secs] [Times: user=0.22 sys=0.00, real=0.06 secs]
  
  2171 250.408: [GC 250.409: [ParNew
  2172 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
  2173 - age   1:   86010184 bytes,   86010184 total
  2174 - age   2:   19119656 bytes,  105129840 total
  
  
  2183 : 930432K-&gt;103360K(930432K), 0.0904080 secs] 4767408K-&gt;4080180K(5065792K), 0.0906520 secs] [Times: user=0.33 sys=0.01, real=0.09 secs]
  2184 251.229: [GC 251.229: [ParNew: 215470K-&gt;215470K(930432K), 0.0000370 secs] 4192291K-&gt;4192291K(5065792K), 0.0001620 secs] [Times: user=0.00 sys=0.00, real     =0.00 secs]
  
  2185 GC locker: Trying a full collection because scavenge failed
  2186 251.229: [Full GC 251.229: [CMS251.495: [CMS-concurrent-mark: 6.443/8.877 secs] [Times: user=30.14 sys=3.55, real=8.87 secs]
  2187  (concurrent mode failure): 3976820K-&gt;354739K(4135360K), 0.9792960 secs] 4192291K-&gt;354739K(5065792K), [CMS Perm : 42722K-&gt;42722K(71212K)], 0.9794580 sec     s] [Times: user=0.96 sys=0.02, real=0.98 secs]
  2188 252.439: [GC 252.440: [ParNew
  2189 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
  2190 - age   1:  105807496 bytes,  105807496 total
  2191 : 837144K-&gt;103360K(930432K), 0.0562310 secs] 1191884K-&gt;474282K(5065792K), 0.0564520 secs] [Times: user=0.22 sys=0.00, real=0.05 secs]
  2192 252.676: [GC 252.676: [ParNew
  2193 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
  2194 - age   1:   95836672 bytes,   95836672 total
  2195 : 924377K-&gt;103360K(930432K), 0.0772210 secs] 1295299K-&gt;575312K(5065792K), 0.0774650 secs] [Times: user=0.28 sys=0.01, real=0.08 secs]
  2196 253.001: [GC 253.001: [ParNew
  2197 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
  2198 - age   1:   99903544 bytes,   99903544 total
  
  2199 : 930432K-&gt;103360K(930432K), 0.0712130 secs] 1405673K-&gt;680963K(5065792K), 0.0714420 secs] [Times: user=0.25 sys=0.01, real=0.07 secs]
  
  2200 253.324: [GC 253.324: [ParNew
  2201 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
  2202 - age   1:  105814880 bytes,  105814880 total
  
  2203 : 930432K-&gt;103360K(930432K), 0.0736730 secs] 1513770K-&gt;807662K(5065792K), 0.0739490 secs] [Times: user=0.27 sys=0.00, real=0.08 secs]
  2204 253.666: [GC 253.667: [ParNew
  </code></pre>