<html>
<head>
<meta content="text/html; charset=utf-8" http-equiv="Content-Type">
</head>
<body bgcolor="#FFFFFF" text="#000000">
<br>
Hi Kirk,<br>
<br>
<div class="moz-cite-prefix">On 2015-09-24 15:29, Kirk Pepperdine
wrote:<br>
</div>
<blockquote
cite="mid:13E93E4C-C0BE-438C-BF14-111C37F616F2@kodewerk.com"
type="cite">
<meta http-equiv="Content-Type" content="text/html; charset=utf-8">
Hi Bengt,
<div class=""><br class="">
</div>
<div class="">
<div>
<blockquote type="cite" class="">
<div class=""><br class="">
Yes, providing logging that is not interleaved with other
logging is indeed one of the main reasons for moving over
to the new logging framework. I agree that this should
make things much easier for tools that parse the log files
in the future.<br class="">
</div>
</blockquote>
<div><br class="">
</div>
Well, I would argue for something a little stronger. </div>
<div><br class="">
</div>
<div>For example we have this</div>
<div><br class="">
</div>
<div>
<pre style="background-color: rgb(255, 255, 255); font-family: Menlo; font-size: 12pt;" class=""><span style="color:#808080;font-style:italic;" class="">10.099: [GC (Allocation Failure) 10.099: [ParNew10.100: [SoftReference, 0 refs, 0.0000141 secs]10.100: [WeakReference, 0 refs, 0.0000029 secs]10.100: [FinalReference, 0 refs, 0.0000026 secs]10.100: [PhantomReference, 0 refs, 0 refs, 0.0000033 secs]10.100: [JNI Weak Reference, 0.0000045 secs] (promotion failed): 72353K->71961K(78656K), 0.0009583 secs]10.100: [CMS10.100: [CMS-concurrent-abortable-preclean: 0.210/2.397 secs] [Times: user=15.12 sys=0.27, real=2.40 secs]</span></pre>
<pre style="background-color: rgb(255, 255, 255); font-family: Menlo; font-size: 12pt;" class=""><span style="font-family: Helvetica; font-size: 12px; white-space: normal;" class="">which is really an ParNew allocation failure dropping into a concurrent mode failure which closes off the abortable-preclean phase and the record contains reference processing information. All good information.</span></pre>
<div class="">
<pre style="background-color: rgb(255, 255, 255); font-family: Menlo; font-size: 12pt;" class=""><span style="color: rgb(128, 128, 128); font-style: italic;" class="">10.099: [GC (Allocation Failure) 10.099: [ParNew (promotion failed): 72353K->71961K(78656K), 0.0009583 secs]</span></pre>
<pre style="background-color: rgb(255, 255, 255); font-family: Menlo; font-size: 12pt;" class=""><span style="color: rgb(128, 128, 128); font-style: italic;" class="">10.100: [CMS10.100: [CMS-concurrent-abortable-preclean: 0.210/2.397 secs] [Times: user=15.12 sys=0.27, real=2.40 secs]</span></pre>
<pre style="background-color: rgb(255, 255, 255);" class=""><pre style="font-family: Menlo; font-size: 12pt;" class=""><span style="color: rgb(128, 128, 128); font-style: italic;" class="">10.100: [SoftReference, 0 refs, 0.0000141 secs]10.100: [WeakReference, 0 refs, 0.0000029 secs]10.100: [FinalReference, 0 refs, 0.0000026 secs]10.100: [PhantomReference, 0 refs, 0 refs, 0.0000033 secs]10.100: [JNI Weak Reference, 0.0000045 secs]</span></pre><div style="font-family: Menlo; font-size: 12pt;" class="">
</div><div class=""><pre class=""><font class="" face="Helvetica"><span style="white-space: normal;" class="">Without reference processing (-XX:+PrintReferenceGC I think is the flag) you’ll get this</span></font></pre><div style="font-family: Menlo; font-size: 12pt;" class="">
</div></div><div class=""><pre style="font-size: 12pt; font-family: Menlo;" class=""><span style="color: rgb(128, 128, 128); font-style: italic;" class="">10.099: [GC (Allocation Failure) 10.099: [ParNew (promotion failed)10.100: [CMS10.100: [CMS-concurrent-abortable-preclean: 0.210/2.397 secs] [Times: user=15.12 sys=0.27, real=2.40 secs]</span></pre><pre class=""><pre style="font-size: 12pt; font-family: Menlo;" class=""><span style="color: rgb(128, 128, 128); font-style: italic;" class="">: 72353K->71961K(78656K), 0.0009583 secs]</span></pre><pre class=""><pre style="font-size: 12px; font-family: Menlo;" class=""><font class="" face="Helvetica"><span style="white-space: normal;" class="">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.</span></font></pre><pre class=""><font class="" face="Helvetica"><span style="white-space: normal;" class="">I would hope that this record would l!
ook the sa
me irregardless if the equivalent of PrintReferenceGC was turned on or not.</span></font></pre></pre></pre></div></pre>
</div>
</div>
</div>
</blockquote>
<br>
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.<br>
<br>
<blockquote
cite="mid:13E93E4C-C0BE-438C-BF14-111C37F616F2@kodewerk.com"
type="cite">
<div class="">
<div>
<div class="">
<pre style="background-color: rgb(255, 255, 255);" class=""><div class=""><pre class=""><pre class=""><pre class=""><font class="" face="Helvetica"><span style="white-space: normal;" class="">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.</span></font></pre></pre></pre></div></pre>
</div>
</div>
</div>
</blockquote>
<br>
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. :)<br>
<br>
<blockquote
cite="mid:13E93E4C-C0BE-438C-BF14-111C37F616F2@kodewerk.com"
type="cite">
<div class="">
<div>
<div class="">
<pre style="background-color: rgb(255, 255, 255);" class=""><div class=""><pre class=""><pre class=""><pre class="">
</pre><pre class=""><font class="" face="Helvetica"><span style="white-space: normal;" class="">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.</span></font></pre></pre></pre></div></pre>
</div>
</div>
</div>
</blockquote>
<br>
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.<br>
<br>
Cheers,<br>
Bengt<br>
<blockquote
cite="mid:13E93E4C-C0BE-438C-BF14-111C37F616F2@kodewerk.com"
type="cite">
<div class="">
<div>
<div class="">
<pre style="background-color: rgb(255, 255, 255);" class=""><div class=""><pre class=""><pre class=""><pre class=""><font class="" face="Helvetica"><span style="white-space: normal;" class="">
</span></font></pre><pre class=""><font class="" face="Helvetica"><span style="white-space: normal;" class="">Kind regards,</span></font></pre><pre class=""><span style="white-space: normal; font-family: Helvetica;" class="">Kirk</span></pre><pre class="">
</pre></pre></pre></div></pre>
</div>
</div>
</div>
</blockquote>
<br>
</body>
</html>