JEP 271: Unified GC Logging - Second pre-review

[Kirk Pepperdine]

>>>> 
>>>>>> [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.

I’m sorry to say but what you are saying just doesn’t correlate well with my experience. In my experience people rarely look at GC logging. That said, you are right, readability is not overly important to me however being completely unreadable wouldn’t be great either because I also open them up and read them.

> 
>> 
>>> 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.

This is a problem that you can’t see in the small. It is my experience tuning systems (sorry for the blatant hand-waving) that the way to choke a logging frame work is to have it work very frequently. The size of the message is secondary in that many small writes are far worse than fewer larger ones. For example, if you have a system that is logging to NAS on a system that is shy on network capacity, GC logging will degrade performance. Frequency in this situation hurts quite a bit. So, per GC logging, I’d agree with you 99% of the time. However it’s that 1% of the time that is important because those are the cases where you need the data and it very hard to get it when collecting it puts more pressure on the system. 

I find it very ironic that logging, which is intended to improve the visibility of your application, is so often a bottleneck in applications simply because the way it works isn’t visible.

All said, I think I’ve offered all I can in terms of my experiences on this subject so no worries, I’ll just let you get on with it.

Kind regards,
Kirk