CMS collection keep working during holiday

Wed Oct 8 08:00:32 UTC 2008

Thanks to your quick response.

I will firstly produce the result with +XX:+PrictReferece and then alter the
vm options to your set for further testing.

> [Perhaps you can check if your application makes use of
> Soft/Weak/References
> in some funny way, so as to perhaps cause the Reference and referent to be
> split between the old and new generations?]

I didn't specially play soft / weak references. Even I don't exactly know
what is weak reference. Your comment alert me that I have called
javolution's api (javolution.text.Text and
javolution.text.TypeFormat.parseFloat).

In the past, we parse the incoming data feed by calling a lot of
Float.parseFloat(String). Last year I found that parseFloat create many temp
objects resulting many garbages to be collected. After google I found
javolution api. It really have better performance.

Javolution's Text Object create instance by ObjectFactory which allocate in
stack context.
http://javolution.org/api/javolution/context/StackContext.html. I am not
sure it's cased by javoltion api.

Anyway or method to shoot it? Is adding -XX:+PrintReference help?

y.s.ramakrishna wrote:
> 
> Hi Ken --
> 
> You do see of course that in the gc.zip that you made available,
> there were 4 promotion failures, followed by compacting collections,
> as listed below in chronological order:-
> 
> 163116.821: [GC 163116.821: [ParNew: 873856K->174720K(873856K), 0.4830286
> secs] 1508484K->961405K(4019584K), 0.4831137 secs] [Times: user=1.59
> sys=0.01, real=0.
> 49 secs]
> ...
> 165310.759: [GC 165310.759: [ParNew (promotion failed):
> 873856K->873856K(873856K), 0.8919148 secs]165311.651:[CMS:
> 1911965K->785641K(3145728K), 2.9784355 secs] 2733287K->785641K(4019584K),
> 3.8704903 secs] [Times: user=4.80 sys=0.16, real=3.88 secs]
> ...
> 231411.554: [GC 231411.554: [ParNew: 873856K->174720K(873856K), 0.5915618
> secs] 1676990K->1122182K(4019584K), 0.5916525 secs] [Times: user=1.45
> sys=0.00, real=0
> .59 secs]
> ...
> 233946.300: [GC 233946.300: [ParNew (promotion failed):
> 873856K->873856K(873856K), 0.9428034 secs]233947.243: [CMS:
> 2172134K->570964K(3145728K), 2.7655578 secs] 2969591K->570964K(4019584K),
> 3.7084973 secs] [Times: user=5.17 sys=0.09, real=3.70 secs]
> ...
> 247864.029: [GC 247864.029: [ParNew (promotion failed):
> 873856K->873855K(873856K), 0.8641325 secs]247864.893: [CMS:
> 1845477K->499108K(3145728K), 2.2010342 secs] 2628538K->499108K(4019584K),
> 3.0652834 secs] [Times: user=4.30 sys=0.06, real=3.06 secs]
> ...
> 248187.856: [GC 248187.856: [ParNew: 699136K->174719K(873856K), 0.3926926
> secs] 1050016K->610565K(4019584K), 0.3927797 secs] [Times: user=1.45
> sys=0.03, real=0.
> 39 secs]
> ...
> 265611.034: [GC 265611.034: [ParNew (promotion failed):
> 873856K->873856K(873856K), 0.6459451 secs]265611.680: [CMS:
> 1854348K->502128K(3145728K), 2.2556597 secs] 2714667K->502128K(4019584K),
> 2.9017069 secs] [Times: user=4.19 sys=0.08, real=2.89 secs]
> ...
> 502712.808: [GC 502712.808: [ParNew: 873856K->174720K(873856K), 1.2972687
> secs] 3806995K->3167193K(4019584K), 1.2973536 secs] [Times: user=1.75
> sys=0.00, real=1
> .30 secs]
> ...
> 504379.249: [GC 504379.249: [ParNew: 873856K->873856K(873856K), 0.0000241
> secs]504379.249: [CMS504379.358: [CMS-concurrent-abortable-preclean:
> 0.209/2.471 secs] [Times: user=1.28 sys=0.00, real=2.48 secs] (concurrent
> mode failure): 2938816K->424257K(3145728K), 5.2334306 secs]
> 3812672K->424257K(4019584K), 5.2335621 secs] [Times:
>  user=5.11 sys=0.02, real=5.23 secs]
> 
> In other words, CMS often does not manage to clear the allocated
> memory. But the CMS collection preceding the promotion failure
> indicates heap usage only a little more than what you see after
> the mark-compact collection. There is almost certainly something
> fishy going on here. It may be related to Reference objects and their
> referents being split across generations, but it's not completely clear.
> 
> [Perhaps you can check if your application makes use of
> Soft/Weak/References
> in some funny way, so as to perhaps cause the Reference and referent to be
> split between the old and new generations?]
> 
> Now one thing we know about the difference between CMS and a full
> mark-compact
> collection is that CMS treats the young gen as a source of roots for the
> CMS and perm gen collection, whereas this is not so for the latter.
> In pathological cases, a dead cycle spanning the young gen and the
> old gen would remain uncollected by CMS but be collected by the
> mark-compact
> collection. Now, I don't think that would be happening in your case, but I
> do see that the frequency of ParNew collections in your case is fairly low
> --
> about 1 every 6 minutes or so. With a tenuring threshold of 11, it's
> possible
> for a dead cycle to live for a full hour before it gets promoted into the
> old generation whence it would be eligible for collection.
> 
> In some cases, the CMS initiating occupancy fraction has not been hit
> (and a CMS collection not even attempte) before a promotion failure
> occurs. This would appear to call for more frequent CMS collections
> following ParNew collections, even something drastic like:-
> 
>     CMSInitiatingOccupancyFraction=25
> 
> This would of course cause your back to back CMS collections that
> would peg your CPU, in order to avoid that, you might disable the
> CMS "timeout" via:-
> 
>      CMSWaitDuration=1200000
> 
> i.e. make it 20 minutes (=120000 ms).
> 
> In addition, I find that your scavenges are unnecessarily copying
> survivors back-and-forth 11 times or so, I'd just scrunch that down
> to:-
> 
>       MaxTenuringThreshold=1 (or at most 2)
> 
> This may or may not address the problem you are seeing here but
> it's at least a start towards eliminating at least some of
> the suspects and of course of eliminating the "busy work"
> that CMS is doing during the holidays.
> 
> -- ramki
> 
> ----- Original Message -----
> From: "Ken-- at newsgroupstats.hk" <dragonken at gmail.com>
> Date: Tuesday, October 7, 2008 11:14 pm
> Subject: Re: CMS collection keep working during holiday
> To: hotspot-gc-dev at openjdk.java.net
> 
> 
>> Thanks to your quick response. I will do it now but it require 1 - 2 
>> days to
>> reproduce the result.
>> 
>> It seems that my case is very special.
>> 
>> What the application is simply a stock quote client server and store
>> daily
>> stock quote and chart data in memory. The lived objects need around 80M
>> memory at day open and 500M memory at day end.
>> 
>> 
>> 
>> 
>> y.s.ramakrishna wrote:
>> > 
>> > 
>> > Could you run with the additional option +PrintReferenceGC and see if
>> > it sheds additional light on the problem? (Please share the resulting
>> > GC logs.)
>> > 
>> > If at all possible, you might try rev'ing down to 6.0 and seeing
>> > if the same behaviour reproduces or not?
>> > 
>> > I understand that some or all of this may not be possible in a
>> > production setting.
>> > 
>> > -- ramki
>> > 
>> > ----- Original Message -----
>> > From: "Ken-- at newsgroupstats.hk" <dragonken at gmail.com>
>> > Date: Tuesday, October 7, 2008 10:17 pm
>> > Subject: Re: CMS collection keep working during holiday
>> > To: hotspot-gc-dev at openjdk.java.net
>> > 
>> > 
>> >> Follow up to the jconsole above. This gif is captured today. You 
>> can 
>> >> see the
>> >> first CMS after a FULL GC is working. The 2nd one is working too 
>> but the
>> >> memory free from 2nd generation is much less than the first CMS. The
>> >> memory
>> >> free by 3rd CMS is further decreased.
>> >> 
>> >> The 5th CMS cannot free enough memory to make occanpcy in old-gen 
>> to less
>> >> than 70%. So, continue non-stopping CMS happen again until a Full GC
>> >> (triggered by Concurrent Mode Failure).
>> >> 
>> >> http://www.nabble.com/file/p19872463/jconsole_20081008.jpg 
>> >> 
>> >> 
>> >> 
>> >> 
>> >> 
>> >> 
>> >> -- 
>> >> View this message in context:
>> >>
>> http://www.nabble.com/CMS-collection-keep-working-during-holiday-tp19773575p19872463.html
>> >> Sent from the OpenJDK Hotspot Garbage Collection mailing list 
>> archive 
>> >> at Nabble.com.
>> >> 
>> > 
>> > 
>> 
>> -- 
>> View this message in context:
>> http://www.nabble.com/CMS-collection-keep-working-during-holiday-tp19773575p19872900.html
>> Sent from the OpenJDK Hotspot Garbage Collection mailing list archive 
>> at Nabble.com.
>> 
> 
> 

-- 
View this message in context: http://www.nabble.com/CMS-collection-keep-working-during-holiday-tp19773575p19874157.html
Sent from the OpenJDK Hotspot Garbage Collection mailing list archive at Nabble.com.