Rebuild java garbage, although enough java memory - why

Question

There is a lot of processor in our Java process, and the log shows that it does GC too often, although the used memory is ~ 5 GB (taken from the JMX console), and Min and Max mem are 10 GB.

our arguments are JVM: JVM_GC = "- verbose: gc -Xnoclassgc -XX: + PrintGCDetails -XX: + UseParNewGC -XX: NewSize = 3GB -XX: ParallelGCThreads = 8 -XX: MaxTenuringThreshold = 15 -XX: + UseConCMarkS

and MinHeap = MaxHeap = 10 GB

Any idea what might trigger the launch of the GC? and why is this often and too early? We cannot connect any profiling tool as its production box, besides getting some settings through JMX ... thanks ..... GC log ....

@ 2011-07-20 02:10:46
[Full GC (System) [CMS: 3333423K-> 4019122K (7340032K), 13.4979250 secs] 4876606K-> 4019122K (10171200K), [CMS Perm: 21656K-> 21608K (21824K)], 13.4980930 s s] [Times: user = 12.99 sys = 0.50, real = 13.50 secs

[GC [1 CMS-initial-mark: 4019122K (7340032K)] 4041525K (10171200K), 0.0009110 sec]] [Times: user = 0.00 sys = 0.00, real = 0.00 secs)
@ 2011-07-20 02:11:10
[CMS-concurrent-mark: 10.322 / 10.753 secs] [Times: user = 21.55 sys = 0.22, real = 10.75 secs]
[CMS-concurrent-preclean: 0.035 / 0.036 secs] [Times: user = 0.04 sys = 0.00, real = 0.04 secs]
@ 2011-07-20 02:11:15
CMS: time interruption [CMS-concurrent-abortable-preclean: 1.083 / 5.063 secs] [Times: user = 1.08 sys = 0.00, real = 5.06 secs]
[GC [filling YG: 282204 K (2831168 K)] [Rescan (parallel), 0.0402030 secs] [processing of weak reflexes, 0.0010550 seconds]
[1 CMS note: 4019122K (7340032K)] 4301 326K (10171200K), 0.0413630 secs] [Times: user = 0.07 sys = 0.01, real = 0.04 secs]
@ 2011-07-20 02:11:16
[CMS-concurrent-sweep: 2.627 / 2.627 secs] [Times: user = 2.63 sys = 0.00, real = 2.63 secs]
[CMS-concurrent- reset: 0.039 / 0.039 secs] [Times: user = 0.04 sys = 0.00, real = 0.04 secs]
@ 2011-07-20 02:11:20
[GC [1 CMS-initial-mark: 4019034K (7340032K)] 4301238K (10171200K), 0.0308450 seconds] [Times: user = 0.03 sys = 0.00, real = 0.03 secs]
@ 2011-07-20 2:11:30
[CMS-concurrent-mark: 10.304 / 10.307 secs] [Times: user = 20.48 sys = 0.11, real = 10.31 secs]
[CMS-concurrent-preclean: 0.018 / 0.019 secs] [Times: user = 0.02 sys = 0.00, real = 0.01 secs)
@ 2011-07-20 02:11:35
CMS: interrupt due to time [CMS-concurrent-abortable-preclean: 1.043 / 5.048 secs] Times: user = 1.03 sys = 0.00, real = 5.05 secs

[GC [filling YG: 282204 K (2831168 K)] [Rescan (parallel), 0.0419560 secs] [weak processing of refs, 0.0010880 secs]
[1 CMS note: 4019034K (7340032K)] 4301 238K (10171200K), 0.0431480 secs] [Times: user = 0.07 sys = 0.01, real = 0.05 secs]
@ 2011-07-20 02:11:38
[CMS-concurrent-sweep: 2.622 / 2.622 secs] [Times: user = 2.63 sys = 0.00, real = 2.62 secs]
[CMS-concurrent- reset: 0,039 / 0,039 sec.] [Times: user = 0.04 sys = 0.00, real = 0.04 secs]

Answer 1

Try using the UseCMSInitiatingOccupancyOnly and CMSInitiatingOccupancyFraction flags. The use of these flags initiating the assembly of the CMS will be initiated on a busy basis. It also probably makes sense to increase the size of generations.

Answer 2

How about memory fragmentation? Parallel labeling and scrolling is not compact memory, and ultimately it can become very fragmented - therefore, although you have enough common space, you may not have enough space to accommodate a new object; and so the GC starts up.