In which case does a java garbage collection of the young generation last long?

Question

yesterday we had the following GC output in our server log of one JBoss application server:

51628.286: [GC 51628.288: [ParNew: 1843200K->204800K(1843200K), 21.3196040 secs]
5177730K->3743415K(7987200K), 21.3217870 secs]
[Times: user=1.38 sys=0.33, real=21.32 secs] 

I understand the output like this: the young generation is sized 1843200K. The size before generation was 1843200K, the size after 204800K. The collection lasted 21.3 seconds.

Normally our young generation collections last <1 sec. Under which circumstances do yg collections last so long?

Our JVM params:

-server 
-verbose:gc
-XX:+PrintGCTimeStamps
-XX:+PrintGCDetails 
-XX:NewRatio=3
-XX:+UseConcMarkSweepGC 
-XX:+UseParNewGC 
-XX:+UseCMSCompactAtFullCollection 
-XX:CMSInitiatingOccupancyFraction=60 
-XX:MaxPermSize=256m 
-Xss512k 
-Xms8000m 
-Xmx8000m

java version:

java version "1.6.0_29"
Java(TM) SE Runtime Environment (build 1.6.0_29-b11)
Java HotSpot(TM) 64-Bit Server VM (build 20.4-b02, mixed mode)

Thanks, Marcel

Answer 1

We had a tomcat server which had garbage collections which lasted ~2 minutes. Eventually, we found the reason, we had allocated more memory to the JVM through -Xmx than we had physical memory on the system. This was causing paging during the garbage collection, which kills it.

Also, we had multiple VMs which were running on the same physical machine. Make sure that you have not allocated more memory to all of the VMs than you have physical memory on the server.

For further information, see Tuning the Memory Management System, section Setting the Heap Size (my emphasis):

Command line options: -Xms: -Xmx:

The heap size has an impact on allocation speed, garbage collection frequency and garbage collection times. A small heap will become full quickly and must be garbage collected more often. It is also prone to more fragmentation, making object allocation slower. A large heap introduces a slight overhead in garbage collection times. A heap that is larger than the available physical memory in the system must be paged out to disk, which leads to long access times or even application freezes, especially during garbage collection.

Answer 2

You are using the concurrent garbage collector (-XX:+UseConcMarkSweepGC ), which runs in a separate thread. From the Times output you posted, it looks like the garbage collector itself did not run long. I would guess that your system did not have enough CPU time left for the GC to run, so it took 20 s for the GC to get the 1 s of CPU time it needed. When using the concurrent GC you should make sure that your application does not eat up all of the CPU time.

Otherwise another thing can happen: If the concurrent collector is not able to free enough memory and reaches a certain barrier it will do a Full GC which will block all other threads and consume a lot of time. This Full GC has a slightly different output though (says Full GC instead of GC), so I guess this is not your problem here.