Request for review (S): 7166894 Add gc cause to Full GC logging for all collectors

[Bengt Rutisson]

Hi again everyone,

It seems like the feedback on hotspot-gc-use is that we should add the 
GC cause to all collectors but also provide a switch to turn this 
logging off.

Here is an updated webrev:
http://cr.openjdk.java.net/~brutisso/7166894/webrev.03/

Changes:
* GC cause logged for all collectors
* Added the flag -XX:-PrintGCCause to turn the new information off
* Refactored the string concatenation code into a helper class

I guess I will also have to update the CR to now reflect the fact that 
this does not just concern full GCs anymore.

Thanks,
Bengt

On 2012-05-07 23:10, Bengt Rutisson wrote:
>
> Hi Kris,
>
> Thanks for looking at this!
>
> Good point regarding CMS. I guess I am a bit concerned about changing 
> that since it might start breaking more parsers. I'll send a question 
> out on the hotspot-gc-use mailing list to get some feedback.
>
> If we do go for adding this information to CMS we can probably also 
> take the chance of adding it to all the young GCs.
>
> I looked at the log sample you referred to. It looks like you were 
> logging more details about exactly why a GC was triggered. That is 
> probably a good idea, but for now I think we should settle for just 
> the text message describing the cause.
>
> Thanks again for looking at this,
> Bengt
>
> On 2012-05-07 15:19, Krystal Mok wrote:
>> Hi Bengt,
>>
>> FYI, I did something similar to CMS as well, covered by a new flag 
>> called "PrintGCReason" in my build.
>> It's primitive, compared with your change. I was striving to keep the 
>> log within the brackets just as they were, and instead print extra 
>> information before the opening bracket, on a separate line. The 
>> parsing tool we use tend to ignore the lines it couldn't recognize, 
>> so doing it this way interrupted the tool the least.
>>
>> An example of the output can be found here [1], page 42. The 
>> motivation to add the extra logging was to track down a mysterious 
>> behavior in CMS that it keep doing back-to-back collections, without 
>> much gains, as explained in [1]. I needed to know why it was 
>> triggered. Some of our applications actually liked the extra logging, 
>> so it remained in the code base after the bug was found.
>>
>> Anyway, I like the idea of getting more info out of GC logs, in a 
>> uniform way.
>> Would you mind adding the extra logging to CMS, too?
>>
>> - Kris
>>
>> [1]: http://www.slideshare.net/RednaxelaFX/jvm-taobao
>>
>> On Mon, May 7, 2012 at 8:31 PM, Bengt Rutisson 
>> <bengt.rutisson at oracle.com <mailto:bengt.rutisson at oracle.com>> wrote:
>>
>>
>>     Hi all,
>>
>>     Can I get a couple of reviews of this simple change:
>>     http://cr.openjdk.java.net/~brutisso/7166894/webrev/
>>     <http://cr.openjdk.java.net/%7Ebrutisso/7166894/webrev/>
>>
>>     Background:
>>     I recently pushed a similar fix for G1 as "7163848: G1: Log GC
>>     Cause for a GC". That fix adds the GC cause information to all G1
>>     GCs. It was discussed if we should do this for all collectors and
>>     we came to the conclusion that it would be fairly safe to do it
>>     for all Full GCs. These log messages already contain the text
>>     "(System)" or "(System.gc())" when a System.gc() happens and
>>     PrintGCDetails are enabled. Now they will always contain the
>>     cause in parenthesis, even when only PrintGC is enabled.
>>     Hopefully most parsing will work with this.
>>
>>     Thanks,
>>     Bengt
>>
>>
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/hotspot-gc-dev/attachments/20120508/e4e51d38/attachment.htm>