CMS GC tuning under JVM 5.0

Sat Apr 19 22:46:12 UTC 2008

Hi Ramki, and Jon,

Thank you for the background information - indeed the bug would appear to explain exactly what we are seeing in terms of long times for the concurrent-abortable-preclean phase. The application is using 5u08 so it would be present.

So just to summarize for anybody else's general information if they happen to come across an application which has similar characteristics (ie has normal steady-state processing, but also has periodic spurts of very much greater activity, which the Collector is not easily able to adapt or respond to), under a JDK 5.0 version prior to u16, what we will try is:

1) Set CMSInitiatingOccupancyFraction to a value so that the tenured area contains at least twice NewSize when it reaches this percent full, AND set +UseCMSInitiatingOccupancyOnly so that the Collector honours this value (ie disabling its default 'JIT plus a bit to be safe' behaviour)

2) Specifically set CMSMaxAbortablePrecleanTime=5 so the concurrent-abortable-preclean phase max time is correctly interpreted under this version as 5 seconds (the 6.0 default value), and

3) As suggested in the second bug mentioned by Ramki, we may also set +CMSScavengeBeforeRemak. This flag is I believe not on by default in any current JDK version, but in our case with a relatively small NewSize, a ParNew collection takes max something like 0.02sec (and that's when at its full 24Mb) so should add virtually nothing to the time the app is stopped.

Actually from looking at other CMS Collections in the same log, just 1) and 3) on their own may fix the problem because we see several examples where the CMS GC has kicked in with eden containing less than 1Mb and the abortable-preclean phase is omitted altogether. However this is specific to the characteristics of our application. I have no doubt that there are other situations where setting CMSScavengeBeforeRemak is not desirable.

Again thanks everyone for your assistance,

Doug.

________________________________

From: hotspot-gc-use-bounces at openjdk.java.net on behalf of Y Srinivas Ramakrishna
Sent: Sat 19/04/2008 2:24 p.m.
To: Y Srinivas Ramakrishna
Cc: Jones, Doug H; hotspot-gc-use at openjdk.java.net; Thomas Viessmann
Subject: Re: CMS GC tuning under JVM 5.0

Here you go:-

http://bugs.sun.com/view_bug.do?bug_id=6538910

It shows up as fixed in 5u16b01 according to the bug report.
Also documented is the workaround.

If you have issues with long remark pauses when you use the
workaround, refer to CR http://bugs.sun.com/view_bug.do?bug_id=6572569

-- ramki

----- Original Message -----
From: Y Srinivas Ramakrishna <Y.S.Ramakrishna at Sun.COM>
Date: Friday, April 18, 2008 7:15 pm
Subject: Re: CMS GC tuning under JVM 5.0
To: Thomas Viessmann <Thomas.Viessmann at Sun.COM>
Cc: "Jones, Doug H" <doug.jones at EDS.COM>, hotspot-gc-use at openjdk.java.net

> > > 31680.017: [CMS-concurrent-mark: 0.477/0.477 secs]
>
> > > 31680.023: [CMS-concurrent-preclean: 0.006/0.006 secs]
>
> > > secs]31768.430: [CMS31768.430: [CMS-concurrent-abortable-preclean:
>
> > > 5.410/88.406 secs]
>
> > > 100080.381: [CMS-concurrent-mark: 0.494/0.494 secs]
>
> > > 100080.390: [CMS-concurrent-preclean: 0.009/0.009 secs]
>
> > > secs]100259.694: [CMS100259.695:
> [CMS-concurrent-abortable-preclean:
> >
> > > 10.649/179.305 sec
> > >
> > > s]
>
> Just to add a bit to what Jon said, the notation [CMS-concurrent-xxx: 
> yyy/zzz secs]
> indicates that the CMS concurrent xxx-phase took roughly zzz secs of wall-clock
> elapsed time, of which yyy secs of accumulated elapsed time was spent
> by the
> CMS thread doing that work; the remainder of the time, zzz - yyy secs,
> the
> thread was either sleeping or was stalled for a lock. Note that yyy
> secs is
> a rough upper bound of the lwp-virtual time, but the thread need not necessarily
> have been on-proc all of that time.
>
> So in particular, in the last display, of the 179 secs of elapsed time
> the CMS thread
> was actually sleeping for 169 secs. Jon's conjecture of the bug about
> CMSMaxAbortablePrecleanTime
> seems to be the most likely explanation. (There was a confusion with
> the interpretation
> of the units, treating an intended ms spec as a seconds spec, the documented
> workaround is to set the value to a value in seconds not exceeding
> about 5:
> -XX:CMSMaxAbortablePrecleanTime=5 -- or to zero to just elide that phase.)
>
> I believe this has been fixed in some later version of JDK 5uXX, but
> am unable to
> check the bug id at the moment.
>
> -- ramki
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use at openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/hotspot-gc-dev/attachments/20080420/8f247e0c/attachment.htm>
-------------- next part --------------
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use