JEP 158：统一 JVM 日志记录

概括

为 JVM 的所有组件引入一个通用的日志系统。

目标

• 所有日志记录的通用命令行选项
• 日志消息使用标签进行分类（例如编译器、gc、类加载、元空间、svc、jfr...）。一条消息可以有多个标签（标签集）
• 日志记录在不同级别执行：error, warning, info, debug, trace, develop.
• 可以根据级别选择记录哪些消息。
• 可以将日志记录重定向到控制台或文件。
• 默认配置是所有使用警告和错误级别的消息都输出到 stderr。
• 按大小和要保留的文件数量进行日志文件的文件轮换（类似于当今的 GC 日志）
• 一次打印一行（同一行内无交错）
• 日志消息采用人类可读的纯文本格式
• 消息可以被“装饰”。默认装饰是：uptime, level, tags。
• 能够配置要打印的装饰**。**
• 现有的“ tty->print...”日志记录应使用统一日志记录作为输出
• 可以通过 jcmd 或 MBean 在运行时动态配置日志记录
• 经过测试和支持——如果/当用户/客户启用时不应崩溃

延伸目标：

• 多行日志记录：可以以在输出时将它们保持在一起（非交错）的方式记录多行日志
• 启用/禁用单个日志消息（例如通过使用__FILE__/ __LINE__）
• 实施系统日志和 Windows 事件查看器输出
• 能够配置装饰的打印顺序

非目标

添加来自所有 JVM 组件的实际日志记录调用超出了本 JEP 的范围。该 JEP 将仅提供进行日志记录的基础设施。

除了装饰的格式和人类可读的纯文本的使用之外，强制执行日志格式也超出了 JEP 的范围。

此 JEP 不会向 JDK 中的 Java 代码添加日志记录。

动机

JVM 是复杂的系统级组件，根本原因分析通常是一项困难且耗时的任务。如果没有广泛的可维护性功能，通常几乎不可能找到生产环境中间歇性崩溃或性能异常的根本原因。可供支持和维护工程使用的细粒度、易于配置的 JVM 日志记录就是这样的功能之一。

JRockit 具有类似的功能，它在为客户提供支持方面发挥了重要作用。

描述

标签

日志框架在 JVM 中定义了一组_标签_。每个标签均通过其名称进行标识（例如：gc、compiler、threads等）。可以根据需要在源代码中更改标签集。当添加日志消息时，它应该与对所记录的信息进行分类的_标签_集相关联。标签_集_由一个或多个标签组成。

级别

每条日志消息都有一个与其关联的日志记录_级别_。可用级别为error、warning、info、debug、trace和develop按详细程度递增的顺序。该develop级别仅在非产品版本中可用。

对于每个输出，可以配置日志记录级别来控制写入该输出的信息量。另一种方法off是完全禁用日志记录。

装饰

记录消息用有关该消息的信息进行_装饰_。以下是可能的装饰的列表：

• time-- ISO-8601 格式的当前时间和日期
• uptime-- 自 JVM 启动以来的时间（以秒和毫秒为单位）（例如，6.567s）
• timemillis-- 与生成的值相同System.currentTimeMillis()
• uptimemillis-- 自 JVM 启动以来的毫秒数
• timenanos-- 与 System.nanoTime() 生成的值相同
• uptimenanos-- 自 JVM 启动以来的纳秒数
• pid-- 进程标识符
• tid-- 线程标识符
• level-- 与日志消息关联的级别
• tags-- 与日志消息关联的标签集

每个输出都可以配置为使用一组自定义装饰器。但它们的顺序始终是上面的顺序。要使用的装饰可以由用户在运行时配置。装饰将被添加到日志消息中

例子：[6.567s][info][gc,old] Old collection complete

输出

目前支持三种类型的输出：

• 标准输出——输出到标准输出。

• stderr——输出到stderr。

• 文本文件——输出到文本文件。

  可以配置为根据写入大小和要轮换的文件数量来处理文件轮换。示例：每 10MB 轮换日志文件，轮换 5 个文件。文件名将在循环中附加其编号。示例：hotspot.log.1, hotspot.log.2, ..., hotspot.log.5当前打开的文件不会附加任何编号。例子：hotspot.log。不保证文件的大小与配置的大小完全相同。该大小最多可以溢出最后写入的日志消息的大小。

某些输出类型可能需要额外的配置。使用简单且定义良好的接口可以轻松实现其他输出类型。

命令行选项

将添加一个新的命令行选项，以控制 JVM 所有组件的日志记录。

• -Xlog

多个参数将按照它们在命令行中出现的顺序应用。同一输出的多个“-Xlog”参数将按照给定的顺序相互覆盖。最后的配置规则。

以下语法将用于配置日志记录：

-Xlog[:option]
    option         :=  [<what>][:[<output>][:[<decorators>][:<output-options>]]]
                       'help'
                       'disable'
    what           :=  <selector>[,...]
    selector       :=  <tag-set>[*][=<level>]
    tag-set        :=  <tag>[+...]
                       'all'
    tag            :=  name of tag
    level          :=  trace
                       debug
                       info
                       warning
                       error
    output         :=  'stderr'
                       'stdout'
                       [file=]<filename>
    decorators     :=  <decorator>[,...]
                       'none'
    decorator      :=  time
                       uptime
                       timemillis
                       uptimemillis
                       timenanos
                       uptimenanos
                       pid
                       tid
                       level
                       tags
    output-options :=  <output_option>[,...]
    output-option  :=  filecount=<file count>
                       filesize=<file size>
                       parameter=value

“ all”标签是由所有可用标签集组成的元标签。*“标签集”定义中的“ ”表示“通配符”标签匹配。不使用“ *”意味着“所有消息都与指定标签完全匹配”。

一起省略“what”将默认为 tag-setall和 level info。

省略“级别”将默认为info

省略“输出”将默认为stdout

省略“装饰器”将默认为uptime, level, tags

' none'装饰器比较特殊，用于关闭所有装饰。

提供的级别是汇总的。例如，如果输出配置为使用“level” info。所有与“what”中的标签匹配且日志级别为 和 的消息都info将warning被error输出。

-Xlog:disable
    this turns off all logging and clears all configuration of the
    logging framework. Even warnings and errors.

-Xlog:help
    prints -Xlog usage syntax and available tags, levels, decorators
    along with some example command lines.

默认配置：

-Xlog:all=warning:stderr:uptime,level,tags
    - default configuration if nothing is configured on command line
    - 'all' is a special tag name aliasing all existing tags
    - this configuration will log all messages with a level that
    matches ´warning´ or ´error´ regardless of what tags the
    message is associated with

简单的例子：

-Xlog

是相同的

-Xlog:all
    - log messages using 'info' level to stdout
    - level 'info' and output 'stdout' are default if nothing else
    is provided
    - default output of all messages at level 'warning' to 'stderr'
    will still be in effect

-Xlog:gc
    - log messages tagged with 'gc' tag using 'info' level to
    'stdout'
    - default output of all messages at level 'warning' to 'stderr'
    will still be in effect

-Xlog:gc=debug:file=gc.txt:none
    - log messages tagged with 'gc' tag using 'debug' level to
    a file called 'gc.txt' with no decorations
    - default output of all messages at level 'warning' to 'stderr'
    will still be in effect

-Xlog:gc=trace:file=gctrace.txt:uptimemillis,pids:filecount=5,filesize=1M
    - log messages tagged with 'gc' tag using 'trace' level to
    a rotating fileset with 5 files with size 1MB with base name
    'gctrace.txt' and use decorations 'uptimemillis' and 'pid'
    - default output of all messages at level 'warning' to 'stderr'
    will still be in effect

-Xlog:gc::uptime,tid
    - log messages tagged with 'gc' tag using default 'info' level to
    default output 'stdout' and use decorations 'uptime' and 'tid'
    - default output of all messages at level 'warning' to 'stderr'
    will still be in effect

-Xlog:gc*=info,rt*=off
    - log messages tagged with at least 'gc' using 'info' level but turn
    off logging of messages tagged with 'rt'
    - messages tagged with both 'gc' and 'rt' will not be logged
    - default output of all messages at level 'warning' to 'stderr'
    will still be in effect

-Xlog:disable -Xlog:rt=trace:rttrace.txt
    - turn off 'all' logging, even warnings and errors, except
    messages tagged with 'rt' using 'trace' level
    - output to a file called 'rttrace.txt'

复杂的例子：

-Xlog:gc+rt*=debug
    - log messages tagged with at least 'gc' and 'rt' tag using 'debug'
    level to 'stdout'
    - default output of all messages at level 'warning' to 'stderr'
    will still be in effect

-Xlog:gc+meta*=trace,rt*=off:file=gcmetatrace.txt
    - log messages tagged with at least 'gc' and 'meta' tag using 'trace'
    level to file 'metatrace.txt' but turn off all messages tagged
    with 'rt'
    - again, messages tagged with 'gc', 'meta' and 'rt' will not be logged
    since 'rt' is set to off
    - default output of all messages at level 'warning' to 'stderr'
    will still be in effect

-Xlog:gc+meta=trace
    - log messages tagged with exactly 'gc' and 'meta' tag using 'trace'
    level to 'stdout'
    - default output of all messages at level 'warning' to 'stderr'
    will still be in effect

-Xlog:gc+rt+compiler*=debug,meta*=warning,svc*=off
    - log messages tagged with at least 'gc' and 'rt' and 'compiler' tag
    using 'trace' level to 'stdout' but only log messages tagged
    with 'meta' with level 'warning' or 'error' and turn off all
    messages tagged with 'svc'
    - default output of all messages at level 'warning' to 'stderr'
    will still be in effect

运行时控制

可以通过诊断命令（实用程序）在运行时控制日志记录jcmd。可以在命令行上指定的所有内容也可以使用诊断命令动态指定。由于诊断命令自动公开为 MBean，因此可以使用 JMX 在运行时更改日志记录配置。

对枚举日志记录配置和参数的附加支持将添加到运行时控制命令列表中。

JVM接口

在 JVM 中，将使用类似于以下的API 创建一组宏：

log_<level>(Tag1[,...])(fmtstr, ...)
    syntax for the log macro

例子：

log_info(gc, rt, classloading)("Loaded %d objects.", object_count)
    the macro is checking the log level to avoid uneccessary
    calls and allocations.

log_debug(svc, debugger)("Debugger interface listening at port %d.", port_number)

等级信息：

LogHandle(gc, meta, classunloading) log;
if (log.is_trace()) {
    ...
}

if (log.is_debug()) {
    ...
}

为了避免执行生成仅用于日志记录的数据的代码，可以询问 Log 类当前配置的日志级别。

表现

不同的日志级别应该有定义该级别的预期性能开销的准则。例如：“警告级别不应该影响性能；信息级别应该是生产可接受的；调试、跟踪和错误级别没有性能要求。”在禁用日志记录的情况下运行应该对性能影响尽可能小。但登录总是要花钱的。

未来可能的扩展

将来，添加一个 Java API 来将日志消息写入此基础结构可能是有意义的，以便在 JDK 中的类中使用。

最初，仅开发三个后端：stdout、stderr 和 file。未来的项目可能会添加其他后端。例如：syslog、Windows 事件查看器、socket 等。

开放式问题

• 我们是否应该在 API 中提供替代方案，将级别作为参数提供给宏？
• 装饰是否应该被其他东西包围而不是[]为了更容易解析输出？
• 日期标记装饰的确切格式是什么？提议采用 ISO 8601。

测试

登录本身不会导致任何不稳定，这一点极其重要，因此需要进行大量测试。

功能测试必须通过启用某些日志消息并检查它们在 stderr 或文件上的存在来完成。

由于可以动态启用日志记录，因此我们需要通过在运行应用程序时不断启用和禁用日志记录来对其进行压力测试。

日志框架将使用单元测试进行测试。

风险和假设

上述设计可能无法满足当今 JVM 中日志记录的所有用途。如果是这样的话，就必须重新审视设计。

影响

• 兼容性：日志消息格式将发生变化，某些 JVM 选项的含义也可能发生变化。
• 安全性：文件权限需要验证。
• 性能/可扩展性：如果启用大量日志记录，性能将受到影响。
• 用户体验：命令行选项将会改变。日志输出将会改变。
• I18n/L10n：日志消息不会本地化或国际化。
• 文档：必须记录新选项及其用法。