-XX:+PrintClassHistogram Does a FullGC even with CMS enabled and -XX:+ExplicitGCInvokesConcurrent ?

[Matt Miller]

Hi Ramki!
Thanks for replying.
I would be ok with it, if PrintClassHistogram did an "explicit" Full GC. 
It should probably put (System) into the log file though, to show that 
this is an Explicit GC.
It should also be preventable with  -XX:+DisableExplicitGC turned on in 
that case.

To me, it seems like a bug if you have -XX:+DisableExplicitGC turned on, 
and +ExplicitGCInvokesConcurrent turned on, yet +PrintClassHistogram can 
still performs a Full STW GC.  There should be away to prevent any STW 
GC's from happening if you're specifying that you want CMS to do the 
work in the tenured space. There should also be a way (Explicit GC) to 
force a Full STW GC when using CMS (That piece seems to work fine ;) ).

It's also hard to identify what the cause of FullGC's are in the log 
file when jmap -histo:live can also produce a FullGC, as well as jmap 
-dump:live and a SIGQUIT with PrintHistogram turned on. As it stands 
right now, you just have to guess that something else is causing the JVM 
to do a STW GC because it's showing that it's supposed to be using the 
CMS collector, and the heap is not full (maybe you're unlucky though and 
you're doing a histogram while the heap is much closer to full?).

I've seen situations where customers have put a cronjob to collect jmap 
-histo output every X minutes.. and then "mysteriously" there are 
FullGCs in the CMS logs .. Which are very hard to identify where they 
are coming from , and then stop them from occurring ...

-Matt

On 4/2/14, 2:41 PM, Srinivas Ramakrishna wrote:
> Hi Matt --
>
> It's been a while since we talked; great to hear from you.
>
> As regards the behaviour of +PrintClassHistogram, I don't recall that 
> interpretation ever having been implemented,
> and definitely not in the CR that you reference below.
>
> +PrintClassHistogram will do an explicit stop-world full gc, even with 
> CMS, then produce a class histogram.
>
> What the description in the CR you pointed to below is saying is that, 
> PrintClassHistogramBefore/AfterFullGC
> will not produce a histogram at the end of a concurrent gc cycle.
>
> However, it will at the end of a stop-world full gc cycle.
>
> That having been said, I do not think it's a good idea to change the 
> interpretation of the SIGQUIT related
> +PrintClassHistogram depending on the GC in question. It looks like 
> what you want here is the ability to
> get a class histogram after a concurrent gc cycle when presented with 
> a SIGQUIT. (There's also the
> question of whether the same behaviour should also apply to jmap 
> -heap:live.)
>
> I think a change in behaviour along the lines of yr suggestion 
> requires discussion by users of concurrent gc's
> to see if that is desirable and secondly whether both kinds of 
> behaviours should be available (i.e. the current one,
> as well as an optional "concurrent" one).
>
> thanks!
> -- ramki
>
>
> On Wed, Apr 2, 2014 at 10:43 AM, Matt Miller 
> <matthew.miller at forgerock.com <mailto:matthew.miller at forgerock.com>> 
> wrote:
>
>     Hi All,
>
>     It seems to me that even with 7 (Tested both u45 and u51) the
>     title holds true.
>     I would expect with ConcMarkSweep enabled, and
>     ExplicitGCInvokesConcurrent that -XX:+PrintClassHistogram would
>     NOT do a FullGC, but instead start a CMS cycle.
>     I thought maybe this was addressed by
>     http://bugs.java.com/view_bug.do?bug_id=6797870
>
>     But I suppose this is not correct?
>
>     Is there a bug to fix PrintClassHistogram when using CMS?
>     Perhaps I am just not finding the correct bug number?
>
>     And of course even -XX:+DisableExplicitGC does not help...
>
>     Example:
>     jconsole -J-Xloggc:/Users/mmiller/gc.log -J-XX:+UseConcMarkSweepGC
>     -J-XX:+PrintGCDetails -J-XX:+ExplicitGCInvokesConcurrent
>     -J-XX:+PrintClassHistogram &
>     [1] 10759
>     $ kill -3 10759
>     $ cat gc.log
>
>     <output snipped>
>
>     19.169: [Full GC19.169: [CMS: 5620K->6303K(7776K), 0.0338410 secs]
>     6950K->6303K(10208K), [CMS Perm : 13492K->13487K(21248K)],
>     0.0340110 secs] [Times: user=0.04 sys=0.00, real=0.03 secs]
>
>      num     #instances         #bytes  class name
>     ----------------------------------------------
>
>     <snip>
>
>
>
>     _______________________________________________
>     hotspot-gc-use mailing list
>     hotspot-gc-use at openjdk.java.net
>     <mailto: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/20140402/74b47d8c/attachment.html>