Java CMS garbage collector log output

Question

I am using Java CMS garbage collector and trying to understand log lines, for example:

22609.787: [GC 22609.788: [ParNew: 1116101K->79200K(1310720K), 0.2369136 secs] 1551730K->516431K(6029312K), 0.2379422 secs] [Times: user=1.68 sys=0.02, real=0.24 secs] 22610.741: [Full GC 22610.741: [CMS: 437230K->278442K(4718592K), 14.8596841 secs] 573355K->278442K(6029312K), [CMS Perm : 241468K->236967K(241856K)], 14.8694544 secs] [Times: user=14.80 sys=0.13, real=14.87 secs] 22635.415: [GC 22635.416: [ParNew: 1048576K->43613K(1310720K), 0.0904065 secs] 1327018K->322055K(6029312K), 0.0914701 secs] [Times: user=0.45 sys=0.00, real=0.09 secs] 

Based on reading http://blogs.oracle.com/poonam/entry/understanding_cms_gc_logs , CMS will do a complete garbage collection in various situations (for example, if "progress in the attempt to delete fails",), but according to this blog it will log the reason for the full GC.

Instead, I see adhoc full GCs. This is definitely a CMS because there are other CMS log entries.

Are there reasons why he will do a full GC, but not register the reason?

EDIT: Sorry, a few java installations (I inherited this setting). In fact, it uses jdk1.6.0_27

EDIT Unfortunately, the JVM parameters are wrapped in configuration files (this is a commercial application that runs on Tomcat), but I am sure that they:

 min.heapsize=6144m max.heapsize=6144m -Xss=512k -XX:MaxPermSize=512m -XX:NewSize=1536m -XX:MaxNewSize=1536m -XX:SurvivorRatio=4 -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+UseTLAB -XX:+UseCompressedOops -XX:+PrintVMOptions -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCTaskTimeStamps -XX:+PrintCommandLineFlags -XX:+PrintGCApplicationStoppedTime -XX:StackShadowPages=20 -XX:+DisableExplicitGC 

Answer 1

ConcurrentMarkSweepGC will perform the GC when it determines that it is about to fill or reach its low water level. (I do not believe in this case)

Most likely, some code calls System.gc () directly. For instance. RMI will call it every hour by default. You can try using -XX:+DisableExplicitGC to find out it doesn't matter. If this happens, I will trace the cause and prevent it (some just leave this option enabled).

Another possible reason is working on free direct memory. Direct memory is cleared only on the GC, but does not contribute much to the heap size, so it looks like you need a GC. When you run out of direct memory, it should call System.gc () to free those ByteBuffers that use it. The way I get around is that we clear the line and the memory displays ByteBuffers explicitly, so I haven't finished work.

I would also try updating Java 6 30 or even updating Java 7, as it may have more predictable behavior (even if you cannot use it, it can be informative)

You can try one that can tell you that the GC was called (but not always)

 `jstat -gccause {pid} 10s`