JEP 271: Unified GC Logging - First pre-review

[Bengt Rutisson]

Hi Staffan,

Thanks for looking at this!

On 2015-10-26 18:14, Staffan Friberg wrote:
> Just skimmed so far, will give it a more through look.
>
> Do we want to keep the space after the the Times output? Does it add 
> any value?
> Can bite you sometimes when you grep and look for line endings.
>
> "[Times: user=0.10 sys=0.00 real=0.02 secs] "
>

Maybe I was unclear in my email. The logs for PrintGC and PrintGCDetails 
are the logs for the "old" logging. In the new logging the Times output 
looks like this:

[1.165s][info   ][gc,cpu      ] GC#1 CPU Times: user=0.39s sys=0.00s 
real=0.40s

Or am I misunderstanding the question?

Bengt

> //Staffan
>
> On 10/26/2015 05:26 AM, Bengt Rutisson wrote:
>>
>> Hi again everyone,
>>
>> An update on the work for JEP 271 Unified GC Logging.
>>
>> I now have a working prototype that covers all GCs. Here are some 
>> examples comparing the old format (using -XX:+PrintGC and 
>> -XX:+PrintGCDetails) with the new format (using -Xlog):
>>
>> http://cr.openjdk.java.net/~brutisso/JEP-271/pre-review.00/compare.html
>>
>> The new logging format, using -Xlog, is much more flexible than the 
>> old format. So, the comparison table on the above page is by no means 
>> complete. I hope it will give a good overview, but to get a real feel 
>> for how the new logging works I think it is necessary to run locally 
>> and play around with the logging options.
>>
>> Here is a webrev of the changes so far:
>> http://cr.openjdk.java.net/~brutisso/JEP-271/pre-review.00/webrev.00/
>>
>> There is still work to do and I have some known issues with the code 
>> changes. So, I am currently not asking for too much feedback on the 
>> actual code changes. I am more looking for feedback on the logging 
>> behavior. The webrev can be useful to get a feel for what the code 
>> changes will look like but mostly I think it can be used to apply the 
>> patch and build your own HotSpot to try out the new logging.
>>
>> Some changes based on the initial feedback:
>> - Start and end timestamps for the GC included on the GC log line.
>> - Printing the unit of a value without a space. I.e. "10.345ms" 
>> instead of "10.345 ms". (Still working on fixing this in all places 
>> as well as trying to use milliseconds instead of seconds in as many 
>> places as possible.)
>> - Printing heap change information with a fixed unit. I am now using 
>> M for overall heap transition and K for detailed information on the 
>> debug level.
>> - Removed the "summary" tag. Instead the end logging for a GC 
>> includes all relevant information.
>>
>> All feedback is very welcome!
>>
>> Thanks,
>> Bengt
>