ashu
ashu

Reputation: 619

Concurrent mode failure, while Full GC

I am facing concurrent mode failure occuring, due to which my application responds to slow. As i see many blogs suggesting to lower the occupancy value and check, is this only solution to concurrent mode failures?



    CMS: abort preclean due to time 2015-09-16T23:18:41.306+0200: 3847212.463: [CMS-concurrent-abortable-preclean: 4.934/5.444 secs] [Times: user=5.00 sys=0.01, real=5.45 secs]
    2015-09-16T23:18:41.311+0200: 3847212.467: [GC[YG occupancy: 266211 K (436928 K)]3847212.467: [Rescan (parallel) , 0.1478990 secs]3847212.615: [weak refs processing, 0.0000180 secs] [1 CMS-remark: 3073996K(4718592K)] 3340208K(5155520K), 0.1480950 secs] [Times: user=1.57 sys=0.01, real=0.15 secs]
    2015-09-16T23:18:41.460+0200: 3847212.616: [CMS-concurrent-sweep-start]
    2015-09-16T23:18:44.204+0200: 3847215.360: [CMS-concurrent-sweep: 2.738/2.744 secs] [Times: user=2.76 sys=0.00, real=2.74 secs]
    2015-09-16T23:18:44.204+0200: 3847215.360: [CMS-concurrent-reset-start]
    2015-09-16T23:18:44.215+0200: 3847215.371: [CMS-concurrent-reset: 0.010/0.010 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
    2015-09-16T23:18:46.221+0200: 3847217.377: [GC [1 CMS-initial-mark: 3073996K(4718592K)] 3347513K(5155520K), 0.3326130 secs] [Times: user=0.33 sys=0.00, real=0.33 secs]
    2015-09-16T23:18:46.554+0200: 3847217.710: [CMS-concurrent-mark-start]
    2015-09-16T23:18:46.926+0200: 3847218.083: [Full GC 3847218.083: [CMS2015-09-16T23:18:50.249+0200: 3847221.405: [CMS-concurrent-mark: 3.688/3.695 secs] [Times: user=13.96 sys=0.31, real=3.70 secs]
     (concurrent mode failure): 3073996K->3011216K(4718592K), 20.7183280 secs] 3348996K->3011216K(5155520K), [CMS Perm : 262143K->40538K(262144K)], 20.7185010 secs] [Times: user=29.87 sys=0.31, real=20.71 secs]
    2015-09-16T23:27:27.701+0200: 3847738.857: [GC 3847738.858: [ParNew: 349568K->28669K(436928K), 0.0532300 secs] 3360784K->3039885K(5155520K), 0.0534380 secs] [Times: user=0.14 sys=0.00, real=0.05 secs]
    2015-09-16T23:33:43.242+0200: 3848114.399: [GC 3848114.399: [ParNew: 378237K->14730K(436928K), 0.0492570 secs] 3389453K->3025946K(5155520K), 0.0494510 secs] [Times: user=0.14 sys=0.00, real=0.05 secs]
    2015-09-16T23:41:35.879+0200: 3848587.035: [GC 3848587.035: [ParNew: 364298K->15247K(436928K), 0.0524070 secs] 3375514K->3026463K(5155520K), 0.0525940 secs] [Times: user=0.15 sys=0.00, real=0.05 secs]
    

Following are JVM parameters set:



    -server
    -d64
    -Xms2048M
    -Xmx2048M
    -XX:+DisableExplicitGC
    -XX:NewSize=512M
    -XX:MaxNewSize=512M
    -XX:SurvivorRatio=4
    -XX:PermSize=256M
    -XX:MaxPermSize=256M
    -XX:+UseParNewGC
    -XX:+UseConcMarkSweepGC
    -XX:CMSInitiatingOccupancyFraction=65
    -XX:+UseCMSInitiatingOccupancyOnly
    -XX:+CMSPermGenSweepingEnabled
    -XX:MaxTenuringThreshold=30

Upvotes: 3

Views: 2158

Answers (1)

Jon Thoms
Jon Thoms

Reputation: 10739

Given the fact that you have CMSInitiatingOccupancyFraction set to 65%, I would be surprised if you needed to lower it any further. And based on the logs you uploaded it appears that a strong candidate for your problem is with the preclean phase. From your logs, I'm seeing a several messages beginning with:

CMS: abort preclean due to time

What this means is that the concurrent preclean phase (where your CMS GC basically does stuff to speed up and reduce the likelihood of later stop-the-world pauses) is being aborted so stop-the-world pauses will be more frequent than they need to be.

As such, you should consider increasing the timeout of your preclean phase. This can be accomplished by manually setting the -XX:CMSMaxAbortablePrecleanTime JVM parameter to something greater than 5 secs.

I did a little bit of research on this, and there is already a nice StackOverflow Q/A on the "abort preclean due to time" issue. There is also a nice Oracle blog detailing the different phases of the CMS collector, including describing what the CMS collector's preclean phase actually does. This last reference details the syntax of the CMSMaxAbortablePrecleanTime JVM parameter.

On a side note, you have several tuning parameters for your JVM here. While they may be helping performance, they also may not be. In fact, setting several JVM parameters can often limit the JVM's ability to optimize garbage collection for your custom application. Consider experimenting with removing some of these tuning parameters to improve your performance issues.

Upvotes: 1

Related Questions