Fwd: JEP 271: Unified GC Logging

[Bengt Rutisson]

Hi Bernd,

(Copying in the mailing list to Benrd's reply.)

On 2015-09-25 19:45, Bernd wrote:
> Hello,
>
>
>
> 2015-09-25 11:19 GMT+02:00 Bengt Rutisson <bengt.rutisson at oracle.com 
> <mailto:bengt.rutisson at oracle.com>>:
>
>
>
>     Hi Bernd,
>
>     On 2015-09-24 18:13, Bernd wrote:
>>     Are you planning to use different locales for the number
>>     rendering? In
>>     your example the comma is not only confusing but also makes it
>>     harder
>>     to parse.
>
>     If you are referring the logging of times in my example then they
>     are printed with the %f formating in C++. So, they will by locale
>     dependent. This is the same as in the existing GC logging. My
>     locale is Swedish, thus the commas as decimal separators.
>
>
> I guess it is technically possible to parse both formats but it is a 
> bit confusing when you have to deal with multiple files from different 
> sources. Especially if thousand-seperators are used as well or the 
> 3-decimal-digit format for seconds is used "1,123". So it might be a 
> good idea to address this (together with the dynamic unit selection, 
> unit formatting and seperation).

Yes, I agree that these issues should be addressed together. I would 
prefer to handle them as a separate issue from the initial conversion of 
the GC logs to the unified logging framework.

>
>
>>     Will size numbers always printed with dynamic units?
>
>     Currently I use the same conversion as the existing GC logging.
>     Personally I don't like it when the unit for a repeated log record
>     changes dynamically. But I'll leave it the same way we have it now
>     for starters. In a second step we can review the unit formatting.
>
>
> Yes, I agree that it adds parser work and makes ad-hoc queries to the 
> files harder to have dynamic units and the error of 0.1M is just quite 
> big. I would favor kib or bytes (the later only if we manage to get 
> working parsers .)

Ok. I'll try to make the formatting as consistent as possible and to not 
round away too much information. Let's pick this discussion up when I 
have more examples to show.

>
>>     is it
>>     possible to stick with one format for seperating units from numbers
>>     (i.e. "12 ms" vs. "12M")
>
>     Sorry, I'm not sure understand this question. Are you referring to
>     the space between the number and the unit? In that case, sure, we
>     can try to standardize on it. What do you prefer ? With or without
>     space?
>
>
> Yes I was refering to the blank and I would say remove it to safe 
> bytes and make "tokens" more atomic to parse.

Good. I'll try to change this as I go along.

>
>
>     ...
>
>
>>     Personally I think we dont need xml, but we should have a simple
>>     pattern to parse those lines.
>>
>>     <blank>*[Name: att1=123 Unit, att2=123 Unit, ...]
>>
>>     This allows variable indention, variable number of attributes.
>>     And if
>>     you stick to "." decimal even the , has a function
>
>     Not sure we want to stick to "." as a decimal separator. I realize
>     that having it locale dependent can cause problems, but it is the
>     standard way of formating floating point numbers.
>
>
> Ok, my main point is this:
>
> It is good to have optional/conditional information in seperate 
> records just like you proposed (inclusing the tagging and level 
> selection). But in addition keep in mind that in the past we have 
> modified (extended) the log format and we should expect that for the 
> future as well. When each record (=line) has a standard format which 
> allows to recognize its type (phase/meansing) and tag all values you 
> can always add (or even remove) values and the parser can still 
> extract information. So sticking with a somewhat readable format this 
> could be something like G1 uses. In the most obvious case : and , 
> would be seperators. It is not a must to avoid comma in numbers (as 
> you can parse it out with digitg-comma-digit which would never be a 
> tag seperator) but it adds to it.

I expect the log format to change in the future too. I am not saying 
that each log line will have a standard format that we can't change. But 
with unified logging changes to one log line will not affect the rest of 
the logging.

>
>
>> ...
>
>>
>>     [0,799s][debug  ][gc,phases ] GC#14    Clear CT: 2,7 ms
>>     [0,799s][debug  ][gc,phases ] GC#14    Other: 8,5 ms
>>     [0,800s][debug  ][gc,phases ] GC#14       Choose CSet: 0,0 ms
>>     [0,800s][debug  ][gc,phases ] GC#14       Ref Proc: 2,4 ms
>>     [0,800s][debug  ][gc,phases ] GC#14       Ref Enq: 0,0 ms
>>     [0,800s][debug  ][gc,phases ] GC#14       Redirty Cards: 2,0 ms
>>     [0,800s][debug  ][gc,phases ] GC#14 Humongous Register: 0,0 ms
>>     [0,800s][debug  ][gc,phases ] GC#14 Humongous Reclaim: 0,0 ms
>>     [0,800s][debug  ][gc,phases ] GC#14       Free CSet: 3,5 ms
>
> BTW: I wonder if this is a single phase mabye a single line would be 
> better:
>
> [0,799s][debug  ][gc,phases ] GC#14    Other: 8,5 ms
> [0,799s][debug  ][gc,phases,detail ] GC#14    Other Breakdown: Choose 
> CSet 8,5ms, Ref Proc 2,4ms, Ref Enq 0,0ms ...
>
> i.e. allow to select/deselect the other breakdown and make sure it is 
> a single (extendable) record (savong lots of bytes).

Right. A more compact format may be nice. I'll play with that a bit.

>
>>     ...
>>
>>     I'm currently thinking that we should probably keep the PrintGC and
>>     PrintGCDetails flags since they are very widely used. We could
>>     deprecate
>>     them and just have them map to some -Xlog configuration. My
>>     suggestion would
>>     be to map PrintGC to -Xlog:gc and PrintGCDetails to -Xlog:gc*=debug.
>
> Do you also plan to keep/map G1LogLevel (experimental)? I think it 
> currently does not really allow to prune down logs (detailed logging 
> maps to fine anyway so finest only selects per-thread info).
>

Certainly. In fact, G1LogLevel was introduced as a simple workaround for 
a missing log framework a few years ago. The intent was always to 
replace it once we had a real framework in place.

Thanks,
Bengt

> Gruss
> Bernd

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