CrystalCracker wrote:
> I am just trying to learn and understand the GC logs. (I did read the sun's
> docs on GC tuning).
> 
> jdk1.6.0_07
> -Xms2g -Xmx2g -Xss256k 
> -XX:+UseLargePages -XX:+PrintGCDetails 
> -verbose:gc -Xloggc:/var/log/gc.log 
> -XX:PermSize=512m -XX:MaxPermSize=512m
> 
> It is running Parallel Collector by default. The full GC usually runs in
> every 20-30 minutes (takes 2 seconds), and the minor collections occur every
> 40-50 seconds. I viewed the logs in GC Viewer, and the throughput is about
> 99.6%, but the pauses tend to get noticable at times slowing the app down
> for upto 10 minutes- and sometimes the app becomes unresponsive after
> running for about a week due to GC. 
> 
> I have pasted the snipped from my GC logs (when the pause became
> noticeable). Does the logs in themselves indicates any possible problems?

Taking the final three full GCs from the end of your logs

> 324198.631: [Full GC [PSYoungGen: 137400K->0K(370880K)] [PSOldGen:
> 1376534K->845248K(1398784K)] 1513934K->845248K(1769664K) [PSPermGen:
> 182317K->178611K(524288K)], 
> 3.1647390 secs] [Times: user=3.10 sys=0.07, real=3.17 secs] 

OldGen falling from 1.35Gb to 0.85Gb suggests you might have too big a
heap. If the app needs 0.8Gb then headroom of 0.5Gb is a little on the
large side but it will depend on how much garbage your app generates and
how quickly.

> 324442.431: [Full GC [PSYoungGen: 35083K->0K(466944K)] [PSOldGen:
> 1384225K->1330342K(1398784K)] 1419308K->1330342K(1865728K) [PSPermGen:
> 178817K->178817K(524288K)],
> 3.6474370 secs] [Times: user=3.63 sys=0.01, real=3.65 secs] 

Another Full GC 44 seconds later is a little more worrying. I'd want to
know how the app managed to use 0.5Gb so quickly. Equally of interest is
why only 0.05Gb could be cleared. That suggests to me that something
quick large (around 0.5Gb) might be sitting in memory.

> 324457.743: [Full GC [PSYoungGen: 233472K->0K(466944K)] [PSOldGen:
> 1330342K->795610K(1398784K)] 1563814K->795610K(1865728K) [PSPermGen:
> 178862K->178862K(524288K)], 
> 2.3725420 secs] [Times: user=2.36 sys=0.01, real=2.37 secs] 

A conclusion which seems to be confirmed by this only 15s later when
0.5Gb can now be freed.

My question would be:
- what was hanging on to the 0.5Gb of memory in the 15 second period
above between the 2nd and 3rd GC.

Time to get yourself a profiler.

Mark


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org

Reply via email to