Details

    • Author:
      Jon Masamitsu
    • JEP Type:
      Feature
    • Exposure:
      Open
    • Subcomponent:
      gc
    • Scope:
      JDK
    • Discussion:
      hotspot dash gc dash dev at openjdk dot java dot net
    • Effort:
      L
    • Duration:
      L
    • Alert Status:
       Green
    • JEP Number:
      271

      Description

      Summary

      Reimplement GC logging using the unified JVM logging framework introduced in JEP 158.

      Non-Goals

      It is not a goal to ensure that current GC log parsers work without change on the new GC logs.

      Not all log entries will necessarily be reproduced in the new logging format.

      Description

      Reimplement GC logging in a manner that is as consistent as is reasonable with the current GC logging format. There will, of necessity, be some difference between the new and the old formats.

      The "gc" Tag

      The idea is that -Xlog:gc (only log on the "gc" tag at info level) should be similar to what -XX:+PrintGC did, which was printing one line per GC. This means that log_info(gc)("message") should be used very carefully. Don't log at the info level on just the "gc" tag unless it is the one message that should be printed per GC.

      It is fine to log at the info level using the "gc" tag if it is combined with other tags. For example:

      log_info(gc, heap, ergo)("Heap expanded");

      The idea here is that -Xlog:gc should be somewhat similar to what you used to get with -XX:+PrintGCDetails. But this mapping is not as strict as the mapping from -Xlog:gc to -XX:+PrintGC. The rule for -XX:+PrintGC was pretty clear: one line per GC. The rule for -XX:+PrintGCDetails has never been very clear. So, some -XX:+PrintGCDetials logging may be mapped to several tags and some may just be mapped to the debug level for the "gc" tag.

      All GC-related logging should use the "gc" tag. Most logging should not use just the "gc" tag but, rather, combine it with other tags as appropriate.

      There are also border-line cases where it is unclear whether "gc" is the appropriate tag, for example in allocation code. Most of these cases should probably not use the "gc" tag.

      Other Tags

      There are many other tags besides "gc". Some of them map pretty cleanly to old flags. PrintAdaptiveSizePolicy, for example, is more or less mapped to the "ergo" tag (in combination with the "gc" tag and potentially other tags).

      Verbose

      Most logging that was guarded by the Verbose flag (a develop flag) should be mapped to the trace level. The exception is if it is very expensive logging from a performance perspective, in which case it is mapped to the develop level.

      Prefix

      The prefix support in the unified logging framework is used to add the GC id to GC log messages. The GC id is only interesting for logging that happens during a GC. Since the prefixes are defined for a particular tag set, i.e., a combination of tags, it is necessary to make sure that logging that occurs between GCs do not use the same tag set as logging that is done during GCs.

      Dynamic Configuration

      Some logging requires that data has been collected at an earlier state. The unified logging framework allows for all logging to be dynamically turned on and off using jcmd. This means that for logging that relies on previously-collected data it is not enough to check whether logging is enabled; there must also be checks in place to check that the data is available.

        Issue Links

          Activity

          Hide
          acorn Karen Kinnear added a comment -
          Are there any specific GC log messages that we believe should keep their current format for customers that parse them today?
          Show
          acorn Karen Kinnear added a comment - Are there any specific GC log messages that we believe should keep their current format for customers that parse them today?
          Hide
          jmasa Jon Masamitsu (Inactive) added a comment -
          From what I've seen of the new logging format, no GC log messages will stay the same. Each message has a leader that has information such as log level and that will make the format of all messages different from today. We will consider keeping the body of the message the same but that is a "nice to have" and not a requirement. We're going to break parsers so we want to get it right.
          Show
          jmasa Jon Masamitsu (Inactive) added a comment - From what I've seen of the new logging format, no GC log messages will stay the same. Each message has a leader that has information such as log level and that will make the format of all messages different from today. We will consider keeping the body of the message the same but that is a "nice to have" and not a requirement. We're going to break parsers so we want to get it right.
          Hide
          jmasa Jon Masamitsu (Inactive) added a comment -
          From the Non-goals:

          Not all log entries will necessarily be reproduced in the new logging format.

          Can you give an example of a log entry that will not be reproduced?

          When there is an example of a "before" and "after" log entries, please include it in
          here. Thanks.
          Show
          jmasa Jon Masamitsu (Inactive) added a comment - From the Non-goals: Not all log entries will necessarily be reproduced in the new logging format. Can you give an example of a log entry that will not be reproduced? When there is an example of a "before" and "after" log entries, please include it in here. Thanks.
          Hide
          brutisso Bengt Rutisson (Inactive) added a comment -
          I don't have a particular example in mind of a log entry that will appear different after the change, but I think this non-goal is present to give us the freedom to change some log entries if that makes the transition to the new framework easier.

          One example of something that might cause us to change a log entry is that the new framework only has the equivalent of outputStream::print_cr() and not outputStream::print(). Logging that previously printed parts of a line now either have to be explicitly buffered or logged as multiple log lines.

          Good suggestion to post some examples of what the new and old logs will look like. I'll do that as soon as I have a prototype up and running.
          Show
          brutisso Bengt Rutisson (Inactive) added a comment - I don't have a particular example in mind of a log entry that will appear different after the change, but I think this non-goal is present to give us the freedom to change some log entries if that makes the transition to the new framework easier. One example of something that might cause us to change a log entry is that the new framework only has the equivalent of outputStream::print_cr() and not outputStream::print(). Logging that previously printed parts of a line now either have to be explicitly buffered or logged as multiple log lines. Good suggestion to post some examples of what the new and old logs will look like. I'll do that as soon as I have a prototype up and running.
          Hide
          mcastegr Mattis Castegren (Inactive) added a comment -
          Note, this TOI can be done together with the general Unified JVM logging JEP
          Show
          mcastegr Mattis Castegren (Inactive) added a comment - Note, this TOI can be done together with the general Unified JVM logging JEP
          Hide
          ostuart Owen Stuart added a comment -
          TOI no longer needed on this topic as it is covered under - Content included in Unified JVM Logging
          Show
          ostuart Owen Stuart added a comment - TOI no longer needed on this topic as it is covered under - Content included in Unified JVM Logging

            People

            • Assignee:
              sjohanss Stefan Johansson
              Reporter:
              jmasa Jon Masamitsu (Inactive)
              Owner:
              Bengt Rutisson (Inactive)
              Reviewed By:
              Mikael Vidstedt
              Endorsed By:
              Mikael Vidstedt
            • Votes:
              0 Vote for this issue
              Watchers:
              10 Start watching this issue

              Dates

              • Due:
                Created:
                Updated:
                Resolved:
                Integration Due: