JEP 271: Unified GC Logging - Second pre-review

[Bengt Rutisson]

Hi Kirk,

On 2015-11-09 17:50, Kirk Pepperdine wrote:
>> On Nov 9, 2015, at 10:28 AM, Bengt Rutisson <bengt.rutisson at oracle.com> wrote:
>>
>>
>> Hi Kirk,
>>
>> On 2015-11-08 00:33, Kirk Pepperdine wrote:
>>>> On Nov 7, 2015, at 5:10 PM, Simone Bordet <sbordet at webtide.com> wrote:
>>>>
>>>> Hi,
>>>>
>>>> On Sat, Nov 7, 2015 at 12:24 PM, Kirk Pepperdine
>>>> <kirk.pepperdine at gmail.com> wrote:
>>>>> Hi Bengt,
>>>>>
>>>>> A couple of comments aimed at bulk and/or frequency trade-offs.
>>>>>
>>>>> [11.247s][info   ][gc          ] GC#265 GC young (G1 Evacuation Pause)
>>>>> 109M->71M(128M) (11.228s, 11.247s) 19.208ms
>>>>>
>>>>> with the exception of the pause time, this line seems redundant.
>>>>>
>>>>> [11.247s][info   ][gc,heap     ] GC#265 Eden: 38912K->0K(2048K)
>>>>> [11.247s][info   ][gc,heap     ] GC#265 Survivor: 4096K->4096K(6144K)
>>>>> [11.247s][info   ][gc,heap     ] GC#265 Old: 68990K->73147K(131072K)
>>>>> [11.247s][info   ][gc,metaspace] GC#265 Metaspace: 2993K->2993K(1056768K)
>>>>>
>>>>> can these 4 lines be combined?
>>>> Don't we also need some number to calculate the promoted bytes ?
>>>> I was doing this before using: promoted = total_young_delta - total_heap_delta.
>>> Ok, let me suggest a format. This is all the information I need. Everything else is chatter.
>>>
>>>>> [11.247s][info   ][gc,heap     ] GC#265 38912K->0K(2048K) 4096K->4096K(6144K) 68990K->73147K(131072K) 2993K->2993K(1056768K)
>> This format may be fine for machine parsing but it is not very readable to humans. Readability is an important use case,
> Trust me on this one... no one reads these things. Even when I tell attendees of my workshop to read the GC log, they still don’t. Readability might be an important an interesting use case from your POV. From mine it really isn’t. As an FYI, you should look at HP and Azul GC logs.

I understand that readability is not important to you. But there are 
many other users than you and many of them depend on being able to read 
the GC logs in a reasonable way.

>
>> so we will need to at least add information about what the numbers map to. As I stated in a previous mail I would prefer these on separate lines, but if we want them on a single line I think the format need to be something like:
>>
>> [11.247s][info   ][gc,heap     ] GC#265 Eden: 38912K->0K(2048K), Survivor: 4096K->4096K(6144K), Old: 68990K->73147K(131072K), Metaspace: 2993K->2993K(1056768K)
>>
>> To me this is line is too long to ready quickly. In particular if I am just trying to follow how, for example, the Eden size changes over time.
> My concern is here and why I believe they should be combined is to minimize the frequency of logging.

The frequency as in logging three lines instead of one line per GC? You 
would have to show me some performance numbers if you want to convince 
me that this would be a problem.

Regards,
Bengt

>
> Regards,
> Kirk
>