<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-17 15:51, Dmitry Fazunenko
      wrote:<br>
    </div>
    <blockquote cite="mid:55310FCF.5030109@oracle.com" type="cite">
      <meta content="text/html; charset=utf-8" http-equiv="Content-Type">
      <tt>Bengt,<br>
        <br>
        Please find comments inline.<br>
        <br>
      </tt>
      <div class="moz-cite-prefix">On 17.04.2015 9:43, Bengt Rutisson
        wrote:<br>
      </div>
      <blockquote cite="mid:5530AB92.2050509@oracle.com" type="cite">
        <meta content="text/html; charset=utf-8"
          http-equiv="Content-Type">
        <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>
      </blockquote>
      fine() invokes level(), level() invokes update(), so G1::fine()
      will return the up to date value:<br>
      <br>
      <pre>   inline static bool fine() {
<span class="removed">-    return _level >= LevelFine;</span>
<span class="new">+    return level() >= LevelFine;</span>
   }</pre>
      <br>
      <pre>   static LogLevel level() {
<span class="new">+    // PringGC and PrintGCDetails are dynamic flags</span>
<span class="new">+    // _level should be in sync with the latest values</span>
<span class="new">+    update_level();</span>
     return _level;
   }</pre>
      <br>
    </blockquote>
    Oh, I missed that you had changed fine() to call level(). This means
    that all calls to G1Log interface has side effects. I don't like
    that at all.<br>
    <br>
    <blockquote cite="mid:55310FCF.5030109@oracle.com" type="cite">
      <blockquote cite="mid:5530AB92.2050509@oracle.com" type="cite"> <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>
      </blockquote>
      <br>
      It must be up to those who change flags at runtime.<br>
      But the following code should work:<br>
      <br>
      MXBean.set(PrintGC, false);<br>
      System.gc();<br>
      MXBean.set(PrintGC, true);<br>
      <br>
      <blockquote cite="mid:5530AB92.2050509@oracle.com" type="cite"> <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>
      </blockquote>
      <blockquote cite="mid:5530AB92.2050509@oracle.com" type="cite"> <br>
        I would prefer that you investigate the hook in the MXBean
        change so we know how much work that would be. </blockquote>
      <br>
      It was my first intention, but I haven't found a way how to
      implement it.<br>
    </blockquote>
    <br>
    I think what you need to do is to extend the Flag class with an
    update() method and call the method in WriteableFlags::set_flag().<br>
    <br>
    <blockquote cite="mid:55310FCF.5030109@oracle.com" type="cite"> <br>
      <blockquote cite="mid:5530AB92.2050509@oracle.com" type="cite">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>
      </blockquote>
      <br>
      Yes, this is a good idea!<br>
    </blockquote>
    <br>
    Yes, it is much cleaner.<br>
    <br>
    <blockquote cite="mid:55310FCF.5030109@oracle.com" type="cite"> <br>
      <blockquote cite="mid:5530AB92.2050509@oracle.com" type="cite"> <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>
      </blockquote>
      <br>
      What I heard about unified logging is that there is no guarantee
      that it will happen in JDK9 time frame.<br>
      I need the feature now to develop tests based on analysis of logs:
      I want to start logging not from begging, but after some steps.<br>
      <br>
      Will you be okay if G1Log::update_level() is invoked once per GC?<br>
    </blockquote>
    <br>
    I would be ok with it, but I'm pretty convinced unified logging will
    make it in to JDK9 so if you can wait for it that might be better.<br>
    <br>
    Thanks,<br>
    Bengt<br>
    <br>
    <blockquote cite="mid:55310FCF.5030109@oracle.com" type="cite"> <br>
      Thanks,<br>
      Dima<br>
      <br>
      <blockquote cite="mid:5530AB92.2050509@oracle.com" type="cite"> <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>
      </blockquote>
      <br>
    </blockquote>
    <br>
  </body>
</html>