G1GC: many consecutive full gcs (was Re: hotspot-gc-use Digest, Vol 40, Issue 4)

Fri Jun 17 00:00:37 PDT 2011

Hi Ramki,

thanks for your interest. See my answers below.

Cheers,

Stefan

On 06/17/2011 12:20 AM, Y. S. Ramakrishna wrote:
> Stefan and Alex --
>
> (1) what's the version of the JVM used?

Java(TM) SE Runtime Environment (build 1.6.0_24-b07)
Java HotSpot(TM) 64-Bit Server VM (build 19.1-b02, mixed mode)

>
> (2) could you try PermSize == MaxPermSize and see if it made any
>     difference?

PermSize was not set until now. I try this setting and can report 
results the next time our cluster nodes are switched.

>
> (3) do you have lots of WeakReference or Finalizer objects in your 
> system?

I have no information about this. I guess a heap dump would provide that 
information. I will ask our admins if it is possible to take a heap dump.

>
> (4) is what you have below your complete GC log (i.e. no gaps between 
> first and last line?)

Yes, that is the original output of the GC. No lines were removed.
>
> (5) what do you see when using CMS (in case you tried it)?

CMS seems to behave better (see attached gc.log). The settings used with 
CMS are:

-Xmx10000M
-Xms1024M
-XX:MaxPermSize=1024m
-XX:+PrintGCDateStamps
-XX:+UseConcMarkSweepGC

>
> (6) do you have a simple test case that you can share with
>     us that exhibits this behaviour?

Unfortunately I have no simple test case. The output is from our life 
system running a tomcat with various wars deployed.

>
> thanks!
> -- ramki
>
> On 06/16/11 14:02, Alex Aisinzon wrote:
>> Stefan
>>
>> I have had similar experience with G1 and reported it here.
>> I tried the option to try to limit GC pauses (-XX:MaxGCPauseMillis with
>> 1s and then 2s). It did not improve things.
>> I am happy to try anything else to help improve G1.
>>
>> Alex A
>>
>> -----Original Message-----
>> From: hotspot-gc-use-bounces at openjdk.java.net
>> [mailto:hotspot-gc-use-bounces at openjdk.java.net] On Behalf Of
>> hotspot-gc-use-request at openjdk.java.net
>> Sent: Thursday, June 16, 2011 12:00 PM
>> To: hotspot-gc-use at openjdk.java.net
>> Subject: hotspot-gc-use Digest, Vol 40, Issue 4
>>
>> Send hotspot-gc-use mailing list submissions to
>>     hotspot-gc-use at openjdk.java.net
>>
>> To subscribe or unsubscribe via the World Wide Web, visit
>>     http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>> or, via email, send a message with subject or body 'help' to
>>     hotspot-gc-use-request at openjdk.java.net
>>
>> You can reach the person managing the list at
>>     hotspot-gc-use-owner at openjdk.java.net
>>
>> When replying, please edit your Subject line so it is more specific
>> than "Re: Contents of hotspot-gc-use digest..."
>>
>>
>> Today's Topics:
>>
>>    1. G1GC: many consecutive full gcs (Stefan Wachter)
>>
>>
>> ----------------------------------------------------------------------
>>
>> Message: 1
>> Date: Thu, 16 Jun 2011 09:23:05 +0200
>> From: Stefan Wachter <Stefan.Wachter at gmx.de>
>> Subject: G1GC: many consecutive full gcs
>> To: hotspot-gc-use at openjdk.java.net
>> Message-ID: <4DF9AF59.90708 at gmx.de>
>> Content-Type: text/plain; charset=ISO-8859-1; format=flowed
>>
>> Hi all,
>>
>> the G1GC runs nicely for some time but then it starts to have bursts 
>> of consecutive full gcs (see log below). Can anyone explain that 
>> behaviour?
>>
>> The JVM is stared with these options:
>>
>> -Xmx10000M
>> -Xms1024M
>> -XX:MaxPermSize=1024m
>> -XX:+UseG1GC
>> -XX:MaxGCPauseMillis=2000
>> -XX:GCPauseIntervalMillis=10000
>>
>> --Stefan
>>
>>
>> 31314.569: [GC pause (young) 3286M->3234M(8937M), 0.0485530 secs]
>> 31374.932: [GC pause (young) 3279M->3236M(8937M), 0.0486560 secs]
>> 31837.688: [GC pause (young) 4614M->3252M(8937M), 0.0739370 secs]
>> 33528.784: [GC pause (young) 5997M->3330M(8937M), 0.1543940 secs]
>> 35372.029: [GC pause (young) 6038M->3405M(8937M), 0.2364930 secs]
>> 36508.343: [Full GC 8525M->2903M(9678M), 8.9121160 secs]
>> 38204.291: [Full GC 8647M->2295M(10000M), 7.4105940 secs]
>> 39038.017: [Full GC 8790M->2092M(6975M), 6.7242110 secs]
>> 39047.736: [Full GC 8996M->2089M(9998M), 6.0741630 secs]
>> 39095.551: [Full GC 8936M->2090M(6969M), 5.5573390 secs]
>> 39104.326: [Full GC 9175M->2092M(9997M), 5.3413860 secs]
>> 39112.760: [Full GC 9392M->2094M(9978M), 5.4884150 secs]
>> 41965.304: [Full GC 9549M->2112M(7043M), 6.4774550 secs]
>> 43830.656: [GC pause (young) 4615M->2309M(7043M), 0.1727720 secs]
>> 46024.398: [GC pause (young) 4638M->2497M(7043M), 0.3039900 secs]
>> 46068.009: [Full GC 8832M->2237M(10000M), 6.6717340 secs]
>> 46077.691: [Full GC 9322M->2187M(9987M), 5.8603570 secs]
>> 46086.731: [Full GC 9487M->2189M(9996M), 5.8521360 secs]
>> 46124.713: [Full GC 8792M->2185M(9895M), 5.7782260 secs]
>> 46133.366: [Full GC 9297M->2188M(9999M), 5.7263360 secs]
>> 46142.238: [Full GC 9509M->2189M(9985M), 5.5704850 secs]
>> 47454.530: [Full GC 9676M->2295M(7653M), 7.3169840 secs]
>> 48163.422: [GC pause (young) 4937M->2431M(7653M), 0.2379570 secs]
>> 48887.388: [GC pause (young) 5007M->2497M(7653M), 0.1999790 secs]
>>
>>
>>
>> ------------------------------
>>
>> _______________________________________________
>> hotspot-gc-use mailing list
>> hotspot-gc-use at openjdk.java.net
>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>
>>
>> End of hotspot-gc-use Digest, Vol 40, Issue 4
>> *********************************************
>> _______________________________________________
>> hotspot-gc-use mailing list
>> hotspot-gc-use at openjdk.java.net
>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>

-------------- next part --------------
A non-text attachment was scrubbed...
Name: gc.log
Type: text/x-log
Size: 691269 bytes
Desc: not available
Url : http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20110617/0a01cec9/attachment-0001.bin 