Why do I have this long GC pause?

Just recently I ran into a question; why did this collection take 9 seconds to complete. It's a question that comes up reasonably often and how to answer it is a topic that I give considerable attention to in my performance tuning workshop. Fortunately the question was accompanied with a garbage collection log fragment and so I though it would be fun to work through the analysis here.

Here are some details before we take a look at the gc log. The application is running in a 6.0 32 bit VM. Max heap configured to 1536mb which is about as big as your going to get in a 32 bit JVM. The Concurrent Mark Sweep collector was explicitly set. MaxPermSize was set to a healthy 256m. Now, lets look at the log record to see what it is telling us.

70314.666: [GC {Heap before gc invocations=1105:
par new generation   total 72512K, used 72448K [0x85800000, 0x89ee0000, 0x8b800000)
 eden space 72448K, 100% used [0x85800000, 0x89ec0000, 0x89ec0000)
 from space 64K,   0% used [0x89ec0000, 0x89ec0000, 0x89ed0000)
 to   space 64K,   0% used [0x89ed0000, 0x89ed0000, 0x89ee0000)
concurrent mark-sweep generation total 1085184K, used 740804K [0x8b800000, 0xcdbc0000, 0xe5800000)
concurrent-mark-sweep perm gen total 262144K, used 138639K [0xe5800000, 0xf5800000, 0xf5800000)
70314.668: [ParNew: 72448K->0K(72512K), 0.0537868 secs] 813252K->756978K(1174720K)Heap after gc invocations=1106:

Read more: Java Performance Services

Posted via email from Jasper-net