Back to back Full Garbage collections when conditions for Full GC do not seem met

Tue Feb 12 21:16:44 PST 2008

Alex,

Much of this information is in

http://java.sun.com/docs/hotspot/gc1.4.2/

In your logs

"def new generation"  implies the serial collector of the young generation

"tenured generation" implies  the serial collector of the tenured generation

"PSYoungGen" implies the parallel young generation collector for
UseParallelGC

"PSOldGen" implies the serial collector for the tenured generation
(basically the
same as "tenured generation"

UseParallelOldGC is not implemented in 1.4.2 so you won't see it.

Comments below.

Alex Aisinzon wrote On 02/12/08 16:15,:

>Jon
>
>The theory that the customer was using the client mode seems not to be
>true.
>We realize that some nodes were using client and some other were using
>server but that the excessive Full GC seems to happen also on the JVMs
>using the server mode.
>  
>
It would be useful to know if the excessive full GC's are occuring with the
UseParallelGC collector ("PSYoungGen" and "PSOldGen" in the logs). 

I also think (as you have suggested) that the size
 of the young gen (500m) is too large for the
size of the tenured generation and the amount of live data
in the tenured generation (the amount of free space is
approaching the size of the young gen).  Do try a smaller
young gen or larger  overall heap.

It looks like only full collections are being attempted.  I don't
recall anything that would cause this type of behavior.
If you have a Sun support contract,  request some help on this.
The support organization is more familar with the current
behavior of  the earlier releases (i.e., what bugs have been fixed
and what enhancements have been made) and might be able to
help.

>The point about the usage of different GC policies is interesting
>though:
>Could you share with me the GC log pattern to GC policy mapping?
>In other words, as you indicate in your blog
>(http://blogs.sun.com/jonthecollector/), there are 3 young generation
>collectors and 3 tenured generation ones.
>When I look at some GC logs, how can I deduce which you and tenured
>generation collectors are used?
>
>Thanks again for the tremendous help provided here.
>
>Regards
>
>Alex A
>
>-----Original Message-----
>From: Jon.Masamitsu at Sun.COM [mailto:Jon.Masamitsu at Sun.COM] 
>Sent: Tuesday, February 12, 2008 2:04 PM
>To: Alex Aisinzon
>Cc: hotspot-gc-use at openjdk.java.net
>Subject: Re: Back to back Full Garbage collections when conditions for
>Full GCdo not seem met
>
>
>
>Alex Aisinzon wrote:
>  
>
>>Jon
>>
>>What you said about the different collectors used may actually be the
>>most enlightening piece.
>>The JVM options corresponding to the ProblematicFullGC.zip logs do not
>>have "-server" as the first parameter. Therefore, we have reasons to
>>believe that, in that case, the JVM is running in client mode.
>>The JVM options corresponding to the OKGC.zip used the "-server"
>>    
>>
>option
>  
>
>>as the first parameter.
>>Is Serial GC the default for the client VM and Parallel GC the default
>>for the server VM?
>>  
>>    
>>
>
>The serial GC is definitely the default collector for the client VM.   
>I'm a little puzzle how
>the UseParallelGC collector is being in the OKGC log.  I don't think it 
>is used by default.
>It's an older release so something might have changed since I worked 
>with it but I thought
>that UseParallelGC would explicitly have to be turned on for it to run.
>
>Does the customer
>have AggressiveHeap turned on?  That would turn on UseParallelGC.
>
>
>  
>
>>In that light, we would ask our customer to use the -server option
>>properly aka as a first parameter.
>>Our application is actually certified on Server mode only.
>>
>>Thanks for letting us know.
>>
>>Regards
>>
>>Alex A
>>
>>
>>
>>-----Original Message-----
>>From: Alex Aisinzon 
>>Sent: Tuesday, February 12, 2008 1:26 PM
>>To: 'Jon.Masamitsu at Sun.COM'
>>Cc: hotspot-gc-use at openjdk.java.net
>>Subject: RE: Back to back Full Garbage collections when conditions for
>>Full GC do not seem met
>>
>>Jon
>>
>>Thanks for the amazingly quick answer. 
>>Would you want me to gather additional information? If so, please
>>provide me details on how to gather that additional information.
>>One theory that I am testing is that, in the customer settings, the
>>"-server" option was not in front.
>>I was told that, in that case, the JVM would not pick that option.
>>To check this further, I just restarted a perf run with the -server
>>    
>>
>not
>  
>
>>in front, like the customer.
>>
>>Regards
>>
>>Alex Aisinzon
>>
>>-----Original Message-----
>>From: Jon.Masamitsu at Sun.COM [mailto:Jon.Masamitsu at Sun.COM] 
>>Sent: Tuesday, February 12, 2008 1:22 PM
>>To: Alex Aisinzon
>>Cc: hotspot-gc-use at openjdk.java.net
>>Subject: Re: Back to back Full Garbage collections when conditions for
>>Full GC do not seem met
>>
>>Alex,
>>
>>The log in ProblematicFullGC.zip is from the serial GC collector which
>>is subject to the "young generation guarantee". The log from OKGC.zip
>>is from the parallel (UseParallelGC) collector and that collector is
>>not subject to the "young generation guarantee".
>>
>>I don't see yet why the collections are starting in
>>ProblematicFullGC.zip.
>>
>>Jon
>>
>>Alex Aisinzon wrote:
>>  
>>    
>>
>>>Hi all
>>>
>>>A customer of ours is experiencing instances whereby the Sun JDK 
>>>1.4.2_16 on Windows goes through many Full GCs for no good reason.
>>>
>>>The Sun JDK parameters used are: -Xms1280m -Xmx1280m -XX:NewSize=500m
>>>      
>>>
>
>  
>
>>>-XX:MaxNewSize=500m -XX:PermSize=150m -XX:MaxPermSize=150m -server 
>>>-XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC
>>>
>>>I have enclosed a snippet of the garbage collection logs with minor
>>>      
>>>
>GC
>  
>
>>>    
>>>      
>>>
>>  
>>    
>>
>>>before and after (ProblematicFullGC.zip).
>>>
>>>From timestamp 21928.044 to 21958.226 + 5 seconds aka 35 seconds, the
>>>      
>>>
>
>  
>
>>>JVM goes through 8 Full GCs with hardly any time in between.
>>>
>>>To the users, the JVM is frozen. The JVM needs to get restarted to
>>>      
>>>
>get
>  
>
>>>    
>>>      
>>>
>>  
>>    
>>
>>>back to a good state.
>>>
>>>The most surprising is that the new generation is almost empty (1 or
>>>      
>>>
>2
>  
>
>>>    
>>>      
>>>
>>  
>>    
>>
>>>MB max used out of 460MB) in all but the first Full GC and that there
>>>      
>>>
>
>  
>
>>>is a lot of free space in the tenured generation (more than 400MB).
>>>
>>>Our thinking is that the JVM may be triggering a Full GC because of 
>>>the "Young Generation Guarantee".
>>>
>>>If such is the case, the behaviour is not consistent across
>>>      
>>>
>platforms:
>  
>
>>>    
>>>      
>>>
>>  
>>    
>>
>>>we have run a similar load test in house with Sun JDK 1.4.2_16 on 
>>>Linux with the identical parameters ("-server -Xms1280m -Xmx1280m 
>>>-XX:NewSize=500m -XX:MaxNewSize=500m -XX:PermSize=150m 
>>>-XX:MaxPermSize=150m -XX:+PrintGCDetails -XX:+PrintHeapAtGC 
>>>-XX:+PrintGCTimeStamps -verbose:gc". In that case, the Full GCs occur
>>>      
>>>
>
>  
>
>>>very normally though the tenured space is much fuller (140-180MB free
>>>      
>>>
>
>  
>
>>>only). A snippet of the GC logs is enclosed at OKGC.zip. It shows 
>>>several Full GCs with a healthy dose of minor GC in between.
>>>
>>>So far, we have recommended to the customer that they use a smaller 
>>>New Generation, as this may make it less likely to get closer to the 
>>>"Young Generation Guarantee" threshold. Nevertheless, as the math is 
>>>not there for that "Young Generation Guarantee", we want to dig 
>>>further into this.
>>>
>>>Thanks in advance for any help.
>>>
>>>Alex Aisinzon
>>>
>>>
>>>    
>>>      
>>>
>------------------------------------------------------------------------
>  
>
>>  
>>    
>>
>>>_______________________________________________
>>>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
>>  
>>    
>>
>_______________________________________________
>hotspot-gc-use mailing list
>hotspot-gc-use at openjdk.java.net
>http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>  
>