Concurrent mode failure, while Full GC

Question

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

Have you read this: http://stackoverflow.com/questions/2918124/how-to-reduce-java-concurrent-mode-failure-and-excessive-gc — assylias, Oct 07 '15 at 07:03
yes, i have gone throught, but still i am not able to figure it out — ashu, Oct 07 '15 at 07:07
if you have gone through that, what exactly have you tried? and what java version? how many cores? and can you provide the full GC logs (upload/pastebin them)? — the8472, Oct 08 '15 at 03:24
jdk version: 1.6.0_32-b05, as i cannot try , bcoz thits occurs in customer site. there complaint is application too slow, its taking more cpu time. http://pastebin.com/NGdkieJA — ashu, Oct 08 '15 at 10:37
As we see [CMS-concurrent-mark: 4.651/4.658 secs] [Times: user=18.04 sys=0.36, real=4.65 secs] DOes it affect performance of our application? — ashu, Oct 08 '15 at 10:52

score 1 · Answer 1 · edited May 23 '17 at 12:14

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.

Concurrent mode failure, while Full GC

1 Answers1