CMS Full GC

Srinivas Ramakrishna ysr1729 at gmail.com
Tue Apr 24 22:09:32 PDT 2012 

Hi Shiv --

Which version of the JDK are you on? As I said there was a temporary
regression in this behaviour (i.e. expand without full gc) with CMS,
which was fixed up later. Unfortunately, can't recall the CR# or the
versions of that, although i can probably  dig that up from the mercurial
history if needed, i don't have the sources handy at the moment.

More importantly, by default CMS does not collect the perm gen in a
concurrent collection cycle, so you have to explicitly enable concurrent
perm gen
collection via -XX:+CMSClassUnloadingEnabled (and in older versions also
-XX:+CMSPermGenSweepingEnabled).

If you are stuck on a version of the JVM where the perm gen expansion
regression exists, you should explicitly set both
-XX:PermSize and -XX:MaxPermSize to the maximum size of perm gen. (And
definitely enable perm gen collection via
he flags listed in the last para.)

Hopefully that should get rid of these "unwanted" full collections.

-- ramki

On Tue, Apr 24, 2012 at 9:09 PM, Shivkumar Chelwa <schelwa at tibco.com> wrote:

> **
>
> Hi Ramki,****
>
> ** **
>
> I enabled “jstat –gccause” for the application instance and found
> following few GC causes in the logs.****
>
> ** **
>
>    1. Allocation Failure – not sure what that means****
>    2. Permanent Generation Full – I have few doubts here.****
>       1. The MaxPermSize is set to 256m but the gc log file displays a
>       different size 74240K. See the following line from gc log file.****
>
> 56876.963: [Full GC 56876.963: [CMS: 4181041K->3724534K(7898752K),
> 77.5881180 secs] 4211397K->3724534K(8339648K), [CMS Perm : *
> 73972K->73511K(74240K)],* 77.5901936 secs] [Times: user=77.47 sys=0.19,
> real=77.59 secs]****
>
>     1. Why should there be a “Full GC” for permanent generation
>       collection?****
>       2. The permanent generation utilization is consistently over 99%
>       and after “Full GC” it comes down to 60%, why it didn’t expand the
>       committed memory instead of doing a full gc?****
>       3. JConsole shows following stats for “CMS Perm Gen” sizes****
>
>  **                                                    i.     **Used:     74,329
> kbytes ****
>
> **                                                   ii.     **Committed:     74,432
> kbytes ****
>
> **                                                  iii.     **Max:    262,144
> kbytes ****
>
> ** **
>
> ** **
>
> These are the garbage collection setting I am using for application,****
>
> ** **
>
> -server -d64 -javaagent:instrumentation.jar -XX:MaxPermSize=256m
> -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+DisableExplicitGC
> -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly
> -verbose:gc -Xloggc:/logs/LB01.log -XX:+PrintGCTimeStamps
> -XX:+PrintGCDetails -Xmx8192M -Xms8192M -Xss256K****
>
> ** **
>
> ** **
>
> There are few lines from “jstat –gccause” output where it displays
> “Permanent Generation Full” as the gc cause. Also attaching the gc log file
> and “jstat –gccasue” output for reference.****
>
> ** **
>
>   S0     S1          E      O      P       YGC    YGCT  FGC    FGCT
> GCT    LGCC                 GCC                 ****
>
>   0.00  20.05   5.24  52.93  99.02   1625   63.648     1    0.000   63.648
>     No GC                Permanent Generation Full****
>
>   0.00  20.05   5.24  52.93  99.02   1625   63.648     1    0.000   63.648
>     No GC                Permanent Generation Full****
>
>   0.00   0.00   0.00  47.15  60.00   1625   63.648     1   77.588  141.236
>    Permanent Generation Full No GC               ****
>
>   0.00   0.00  41.19  47.15  60.02   1625   63.648     1   77.588
> 141.236   Permanent Generation Full No GC               ****
>
> ** **
>
> Thanks,****
>
> Shiv****
>
> ** **
>  ------------------------------
>
> *From:* Srinivas Ramakrishna [mailto:ysr1729 at gmail.com]
> *Sent:* 17 April 2012 15:07
> *To:* Shivkumar Chelwa
> *Cc:* **hotspot-gc-use at openjdk.java.net**
> *Subject:* Re: CMS Full GC****
>
> ** **
>
> Is it possible that you are GC'ing here to expand perm gen. Check if
> permgen footprint changed between the two JVM releases (when running yr
> application).
>
> Now, CMS should quietly expand perm gen without doing a stop-world GC, but
> there was a temporary regression in that functionality before it was fixed
> again.
> I can't however recall the JVM versions where the regression was
> introduced and then fixed. But all of this is handwaving on my part.
> If you run 6u22 and 6u29 both with -XX:+PrintHeapAtGC, you might have more
> visibility into why the GC is kicking in. A longer log would allow
> the community to perhaps provide suggestions as well.
>
> Which reminds me that there is a bug in the printing of GC cause (as
> printed by jstat) which needs to be fixed. HotSpot/GC folk, have you
> noticed that we never
> see a "perm gen allocation" as the GC cause even when that's really the
> reason for a full gc? (not that that should happen here where CMS is being
> used.)
>
> -- ramki****
>
>  On Tue, Apr 17, 2012 at 8:08 AM, Shivkumar Chelwa <schelwa at tibco.com>
> wrote:****
>
> Hi,****
>
>  ****
>
> Till date I was using JRE 6u22 with following garbage collection
> parameters and the CMS cycle use to kick-in appropriately (when heap
> reaches 75%)****
>
>  ****
>
>  ****
>
> -server -d64 -Xms2048m -Xmx2048m -javaagent: my-instrumentation.jar
> -XX:MaxPermSize=256m -XX:+UseParNewGC -XX:+UseConcMarkSweepGC
> -XX:+DisableExplicitGC -XX:CMSInitiatingOccupancyFraction=75
> -XX:+UseCMSInitiatingOccupancyOnly -verbose:gc -Xloggc:LB01.log
> -XX:+PrintGCTimeStamps -XX:+PrintGCDetails
> -Djava.library=/usr/java/jre/lib/sparcv9/server/libjvm.so -Xmx8192M
> -Xms8192M -Xss256K****
>
>  ****
>
> But I switched to JRE 6u29 and see the *CMS Full GC* happening randomly.
> Can you please help me undercover this mystery. Here is one of the log
> message from gc log file.****
>
>  ****
>
> 13475.239: [*Full GC* 13475.239: [CMS: 4321575K->3717474K(7898752K), *54.0602376
> secs*] 4412277K->3717474K(8339648K), [CMS Perm : 73791K->73339K(74048K)],
> 54.0615557 secs] [Times: user=53.97 sy****
>
> s=0.12, real=54.06 secs]****
>
>  ****
>
>  ****
>
> Kindly help.****
>
>  ****
>
>  ****
>
> Regards,****
>
> Shiv****
>
>  ****
>
>  ****
>
>  ****
>
>
> _______________________________________________
> 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: http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20120424/84e221ff/attachment-0001.html

More information about the hotspot-gc-use mailing list