Different Full GCs?

Hi Guava higuava at gmail.com
Thu Oct 14 13:14:02 PDT 2010


Thanks for your response. It helped a lot.
I think you are right about the mislabeled scavenges since I don't see
them under 6uXX. I also noticed additional (System) label in the full
gc messages in 6uXX.
You asked about Eden or Young Gen size. I can only try to answer by
the logs. The logs are from our customer's production. I think the
Young Gen size is 42496K because of "[ParNew: 750K->0K(42496K)" in the
log. I think the Eden size is 42496K / 8 * 6  = 31872K since
-XX:SurvivorRatio is not set and its default is 6.
Our application usually uses heap size between 8G to 64G. It creates
large number of short lived objects in bursts. Should we use a large
Young generation size because of this? Do you have any recommendation
for Young/Tenured ratio and Eden/Survivor ratio?

Thanks.

On Thu, Oct 14, 2010 at 2:20 PM, Y. S. Ramakrishna
<y.s.ramakrishna at oracle.com> wrote:
>
> Hello --
>
> On 10/14/10 10:42, Hi Guava wrote:
>>
>> I've seen different full GC messages and I don't quite understand them:
>> 13011:1474.283: [Full GC 1474.283: [CMS:
>> 3333048K->1021496K(12540352K), 6.3444520 secs]
>> 3363388K->1021496K(12582848K), [CMS Perm : 30528K->30483K(30656K)],
>> 6.3447880 secs]
>
> This is a full gc; it collects the whole heap.
>
>> 34822:4101.808: [Full GC 4101.808: [ParNew: 667K->0K(42496K),
>> 0.0210030 secs] 5953849K->5953209K(12582848K), 0.0211110 secs]
>> 51586:25535.616: [Full GC 25535.616: [ParNew: 750K->0K(42496K),
>> 0.0324350 secs] 5341677K->5340939K(12582848K), 0.0326130 secs]
>
> These two are not full gc's. They are mislabelled. They are likely
> scavenge's forced by the allocation policy interacting with
> JNI critical sections preventing a scavenge attempt made previously.
> I think the labelling has been fixed in 6uXX.
>
>> 63486:26306.646: [Full GC 26306.646: [CMS[Unloading class
>> sun.reflect.GeneratedConstructorAccessor20]
>
> Yes this is also a full gc.
>
> In 6uXX, the first and the last would be labelled with an additional
> "System.gc()"  label, and the two middle ones would not say "Full".
> I don't have a bug id handy to point you to, but i might be able to
> dig one up after some archeology.
>
>>
>> Both GC #1 and #4 are triggered by System.gc() in our code. I believe
>> they are the same type. There was less memory available during #4 so
>> it unloaded classes (soft reference?).
>> But full gc is the stop-the-world gc. Why does it mention CMS in the
>> message?
>
> You are right that the "CMS" is misleading in that sense.
> The idea was that it collects the old generation which is typically
> collected by CMS. I agree that the CMS label is misleading and probably
> should be fixed; it's a consequence of our internal naming scheme for
> generation "types".
>
>> GC #2 and #3 look weird to me. They were not triggered by System.gc().
>> They are always very short and the duration is about the same as young
>> generation GCs. In fact, the message is exact like young generation
>> GCs except the extra word "Full". What are these short full gcs? Are
>> there different level of full GCs?
>
> No, and you are right that these are just scavenges. What must have happened
> is that your application probably does a few short-lived JNI critical
> sections (JNI_Get{Array,String}Critical) which happens around the time
> when another thread wants to do a large allocation which will not fit in
> the current space available in Eden, so the allocator attempts to do a
> scavenge, but is prevented from doing so because of the JNI critical
> section.
> This is remembered and when the critical section is exited, a scavenge
> is forced. At least that's my guess based on the messages above.
> (BTW, what's the size of your Eden or Young Gen? The policy should
> probably be a little smarter and not do those scavenges until an
> allocation request (would) fail.)
>
>> I spent some time searching for answer but I am still confused. Can
>> somebody help explain and suggest some reading materials?
>
> Hope that helps a bit. Try JDK 7 or 6u21 (or whatever is the latest) and
> see if the confusing messages are gone. If they are still there,
> let us know.
>
> thanks.
> -- ramki
>
>>
>> Thanks!
>>
>> The environment:
>> Java HotSpot(TM) 64-Bit Server VM Version 1.5.0_19-b02
>> Linux Version 2.6.9-89.0.20.ELsmp
>> amd64
>>
>> -Xms12g
>> -Xmx12g
>> -XX:+PrintGC
>> -XX:+PrintGCDetails
>> -XX:+PrintGCTimeStamps
>> -XX:+UseConcMarkSweepGC
>> _______________________________________________
>> hotspot-gc-use mailing list
>> hotspot-gc-use at openjdk.java.net
>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>


More information about the hotspot-gc-use mailing list