JEP 158：统一的 JVM 日志记录

QWen Max 中英对照

概述

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

目标

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

延伸目标：

• 多行日志记录：可以将多行内容记录在一起，确保在输出时它们不会交错（保持连续性）
• 启用/禁用单个日志消息（例如通过使用 __FILE__ / __LINE__）
• 实现 syslog 和 Windows 事件查看器输出
• 能够配置 装饰内容的打印顺序

非目标

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

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

本 JEP 不会将日志记录添加到 JDK 中的 Java 代码中。

动机

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

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

描述

标签

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

等级

每条日志消息都有一个与其关联的日志 级别。可用的级别按详细程度递增的顺序为 error（错误）、warning（警告）、info（信息）、debug（调试）、trace（追踪）和 develop（开发）。develop 级别仅在非生产版本中可用。

对于每个输出，可以配置一个日志记录级别，以控制写入该输出的信息量。选择 off 则完全禁用日志记录。

装饰

日志消息会附带有关该消息的信息。以下是可能的附加信息列表：

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

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

示例：[6.567 秒][信息][gc,old] 旧集合完成

输出

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

• stdout -- 输出到标准输出。

• stderr -- 输出到标准错误输出。

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

  可配置为根据写入大小和要轮转的文件数量来处理文件轮转。示例：每 10 MB 轮转一次日志文件，保留 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” 标签是一个元标签，包含所有可用的标签集。在 “tag-set” 定义中的 “*” 表示通配符标签匹配。不使用 “*” 则意味着 “所有与指定标签完全匹配的消息”。

完全省略 “what” 将默认为标签集 all 和级别 info。

省略 level 将默认为 info

省略 output 将默认使用 stdout。

省略 ‘decorators’ 将默认为 uptime, level, tags

“none”装饰器是特殊的，用于关闭所有装饰。

提供的日志级别是聚合的。例如，如果某个输出被配置为使用 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 工具）在运行时进行控制。所有能在命令行中指定的内容，都可以通过诊断命令动态地指定。由于诊断命令会自动作为 MBeans 暴露出来，因此可以使用 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 和文件。未来的项目可以添加其他后端。例如：syslog、Windows 事件查看器、套接字等。

开放性问题

• 我们是否应该在 API 中提供一个替代方案，以便将级别作为参数提供给宏？
• 装饰部分是否应该使用 [] 以外的其他符号包围，以方便解析输出？
• 日期戳装饰部分的确切格式是什么？建议采用 ISO 8601 标准。

测试

登录本身不能导致任何不稳定，因此需要进行广泛的测试，这是非常重要的。

功能测试必须通过启用某些日志消息并检查它们在标准错误输出（stderr）或文件中的存在来进行。

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

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

风险与假设

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

影响

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