Skip to content

JEP 158: Unified JVM Logging | 统一的 JVM 日志记录

摘要

为 JVM 的所有组件引入一个共同的日志记录系统。

目标

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

扩展目标:

  • 多行日志记录:可以将多行日志记录在一起(不交错)以保持它们的完整性
  • 启用/禁用单个日志消息(例如使用 __FILE__ / __LINE__
  • 实现 syslog 和 Windows 事件查看器输出
  • 能够配置装饰内容的打印顺序

非目标

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

本 JEP 的范围还不包括强制要求日志记录格式,除了装饰内容的格式和使用人类可读的纯文本。

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

动机

JVM 是一个复杂的系统级组件,常常需要进行复杂和耗时的根本原因分析。在没有广泛的可维护性功能的情况下,几乎不可能在生产环境中找到间歇性崩溃或性能问题的根本原因。对于支持和持续工程而言,可细粒度、易配置的 JVM 日志记录是一种重要功能。

JRockit 拥有类似的功能,并且在为客户提供支持方面发挥了重要作用。

描述

标签

日志框架在 JVM 中定义了一组标签。每个标签由其名称标识(例如:gccompilerthreads 等)。标签集可以根据需要在源代码中进行更改。在添加日志消息时,应使用标签集与所记录的信息相关联。标签集由一个或多个标签组成。

级别

每个日志消息都有与其关联的日志记录级别。可用的级别按递增顺序为 error、warning、info、debug、tracedevelopdevelop 级别仅在非产品构建中可用。

对于每个输出,可以配置日志记录级别以控制写入该输出的信息量。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

输出

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

  • stdout - 输出到标准输出。
  • stderr - 输出到标准错误。
  • 文本文件 - 输出到文本文件。

可以根据写入的大小和要保留的文件数来配置日志文件的轮转。例如:每 10MB 轮转一次日志文件,保留 5 个轮转文件。文件名将附加其在轮转中的编号。例如:hotspot.log.1、hotspot.log.2、...、hotspot.log.5 当前打开的文件不会附加任何编号。例如:hotspot.log。不能保证文件的大小恰好是配置的大小。大小最多可能超过最后一条日志消息的大小。

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

命令行选项

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

  • -Xlog

多个参数将按照它们在命令行上出现的顺序应用。对于相同输出的多个 -Xlog 参数,它们将按照给定的顺序覆盖彼此。最后的配置规则。

将使用以下语法配置日志记录:

plaintext
-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 装饰符是特殊的,用于关闭所有装饰。

提供的级别是聚合的。例如,如果配置一个输出使用 levelinfo 。所有与 what 中的标签匹配且日志级别为 infowarningerror 的消息都将被输出。

plaintext
-Xlog:disable
    这将关闭所有日志记录并清除日志框架的所有配置,包括警告和错误。

-Xlog:help
    打印-Xlog使用语法和可用标签、级别、装饰器以及一些示例命令行。

默认配置:

plaintext
-Xlog:all=warning:stderr:uptime,level,tags
    - 如果没有在命令行上配置任何内容,则为默认配置
    - “all” 是一个特殊的标签名称,别名为所有现有标签。
    - 此配置将记录所有消息并记录与 “warning” 或 “error” 匹配的级别,而不管消息与何种标记相关联。

简单示例:

plaintext
-Xlog

相当于

plaintext
-Xlog:all
    - 使用 “info” 级别记录消息到 stdout
    - 如果没有提供其他内容,则级别 “info” 和输出 “stdout” 是默认值
    - 所有级别为 “warning” 的默认输出到 “stderr” 仍将生效

-Xlog:gc
    - 使用 “info” 级别记录带有 “gc” 标签的消息到 “stdout”
    - 所有级别为 “warning” 的默认输出到 “stderr” 仍将生效

-Xlog:gc=debug:file=gc.txt:none
    - 使用 “debug” 级别记录带有 “gc” 标签的消息到名为 “gc.txt” 的文件中,无装饰符
    - 所有级别为 “warning” 的默认输出到 “stderr” 仍将生效

-Xlog:gc=trace:file=gctrace.txt:uptimemillis,pids:filecount=5,filesize=1M
    - 使用 “trace” 级别记录带有 “gc” 标签的消息到 5 个文件的旋转文件集中,每个文件的大小为 1MB,基本名称为“gctrace.txt”,并使用 “uptimemillis” 和 “pid” 装饰符
    - 所有级别为 “warning” 的默认输出到 “stderr” 仍将生效

-Xlog:gc::uptime,tid
    - 使用默认的 “info” 级别记录带有 “gc” 标签的消息到默认输出 “stdout”,并使用 “uptime” 和 “tid” 装饰符
    - 所有级别为 “warning” 的默认输出到 “stderr” 仍将生效

-Xlog:gc*=info,rt*=off
    - 使用 “info” 级别记录至少带有 “gc” 标签的消息,但关闭带有 “rt” 标签的消息记录
    - 带有 “gc” 和 “rt” 标签的消息将不会被记录
    - 所有级别为 “warning” 的默认输出到 “stderr” 仍将生效

-Xlog:disable -Xlog:rt=trace:rttrace.txt
    - 关闭所有日志记录,甚至警告和错误,除了使用 “trace” 级别记录带有 “rt” 标签的消息
    - 输出到名为 “rttrace.txt” 的文件。

复杂示例:

plaintext
-Xlog:gc+rt*=debug
    - 使用 “debug” 级别记录带有至少 “gc” 和 “rt” 标签的消息到 “stdout”
    - 所有级别为 “warning” 的默认输出到 “stderr” 仍将生效

-Xlog:gc+meta*=trace,rt*=off:file=gcmetatrace.txt
    - 使用 “trace” 级别记录带有至少 “gc” 和 “meta” 标签的消息到名为 “metatrace.txt” 的文件中,但关闭所有带有 “rt” 标签的消息
    - 同样,带有 “gc”、“meta” 和 “rt” 标签的消息将不会被记录,因为 “rt” 被关闭
    - 所有级别为 “warning” 的默认输出到 “stderr” 仍将生效

-Xlog:gc+meta=trace
    - 使用 “trace” 级别记录带有 “gc” 和 “meta” 标签的消息到 “stdout”
    - 所有级别为 “warning” 的默认输出到 “stderr” 仍将生效

-Xlog:gc+rt+compiler*=debug,meta*=warning,svc*=off
    - 使用 “trace” 级别记录带有至少 “gc”、“rt” 和 “compiler” 标签的消息到 “stdout”,但仅记录具有 “warning” 或 “error” 级别的具有 “meta” 标签的消息,并关闭所有带有 “svc” 标签的消息
    - 所有级别为 “warning” 的默认输出到 “stderr” 仍将生效

控制运行时

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

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

JVM interface

JVM 中将创建一组宏,其 API 与以下类似:

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

Example:

java
log_info(gc, rt, classloading)("Loaded %d objects.", object_count)
    该宏检查日志级别以避免不必要的调用和分配。

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

Level information 级别信息:

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

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

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

性能

不同的日志级别应具有定义级别的预期性能开销的指南。例如:“警告级别不应影响性能;信息级别应该在生产中是可接受的;调试、跟踪和错误级别没有性能要求。”禁用日志记录应该对性能的影响尽可能小。但日志记录总会带来一定的开销。

未来可能的扩展

在将来,可能有必要添加用于向此基础架构编写日志消息的 Java API,供 JDK 中的类使用。

最初,将开发三个后端:stdout、stderr 和 file。未来的项目可能会添加其他后端。例如:syslog、Windows 事件查看器、套接字等。

开放问题

  • 我们是否应该在 API 中提供另一种选择,将级别作为宏的参数提供?
  • 装饰符是否应该用其他字符而不是 [] 括起来,以便更易于解析输出?
  • 日期戳装饰符的确切格式是什么?建议采用 ISO 8601。

测试

非常重要的是,日志记录本身不会导致任何不稳定性,因此需要进行广泛的测试。

通过启用某些日志消息并检查它们是否存在于 stderr 或文件中,必须进行功能测试。

因为将来可能动态启用日志记录,我们需要通过在应用程序运行时不断启用和禁用日志记录来进行压力测试。

日志框架将通过单元测试进行测试。

风险和假设

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

影响

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