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

[John Cuthbertson]

Hi Bengt,

Looks good to me. Ship it.

JohnC

On 05/15/12 00:51, Bengt Rutisson wrote:
>
> Hi John,
>
> Thanks for looking at this!
>
> On 2012-05-14 21:00, John Cuthbertson wrote:
>> Hi Bengt,
>>
>> Overall this looks good to me, but I do have a couple of minor 
>> comments and questions....
>>
>> arguments.cpp - Typo @ line 3096
>
> Fixed.
>
>>
>> gcCause.hpp - fields in the new class should have a leading underscore.
>
> Of course! I keep missing that when I create new classes. Thanks for 
> finding it! Fixed.
>
>> g1CollectedHeap.cpp - @ line 3600. IMO using a local to hold the GC 
>> string and pass that into the TraceTime constructor would improve the 
>> readability significantly.
>
> Fixed.
>
>>
>> g1CollectorPolicy.cpp - @ line 888. If you have a log level == finer, 
>> where is the print of the date/timestamp prefix now?
>
> Good catch! I clearly removed one line too much. Added it back.
>
> Here is an updated webrev:
> http://cr.openjdk.java.net/~brutisso/7166894/webrev.06/
>
> Thanks again for looking at this!
> Bengt
>
>
>
>>
>> Other than that, it looks good?
>>
>> JohnC
>>
>> On 05/14/12 00:46, Bengt Rutisson wrote:
>>>
>>> Hi again,  :-)
>>>
>>> Here is an updated webrev where PrintGCCause is off by default in 
>>> JDK7 but on by default in JDK8:
>>> http://cr.openjdk.java.net/~brutisso/7166894/webrev.05/
>>>
>>> The relevant change is in arguments.cpp:
>>> http://cr.openjdk.java.net/~brutisso/7166894/webrev.05/src/share/vm/runtime/arguments.cpp.udiff.html
>>>
>>> With this proposal there is still one slight change in JDK7 logging. 
>>> For full GCs that were triggered by System.gc() calls we used to log 
>>> the cause. Now this will not happen unless you add 
>>> -XX:+PrintGCCause. This will not break any parsers, but it might 
>>> make some parsers miss System.gc() calls.
>>>
>>> I think we are getting closer to wrapping this change up. It is a 
>>> little unclear to me who would like to be listed as reviewers. Could 
>>> those that would like to be reviewers please take a look at the 
>>> latest webrev and let me know.
>>>
>>> Thanks,
>>> Bengt
>>>
>>>
>>> On 2012-05-11 19:51, Srinivas Ramakrishna wrote:
>>>> Mikael, thanks for sounding that note of caution... what you say 
>>>> makes sense.
>>>>
>>>> -- ramki
>>>>
>>>> On Fri, May 11, 2012 at 10:17 AM, Mikael Vidstedt 
>>>> <mikael.vidstedt at oracle.com <mailto:mikael.vidstedt at oracle.com>> wrote:
>>>>
>>>>
>>>>     I'm all for improving the information in the log messages,
>>>>     great work! However, I'm not sure I'm warm and fuzzy about
>>>>     potentially breaking users' log parsers in a minor update. My
>>>>     preference would be to have the PrintGCCause flag be default
>>>>     false in jdk7 and default true in jdk8+. In general I'd prefer
>>>>     to only change the log messages in major releases.
>>>>
>>>>     Reasonable?
>>>>
>>>>     Cheers,
>>>>     Mikael
>>>>
>>>>
>>>>     On 2012-05-11 07:30, Bengt Rutisson wrote:
>>>>>
>>>>>     Hi Kris,
>>>>>
>>>>>     Thanks again for looking at this.
>>>>>
>>>>>     I had to make some minor changes make it compile on all
>>>>>     platforms. Mostly some explicit casts to const char*. Here is
>>>>>     an updated webrev:
>>>>>     http://cr.openjdk.java.net/~brutisso/7166894/webrev.04/
>>>>>     <http://cr.openjdk.java.net/%7Ebrutisso/7166894/webrev.04/>
>>>>>
>>>>>     More comments inline.
>>>>>
>>>>>     On 2012-05-08 16:43, Krystal Mok wrote:
>>>>>>     Hi Bengt,
>>>>>>
>>>>>>     The current factoring looks nice and uniform. Thanks :-)
>>>>>>
>>>>>>     But for most minor GCs and both CMS pause phases, the extra
>>>>>>     logging doesn't really give additional information.
>>>>>>     Most minor GCs are going to say "Allocation Failure", and the
>>>>>>     two CMS phases would change from, e.g.
>>>>>>
>>>>>>     [GC [1 CMS-initial-mark
>>>>>>
>>>>>>     to something like
>>>>>>
>>>>>>     [GC (CMS Initial Mark) [1 CMS-initial-mark
>>>>>>
>>>>>>     which is probably reasonable given the scope of the change,
>>>>>>     but not really helpful.
>>>>>>     The "real cause", such as which generation (or perhaps
>>>>>>     System.gc() with ExplicitGCInvokesConcurrent, or even GC
>>>>>>     locker) is triggering this collection cycle, may be more
>>>>>>     useful, but it's hard to fit into the current form.
>>>>>
>>>>>     Yes, I think you are correct in both cases. The gc cause that
>>>>>     we have available does not always add a lot of information.
>>>>>     This is relevant to fix but it is a slightly different issue
>>>>>     than what this patch sets out to fix. Let's try to get this in
>>>>>     first and then evaluate how the GC causes should be set.
>>>>>
>>>>>     Thanks,
>>>>>     Bengt
>>>>>
>>>>>>
>>>>>>     - Kris
>>>>>>
>>>>>>     On Tue, May 8, 2012 at 10:18 PM, Bengt Rutisson
>>>>>>     <bengt.rutisson at oracle.com
>>>>>>     <mailto:bengt.rutisson at oracle.com>> wrote:
>>>>>>
>>>>>>
>>>>>>         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/
>>>>>>         <http://cr.openjdk.java.net/%7Ebrutisso/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
>>>>>>
>>>>>
>>>>
>>>>
>>>
>>
>

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