JEP 271: Unified GC Logging

[Kirk Pepperdine]

Hi Bengt,


>> Not so bad that the concurrent phase gets closed in the same line as the ParNew but that the Reference GC shifts it over is a bit of a pain.
>> I would hope that this record would l! ook the sa me irregardless if the equivalent of PrintReferenceGC was turned on or not.
> 
> I totally agree. My intent is that all log records should always look the same no matter what other logging is enabled. In particular I plan to use a "ref" tag for the reference processing and log that on separate lines. I think that will look pretty natural given the new start and end lines for the GC. I'll post an example of that when I have it implemented.

Cool!

> 
>> I can root around for better example if you’re interested. Or, maybe there is a way I can make my DB of gc logs available.
> 
> Thanks, but I don't think that is necessary for this purpose. I think I understand the issues you describe. But for other reasons it would of course be interesting if you could make your DB of logs available. :)

Martijn and I have been talking about this. We have a closed repository on GitHub with GC logs of interest. The problem is some of the logs are too big to stash there. We also would have to sanitize them to ensure we don’t violate any NDAs.
> 
>> One point on date stamps. The can often get misaligned with the time stamp. So I’m inclined to pick up the first date as a reference point and then calculate dates using the time stamp from there on. It gets rid of most weird conditions that can happen when the values get misaligned and you think you’ve gone back in time when you haven’t.
> 
> I'm not quite sure I understand your issue here. But the absolute time and date stamps will all be provided by the decorations support in the unified logging framework. So, maybe this question is better discussed in that thread? The GC logging will only add duration timing.

ok, I have an examples but where is the question at the moment. When I find it, I’ll post it. In Censum I have a check that tells me when the time stamps move back in time. I typically see this when people concatenate logs together or if NTP rolls the clock back. Sometimes it just seems that there is a gap between when the date stamp and the time stamp are taken. So in Censum it appears as if the clock rolled backwards when only one of the timers (either the date stamp or the time stamp) has become misaligned. In these cases, the problem always seems to corrects its self on the next record. For that reason I’ll capture a date stamp and calibrate it to the start of the JVM and then after that only look for time stamps. If I need a date from the time stamp then I can refer back to the initial date stamp to calculate it. It sound tricky but what it does do is help me get past some of the problems that I run into when reading timing data from the logs.

As to the last point, I’m concerned that there will be gap between then the GC event starts and when it gets logged. That will cause problems with certain calculations. I’d much rather get a time stamp from the GC log entry for the start of an event than get it from UL.


> 
> Cheers,
> Bengt
>> Kind regards,
>> Kirk
> 

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/hotspot-gc-dev/attachments/20150925/64c653ef/attachment.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 496 bytes
Desc: Message signed with OpenPGP using GPGMail
URL: <https://mail.openjdk.org/pipermail/hotspot-gc-dev/attachments/20150925/64c653ef/signature.asc>