Hi,
I am running a performance test on our application. After the test was run for 1 hour, I see long GC pause which caused response time spikes. Need some help or suggestion on how to reduce the GC pause.
Here are the GC log :
2012-05-15T22:52:56.161-0700: 6177.078: [GC 6177.078: [ParNew: 17695592K->1339126K(18874368K), 0.3434470 secs] 43749198K->27457582K(48234496K), 0.3436340 secs]
[Times: user=5.62 sys=0.02, real=0.34 secs]
2012-05-15T22:53:05.970-0700: 6186.887: [GC 6186.887: [ParNew: 18115900K->1689020K(18874368K), 0.3852740 secs] 44234355K->27966612K(48234496K), 0.3854630 secs]
[Times: user=5.47 sys=0.06, real=0.39 secs]
2012-05-15T22:53:15.642-0700: 6196.558: [GC 6196.558: [ParNew (promotion failed): 18466236K->17822574K(18874368K), 1.5893900 secs]6198.147: [CMS
: 26715373K->25179454K(29360128K), 56.2166540 secs] 44743828K->25179454K(48234496K), [CMS Perm : 41353K->41229K(69084K)], 57.8062970 secs]
[Times: user=62.74 sys=0.24, real=57.80 secs]
2012-05-15T22:54:28.938-0700: 6269.855: [GC 6269.855: [ParNew: 16774330K->778090K(18874368K), 0.0507380 secs] 41953785K->25957545K(48234496K), 0.0509320 secs]
[Times: user=0.99 sys=0.00, real=0.05 secs]
2012-05-15T23:46:04.707-0700: 9365.623: [GC 9365.623: [ParNew: 17040515K->359475K(18874368K), 0.0740660 secs] 46306893K->29625853K(48234496K), 0.0741870 secs] [Times: user=1.46 sys=0.00, real=0.08 secs]
2012-05-15T23:46:05.067-0700: 9365.984: [CMS-concurrent-sweep: 13.441/13.605 secs] [Times: user=142.94 sys=1.38, real=13.60 secs]
2012-05-15T23:46:05.067-0700: 9365.984: [CMS-concurrent-reset-start]
2012-05-15T23:46:05.153-0700: 9366.069: [CMS-concurrent-reset: 0.085/0.085 secs] [Times: user=0.73 sys=0.01, real=0.09 secs]
2012-05-15T23:46:05.432-0700: 9366.348: [GC [1 CMS-initial-mark: 29264165K(29360128K)] 30880704K(48234496K), 0.2924050 secs] [Times: user=0.29 sys=0.00, real=0.29 secs]
2012-05-15T23:46:05.724-0700: 9366.641: [CMS-concurrent-mark-start]
2012-05-15T23:46:11.304-0700: 9372.220: [GC 9372.220: [ParNew: 17135902K->301516K(18874368K), 0.1034410 secs] 46400067K->29630497K(48234496K), 0.1035600 secs]
[Times: user=1.74 sys=0.00, real=0.10 secs]
2012-05-15T23:46:18.652-0700: 9379.568: [Full GC 9379.568: [CMS
2012-05-15T23:46:23.919-0700: 9384.835: [CMS-concurrent-mark: 17.954/18.194 secs] [Times: user=206.41 sys=4.01, real=18.19 secs]
(concurrent mode failure): 29328981K->29057103K(29360128K), 78.5226800 secs] 46405706K->29057103K(48234496K), [CMS Perm : 41177K->41173K(69084K)], 78.5228130 secs] [Times: user=91.91 sys=1.77, real=78.51 secs]
The server has 24 cores on Linux 64bit OS. JVM version: 1.6.0_24-b07. Here is the JVM options I used:
-XX:+DisableExplicitGC -server -Xms48G -Xmx48G -XX:MaxPermSize=728m -Xss128k -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:NewSize=20G -XX:ParallelGCThreads=20 -XX:+PrintGCDateStamps -XX:+PrintGCDetails
Thanks in advance for any suggestion.
Jimy