JEP 271: Unified GC Logging - Second pre-review

Bengt Rutisson bengt.rutisson at oracle.com
Thu Nov 12 08:56:25 UTC 2015



On 2015-11-11 16:20, Vitaly Davidovich wrote:
>
> That was my motivation as well.  Unfortunately for Bengt, both use 
> cases are valid and real.
>

Yes, I think both use cases are important. So, we have to find a good 
balance of making the logs easily parsable for tools and at the same 
time as readable as possible for humans.

Bengt

> sent from my phone
>
> On Nov 11, 2015 10:17 AM, "charlie hunt" <charlie.hunt at oracle.com 
> <mailto:charlie.hunt at oracle.com>> wrote:
>
>     Hi Kirk,
>
>     I was just about to say a similar thing … visualizations offer a
>     good way to spot trends and other subtleties.
>
>     To be quite honest, my motivation for jumping in on this thread
>     was to highlight that there are many use cases where manually
>     looking logs are useful, i.e. GC log information shouldn’t be
>     tailored only for tooling. It should also be easily human readable
>     too.
>
>     In other words, both general uses are useful, needed, and should
>     be accounted for in Bengt’s unified GC logging implementation.
>
>     It is probably also worth saying that whatever the ending
>     implementation looks, there will likely be someone who will not be
>     happy with it. :-]
>
>     thanks,
>
>     charlie
>
>>     On Nov 11, 2015, at 9:09 AM, Kirk Pepperdine
>>     <kirk.pepperdine at gmail.com <mailto:kirk.pepperdine at gmail.com>> wrote:
>>
>>     Hi all,
>>
>>     I think there are things that you can’t find when looking at
>>     things manually like subtile trends and frequencies and
>>     relationships between trends of different metrics. Plus, I have
>>     analytics that I can run over the logs that can show you things
>>     that would be hard to see otherwise. In addition, I did a talk at
>>     Devoxx yesterday where looking at a GC log was part a demo I was
>>     doing. During the demo, something interesting showed up that
>>     caused the GC threads to accumulate a lot of Kernel time. Without
>>     the analytic, I would have completely missed these events and a
>>     great opportunity to run off-script with something interesting
>>     and useful. There is no way under those conditions I’d see this
>>     interesting event. In addition, I just got a zip of about 20GC
>>     logs from a customer. That is a small zip as can get logs from
>>     systems to 100s of JVMs. The only way to get through this many
>>     logs in a reasonable amount of time is with tooling.
>>
>>     Regards,
>>     Kirk
>>
>>>     On Nov 10, 2015, at 6:19 PM, Vitaly Davidovich
>>>     <vitalyd at gmail.com <mailto:vitalyd at gmail.com>> wrote:
>>>
>>>     I think it's more of whether the GC log info is noise or
>>>     signal.  If a process is GC'ing very frequently, looking at it
>>>     manually doesn't strike me as practical -- you'll need a tool to
>>>     make sense of it (i.e. each GC occurrence is noise).
>>>
>>>     On Tue, Nov 10, 2015 at 12:16 PM, charlie hunt
>>>     <charlie.hunt at oracle.com <mailto:charlie.hunt at oracle.com>> wrote:
>>>
>>>
>>>         On Nov 10, 2015, at 11:02 AM, Vitaly Davidovich
>>>         <vitalyd at gmail.com <mailto:vitalyd at gmail.com>> wrote:
>>>
>>>>             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.
>>>>
>>>>
>>>>         I do occasionally look at GC logs manually.  The reason is
>>>>         because GC is unexpected and/or rare event on some
>>>>         daemons.  I agree that on daemons where GC is a frequent
>>>>         occurrence nobody is likely to look at it manually unless
>>>>         they're examining a particular outlier.
>>>>
>>>
>>>         I may not be the norm ... I almost always look at GC logs
>>>         manually.
>>>
>>>         And in those cases where look at GC logs via tools /
>>>         visualization I always end up looking at the logs to see was
>>>         happening leading up to some GC event of interest.
>>>
>>>         That said ... on the one hand I agree that many folks don't
>>>         read GC logs, but on the other hand, for my selfish
>>>         purposes, I look at them, and I'd like something that's easy
>>>         to read. (Put whatever definition you'd like on "easy to read").
>>>
>>>         Don't know if that helps or complicates things for Bengt?
>>>
>>>         Charlie
>>>
>>>>         On Tue, Nov 10, 2015 at 10:51 AM, Kirk Pepperdine
>>>>         <kirk.pepperdine at gmail.com
>>>>         <mailto:kirk.pepperdine at gmail.com>> wrote:
>>>>
>>>>
>>>>             >>>>
>>>>             >>>>>> [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
>>>>
>>>>
>>>
>>
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-dev/attachments/20151112/f2c3f0a2/attachment.html>


More information about the hotspot-gc-dev mailing list