<html>
<head>
<meta content="text/html; charset=utf-8" http-equiv="Content-Type">
</head>
<body bgcolor="#FFFFFF" text="#000000">
<br>
Hi Dima,<br>
<br>
<div class="moz-cite-prefix">On 2015-04-16 15:36, Dmitry Fazunenko
wrote:<br>
</div>
<blockquote cite="mid:552FBAF5.1060908@oracle.com" type="cite">
<meta content="text/html; charset=utf-8" http-equiv="Content-Type">
Hi Bengt,<br>
<br>
thanks for looking.<br>
<br>
<div class="moz-cite-prefix">On 16.04.2015 15:42, Bengt Rutisson
wrote:<br>
</div>
<blockquote cite="mid:552FAE22.4020009@oracle.com" type="cite">
<meta content="text/html; charset=utf-8"
http-equiv="Content-Type">
<br>
Hello Dima,<br>
<br>
<div class="moz-cite-prefix">On 2015-04-16 13:40, Dmitry
Fazunenko wrote:<br>
</div>
<blockquote cite="mid:552F9FA8.3030403@oracle.com" type="cite">
<meta http-equiv="content-type" content="text/html;
charset=utf-8">
Hello,<br>
<br>
Would you review a simple fix in G1.<br>
<br>
Short description: <br>
after introduction G1Log - dynamic changes of PrintGC and
PrintGCDetails flag has no effect anymore, because G1Log looks
for these flags during initialization only. The fix: sync the
log level with the flags values.<br>
<br>
A huge thanks to Jesper who helped me a lot with my first
product fix.<br>
<br>
Bug: <a moz-do-not-send="true" class="moz-txt-link-freetext"
href="https://bugs.openjdk.java.net/browse/JDK-8073476">https://bugs.openjdk.java.net/browse/JDK-8073476</a><br>
Webrev: <a moz-do-not-send="true"
class="moz-txt-link-freetext"
href="http://cr.openjdk.java.net/%7Edfazunen/8073476/webrev.06/">http://cr.openjdk.java.net/~dfazunen/8073476/webrev.06/</a><br>
</blockquote>
<br>
Sorry, but I don't really like the way this is solved. With this
approach calling G1GCPhaseTimes::print() suddenly has the side
effect that it resets the log level. That's quite unexpected for
me. Especially if you consider the code path in
G1CollectedHeap::log_gc_footer() where we do this:<br>
<br>
void G1CollectedHeap::log_gc_footer(double pause_time_sec) {<br>
if (!G1Log::fine()) {<br>
return;<br>
}<br>
<br>
if (G1Log::finer()) {<br>
...<br>
g1_policy()->phase_times()->print(pause_time_sec);<br>
...<br>
}<br>
<br>
If we don't have G1Log::fine() (which is PrintGC) enabled we
will never call the print() method and will thus not detect any
changes made by the MXBean. If we have G1Log::finer() enabled we
enter the logging code, print other things at the "finer" level
(which is PrintGCDetails) and then do the call to the print()
method where we can suddenly decide that PrintGCDetails no
longer is enabled and not do the rest of the logging. So for the
same GC we will print some stuff at PrintGCDetails level and
some things at another level. Strange.<br>
</blockquote>
<br>
May it's not clear, but the change will have effect only if
PrintGC or PrintGCDetails has been changed during execution.<br>
Otherwise, the level will not change.<br>
</blockquote>
<br>
I understand that, but what I was saying with the example above is
that you will not get the desired effect if you change PrintGC or
PrintGCDetails at runtime. If they are disabled, and then turn them
on at runtime you will not enter the update code because of this
check at the start of the log_gc_footer() method:<br>
<br>
if (!G1Log::fine()) {<br>
return;<br>
}<br>
<br>
<br>
Similarly turning them off at runtime will start to have an effect
in the middle of a GC. Which is probably not the effect you are
looking for.<br>
<br>
This is why making the level() getter having the side effect of
changing the log level is a bad idea. You have no control over when
that happens.<br>
<br>
<blockquote cite="mid:552FBAF5.1060908@oracle.com" type="cite"> <br>
To me, it's strange, that when I disable PrintGC in G1 I still
seeing gc log messages... <br>
Or, I can't turn logging on during execution with G1.<br>
This works well for other collectors.<br>
<br>
Would it make sense to make PrintGC and PrintGCDetails
unmanageable in case of g1?<br>
</blockquote>
<br>
I think they can be manageble but their changed states need to be
handled more explicitly.<br>
<br>
<blockquote cite="mid:552FBAF5.1060908@oracle.com" type="cite"> <br>
<br>
<blockquote cite="mid:552FAE22.4020009@oracle.com" type="cite"> <br>
<br>
I would prefer to have a hook when the MXBean changes the value
and only update the level at that point.<br>
</blockquote>
<br>
Yes, it would be ideal solution. But I haven't found such a
mechanism supported. And it's unlikely worth adding just for this
case.<br>
In my version, the sync will be done more frequently. <br>
</blockquote>
<br>
The sync is done very frequently. Actually way too often in my view.<br>
<br>
I would prefer that you investigate the hook in the MXBean change so
we know how much work that would be. If that is not possible I think
a better solution is to call G1Log::update_level() *once* at the
start of a GC. That way the log level is always consistent
throughout the GC.<br>
<br>
<blockquote cite="mid:552FBAF5.1060908@oracle.com" type="cite"> <br>
<blockquote cite="mid:552FAE22.4020009@oracle.com" type="cite"> <br>
Having said that I am not sure that this bug is worth fixing
right now. I am currently working on the JEP to make the GC
logging use the new unified logging format. That will change all
of this and most likely remove the G1Log class all together. So,
my suggestion would be to leave this as is for now and instead
add the MXBean requirement to the unified logging work.<br>
</blockquote>
<br>
Yes, I'm aware of unified logging and expect that G1Log class will
go away someday.<br>
But I would like to be able to disable logging in JDK9, to not see
GC events occurred at the certain period of time.<br>
</blockquote>
<br>
Can you explain more why this is important to fix right now? Unified
logging is targeted for JDK 9.<br>
<br>
Thanks,<br>
Bengt<br>
<br>
<blockquote cite="mid:552FBAF5.1060908@oracle.com" type="cite"> <br>
Thanks,<br>
Dima<br>
<br>
<br>
<blockquote cite="mid:552FAE22.4020009@oracle.com" type="cite"> <br>
Thanks,<br>
Bengt<br>
<blockquote cite="mid:552F9FA8.3030403@oracle.com" type="cite">
<br>
Testing: <br>
I ran manually the test from the bug report to make sure the
change fixes the problem.<br>
A regression test will be delivered separately as a fix of <a
moz-do-not-send="true" id="key-val" rel="4774806"
href="https://bugs.openjdk.java.net/browse/JDK-8077056">JDK-8077056</a><br>
<br>
Thanks,<br>
Dima </blockquote>
<br>
</blockquote>
<br>
</blockquote>
<br>
</body>
</html>