<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 3.2//EN">
<HTML>
<HEAD>
<META HTTP-EQUIV="Content-Type" CONTENT="text/html; charset=us-ascii">
<META NAME="Generator" CONTENT="MS Exchange Server version 6.5.7653.21">
<TITLE>CMS GC tuning under JVM 5.0</TITLE>
</HEAD>
<BODY>
<!-- Converted from text/rtf format -->
<BR>
<P><FONT SIZE=2 FACE="Verdana">Hi,</FONT>
</P>
<P><FONT SIZE=2 FACE="Verdana">We have considerable experience with JVM tuning of our SunOne appservers, utilizing CMS GC and adjusting NewSize/heapsize values etc under JVM version 1.4.2 to get some very low GC pause times.</FONT></P>
<P><FONT SIZE=2 FACE="Verdana">We are currently moving to manage an application running under JVM 5.0. This is still in Test, but our initial GC monitoring is raising some questions.</FONT></P>
<P><FONT SIZE=2 FACE="Verdana">The application has some normal activity but hourly it needs to do some significant background processing. This drives memory use much higher than normal. So what we see is ParNew's going from approximately one every 5 minutes to just a second or two apart. That is of course no problem in itself. But what we are also see is an occasional concurrent-mode failure, followed by a relatively long single-thread STW collection. While we haven't exactly done the correlation we're assuming that the hourly burst in activity has coincided with the tenured area being close to full (so the CMS GC has not been able to complete before free space available has become less than NewSize). The two examples below are exactly 19 hours apart.</FONT></P>
<P><FONT SIZE=2 FACE="Verdana">Example 1:</FONT>
</P>
<P><FONT SIZE=2 FACE="Verdana">31123.434: [GC 31123.434: [ParNew: 24448K->0K(24512K), 0.0294222 secs] 292487K->269028K(327616K), 0.0296926 secs]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">31468.449: [GC 31468.449: [ParNew: 24448K->0K(24512K), 0.0228006 secs] 293476K->269851K(327616K), 0.0230994 secs]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">31678.918: [GC 31678.919: [ParNew: 24447K->0K(24512K), 0.0950828 secs] 294299K->278163K(327616K), 0.0954078 secs]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">31679.235: [GC 31679.235: [ParNew: 24391K->0K(24512K), 0.2853518 secs] 302554K->298349K(327616K), 0.2856694 secs]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">31679.536: [GC [1 CMS-initial-mark: 298349K(303104K)] 298442K(327616K), 0.0033056 secs]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">31679.540: [CMS-concurrent-mark-start]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">31680.017: [CMS-concurrent-mark: 0.477/0.477 secs]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">31680.017: [CMS-concurrent-preclean-start]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">31680.023: [CMS-concurrent-preclean: 0.006/0.006 secs]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">31680.023: [CMS-concurrent-abortable-preclean-start]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">31768.429: [GC 31768.429: [ParNew: 24448K->24448K(24512K), 0.0000510 secs]31768.430: [CMS31768.430: [CMS-concurrent-abortable-preclean: 5.410/88.406 secs]</FONT></P>
<P><FONT SIZE=2 FACE="Verdana"> (concurrent mode failure): 298349K->35861K(303104K), 0.9340408 secs] 322797K->35861K(327616K), 0.9345904 secs]</FONT>
</P>
<BR>
<P><FONT SIZE=2 FACE="Verdana">Example 2:</FONT>
</P>
<P><FONT SIZE=2 FACE="Verdana">100064.686: [GC 100064.686: [ParNew: 24448K->0K(24512K), 0.0155892 secs] 293020K->268870K(327616K), 0.0160228 secs]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">100079.843: [GC 100079.843: [ParNew: 24382K->0K(24512K), 0.0390096 secs] 293253K->291786K(327616K), 0.0393622 secs]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">100079.883: [GC [1 CMS-initial-mark: 291786K(303104K)] 291881K(327616K), 0.0028736 secs]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">100079.887: [CMS-concurrent-mark-start]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">100080.381: [CMS-concurrent-mark: 0.494/0.494 secs]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">100080.381: [CMS-concurrent-preclean-start]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">100080.390: [CMS-concurrent-preclean: 0.009/0.009 secs]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">100080.390: [CMS-concurrent-abortable-preclean-start]</FONT>
<BR><FONT SIZE=2 FACE="Verdana">100259.694: [GC 100259.694: [ParNew: 24448K->24448K(24512K), 0.0000456 secs]100259.694: [CMS100259.695: [CMS-concurrent-abortable-preclean: 10.649/179.305 sec</FONT></P>
<P><FONT SIZE=2 FACE="Verdana">s]</FONT>
<BR><FONT SIZE=2 FACE="Verdana"> (concurrent mode failure): 291786K->43120K(303104K), 1.0073652 secs] 316234K->43120K(327616K), 1.0078356 secs]</FONT>
</P>
<P><FONT SIZE=2 FACE="Verdana">This is not a problem to us in Test, but if we extrapolate to Production with a proposed heap size of 1.5GB, this may become more of an issue.</FONT></P>
<P><FONT SIZE=2 FACE="Verdana">Under JVM 1.4.2 we can circumvent the default Collector behaviour by adding the flag "-XX:+UseCMSInitiatingOccupancyOnly=true" to ensure CMS GC's occur at approximately the CMSInitiatingOccupancyFraction percent full. But this flag does not appear to be available under JVM 5.0.</FONT></P>
<P><FONT SIZE=2 FACE="Verdana">So we have two questions:</FONT>
</P>
<P><FONT SIZE=2 FACE="Verdana">1) Is there an equivalent option for JVM 5.0 which will force CMS Collections to occur with a reasonably large amount of free space left in tenured (ie relative to NewSize), and</FONT></P>
<P><FONT SIZE=2 FACE="Verdana"> </FONT>
<BR><FONT SIZE=2 FACE="Verdana">2) Could you interpret the pair of times on the CMS-concurrent-abortable-preclean step, in particular the large time (88 and 179secs in the above examples).</FONT></P>
<BR>
<P><FONT SIZE=2 FACE="Verdana">Thanks,</FONT>
<BR><FONT SIZE=2 FACE="Verdana">Doug.</FONT>
<BR><FONT SIZE=2 FACE="Verdana"> </FONT>
</P>
<P><FONT SIZE=2 FACE="Verdana"> </FONT>
</P>
</BODY>
</HTML>