JAVA日志专辑

欢迎你来读这篇博客,这篇博客主要是关于Java日志的分享。
其中包括了关于我的经验和收集的知识分享。

序言

Java日志是 Java 开发中非常重要的组件,它可以帮助我们快速定位问题,也可以帮助我们快速定位问题。

先来点直接的。

推荐使用 log 日志输出调试信息而不要使用 System.out.println()方法,主要是因为 println()使用了同步锁,会影响程序的并发性能和系统的吞吐量。

日志的分类

日志级别

  • 错误级别:ERROR
  • 警告级别:WARN
  • 信息级别:INFO
  • 调试级别:DEBUG
  • 跟踪级别:TRACE

强制标准:打印日志判断级别

目的是支持动态修改日志级别,以及环境区分。dev/test 环境可能会打印大量 info 用于开发测试调试,线上并不需要这些日志。或者线上出问题了,动态修改日志级别,再去打印此类日志。

线上分析工具,Arthas支持动态修改日志级别,以及更多操作。Arthas

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
// 示例
if (log.isErrorEnabled()) {
log.error("log.......");
}
if (log.isWarnEnabled()) {
log.warn("log.......");
}
if (log.isInfoEnabled()) {
log.info("log.......");
}
if (log.isDebugEnabled()) {
log.debug("log.......");
}
if (log.isTraceEnabled()) {
log.trace("log.......");
}

日志类型

  • 系统日志:系统日志是指系统运行过程中的日志,比如系统启动,系统关闭等。
  • 应用日志:应用日志是指应用运行过程中的日志,比如用户登录,用户操作等。
  • 访问日志:访问日志是指用户访问系统的日志,比如用户访问的页面,用户访问的接口等。

好的日志习惯

  • 日志格式统一
  • 日志文件大小拆分策略
  • 不打无用日志
  • 关键信息提到最前
  • 敏感信息和日期
  • 用好 debug 级别
  • 用好切面日志

优化日志的输出格式

官网对这几类模式的说明中反复强调了会影响性能。如果使用了如下属性输出,将极大的损耗性能:

比如 log4j 官网

1
%C or $class, %F or %file, %l or %location, %L or %line, %M or %method

Java 日志框架总览

理解日志库需要从下面三个角度去理解:

  • 最重要的一点是 区分日志系统和日志门面;
  • 其次是日志库的使用, 包含配置与 API 使用;配置侧重于日志系统的配置,API 使用侧重于日志门面;
  • 最后是选型,改造和最佳实践等

日志的艺术

理解日志并不是一件容易的事,开发人员在编写代码之时往往会纠结在某处打印的日志是不是有意义的,而 SRE 在面对缺少日志的生产问题时往往一筹莫展,Ops
在对面海量日志时往往需要花费更多的精力来维护,而项目的实际管理者在面对毫无实际业务价值的日志时,往往不想花费太多的人力和财力去管理它。

因此,在开发应用程序时遵循良好的实践,在收集管理日志时选用成熟的方案,往往能让这些矛盾得以缓解,这也就有了这一篇的分享。

矛盾的开始

首先介绍的是为什么需要记录日志,日志的作用。其实关于日志的作用无需介绍太多,因为大多数的开发人员在调试代码问题时,解决不同环境的
Bug
时都有很明确的感受以及强烈的需求。日志作为调试的助手,生产环境的救星。笔者只见过嫌弃日志打的太少的,几乎没有见过嫌弃日志打的太多的开发和运维人员。通过查询日志的方式来确定代码的分支走向,API
是否请求正确,核心业务的数据是否正确,是否有错误的堆栈信息,这些都构成开发和运维人员判断代码和生产问题的第一手段。笔者难以想象如果一个复杂庞大的系统没有记录任何日志,该如何排查生产环境的
Bug。

如果有如此强烈的需求,那每一行代码都打日志来记录上下文不就行了吗?这样无论什么环境有什么代码有问题,通过搜索日志都可以排查出来。理论上这样确实可行,但是有一些问题目前无法解决,一是日志存储量的问题,常见的中大型系统日志大概在
TB 级,超大型系统的日志大概在 PB 级,根据 Cloudflare 提供的数据,它每秒大概处理 4 千万的请求,这对于存储的费用来讲是一个巨大的挑战。二是搜索的性能下降,像
Elasticsearch 数据库这类常见的日志存储方案,海量的日志会导致其所维护的映射关系爆炸式增长,即使划分不同的 Index,分布式管理不同的
ElasticSearch 集群,也很难做到搜索性能不随数据量的增加而下降。三是海量日志的生成会在峰期时拖慢系统性能,增大出故障的风险。

所以综上可以得出最简单的结论,即日志既不能打印太多导致存储和管理日志太难,也不应该因为打印太少导致运维人员无法排查问题,这听起来自相矛盾,但这就是关于日志的艺术!

  • 场景一
    • 某工程师在调查生产环境中某个创建资源的 API 性能较低问题时,发现是由于该 API 在保存资源前做了写 INFO
      级别的日志,将资源对象都写到日志中,由于资源的对象属性很多,所以导致在业务峰期时,代码打印出海量日志,耗尽 Buffer
      区内存,从而拖慢主线程,造成服务性能整体下降。因此该工程师将该业务日志打印操作删除,以降低生产环境磁盘
      IO 损耗,解决性能问题。
    • 但是某天由于修改了该 API 服务调用链路上的某服务代码,导致该 API 创建出来的对象有错误,并且由于缺少了生产环境保存该资源时的日志,无法排查出是
      API 的请求参数有问题,还是后续的计算逻辑有问题。这时我们只能重新修改日志级别,重新构建发布上线吗?
  • 场景二
    • 假设将生产环境的日志设置为 ERROR 级别。某一时刻,依赖的下游服务故障,导致请求大量超时。又由于在业务峰期 QPS
      非常高的时期,短时间内集中产生大量的错误日志,导致磁盘 IO 急剧提高,耗费大量 CPU,进而导致整个服务瘫痪。我们应该如何处理?
  • 场景三
    • 某工程师在排查生产问题时,发现 INFO 级别的日志还无法满足排查 Root Cause,有一个 DEBUG 日志级别的日志是他需要的,但是生产环境只有
      INFO 级别,这时只能修改级别然后重新启动服务吗?

日志级别规范与动态调整

解决以上问题的方法,一是需要我们在项目中,明确日志级别的规范,不为了调试方便和减少存储随意使用日志级别。二是给日志级别加上动态调整的功能。也就是需要解决线上问题时,调低线上日志输出级别,获取全面的
Debug 日志,帮助工程师提高定位问题的效率。在生产日志海量增加拖慢服务性能时,调高线上日志输出级别,减少日志的生成,缓解磁盘
IO 压力和提高服务性能。

以下是对于日志级别给出的建议:

  • TRACE:应该在开发期间使用它来追踪错误,但永远不要提交到版本控制系统(VCS)中。
  • DEBUG:记录程序中发生的任何事情。主要在调试期间使用,建议在进入生产阶段之前缩减调试语句的数量,只留下最有意义的条目,并可以在故障排除期间激活。
  • INFO:记录所有由用户驱动的事件或特定于系统的操作(例如定期计划操作)。
  • WARN:此级别记录所有可能成为错误的事件。例如,如果一个数据库调用花费的时间超过预定义的时间,或者如果内存缓存接近容量。这将允许适当的自动警报,并在故障排除期间允许更好地了解系统在故障之前的行为方式。
  • ERROR:在此级别记录每个错误条件。这可以是返回错误或内部错误条件的 API 调用。
  • FATAL:代表整个服务已经无法工作。请非常节制地使用这个级别。通常此级别记录表示程序的结束。

记录日志

  • 什么时候记录日志
    • 什么时候记录日志并没有标准规范,需要开发人员根据业务和代码来自行判断,除了常规的记录事件,例如进行了哪些操作、发生了与预期不符的情况、运行期间出现未能处理的异常或警告、定期自动执行的任务外。笔者还建议在以下场景加上日志:
  • 在调用第三方系统时,将调用 API 的 URL 带上 Request/Response Body
    和异常都记录到日志。原因是当发生故障时,能够有明确且清晰的的日志报告说明故障原因,减少不同系统服务运维人员或者不同公司之间的责任界定,以更顺畅的方式推动问题的解决。
  • 在重要核心业务的关键代码和分支加上日志,例如 if-then-else
    语句,它可以帮助开发人员了解程序是否根据其当前状态遍历了预期路径。并且由于核心业务的数据普遍难以手动复现,了解代码分支的走向至关重要。
  • 核心业务的审计日志,如果某业务和法律或合同具有关联性,给对应的操作加上审计日志是非常有必要的。并且存储日志要求强一致性数据库。
  • 应用服务启动时输出配置信息。初始化配置的逻辑一般只会执行一次,不便于诊断时复现,所以应该输出到日志中。

日志属性

除了在日志常规需要打印的 log level,timestamp,message,exception 和 stack trace 外,排查问题往往还需要其它的字段来帮助定位和查找
Root Cause,常见的额外字段有以下几种:

  • trace id 即服务链路追踪的唯一 ID。在请求进入到系统 7 层网关时,即在 HTTP header 中加上对应请求整个生命周期唯一的 trace
    id,并随着该请求调用一直携带。当请求链路过长,开发人员难以找到完整的请求日志时,trace id 有助于反向查找完整日志。
  • span id 即表示 trac id 生命周期中拆分的单个操作。例如当请求到达每个服务后,服务都会为请求生成 spanid,第一个 spanid 称之为
    root span,而随请求一起从上游传过来的 spanid 会被记录成 pspanid (parent-spanid)。当前服务生成的 spanid
    随着请求一起再传到下游服务时,这个 spanid 又会被下游服务当做 pspanid 记录。由此 span id 有助于当服务调用复杂时还原出整个请求的调用链路视图。
  • user id 即用户的唯一 ID。确保当用户上报 Issue 或者提交 TIcket 的时候,可以根据当前用户的唯一 ID 直接查询对应错误日志,减少干扰项,缩短排查周期。
  • tenant_id 这是租户 ID(如果存在)。对多租户系统非常有帮助
  • request uri 即当前微服务请求 URI (用户一个业务操作可能对应着多个服务不同的 request uri),当某业务出现问题时,通过该业务对应入口的
    request uri 往往能很快拿到 trac id,再通过 trac id 去查找对应请求的日志往往能很快解决问题。
  • application name 即当前微服务名称。有助于识别哪个服务生成了此日志,也有助于通过 application name 过滤日志,查询服务整体故障。
  • pod name 即当前请求所在的 k8s 资源 Pod 名称(如果存在)。目前大多数微服务使用 k8s 来完成容器编排,打印 pod name 有助于当某个
    pod 故障时,重启或者 Kill Pod。
  • host name 即当前请求所在的机器名称。即使使用 k8s 托管微服务,也会出现由于 k8s 集群所在的某台机器出现磁盘或者网络故障时,服务无法正常工作的情况,打印
    host name 有助于排查问题最后一公里,即由于机器硬件问题导致故障。

日志 Sec

日志需要保证日志框架的安全和敏感信息处理。框架安全指的是使用成熟的,经过大量生产环境验证的日志框架库,而非自己造轮子。敏感信息处理是大部分公司的生命线,请牢记日志的安全性和合规性要求:

  • 不要泄露敏感的个人身份信息 (PII)。
  • 不要泄露加密密钥或秘密。
  • 确保公司的隐私政策涵盖日志数据。
  • 确保日志提供商满足合规性需求。
  • 确保满足数据存储时间要求。

bad smell

  • 使用中文或者非英文打印日志。
    • 英文表示日志将以 ASCII 字符记录。这一点特别重要,因为像中文经过一系列处理后,它可能因为字符集或者编码集最终无法正确呈现。
    • 英文自带分词效果,像使用 ElasticSearch 这类倒排索引存储引擎存储日志,中文日志不仅需要添加专门的分词器,并且存储和查询效果不如英文。
  • 没有上下文的日志。类似直接打印 Transaction failed 或者 User operation succeeds
    这类日志。因为在写代码时通过代码上下文能够理解日志消息,但是当阅读日志本身时,这个上下文不存在,这些消息可能无法理解。
  • 将打印日志的操作放在循环当中。除非特定需求,否则打印出来的日志不仅难以阅读和查找,还会耗费大量存储资源。
  • 引用慢操作数据,如果当前上下文中没有打印日志需要的数据,需要调用远程服务或者从数据库获取,又或者通过大量计算,那应该先考虑这项信息放到日志中是不是必要且恰当的。

日志 visible

最近十年因为微服务和云原生的相继崛起,收集存储和分析日志领域发生了重大的变化。早期我们无需进行日志的收集,当时将单体服务的所有日志存储在文件当中,使用
tail、grep、awk 来从日志中挖掘信息。但是在系统日益复杂的今天,这种方式已经无法满足我们的需求。为了应对日益复杂的日志管理需求,开源社区和工业界也发展出一些列的方案,例如最为流行的
Elastic Stack 开源解决方案,云厂商提供的一站式解决方案像 AWS DataDog 和 Azure Dynatrace。

无论使用哪种方案,日志管理都已经不再是一个简单的话题。在我们有明确感知的打印日志和查询分析日志之间,还包含着对日志进行收集、缓冲、聚合、加工、索引、存储等若干个步骤,并且每一步都蕴含着艰难曲折。

日志 collection

最早我们使用 Elastic Stack 中的 Logstash 来进行日志的收集和加工。系统中不同的服务通过使用 tcp/udp 的协议,主动发送请求将日志推送到
Logstash 中,接着 Logstash 将日志进行转换加工(数据结构化)和输出。这种模式维持了很长一段时间,但是它也有比较严重的缺陷,那就是
Logstash 与它的插件是基于 JRuby 编写的,要跑在单独的 Java 虚拟机进程上,默认的堆大小就到了
1GB。如果需要部署成千上万个日志收集器,那么这种方案就显得太过沉重。所以后来 Elastic.co 公司使用 Golang
重写了一个功能较少,却更轻量高效的日志收集器 Filebeat 才缓解了这一矛盾。

除此之外 Fluentd 通常是配合 Kubernetes 时的首选开源日志收集器。它是 Kubernetes 原生的,可以使用 DaemonSet 的方式部署与
Kubernetes 无缝集成。它允许从不同的地方像 Kubernetes 集群、MySQL、Apache2 等收集日志,并解析发送到所需位置如
Elasticsearch、Amazon S3 等。Fluentd 用 Ruby 编写的,在低容量下运行良好,但当需要增加节点和应用程序的数量时,也会有会性能问题。

最后在日志收集时,有可能会因为业务峰期生成海量日志,影响服务稳定性和造成日志丢失。在这种情况下,我们还需要在 Logstash
或者存储日志数据库前加上一道缓冲层。在较小规模的系统中 Redis streams 是一个较好的选择,如果面对的规模更大的数据,那么 Kafka
集群或者云厂商提供的消息队列解决方案将是不二之选。

日志 struct

在收集完日志后,我们还需要进行结构化的处理。因为日志是非结构化数据,一行日志中通常会包含多项信息,如果不做处理,那只能以全文检索的原始方式去使用日志,这样既不利于统计对比,也不利于条件过滤。像下面这一行是
Nginx 服务器的 Access Log。

1
10.209.21.28 - - [04/Mar/2023:18:12:11 +0800] "GET /index.html HTTP/1.1" 200 1314 "https://guangzhengli.com" Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/110.0.0.0 Safari/537.36

尽管我们已经习惯了默认的 Nginx 格式,但上面的示例仍然难以阅读和处理。我们可以通过 Logstash 或者其它工具将它转换成结构化的数据,例如
JSON 格式。

1
2
3
4
5
6
7
8
9
10
11
12
{
"RemoteIp": "10.209.21.28",
"RemoteUser": null,
"Datetime": "04/Mar/2023:10:49:21 +0800",
"Method": "GET",
"URL": "/index.html",
"Protocol": "HTTP/1.1",
"Status": 200,
"Size": 1314,
"Refer": "https://guangzhengli.com",
"Agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/110.0.0.0 Safari/537.36"
}

经过结构化后,例如像 ElasticSearch 这类倒排索引数据库可以针对不同的数据项建立索引,进行查询统计、聚合等操作。

除此之外还有一种工业界的做法像 Splunk 推荐将字段变为 key-value 对的形式放在同一个大的规范日志行中(logfmt),如将 Nginx
日志作为规范日志行将变成如下这样:

1
remote-ip=10.209.21.28 remote-user=null datetime="04/Mar/2023:10:49:21 +0800" method=GET url=/index.html protocol=HTTP/1.1 status=200 size=1314 refer=https://guangzhengli.com agent="Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/110.0.0.0 Safari/537.36"

这类数据经过 Splunk 存储后,可以通过使用内置的查询语言进行检索,像使用 method=get status=500 查询所有返回 500 响应的 GET
方法。使用 method=get method=get status=500 earliest=-7d | timechart count 查询语句得到过去 7 天返回 500 响应的 GET
方法总数量和图表。

日志的存储与查询
经过日志的数据结构化后,可以将数据存入数据库中并进行查询分析。在选择使用什么方案来存储和分析之前,我们先来看看日志数据的特点。

  • 日志是写入密集型的,超过 99% 的日志写入后不会被查询使用。
  • 日志是标准的时间流数据,需要顺序写入,存储到数据库后,不会再进行修改变动。
  • 日志是具有时效性的,一般只需要最近一段时间的日志来查询分析或者排查故障,一段时间以后会被保留策略清除或者归档。
  • 日志是半结构化的,尽管我们将所有应用服务的日志都进行结构化,还是还包含系统日志,网络日志等日志,它们字段各不相同。
  • 查询日志依赖全文检索和即席查询(Ad-hoc search)。
  • 查询日志不要求日志具有强时效性,但是也无法接受按小时甚至按天的延时。

总览

日志框架-日志系统

目前 SpringBoot 目前支持 4 种类型的日志,分别是 JDK 内置的 Log(JavaLoggingSystem)以及 Log4j(Log4JLoggingSystem)、Log4j2(
Log4J2LoggingSystem)以及 Logback(LogbackLoggingSystem).

LoggingSystem 是个抽象类,内部有这几个方法:

  • beforeInitialize 方法:日志系统初始化之前需要处理的事情。抽象方法,不同的日志架构进行不同的处理
  • initialize 方法:初始化日志系统。默认不进行任何处理,需子类进行初始化工作
  • cleanUp 方法:日志系统的清除工作。默认不进行任何处理,需子类进行清除工作
  • getShutdownHandler 方法:返回一个 Runnable 用于当 jvm 退出的时候处理日志系统关闭后需要进行的操作,默认返回 null,也就是什么都不做
  • setLogLevel 方法:抽象方法,用于设置对应 logger 的级别

SpringBoot 在启动时,会完成 LoggingSystem 的初始化,这部分代码是在 LoggingApplicationListener 中实现的

有了 LoggingSystem 以后,我们就可以通过他的 setLogLevel 方法来动态的修改日志级别。他帮我们屏蔽掉了底层的具体日志框架。

1
2
3
4
5
6
7
8
@Autowired
private LoggingSystem loggingSystem;

在 setLoggerLevel 方法内根据获取的loglevel 进行修改就行了。具体参考实现类。

如果需要支持动态日志级别,可以做监听器,监听日志等级变更,然后去动态修改。

Arthas 也支持 线上动态修改。

java.util.logging (JUL)

JDK1.4 开始,通过 java.util.logging 提供日志功能。虽然是官方自带的 log lib,JUL 的使用确不广泛。

主要原因:JUL 从 JDK1.4 才开始加入(2002 年),当时各种第三方 log
lib 已经被广泛使用了 JUL 早期存在性能问题,到 JDK1.5 上才有了不错的进步,但现在和 Logback/Log4j2 相比还是有所不如 JUL
的功能不如 Logback/Log4j2 等完善,比如 Output
Handler 就没有 Logback/Log4j2 的丰富,有时候需要自己来继承定制,又比如默认没有从 ClassPath 里加载配置文件的功能

Log4j

Log4j 是 apache 的一个开源项目,创始人 Ceki Gulcu。

Log4j 应该说是 Java 领域资格最老,应用最广的日志工具。Log4j
是高度可配置的,并可通过在运行时的外部文件配置。它根据记录的优先级别,并提供机制,以指示记录信息到许多的目的地,诸如:数据库,文件,控制台,UNIX
系统日志等。Log4j 中有三个主要组成部分:

  • loggers - 负责捕获记录信息。
  • appenders - 负责发布日志信息,以不同的首选目的地。
  • layouts - 负责格式化不同风格的日志信息。
  • 官网地址:http://logging.apache.org/log4j/2.x/

Log4j 的短板在于性能,在 Logback 和 Log4j2 出来之后,Log4j 的使用也减少了。

Logback

Logback 是由 Log4j 创始人 Ceki Gülcü 设计的日志实现,也是 Spring Boot 默认使用的日志系统。业务代码通常通过 SLF4J API 打日志,Logback 负责完成日志事件的过滤、格式化、路由和输出。

在 Spring Boot 项目中,推荐始终保持下面的依赖方向:

1
2
3
4
5
6
7
8
9
业务代码

SLF4J API

Logback Classic

Appender

Console / File / Rolling File / Remote System

业务代码不要直接依赖 ch.qos.logback.classic.Logger,否则会把日志实现写死。正常业务代码只需要依赖 SLF4J:

1
2
3
4
5
6
7
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class SettlementService {

private static final Logger log = LoggerFactory.getLogger(SettlementService.class);
}

Logback 的三个模块

Logback 由三个主要模块组成:

  • logback-core:基础模块,提供 Appender、Encoder、Layout、Filter、RollingPolicy 等核心能力。
  • logback-classic:实现 SLF4J API,提供 Logger、LoggerContext、日志级别、MDC 等常用功能。
  • logback-access:面向 Servlet 容器访问日志的模块。现代 Spring Boot 项目也可以使用网关、Nginx、Tomcat Access Log 或应用过滤器记录访问日志,不一定必须引入它。

Spring Boot Starter 默认已经带入 slf4j-apilogback-corelogback-classic,普通项目不要手动指定一个与 Spring Boot 依赖管理冲突的 Logback 版本。

Logback 的核心执行模型

一条日志并不是直接写进文件。以如下代码为例:

1
log.info("finance bill calculate success, billId={}", billId);

大致会经历以下过程:

1
2
3
4
5
6
7
8
9
10
11
12
13
Logger 接收日志请求

根据 Logger 有效级别判断是否启用

创建 ILoggingEvent 日志事件

经过 TurboFilter / Appender Filter

根据 Logger 层级与 additivity 路由到 Appender

Encoder 将事件编码为文本或 JSON

Appender 输出到控制台、文件或其它目标

理解这个流程后,很多配置问题就不再神秘:

  • 日志完全没有出现:先检查 Logger 级别。
  • ERROR 出现在多个文件:检查多个 Appender 是否都接收到了同一个事件。
  • 自定义 Logger 出现重复日志:检查 additivity
  • 文件格式不符合预期:检查 Encoder,而不是只看 Appender。
  • 过滤规则不生效:区分 Logger 级别、Filter 和 Appender 的职责。

LoggerContext 与 Logger 层级

所有 Logger 都由 LoggerContext 管理,并按照名称形成树状层级。通常使用类的全限定名作为 Logger 名称:

1
2
3
4
5
ROOT
└── com
└── mario
└── finance
└── SettlementService

如果 com.mario.finance.SettlementService 没有显式配置级别,它会向上查找最近的已配置祖先,最终至少会继承 ROOT Logger 的级别。

日志级别的基本选择规则是:

1
TRACE < DEBUG < INFO < WARN < ERROR

只有日志事件级别大于或等于 Logger 的有效级别时,事件才会继续处理。例如 Logger 有效级别为 INFO 时:

日志调用 是否创建并输出日志事件
log.trace(...)
log.debug(...)
log.info(...)
log.warn(...)
log.error(...)

Logback 没有独立的 FATAL 级别。在 Spring Boot 中,FATAL 会映射为 ERROR

Appender 与日志路由

Appender 决定日志输出到哪里。常见 Appender 包括:

Appender 用途
ConsoleAppender 输出到标准输出或标准错误
FileAppender 持续写入固定文件
RollingFileAppender 按时间、大小等条件滚动归档
AsyncAppender 使用队列和后台线程转发日志事件
SocketAppenderSyslogAppender 将日志发送到远程系统

一个 Logger 可以关联多个 Appender,因此一条 ERROR 日志可以同时进入:

  • 控制台;
  • application.log
  • error.log

这不是重复打印错误,而是有意进行多目标路由。真正容易造成意外重复的是 Logger 的叠加性。

additivity:最常见的重复日志原因

Logger 默认 additivity="true"。子 Logger 的事件不仅会发送到自己的 Appender,还会继续向父 Logger 传播,直到 ROOT。

例如:

1
2
3
4
5
6
7
8
<logger name="BIZ_FINANCE" level="INFO">
<appender-ref ref="BIZ_FILE"/>
</logger>

<root level="INFO">
<appender-ref ref="CONSOLE"/>
<appender-ref ref="APP_FILE"/>
</root>

BIZ_FINANCE 的日志会同时进入 BIZ_FILECONSOLEAPP_FILE。如果只希望它进入业务文件,需要显式关闭叠加:

1
2
3
<logger name="BIZ_FINANCE" level="INFO" additivity="false">
<appender-ref ref="BIZ_FILE"/>
</logger>

不要看到重复日志就到处添加 additivity="false"。先明确该 Logger 是否应该继续进入主日志,再决定是否切断传播链路。

Encoder 与 Layout

Layout 负责把日志事件转换为格式化结果,Encoder 负责把日志事件编码成字节并写给 OutputStream 类型的 Appender。

在现代 Logback 配置中,最常用的是 PatternLayoutEncoder

1
2
3
4
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%thread] %logger{36} - %msg%n</pattern>
<charset>UTF-8</charset>
</encoder>

它可以理解为 PatternLayout 与字符编码输出的组合。对于 ConsoleAppenderFileAppenderRollingFileAppender,优先配置 <encoder>,不要照搬过时示例直接挂载 <layout>

常用 Pattern:

Pattern 含义
%d{...} 时间
%-5level 日志级别,左对齐占五个字符
%thread 线程名
%logger{36} Logger 名称,最长显示 36 个字符
%msg 格式化后的消息
%n 换行
%X{traceId:-} 读取 MDC 中的 traceId
%kvp 输出 SLF4J Fluent API 添加的键值字段
%wEx Spring Boot 提供的扩展异常格式

生产日志一般不要使用 %class%method%line%caller 等位置信息。这些信息通常需要分析调用栈,尤其在异步日志中代价更高。

Filter:对已经进入日志系统的事件做精细过滤

Logger 级别负责第一层粗粒度筛选,Filter 负责 Appender 级别的精细路由。

Logback Filter 使用三态结果:

  • DENY:立即拒绝事件;
  • NEUTRAL:交给后续 Filter 继续判断;
  • ACCEPT:立即接受事件。

两个最常用的 Filter:

LevelFilter:只匹配一个精确级别
1
2
3
4
5
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>

适用于只把 ERROR 镜像到 error.log

ThresholdFilter:接受阈值及以上级别
1
2
3
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>WARN</level>
</filter>

它会拒绝 TRACE、DEBUG、INFO,允许 WARN、ERROR 继续处理。

两者不要混淆:

1
2
LevelFilter(ERROR)      = 只接受 ERROR
ThresholdFilter(WARN) = 接受 WARN 和 ERROR

TurboFilter 的作用域是整个 LoggerContext,并且可以在创建完整日志事件之前进行判断,适合全局、高性能过滤或基于 MDC、Marker 的动态阈值控制。普通业务项目如果没有明确需求,不要为了“高级”而自定义 TurboFilter,复杂过滤规则很容易变成线上日志黑洞。

RollingPolicy 与 TriggeringPolicy

RollingFileAppender 负责写活动文件,但什么时候滚动、归档文件叫什么,由滚动策略决定。

Logback 常用两类策略:

  • TimeBasedRollingPolicy:按照时间滚动,例如每天一个归档。
  • SizeAndTimeBasedRollingPolicy:按时间分段,同时限制单个文件大小。

如果只需要“每天滚动,并限制所有历史归档的总大小”,优先使用 TimeBasedRollingPolicy + totalSizeCap。只有日志平台、传输链路或运维工具要求限制单文件大小时,才使用 SizeAndTimeBasedRollingPolicy

使用大小与时间组合滚动时,fileNamePattern 必须同时包含 %d%i

1
<fileNamePattern>application.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>

其中:

  • %d 决定时间周期;
  • %i 是同一周期内因文件大小触发的递增序号;
  • .gz 表示滚动后压缩归档。

MDC:线程级诊断上下文

MDC 适合保存贯穿一次请求或任务生命周期的上下文:

1
2
3
4
5
6
7
8
try {
MDC.put("traceId", traceId);
MDC.put("requestId", requestId);
MDC.put("tenantId", tenantId);
service.execute();
} finally {
MDC.clear();
}

配置中通过 %X{key} 读取:

1
<pattern>traceId=%X{traceId:-} requestId=%X{requestId:-} %msg%n</pattern>

需要特别注意:MDC 是线程上下文,子线程和线程池任务不会自动可靠继承父线程的 MDC。使用线程池、CompletableFuture@Async、Spring Event、消息消费或虚拟线程任务时,都要确认上下文透传和执行后清理策略。

Logback 配置文件的选择

原生 Logback 常见配置文件包括:

  • logback-test.xml:通常用于测试环境;
  • logback.xml:原生 Logback 配置;
  • 通过 -Dlogback.configurationFile=... 指定的外部配置。

Spring Boot 项目推荐使用:

1
src/main/resources/logback-spring.xml

原因是 logback-spring.xml 可以使用 Spring Boot 扩展:

  • <springProperty>:读取 Spring Environment 属性;
  • <springProfile>:按照 Spring Profile 启用配置片段;
  • Spring Boot 的 %clr%wEx、结构化日志 Encoder 等能力。

普通 logback.xml 加载得更早,不能稳定使用这些 Spring Boot 扩展。

为什么不要在 logback-spring.xml 中使用 scan

原生 Logback 支持:

1
<configuration scan="true" scanPeriod="60 seconds">

但 Spring Boot 的 <springProperty><springProfile> 扩展与 Logback 配置扫描不兼容。因此只要使用 logback-spring.xml 和 Spring 扩展,就不要开启 scan="true"

错误组合通常会出现类似日志:

1
2
no applicable action for [springProperty]
no applicable action for [springProfile]

需要动态调整日志级别时,应使用 Spring Boot Actuator、Arthas、配置中心监听或 LoggingSystem,而不是依赖 XML 自动扫描。

属性作用域与属性来源

Logback 原生 <property> 适合定义 XML 内部变量:

1
<property name="LOG_DIR" value="./logs"/>

Spring Boot <springProperty> 可以读取 application.yml、环境变量和启动参数:

1
2
3
4
<springProperty scope="context"
name="APP_NAME"
source="spring.application.name"
defaultValue="application"/>

source 建议使用 kebab-case 的配置名,例如:

1
2
app.logging.instance-name
logging.logback.rollingpolicy.max-file-size

属性职责建议保持清晰:

  • application.yml:环境差异、Logger 级别、日志组、容量参数;
  • logback-spring.xml:Appender、Encoder、Filter、日志路由结构;
  • 环境变量:容器实例名、日志目录、环境名称等部署参数。

配置诊断

Logback 配置没有生效时,可以临时打开内部状态输出:

1
<configuration debug="true">

这里的 debug="true" 只会输出 Logback 自身的配置过程,不会把 ROOT Logger 改成 DEBUG。

也可以通过 JVM 参数强制输出状态信息:

1
-Dlogback.statusListenerClass=ch.qos.logback.core.status.OnConsoleStatusListener

定位完成后应关闭详细状态输出,避免生产启动日志过多。

官网地址:Logback

Log4j2

维护 Log4j 的人为了性能又搞出了 Log4j2。Log4j2 和 Log4j1.x 并不兼容,设计上很大程度上模仿了
SLF4J/Logback,性能上也获得了很大的提升。Log4j2 也做了 Facade/Implementation 分离的设计,分成了 log4j-api 和 log4j-core。
官网地址: http://logging.apache.org/log4j/2.x/

Log4j vs Logback vs Log4j2

从性能上 Log4J2 要强,但从生态上 Logback+SLF4J 优先

为什么禁止工程师直接使用日志系统中的 API

  • 使用门面日志系统,解耦。
  • 门面模式针对日志系统做了优化性的封装

门面型日志框架

最常见的门面模式/外观模式应用场景,面试被问设计模式再也不害怕啦!

JCL

Jakarta Commons-logging

他是 apache 开源的对 jdk log 进行封装的 log 组件,是一套 Java 日志接口。他可以配合 log4j.不需要强依赖他们。松耦合的状态。

  1. 首先去找配置文件 commons-logging.properties,找不到的情况那么默认 Log 的实现类。
  2. 找到是否有其他的组件库比如 log4j
  3. 找不到用 jdk 的原生
  4. 找不到结合 commons-logging 自己提供这个日志实现类

官网地址: http://commons.apache.org/proper/commons-logging/

Sel4j

Simple Logging Facade for Java,缩写 Slf4j。是一套简易 Java 日志门面,本身并无日志的实现。

已经有 log 组件了,为什么还要再开发一套新的组件?

  • log 打印的时候支持通配符
  • 封装的比较完整
  • 速度比较快
  • 不会影响 gc
  • 支持异步不影响业务设计的比较清晰

官网地址: http://www.slf4j.org/

细节差异:

  • Log4j 提供 TRACE, DEBUG, INFO, WARN, ERROR 及 FATAL 六种纪录等级,但是 SLF4J 认为 ERROR 与 FATAL 并没有实质上的差别,所以拿掉了
    FATAL 等级,只剩下其他五种。
  • 大部分人在程序里面会去写 logger.error(exception),其实这个时候 Log4j 会去把这个 exception tostring。真正的写法应该是
    logger(
    message.exception);而 SLF4J 就不会使得程序员犯这个错误。
  • Log4j 间接的在鼓励程序员使用 string 相加的写法(这种写法是有性能问题的),而 SLF4J 就不会有这个问题
    ,你可以使用 logger.error(“{} is+serviceid”,serviceid);
  • SLF4J 只支持 MDC,不支持 NDC。

选型

日志打点 API 绑定实现

slf4j-api 和 log4j-api 都是接口,不提供具体实现,理论上基于这两种 api 输出的日志可以绑定到很多的日志实现上。slf4j 和 log4j2
也确实提供了很多的绑定器。简单列举几种可能的绑定链:

  • slf4j → logback
  • slf4j → slf4j-log4j12 → log4j
  • slf4j → log4j-slf4j-impl → log4j2
  • slf4j → slf4j-jdk14 → jul
  • slf4j → slf4j-jcl → jcl
  • jcl → jul
  • jcl → log4j
  • log4j2-api → log4j2-cor
  • log4j2-api → log4j-to-slf4j → slf4j

环图

对 Java 日志组件选型的建议

slf4j 已经成为了 Java 日志组件的明星选手,可以完美替代 JCL,使用 JCL 桥接库也能完美兼容一切使用 JCL
作为日志门面的类库,现在的新系统已经没有不使用 slf4j 作为日志 API 的理由了。日志记录服务方面,log4j 在功能上输于 logback 和
log4j2,在性能方面 log4j2 则全面超越 log4j 和 logback。所以新系统应该在 logback 和 log4j2 中做出选择,对于性能有很高要求的系统,应优先考虑
log4j2

对日志架构使用比较好的实践

总是使用 Log Facade,而不是具体 Log Implementation

正如之前所说的,使用 Log Facade 可以方便的切换具体的日志实现。而且,如果依赖多个项目,使用了不同的 Log Facade,还可以方便的通过
Adapter 转接到同一个实现上。如果依赖项目使用了多个不同的日志实现,就麻烦的多了。

具体来说,现在推荐使用 Log4j-API 或者 SLF4j,不推荐继续使用 JCL。

只添加一个 Log Implementation 依赖

毫无疑问,项目中应该只使用一个具体的 Log Implementation,建议使用 Logback 或者 Log4j2。如果有依赖的项目中,使用的 Log
Facade 不支持直接使用当前的 Log Implementation,就添加合适的桥接器依赖。

具体的日志实现依赖应该设置为 optional 和使用 runtime scope

在项目中,Log Implementation 的依赖强烈建议设置为 runtime scope,并且设置为 optional。例如项目中使用了 SLF4J 作为 Log
Facade,然后想使用 Log4j2 作为 Implementation,那么使用 maven 添加依赖的时候这样设置:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-core</artifactId>
<version>${log4j.version}</version>
<scope>runtime</scope>
<optional>true</optional>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-slf4j-impl</artifactId>
<version>${log4j.version}</version>
<scope>runtime</scope>
<optional>true</optional>
</dependency>

设为 optional,依赖不会传递,这样如果你是个 lib 项目,然后别的项目使用了你这个 lib,不会被引入不想要的 Log Implementation
依赖;

Scope 设置为 runtime,是为了防止开发人员在项目中直接使用 Log Implementation 中的类,而不适用 Log Facade 中的类。

如果有必要, 排除依赖的第三方库中的 Log Impementation 依赖

这是很常见的一个问题,第三方库的开发者未必会把具体的日志实现或者桥接器的依赖设置为
optional,然后你的项目继承了这些依赖——具体的日志实现未必是你想使用的,比如他依赖了 Log4j,你想使用
Logback,这时就很尴尬。另外,如果不同的第三方依赖使用了不同的桥接器和 Log 实现,也极容易形成环。

这种情况下,推荐的处理方法,是使用 exclude 来排除所有的这些 Log 实现和桥接器的依赖,只保留第三方库里面对 Log Facade 的依赖。

比如阿里的 JStorm 就没有很好的处理这个问题,依赖 jstorm 会引入对 Logback 和 log4j-over-slf4j 的依赖,如果你想在自己的项目中使用
Log4j 或其他 Log 实现的话,就需要加上 excludes:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
<dependency>
<groupId>com.alibaba.jstorm</groupId>
<artifactId>jstorm-core</artifactId>
<version>2.1.1</version>
<exclusions>
<exclusion>
<groupId>org.slf4j</groupId>
<artifactId>log4j-over-slf4j</artifactId>
</exclusion>
<exclusion>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
</exclusion>
</exclusions>
</dependency>

避免为不会输出的 log 付出代价

Log 库都可以灵活的设置输出界别,所以每一条程序中的 log,都是有可能不会被输出的。这时候要注意不要额外的付出代价。

先看两个有问题的写法:

1
2
logger.debug("start process request, url: " + url);
logger.debug("receive request: {}", toJson(request));

第一条是直接做了字符串拼接,所以即使日志级别高于 debug 也会做一个字符串连接操作;

第二条虽然用了 SLF4J/Log4j2 中的懒求值方式来避免不必要的字符串拼接开销,但是 toJson()这个函数却是都会被调用并且开销更大。

推荐的写法如下:

1
2
3
4
5
6
logger.debug("start process request, url:{}", url); // SLF4J/LOG4J2
logger.debug("receive request: {}", () -> toJson(request)); // LOG4J2
logger.debug(() -> "receive request: " + toJson(request)); // LOG4J2
if (logger.isDebugEnabled()) { // SLF4J/LOG4J2
logger.debug("receive request: " + toJson(request));
}

日志格式中最好不要使用行号,函数名等字段

原因是,为了获取语句所在的函数名,或者行号,log 库的实现都是获取当前的 stacktrace,然后分析取出这些信息,而获取 stacktrace
的代价是很昂贵的。如果有很多的日志输出,就会占用大量的 CPU。在没有特殊需要的情况下,建议不要在日志中输出这些这些字段。

最后, log 中不要输出稀奇古怪的字符!

部分开发人员为了方便看到自己的 log,会在 log 语句中加上醒目的前缀,比如:

1
logger.debug("========================start process request=============");

虽然对于自己来说是方便了,但是如果所有人都这样来做的话,那 log 输出就没法看了!正确的做法是使用 grep 来看只自己关心的日志。

Spring Boot 日志分组(Log Groups)

Spring Boot 的“日志分组”解决的是一组 Logger 统一调整日志级别的问题,它不是把日志拆分到不同文件。两者要区分:

  • 日志分组:logging.group.*,用于批量控制多个包或 Logger 的级别。
  • 日志路由:Logback 的 Logger + Appender + Filter,用于决定日志写到控制台、主文件、错误文件还是审计文件。

例如 Web、数据库、RPC、消息队列通常包含多个包。没有日志分组时,每次排查都要逐个调整:

1
2
3
4
5
6
logging:
level:
org.springframework.web: debug
org.springframework.http: debug
org.apache.catalina: debug
org.apache.coyote: debug

定义分组后,只需要调整一个逻辑名称:

1
2
3
4
5
6
7
8
9
10
11
12
13
logging:
group:
web-stack: org.springframework.web,org.springframework.http,org.apache.catalina,org.apache.coyote
persistence: org.mybatis,org.mybatis.spring,com.baomidou.mybatisplus,org.springframework.jdbc,org.hibernate.SQL
rpc: org.apache.dubbo,io.grpc
messaging: org.springframework.kafka,org.springframework.amqp

level:
root: info
web-stack: info
persistence: warn
rpc: info
messaging: info

Spring Boot 还内置了两个常用分组:

  • web:Spring Web、HTTP 编解码和 Web Actuator 等相关 Logger。
  • sql:Spring JDBC、Hibernate SQL 和 jOOQ SQL 相关 Logger。

可以直接使用:

1
2
3
4
logging:
level:
web: info
sql: warn

需要注意,内置 sql 分组并不等于“所有数据库框架日志”,MyBatis、MyBatis-Plus、数据库连接池以及 Hibernate 参数绑定 Logger 仍可能需要加入自定义分组。企业项目更推荐定义自己的 persistence 分组,让日志口径不依赖 Spring Boot 内置分组未来是否调整。

按环境调整分组

公共配置 application.yml 只定义分组和稳妥的默认级别:

1
2
3
4
5
6
7
8
9
10
11
12
13
logging:
group:
web-stack: org.springframework.web,org.springframework.http,org.apache.catalina,org.apache.coyote
persistence: org.mybatis,org.mybatis.spring,com.baomidou.mybatisplus,org.springframework.jdbc,org.hibernate.SQL
rpc: org.apache.dubbo,io.grpc
messaging: org.springframework.kafka,org.springframework.amqp

level:
root: info
web-stack: info
persistence: warn
rpc: info
messaging: info

开发环境 application-dev.yml 临时放开:

1
2
3
4
5
logging:
level:
web-stack: debug
persistence: debug
rpc: debug

生产环境 application-prod.yml 保持克制:

1
2
3
4
5
6
7
logging:
level:
root: info
web-stack: info
persistence: warn
rpc: info
messaging: info

线上排障时应该只将目标分组或目标包临时调整为 DEBUG,不要直接把 root 改成 DEBUG。否则 SQL、网络、心跳、连接池和框架内部日志可能一起涌出,磁盘会比问题先“解决”服务。

Spring Boot 滚动日志

Spring Boot 默认只输出控制台日志。配置 logging.file.namelogging.file.path 后,才会启用默认文件输出。

1
2
3
logging:
file:
name: ./logs/application.log

或者:

1
2
3
logging:
file:
path: ./logs

两者同时配置时,logging.file.name 优先,logging.file.path 会被忽略。

Spring Boot 3.5 对 Logback 提供以下滚动配置:

配置项 作用
logging.logback.rollingpolicy.file-name-pattern 归档文件命名规则
logging.logback.rollingpolicy.max-file-size 活动文件达到多大后按大小滚动
logging.logback.rollingpolicy.max-history 最多保留多少个时间周期
logging.logback.rollingpolicy.total-size-cap 所有历史归档允许占用的总空间
logging.logback.rollingpolicy.clean-history-on-start 启动时是否立即执行历史归档清理

Spring Boot 3.5 默认文件达到 10MB 时滚动,默认最多保留 7 个归档周期。生产环境建议显式配置,不要让容量治理依赖隐含默认值。

不使用自定义 XML 的滚动配置

简单项目可以只使用 application.yml

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
spring:
application:
name: finance-bill-service

logging:
file:
name: ${LOG_FILE:./logs/${spring.application.name}.log}

logback:
rollingpolicy:
file-name-pattern: ${LOG_ARCHIVE:./logs/archive}/${spring.application.name}.%d{yyyy-MM-dd}.%i.log.gz
max-file-size: 100MB
max-history: 30
total-size-cap: 10GB
clean-history-on-start: false

这套配置同时按照日期和大小滚动:

1
2
3
finance-bill-service.2026-07-16.0.log.gz
finance-bill-service.2026-07-16.1.log.gz
finance-bill-service.2026-07-17.0.log.gz

需要注意:

  1. 使用 SizeAndTimeBasedRollingPolicy 时,归档文件名必须同时包含 %d%i
  2. .gz 表示归档后压缩,适合文本日志。
  3. max-history 的含义是保留时间周期,不是简单保留文件个数。按天滚动时 30 表示保留约 30 天;一天内可能因为大小限制产生多个归档文件。
  4. total-size-cap 只有在配置了 max-history 后才生效,并且先执行历史周期限制,再执行总大小限制。
  5. total-size-cap 按 RollingPolicy/Appender 独立计算。主日志配置 10GB、ERROR 日志配置 2GB,总预算接近 12GB,不是 10GB
  6. clean-history-on-start=false 是更稳妥的长生命周期服务默认值。短生命周期任务、频繁重启服务或长期没有发生滚动的应用,可以根据归档数量与启动 I/O 情况改为 true
  7. 多实例不要共同写同一个活动文件。应该至少按应用名和实例名拆目录,避免归档竞争、覆盖、删除冲突和文件锁问题。
  8. Kubernetes 优先输出 stdout/stderr,由容器运行时和日志采集组件负责轮转。应用内文件滚动更适合虚拟机、物理机、传统容器挂载盘或本地兜底场景。

TimeBasedRollingPolicy 还是 SizeAndTimeBasedRollingPolicy

两种常用选择:

只按时间滚动
1
2
3
4
5
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>${LOG_DIR}/archive/application.%d{yyyy-MM-dd}.log.gz</fileNamePattern>
<maxHistory>30</maxHistory>
<totalSizeCap>10GB</totalSizeCap>
</rollingPolicy>

适合:

  • 每日日志量可控;
  • 日志采集系统不限制单文件大小;
  • 希望减少同一天大量文件重命名和归档操作。
按时间和大小滚动
1
2
3
4
5
6
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>${LOG_DIR}/archive/application.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
<maxFileSize>100MB</maxFileSize>
<maxHistory>30</maxHistory>
<totalSizeCap>10GB</totalSizeCap>
</rollingPolicy>

适合:

  • 单日日志量较大;
  • 日志采集或上传系统限制单文件大小;
  • 运维明确要求归档文件不能超过固定容量。

Logback 官方并不建议在没有真实需求时机械使用大小滚动。文件重命名和归档不是免费的,配置要服务于部署和采集约束,而不是为了让 XML 看起来更忙。

推荐的文件拆分方式

不推荐默认拆成 DEBUG、INFO、WARN、ERROR 四个互斥文件。更实用的生产方案是:

1
2
3
4
5
6
7
8
logs/
└── finance-bill-service/
└── finance-bill-service-7d96c6f8b7-abcde/
├── application.log
├── error.log
└── archive/
├── application.2026-07-16.0.log.gz
└── error.2026-07-16.0.log.gz

职责划分:

  • application.log:保存所有通过 Logger 级别判断后的应用日志。
  • error.log:额外镜像 ERROR,方便快速检索、告警和设置独立保留周期。
  • audit.log:只有确实存在审计需求时单独输出;资金、合同、结算证据不能只依赖普通日志文件。
  • access.log:HTTP 访问日志由网关、Nginx、Tomcat Access Log 或专门 Filter 负责,不和业务日志混在一起。

java 日志模板 logback

Spring Boot 项目建议将配置文件命名为:

1
src/main/resources/logback-spring.xml

下面这份 V3 模板面向 Spring Boot 3.5、SLF4J 2.x 和 Logback 1.5.x,支持三种运行模式:

  • local/dev/test:人类可读的彩色控制台日志,不主动写文件。
  • k8s:控制台输出 Spring Boot 结构化 JSON,由采集组件收集。
  • 其它环境:控制台 + 异步主文件 + 同步 ERROR 镜像。

模板设计原则:

  • 不开启 scan,避免与 <springProperty><springProfile> 冲突。
  • 日志级别放在 application.yml 管理,XML 负责输出结构和路由。
  • 主日志异步削峰,ERROR 文件同步保底。
  • 默认不丢弃 TRACE、DEBUG、INFO,但队列满时会反压业务线程。
  • 不采集调用方行号、类名和方法名等昂贵位置信息。
  • 日志目录包含应用名和实例名,避免多实例共写一个文件。
  • 主日志与 ERROR 镜像分别设置磁盘容量上限。
  • K8s 使用 Spring Boot 3.4+ 自带的 StructuredLogEncoder,不额外引入第三方 JSON Encoder。

完整 logback-spring.xml

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
<?xml version="1.0" encoding="UTF-8"?>
<configuration>

<!--
不要在这里配置 scan="true"。
Spring Boot 的 springProperty / springProfile 扩展不能与 Logback 自动扫描同时使用。
-->

<!--
复用 Spring Boot 默认变量和转换器:
- %clr:控制台颜色
- %wEx:Spring Boot 扩展异常输出
- LOG_EXCEPTION_CONVERSION_WORD 等默认属性
-->
<include resource="org/springframework/boot/logging/logback/defaults.xml"/>

<!-- ========================= 1. Spring Environment 属性 ========================= -->

<!-- 当前应用名称 -->
<springProperty scope="context"
name="APP_NAME"
source="spring.application.name"
defaultValue="application"/>

<!-- 当前激活环境,例如 dev、test、prod、k8s -->
<springProperty scope="context"
name="APP_ENV"
source="spring.profiles.active"
defaultValue="default"/>

<!-- 日志根目录。传统部署可设置 LOG_HOME=/data/logs -->
<springProperty scope="context"
name="LOG_HOME"
source="logging.file.path"
defaultValue="./logs"/>

<!--
实例名用于隔离多实例日志。
推荐在 application.yml 中映射 INSTANCE_ID 或 HOSTNAME。
-->
<springProperty scope="context"
name="INSTANCE_NAME"
source="app.logging.instance-name"
defaultValue="local"/>

<!-- ROOT Logger 默认级别,仍建议通过 logging.level.root 管理 -->
<springProperty scope="context"
name="ROOT_LOG_LEVEL"
source="logging.level.root"
defaultValue="INFO"/>

<!-- 主日志滚动参数 -->
<springProperty scope="context"
name="MAX_FILE_SIZE"
source="logging.logback.rollingpolicy.max-file-size"
defaultValue="100MB"/>
<springProperty scope="context"
name="MAX_HISTORY"
source="logging.logback.rollingpolicy.max-history"
defaultValue="30"/>
<springProperty scope="context"
name="TOTAL_SIZE_CAP"
source="logging.logback.rollingpolicy.total-size-cap"
defaultValue="10GB"/>
<springProperty scope="context"
name="CLEAN_HISTORY_ON_START"
source="logging.logback.rollingpolicy.clean-history-on-start"
defaultValue="false"/>

<!-- ERROR 镜像单独设置容量,避免与主日志各占一份 10GB -->
<springProperty scope="context"
name="ERROR_TOTAL_SIZE_CAP"
source="app.logging.error-total-size-cap"
defaultValue="2GB"/>

<!-- AsyncAppender 参数 -->
<springProperty scope="context"
name="ASYNC_QUEUE_SIZE"
source="app.logging.async.queue-size"
defaultValue="8192"/>
<springProperty scope="context"
name="ASYNC_DISCARDING_THRESHOLD"
source="app.logging.async.discarding-threshold"
defaultValue="0"/>
<springProperty scope="context"
name="ASYNC_NEVER_BLOCK"
source="app.logging.async.never-block"
defaultValue="false"/>
<springProperty scope="context"
name="ASYNC_MAX_FLUSH_TIME"
source="app.logging.async.max-flush-time"
defaultValue="5000"/>

<!-- K8s 结构化日志格式:ecs / gelf / logstash -->
<springProperty scope="context"
name="CONSOLE_STRUCTURED_FORMAT"
source="logging.structured.format.console"
defaultValue="ecs"/>

<!-- 每个应用、每个实例独立目录,避免多个 JVM 或 Pod 争用同一个活动文件 -->
<property name="LOG_DIR" value="${LOG_HOME}/${APP_NAME}/${INSTANCE_NAME}"/>

<!-- LoggerContext 名称,排查同一进程中的多个日志上下文时有用 -->
<contextName>${APP_NAME}</contextName>

<!-- ========================= 2. 日志格式 ========================= -->

<!--
技术链路字段建议直接兼容 Micrometer Tracing 常用的 traceId / spanId。
requestId、tenantId、userId、entId 由网关、Filter 或业务上下文写入 MDC。
-->
<property name="MDC_LOG_PATTERN"
value="traceId=%X{traceId:-} spanId=%X{spanId:-} requestId=%X{requestId:-} tenantId=%X{tenantId:-} userId=%X{userId:-} entId=%X{entId:-}"/>

<!--
文件日志不输出颜色控制字符。
%kvp 输出 SLF4J 2.0 Fluent API 的 addKeyValue 字段。
不使用 %class、%method、%line、%caller,避免解析调用栈。
-->
<property name="V3_FILE_LOG_PATTERN"
value="%d{yyyy-MM-dd'T'HH:mm:ss.SSSXXX} %-5level app=${APP_NAME} env=${APP_ENV} instance=${INSTANCE_NAME} pid=${PID} [%thread] %logger{48} ${MDC_LOG_PATTERN} %kvp - %msg%n${LOG_EXCEPTION_CONVERSION_WORD}"/>

<!-- 本地控制台日志:保留颜色,方便开发阅读 -->
<property name="V3_CONSOLE_LOG_PATTERN"
value="%clr(%d{yyyy-MM-dd'T'HH:mm:ss.SSSXXX}){faint} %clr(%-5level) %clr(${PID}){magenta} %clr([%thread]){faint} %clr(%logger{40}){cyan} ${MDC_LOG_PATTERN} %kvp %clr(:){faint} %msg%n${LOG_EXCEPTION_CONVERSION_WORD}"/>

<!-- ========================= 3. 通用控制台 Appender ========================= -->

<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<pattern>${V3_CONSOLE_LOG_PATTERN}</pattern>
<charset>UTF-8</charset>
</encoder>
</appender>

<!-- ========================= 4. 本地、开发、测试环境 ========================= -->

<springProfile name="(local | dev | test) &amp; !k8s">
<!--
开发环境只输出控制台,减少本机日志目录污染。
需要本地文件时,可以把 ASYNC_APP_FILE 等配置提取为公共 Appender 后再引用。
-->
<root level="${ROOT_LOG_LEVEL}">
<appender-ref ref="CONSOLE"/>
</root>
</springProfile>

<!-- ========================= 5. Kubernetes 结构化日志 ========================= -->

<springProfile name="k8s">
<!--
Spring Boot 3.4+ 内置 StructuredLogEncoder。
ECS、GELF、Logstash 格式均会自动包含 MDC 和 SLF4J Fluent KeyValue 字段。
-->
<appender name="JSON_CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder class="org.springframework.boot.logging.logback.StructuredLogEncoder">
<format>${CONSOLE_STRUCTURED_FORMAT}</format>
<charset>UTF-8</charset>
</encoder>
</appender>

<!--
K8s 中优先只写 stdout,由 Fluent Bit、Vector、Filebeat 等组件采集。
不在容器可写层重复落盘,避免应用滚动与容器轮转互相打架。
-->
<root level="${ROOT_LOG_LEVEL}">
<appender-ref ref="JSON_CONSOLE"/>
</root>
</springProfile>

<!-- ========================= 6. 传统生产部署:控制台 + 文件 ========================= -->

<springProfile name="!local &amp; !dev &amp; !test &amp; !k8s">

<!-- 主日志同步写入目标。真正挂到 ROOT 上的是后面的 ASYNC_APP_FILE。 -->
<appender name="APP_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${LOG_DIR}/application.log</file>
<append>true</append>

<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<pattern>${V3_FILE_LOG_PATTERN}</pattern>
<charset>UTF-8</charset>
</encoder>

<!--
按天 + 按大小滚动:
- %d:时间周期
- %i:同一周期内的大小滚动序号
- .gz:归档压缩
-->
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>${LOG_DIR}/archive/application.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
<maxFileSize>${MAX_FILE_SIZE}</maxFileSize>
<maxHistory>${MAX_HISTORY}</maxHistory>
<totalSizeCap>${TOTAL_SIZE_CAP}</totalSizeCap>
<cleanHistoryOnStart>${CLEAN_HISTORY_ON_START}</cleanHistoryOnStart>
</rollingPolicy>
</appender>

<!--
主日志异步削峰:
- queueSize:队列容量,不是字节数,而是日志事件数量
- discardingThreshold=0:不在队列剩余 20% 时自动丢弃 TRACE/DEBUG/INFO
- neverBlock=false:队列满时阻塞业务线程,优先保证日志完整
- includeCallerData=false:不采集昂贵的调用方位置信息
- maxFlushTime=5000:正常关闭时最多等待 5 秒冲刷队列
-->
<appender name="ASYNC_APP_FILE" class="ch.qos.logback.classic.AsyncAppender">
<queueSize>${ASYNC_QUEUE_SIZE}</queueSize>
<discardingThreshold>${ASYNC_DISCARDING_THRESHOLD}</discardingThreshold>
<neverBlock>${ASYNC_NEVER_BLOCK}</neverBlock>
<includeCallerData>false</includeCallerData>
<maxFlushTime>${ASYNC_MAX_FLUSH_TIME}</maxFlushTime>
<appender-ref ref="APP_FILE"/>
</appender>

<!-- ERROR 镜像保持同步,主异步队列拥堵时仍保留关键错误证据。 -->
<appender name="ERROR_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${LOG_DIR}/error.log</file>
<append>true</append>

<!-- LevelFilter 是精确匹配,只接收 ERROR。 -->
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>

<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<pattern>${V3_FILE_LOG_PATTERN}</pattern>
<charset>UTF-8</charset>
</encoder>

<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>${LOG_DIR}/archive/error.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
<maxFileSize>${MAX_FILE_SIZE}</maxFileSize>
<maxHistory>${MAX_HISTORY}</maxHistory>
<totalSizeCap>${ERROR_TOTAL_SIZE_CAP}</totalSizeCap>
<cleanHistoryOnStart>${CLEAN_HISTORY_ON_START}</cleanHistoryOnStart>
</rollingPolicy>
</appender>

<!--
Logger 级别不要在 XML 和 application.yml 两边重复维护。
ERROR 会进入:CONSOLE + application.log + error.log。
-->
<root level="${ROOT_LOG_LEVEL}">
<appender-ref ref="CONSOLE"/>
<appender-ref ref="ASYNC_APP_FILE"/>
<appender-ref ref="ERROR_FILE"/>
</root>
</springProfile>

</configuration>

对应 application.yml

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
spring:
application:
name: finance-bill-service

# 自定义日志运行参数,由 logback-spring.xml 的 springProperty 读取
app:
logging:
# K8s 中 HOSTNAME 通常就是 Pod 名;传统服务器可显式传 INSTANCE_ID
instance-name: ${INSTANCE_ID:${HOSTNAME:local}}

# ERROR 镜像的独立磁盘预算
error-total-size-cap: 2GB

async:
# 单位是日志事件数量,需要结合日志峰值、平均事件大小和堆内存压测
queue-size: 8192

# 0 表示不按 Logback 默认策略提前丢弃 TRACE/DEBUG/INFO
discarding-threshold: 0

# false:队列满时阻塞;true:队列满时直接丢日志
never-block: false

# JVM 正常关闭时,等待异步队列冲刷的最大毫秒数
max-flush-time: 5000

logging:
# 传统文件部署使用;K8s profile 不引用文件 Appender
file:
path: ${LOG_HOME:./logs}

group:
web-stack: org.springframework.web,org.springframework.http,org.apache.catalina,org.apache.coyote
persistence: org.mybatis,org.mybatis.spring,com.baomidou.mybatisplus,org.springframework.jdbc,org.hibernate.SQL
rpc: org.apache.dubbo,io.grpc
messaging: org.springframework.kafka,org.springframework.amqp

level:
root: info
web-stack: info
persistence: warn
rpc: info
messaging: info
top.atluofu: info

logback:
rollingpolicy:
max-file-size: 100MB
max-history: 30
total-size-cap: 10GB
clean-history-on-start: false

application-dev.yml

1
2
3
4
5
6
logging:
level:
root: info
web-stack: debug
persistence: debug
rpc: debug

application-prod.yml

1
2
3
4
5
6
7
logging:
level:
root: info
web-stack: info
persistence: warn
rpc: info
messaging: info

application-k8s.yml

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
logging:
structured:
format:
console: ecs
ecs:
service:
name: ${spring.application.name}
version: ${APP_VERSION:unknown}
environment: ${DEPLOY_ENV:k8s}
node-name: ${HOSTNAME:local}
json:
# MDC 中如果使用 traceId/spanId,可在 JSON 中统一改为 snake_case
rename:
traceId: trace_id
spanId: span_id
requestId: request_id
tenantId: tenant_id
stacktrace:
root: first
max-length: 8192
include-common-frames: false
include-hashes: true

启动方式

开发环境:

1
2
java -jar finance-bill-service.jar \
--spring.profiles.active=dev

传统生产环境:

1
2
3
4
SPRING_PROFILES_ACTIVE=prod \
LOG_HOME=/data/logs \
INSTANCE_ID=finance-bill-service-01 \
java -jar finance-bill-service.jar

Kubernetes:

1
2
3
4
5
6
7
8
9
10
containers:
- name: finance-bill-service
image: finance-bill-service:3.0.0
env:
- name: SPRING_PROFILES_ACTIVE
value: k8s
- name: APP_VERSION
value: 3.0.0
- name: DEPLOY_ENV
value: prod

HOSTNAME 通常由 Kubernetes 自动设置为 Pod 名,不需要手工注入。

写一组验证日志

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.boot.ApplicationArguments;
import org.springframework.boot.ApplicationRunner;
import org.springframework.stereotype.Component;

@Component
public class LogbackVerificationRunner implements ApplicationRunner {

private static final Logger log = LoggerFactory.getLogger(LogbackVerificationRunner.class);

@Override
public void run(ApplicationArguments args) {
try {
MDC.put("traceId", "trace-demo-001");
MDC.put("requestId", "request-demo-001");
MDC.put("tenantId", "10001");

log.debug("logback debug verification");

log.atInfo()
.setMessage("finance bill calculate success")
.addKeyValue("biz", "finance_bill")
.addKeyValue("scene", "settlement")
.addKeyValue("step", "calculate")
.addKeyValue("bill_id", 10001L)
.addKeyValue("cost_ms", 32)
.log();

try {
throw new IllegalStateException("logback verification exception");
} catch (Exception exception) {
log.error("finance bill calculate failed, billId={}", 10001L, exception);
}
} finally {
MDC.clear();
}
}
}

传统生产模式启动后,应看到:

1
2
logs/finance-bill-service/finance-bill-service-01/application.log
logs/finance-bill-service/finance-bill-service-01/error.log

验证要点:

  • INFO 同时出现在控制台和 application.log
  • ERROR 同时出现在控制台、application.logerror.log
  • DEBUG 是否出现由 logging.level 决定。
  • MDC 字段可以看到 traceIdrequestIdtenantId
  • %kvp 可以看到 bizscenebill_idcost_ms
  • K8s profile 输出一行一个 JSON,MDC 和 Fluent KeyValue 变为独立 JSON 字段。

验证滚动策略

测试时临时把文件大小调小:

1
2
3
4
5
6
logging:
logback:
rollingpolicy:
max-file-size: 1MB
max-history: 3
total-size-cap: 20MB

然后循环打印足量日志:

1
2
3
for (int i = 0; i < 100_000; i++) {
log.info("rolling verification index={}, payload={}", i, "x".repeat(200));
}

预期目录:

1
2
3
archive/application.2026-07-16.0.log.gz
archive/application.2026-07-16.1.log.gz
archive/application.2026-07-16.2.log.gz

测试完成后恢复生产容量,避免把 1MB 的实验配置带上生产。日志滚得太勤快,磁盘目录会像在刷短视频,一眨眼全是新文件。

验证异步队列策略

AsyncAppender 默认队列容量只有 256,并且队列达到约 80% 时,会丢弃 TRACE、DEBUG、INFO。V3 模板显式配置:

1
2
3
<queueSize>8192</queueSize>
<discardingThreshold>0</discardingThreshold>
<neverBlock>false</neverBlock>

含义:

  • 不提前丢弃低级别日志;
  • 队列完全写满时阻塞业务线程;
  • 日志系统故障会对业务产生反压,而不是静默丢失证据。

这适合更重视可追溯性的财务、结算、订单类系统,但不能只凭感觉使用。压测至少观察:

  • 应用吞吐量和 P99 延迟;
  • 日志线程 CPU;
  • 磁盘写入吞吐与 I/O 等待;
  • 堆内存与 GC;
  • 高峰期队列是否持续打满;
  • 应用关闭时是否有队列未冲刷完。

如果业务更重视延迟并允许丢失普通 INFO 日志,可以把:

1
2
3
4
5
app:
logging:
async:
never-block: true
discarding-threshold: 1638

1638 约等于队列 8192 的 20%。这会在剩余容量不足时优先丢弃 TRACE、DEBUG、INFO,并在队列完全满时直接丢事件。启用前必须把“允许丢哪些日志”写入运维规范,不能把日志丢失伪装成性能优化。

是否一定要使用 AsyncAppender

不一定。异步日志只是把部分格式化与 I/O 等待从业务线程转移到日志线程,并引入队列、内存、反压和丢失策略。

推荐顺序:

  1. 先规范日志量,删除无价值的大对象、循环日志和重复日志。
  2. 使用同步 RollingFileAppender 完成基准压测。
  3. 确认日志 I/O 是真实瓶颈后,再引入 AsyncAppender
  4. 压测队列容量、阻塞策略和关闭冲刷时间。
  5. ERROR 镜像、审计日志和关键证据采用更保守策略。

需要注意:

  • neverBlock=false 不等于绝不丢日志。进程被 kill -9、容器被强制终止、磁盘损坏时仍可能丢失未落盘事件。
  • maxFlushTime=0 会在关闭时无限等待队列冲刷,日志目标异常时可能拖住停机。模板使用 5 秒有界等待,并用同步 ERROR 文件保底。
  • Spring Boot 默认注册日志系统关闭钩子,普通可执行 Jar 不需要再手工添加 Logback ShutdownHook。
  • Kubernetes 应配置合理的 terminationGracePeriodSeconds,让 JVM 有机会优雅关闭;SIGKILL 不讲武德,也不会等日志写完。

动态调整日志级别

不要通过 scan="true" 热加载 logback-spring.xml。Spring Boot 项目推荐使用 Actuator:

1
2
3
4
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-actuator</artifactId>
</dependency>
1
2
3
4
5
management:
endpoints:
web:
exposure:
include: health,info,loggers

查看 Logger:

1
curl http://localhost:8080/actuator/loggers/top.atluofu

临时调整:

1
2
3
4
curl -X POST \
-H 'Content-Type: application/json' \
-d '{"configuredLevel":"DEBUG"}' \
http://localhost:8080/actuator/loggers/top.atluofu

恢复继承级别:

1
2
3
4
curl -X POST \
-H 'Content-Type: application/json' \
-d '{"configuredLevel":null}' \
http://localhost:8080/actuator/loggers/top.atluofu

生产环境必须保护 Actuator 端点,不能把动态日志级别接口裸奔在公网。

常见故障排查

1. springProperty 或 springProfile 报错

现象:

1
no applicable action for [springProperty]

检查:

  • 文件是否误命名为 logback.xml
  • 是否开启了 scan="true"
  • 是否通过原生 Logback 在 Spring Boot 接管前提前加载配置;
  • logging.config 是否指向了错误文件。
2. 日志重复打印

检查:

  • 自定义 Logger 是否同时挂载 Appender 并继续向 ROOT 传播;
  • 是否确实需要 additivity="false"
  • ROOT 是否重复引用了同一个底层 Appender和它的 Async 包装;
  • 是否同时引入了两份配置文件。

错误示例:

1
2
3
4
<root level="INFO">
<appender-ref ref="APP_FILE"/>
<appender-ref ref="ASYNC_APP_FILE"/>
</root>

ASYNC_APP_FILE 已经转发到 APP_FILE,ROOT 再直接引用 APP_FILE 会写两次。

3. application.yml 的滚动参数不生效

使用完全自定义的 logback-spring.xml 后,Spring Boot 不会自动猜测 XML 中哪个 RollingPolicy 应该应用哪组属性。必须像 V3 模板一样,通过 <springProperty> 显式读取:

1
2
3
<springProperty name="MAX_FILE_SIZE"
source="logging.logback.rollingpolicy.max-file-size"
defaultValue="100MB"/>
4. ERROR 没有进入 error.log

检查:

  • ROOT 是否引用 ERROR_FILE
  • LevelFilteronMatch/onMismatch 是否写反;
  • 代码是否使用 log.error(...)
  • 文件目录是否有写权限;
  • 活跃的 Spring Profile 是否进入了文件配置分支。
5. MDC 在线程池中丢失

MDC 不会自动可靠透传到线程池任务。检查:

  • TaskDecorator 是否配置到实际使用的线程池;
  • CompletableFuture 是否使用了另一个未装饰的 Executor;
  • 消息消费线程是否在每条消息开始时写入、结束时清理 MDC;
  • 虚拟线程任务是否在创建任务时复制了需要的上下文;
  • 是否在 finally 中恢复或清理旧上下文,防止线程复用污染。
6. 历史日志没有删除

检查:

  • maxHistory 是否为 0;
  • totalSizeCap 是否在没有 maxHistory 的情况下单独配置;
  • 应用是否一直没有触发滚动;
  • 短生命周期服务是否需要 cleanHistoryOnStart=true
  • 文件时间、时区和挂载盘是否正常。
7. K8s 中出现文件和 JSON 控制台两套日志

检查是否同时激活了不互斥的部署 Profile。建议把 k8s 作为部署模式 Profile,不要同时使用会启用传统文件 Appender 的自定义 Profile 分支。

8. %kvp 没有业务字段

%kvp 只负责输出日志事件中通过 SLF4J Fluent API 添加的键值字段:

1
log.atInfo().addKeyValue("bill_id", billId).log("bill calculated");

普通占位符:

1
log.info("bill calculated, billId={}", billId);

只会形成 message,不会自动变成 %kvp 字段。

9. 日志目录没有创建或无法写入

检查:

1
2
ls -ld /data/logs
id

容器中还要检查:

  • 挂载目录是否存在;
  • securityContext.runAsUser 是否有写权限;
  • 根文件系统是否只读;
  • 多个 Pod 是否错误共享同一个活动文件路径。
10. 检查日志依赖冲突

Maven:

1
2
mvn dependency:tree \
-Dincludes=org.slf4j,ch.qos.logback,org.apache.logging.log4j

重点检查:

  • Spring Boot Logback 项目中是否意外引入多个 SLF4J Provider;
  • 是否同时出现 Logback 与 log4j-slf4j2-impl
  • 是否把 log4j-to-slf4j 与 Log4j2 的 SLF4J Provider 组成循环;
  • 是否手工指定了不兼容的 Logback 版本。

配置上线检查清单

  • 配置文件名是 logback-spring.xml
  • 没有开启 scan="true"
  • application.yml 与 XML 的职责没有重复冲突。
  • ROOT Logger 在当前 Profile 中只定义一次。
  • AsyncAppender 和它包装的 APP_FILE 没有同时被 ROOT 引用。
  • ERROR 镜像使用 LevelFilter 精确匹配 ERROR。
  • 文件日志没有 ANSI 颜色控制字符。
  • 没有 %class%method%line%caller
  • maxHistorytotalSizeCap 和磁盘容量预算经过计算。
  • 多实例日志目录包含实例名。
  • K8s 使用 stdout JSON,不依赖容器可写层保存历史日志。
  • MDC 在线程池、异步任务和消息消费中可以透传且能够清理。
  • 动态日志级别端点有认证与网络访问控制。
  • 做过日志高峰压测和优雅停机验证。

java 日志模板 log4j2

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
<?xml version="1.0" encoding="UTF-8"?>
<!--Configuration后面的status,这个用于设置log4j2自身内部的信息输出,可以不设置,当设置成trace时,你会看到log4j2内部各种详细输出-->
<!--monitorInterval:Log4j能够自动检测修改配置 文件和重新配置本身,设置间隔秒数-->
<configuration monitorInterval="5">
<!--日志级别以及优先级排序: OFF > FATAL > ERROR > WARN > INFO > DEBUG > TRACE > ALL -->

<!--变量配置-->
<Properties>
<!-- 格式化输出:%date表示日期,%thread表示线程名,%-5level:级别从左显示5个字符宽度 %msg:日志消息,%n是换行符-->
<!-- %logger{36} 表示 Logger 名字最长36个字符 -->
<property name="LOG_PATTERN" value="%date{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n"/>
<!-- 定义日志存储的路径 -->
<property name="FILE_PATH" value="更换为你的日志路径"/>
<property name="FILE_NAME" value="更换为你的项目名"/>
</Properties>

<appenders>

<console name="Console" target="SYSTEM_OUT">
<!--输出日志的格式-->
<PatternLayout pattern="${LOG_PATTERN}"/>
<!--控制台只输出level及其以上级别的信息(onMatch),其他的直接拒绝(onMismatch)-->
<ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
</console>

<!--文件会打印出所有信息,这个log每次运行程序会自动清空,由append属性决定,适合临时测试用-->
<File name="Filelog" fileName="${FILE_PATH}/test.log" append="false">
<PatternLayout pattern="${LOG_PATTERN}"/>
</File>

<!-- 这个会打印出所有的info及以下级别的信息,每次大小超过size,则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩,作为存档-->
<RollingFile name="RollingFileInfo" fileName="${FILE_PATH}/info.log"
filePattern="${FILE_PATH}/${FILE_NAME}-INFO-%d{yyyy-MM-dd}_%i.log.gz">
<!--控制台只输出level及以上级别的信息(onMatch),其他的直接拒绝(onMismatch)-->
<ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="${LOG_PATTERN}"/>
<Policies>
<!--interval属性用来指定多久滚动一次,默认是1 hour-->
<TimeBasedTriggeringPolicy interval="1"/>
<SizeBasedTriggeringPolicy size="10MB"/>
</Policies>
<!-- DefaultRolloverStrategy属性如不设置,则默认为最多同一文件夹下7个文件开始覆盖-->
<DefaultRolloverStrategy max="15"/>
</RollingFile>

<!-- 这个会打印出所有的warn及以下级别的信息,每次大小超过size,则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩,作为存档-->
<RollingFile name="RollingFileWarn" fileName="${FILE_PATH}/warn.log"
filePattern="${FILE_PATH}/${FILE_NAME}-WARN-%d{yyyy-MM-dd}_%i.log.gz">
<!--控制台只输出level及以上级别的信息(onMatch),其他的直接拒绝(onMismatch)-->
<ThresholdFilter level="warn" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="${LOG_PATTERN}"/>
<Policies>
<!--interval属性用来指定多久滚动一次,默认是1 hour-->
<TimeBasedTriggeringPolicy interval="1"/>
<SizeBasedTriggeringPolicy size="10MB"/>
</Policies>
<!-- DefaultRolloverStrategy属性如不设置,则默认为最多同一文件夹下7个文件开始覆盖-->
<DefaultRolloverStrategy max="15"/>
</RollingFile>

<!-- 这个会打印出所有的error及以下级别的信息,每次大小超过size,则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩,作为存档-->
<RollingFile name="RollingFileError" fileName="${FILE_PATH}/error.log"
filePattern="${FILE_PATH}/${FILE_NAME}-ERROR-%d{yyyy-MM-dd}_%i.log.gz">
<!--控制台只输出level及以上级别的信息(onMatch),其他的直接拒绝(onMismatch)-->
<ThresholdFilter level="error" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="${LOG_PATTERN}"/>
<Policies>
<!--interval属性用来指定多久滚动一次,默认是1 hour-->
<TimeBasedTriggeringPolicy interval="1"/>
<SizeBasedTriggeringPolicy size="10MB"/>
</Policies>
<!-- DefaultRolloverStrategy属性如不设置,则默认为最多同一文件夹下7个文件开始覆盖-->
<DefaultRolloverStrategy max="15"/>
</RollingFile>

</appenders>

<!--Logger节点用来单独指定日志的形式,比如要为指定包下的class指定不同的日志级别等。-->
<!--然后定义loggers,只有定义了logger并引入的appender,appender才会生效-->
<loggers>

<!--过滤掉spring和mybatis的一些无用的DEBUG信息-->
<logger name="org.mybatis" level="info" additivity="false">
<AppenderRef ref="Console"/>
</logger>
<!--监控系统信息-->
<!--若是additivity设为false,则 子Logger 只会在自己的appender里输出,而不会在 父Logger 的appender里输出。-->
<Logger name="org.springframework" level="info" additivity="false">
<AppenderRef ref="Console"/>
</Logger>

<root level="info">
<appender-ref ref="Console"/>
<appender-ref ref="Filelog"/>
<appender-ref ref="RollingFileInfo"/>
<appender-ref ref="RollingFileWarn"/>
<appender-ref ref="RollingFileError"/>
</root>
</loggers>

</configuration>

配置文件详解

  • 日志级别
    • 机制:如果一条日志信息的级别大于等于配置文件的级别,就记录。
    • trace:追踪,就是程序推进一下,可以写个 trace 输出
    • debug:调试,一般作为最低级别,trace 基本不用。
    • info:输出重要的信息,使用较多
    • warn:警告,有些信息不是错误信息,但也要给程序员一些提示。
    • error:错误信息。用的也很多。
    • fatal:致命错误。
  • 输出源
    • CONSOLE(输出到控制台)
  • FILE(输出到文件)
  • 格式
    • SimpleLayout:以简单的形式显示
    • HTMLLayout:以 HTML 表格显示
    • PatternLayout:自定义形式显示

PatternLayout 自定义日志布局:

1
2
3
4
5
6
7
8
9
10
11
12
13
%d{yyyy-MM-dd HH:mm:ss, SSS} : 日志生产时间,输出到毫秒的时间
%-5level : 输出日志级别,-5表示左对齐并且固定输出5个字符,如果不足在右边补0
%c : logger的名称(%logger)
%t : 输出当前线程名称
%p : 日志输出格式
%m : 日志内容,即 logger.info("message")
%n : 换行符
%C : Java类名(%F)
%L : 行号
%M : 方法名
%l : 输出语句所在的行数, 包括类名、方法名、文件名、行数
hostName : 本地机器名
hostAddress : 本地ip地址

Log4j2 配置详解

根节点 Configuration 有两个属性:

  • status

  • monitorinterval
    有两个子节点:

  • Appenders

  • Loggers(表明可以定义多个 Appender 和 Logger).

  • status 用来指定 log4j 本身的打印日志的级别.

  • monitorinterval 用于指定 log4j 自动重新配置的监测间隔时间,单位是 s,最小是 5s.

  • Appenders 节点

  • 常见的有三种子节点:Console、RollingFile、File

  • Console 节点用来定义输出到控制台的 Appender.

    • name:指定 Appender 的名字.
    • target:SYSTEM_OUT 或 SYSTEM_ERR,一般只设置默认:SYSTEM_OUT.
    • PatternLayout:输出格式,不设置默认为:%m%n.
  • File 节点用来定义输出到指定位置的文件的 Appender.

    • name:指定 Appender 的名字.
    • fileName:指定输出日志的目的文件带全路径的文件名.
    • PatternLayout:输出格式,不设置默认为:%m%n.
  • RollingFile 节点用来定义超过指定条件自动删除旧的创建新的 Appender.

    • name:指定 Appender 的名字.
    • fileName:指定输出日志的目的文件带全路径的文件名.
    • PatternLayout:输出格式,不设置默认为:%m%n.
    • filePattern : 指定当发生 Rolling 时,文件的转移和重命名规则.
    • Policies:指定滚动日志的策略,就是什么时候进行新建日志文件输出日志.
    • TimeBasedTriggeringPolicy:Policies 子节点,基于时间的滚动策略,interval 属性用来指定多久滚动一次,默认是 1
    • hour。modulate=true 用来调整时间:比如现在是早上 3am,interval 是 4,那么第一次滚动是在 4am,接着是 8am,12am…而不是
      7am.
    • SizeBasedTriggeringPolicy:Policies 子节点,基于指定文件大小的滚动策略,size 属性用来定义每个日志文件的大小.
    • DefaultRolloverStrategy:用来指定同一个文件夹下最多有几个日志文件时开始删除最旧的,创建新的(通过 max 属性)。
  • Loggers 节点,常见的有两种:Root 和 Logger.
    Root 节点用来指定项目的根日志,如果没有单独指定 Logger,那么就会默认使用该 Root 日志输出

  • level:日志输出级别,共有 8 个级别,按照从低到高为:All < Trace < Debug < Info < Warn < Error <

    • AppenderRef:Root 的子节点,用来指定该日志输出到哪个 Appender.
    • Logger 节点用来单独指定日志的形式,比如要为指定包下的 class 指定不同的日志级别等。
    • level:日志输出级别,共有 8 个级别,按照从低到高为:All < Trace < Debug < Info < Warn < Error < Fatal < OFF.
    • name:用来指定该 Logger 所适用的类或者类所在的包全路径,继承自 Root 节点.
    • AppenderRef
      :Logger 的子节点,用来指定该日志输出到哪个 Appender,如果没有指定,就会默认继承自 Root.如果指定了,那么会在指定的这个
      Appender 和 Root 的 Appender 中都会输出,此时我们可以设置 Logger 的 additivity=”
      false”只在自定义的 Appender 中进行输出。

性能调优之日志打印的坑

一是前段时间架构组同事的一次性能优化分享,单单日志(log4j2)这一项优化性能就提升了 19 倍,QPS 从 1660 升到 32000,被震撼到了。

二是最近接手的一个项目中,日志加了彩色打印,按日志的级别设置了不同的高亮颜色,看得我眼花缭乱,用 less
等一些命令查看时还会展示出来一堆 “ESC[m]”,这让有点强迫症的我看着很不爽。

趁着技术优化,把这块也改一下,自己先爽了再说。顺便也重新认识一下在各种算法、秒杀设计大行其道的当下,这个不太起眼的小家伙。

综述

在任何系统中,日志对服务的重要性不言而喻,它是反映系统运行情况的重要依据;它轻巧、简单,与我们形影不离,使得我们在排查问题时无需绞尽脑汁。被线上服务问题毒打过的人都认可日志的重要性,但看似不起眼的日志,却是一把双刃剑,隐藏着各式各样的“坑”,如果使用不当,不仅不能助我们一臂之力,反而会成为服务“杀手”,所以,你知道有哪些场景可能导致性能问题吗?今天楼兰胡杨和各位老铁聊聊高并发系统下
Java 日志性能那些事,同时提供一套异步+随机采样方案能让程序与日志“和谐共处”。

Java 日志打印对服务的影响包括多种因素,例如日志级别、日志输出目标和日志格式等。下面的流程图展示了 Java 日志打印的一般流程和对
CPU 的影响。

image

根据以上流程图可以得出以下结论:

Java 日志打印会增加代码的执行时间,因为需要执行额外的日志打印语句。

日志级别的选择会影响 CPU 的占用率。较低的日志级别(如 INFO 或 DEBUG)会导致更多的日志打印语句被执行,增加 CPU 的负担。

日志输出目标的选择也会影响 CPU 的占用率。将日志输出到控制台会导致额外的 I/O 操作,增加 CPU 的负担。

日志格式的复杂程度也会影响 CPU 的占用率。使用更复杂的日志格式可能会导致更多的字符串操作,增加 CPU 的负担。

影响性能的日志因素

位置信息

官网称作 Location Information,就是我们配置文件里的这类信息(%c{3}#%M %L),含义是当前这行日志是哪个类的哪个方法哪一行打印的。输出效果如下:

可配置的模式有很多,具体见官网 https://logging.apache.org/log4j/2.x/manual/layouts.html#Patterns

这里只说和位置相关的 %C or %class, %F or %file, %l or %location, %L or %line, %M or %method。

官网这几个模式的说明中也都反复强调了会影响性能。同时也给出了具体的性能数据,比常用的同步 logger 慢 1.3 ~ 5 倍。如果在异步
logger 中使用位置信息,将会慢 30 ~ 100 倍。

为什么会这么慢呢?

我们都知道,java 程序执行时,每个线程都会有自己的栈,每个方法都会生成一个 frame,要获取位置信息,就要获取当前线程的栈帧信息,java
9 之前提供了两种获取栈帧的方法

1
2
java.lang.Throwable#getStackTrace()
java.lang.Thread#getStackTrace()

java 9 提供了 StackWalker 类,有网友说它的性能要好一些,我没找到有力证据,看到的都是介绍跳帧的功能,有兴趣的可以深究一下。

我们就看一下 java 9 之前的 2 种方法:

有网友说 java.lang.Throwable#getStackTrace() 的性能要好一些,我也没有找到直接证据,但从调用底层 native 的方法名字看 Thread
里调用的是 dumpThreads ,看到 dump 字眼,就会联想到 stop the world ,如果真挂起线程,那效率就低了。

而且 log4j 里用的是 java.lang.Throwable#getStackTrace()。

不管是哪种方法获取堆栈信息,应该都不会太高效。

想想我们一个请求,从框架层面交给一个线程后,动辄几十层方法才能调到我们的业务代码太正常不过了。

既然这么低效,那我们不打位置信息,有问题怎么定位呢?

我仔细回想了一下过往排查问题时,好像都是通过日志内容,定位到哪一行代码,几乎没有通过类名行号去定位代码,编译后的行号准不准确也另说。

其实我们的主要目的是不通过框架获取堆栈的形式打印位置信息,我们完全可以在日志的内容中带上位置信息,通过一个切面就能搞定的事。

不同的 Appender

我们工作中一般都是把日志输出到文件中的,我们就挑 3 个文件相关的 Appender 说明一下,不同的 Appender 性能的差异主要在 I/O 上。

FileAppender 和 RollingFileAppender 内部使用的都是 BufferedOutputStream。

而 RandomAccessFileAppender 内部使用了 ByteBuffer + RandomAccessFile 技术,与 FileAppender 相比,性能提高了 20 ~ 200%。

AsyncAppender 它不能独立存在,要依赖其他的 Appenders,配置在它们之后。

它只是新起一个线程中把 LogEvents 交给了它所依赖的 Appenders。默认内部使用的是 ArrayBlockingQueue
,多线程并发打日志时,性能可能会变得更差。这种场景官方推荐使用无锁的 Asynchronous Loggers 。

Asynchronous Loggers,它是 log4j2 新提供的功能,通过新起线程执行 I/O 操作来提升性能,底层使用的是 Disruptor 框架,通过无锁线程通信,代替了
ArrayBlockingQueue 。

它支持所有 Loggers 异步处理,也支持同步、异步 组合使用。可靠性要求高的比如异常信息就可以配成同步的,其他配成异步的。

每个 Appender 的具体用法可以从官网查看,

https://logging.apache.org/log4j/2.x/manual/appenders.html

不同的刷盘策略

上面说到的 Appenders 的配置项中,都有一个 “immediateFlush”,默认 = false,日志文件不像数据库那样追求高可靠性,可以忽略此配置,知道配置为
true 性能会变差就行。

貌似所有涉及到刷盘的技术,都会提供这类的配置项,这里就不多说了。

不合理的书写方法

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
// 格式1
log.debug("User id = " + userId);

// 格式2
if (log.isdebugEnable()) {
log.debug("User id = " + userId);
}

// 格式3
log.debug("User msg {}!", JSON.toJSONString(user));

// 格式4,既然加了开关,说明是核心日志,打印info级别
if (日志开关已开启) {
log.info("User msg {}!", JSON.toJSONString(user));
}

如上四种写法,我相信大家或多或少都在项目代码中看到过,那么它们之间有什么区别?对性能会造成什么影响?如果此时关闭 DEBUG
级别日志,差异就显露出来了。

  • 格式 1 即使它不输出日志,依然需要执行字符串拼接,属于资源浪费。
  • 格式 2 缺点是需要加入额外的判断逻辑,增加了废代码,一点不优雅。
  • 格式 3 缺点是仍然需要根据系统配置的日志级别判断是否打印日志,并且需要提前序列化对象为 JSON 字符串,但是,不需要拼接字符串。
  • 格式 4 推荐在高并发系统中使用,优点是根据 Boolean 类型日志开关判断是否走日志打印逻辑,开关关闭时,不必校验是否需要打印日志。

结构化日志到底解决什么问题

如果项目已经是 Spring Boot 3.4+,优先使用 Spring Boot 内置结构化日志能力:

  • 本地、开发环境:保留普通 PatternLayout,方便人眼阅读。
  • 测试、预发、生产环境:输出 JSON,推荐 ECS 或 Logstash 格式。
  • 业务字段:用 MDC 或 SLF4J 2.0 Fluent API 写入,不要把一堆字段拼进 message。
  • 应用代码:继续使用 SLF4J,不要在业务代码里直接依赖 Logback 或 Log4j2。
  • 是否迁移 Log4j2:看性能、异步日志、模板定制和团队统一诉求,不要为了“听起来高级”硬迁移。

日志这东西,最怕“看起来很规范,线上一查全是字符串糊成一坨”。JSON 化不是终点,字段规范才是。

传统日志通常长这样:

1
2026-06-01 10:12:31.008 [http-nio-8080-exec-1] INFO  c.m.finance.BillService - calculate bill success, billId=10001, cost=32ms

人看还行,机器分析就不太舒服。你想查 billId=10001tenantId=8cost_ms > 1000,通常只能靠正则、全文检索或日志平台的二次解析。

结构化日志应该长这样:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
{
"@timestamp": "2026-06-01T10:12:31.008+08:00",
"log.level": "INFO",
"service.name": "finance-bill-service",
"process.thread.name": "http-nio-8080-exec-1",
"log.logger": "com.mario.finance.BillService",
"message": "finance bill calculate success",
"trace_id": "a7f8c9e2f4d24a2e9c3b88b2c9e6d001",
"span_id": "b21c1f0a8a6d4e20",
"request_id": "REQ-20260601-000001",
"tenant_id": "8",
"biz": "finance_bill",
"scene": "settlement",
"step": "calculate",
"phase": "finish",
"bill_type": "pool_statement",
"bill_id": "10001",
"status": "SUCCESS",
"cost_ms": 32
}

这才是线上排查时能救命的格式。因为每个字段都能被索引、过滤、聚合和告警。

Spring Boot 3.4 的结构化日志能力

Spring Boot 3.4+ 内置支持三种 JSON 结构化日志格式:

  • ecs:Elastic Common Schema,适合 Elasticsearch / Kibana 生态。
  • gelf:Graylog Extended Log Format,适合 Graylog。
  • logstash:Logstash JSON 风格,适合通用 Logstash/Filebeat 管道。

最简单的配置如下:

1
logging.structured.format.console=ecs

如果只想文件输出 JSON,控制台仍然给开发者看普通文本:

1
2
logging.structured.format.file=ecs
logging.file.name=logs/app.json

更推荐的做法是:不要把结构化配置放在公共 application.yml,而是放到 application-prod.ymlapplication-k8s.yml
。这样本地不会被 JSON 日志糊脸,生产也不会因为开发者喜欢彩色日志导致采集系统解析失败。

推荐配置:本地文本,生产 JSON

application.yml

1
2
3
4
5
6
7
8
9
10
11
spring:
application:
name: finance-bill-service

logging:
level:
root: info
org.springframework: info
org.mybatis: info
pattern:
console: "%d{yyyy-MM-dd'T'HH:mm:ss.SSSXXX} %-5level [%thread] [%X{trace_id:-}] [%X{request_id:-}] %logger{36} - %msg%n%wEx"

application-prod.yml

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
logging:
file:
name: ${LOG_FILE:./logs/${spring.application.name}.json}
structured:
format:
console: ecs
file: ecs
ecs:
service:
name: ${spring.application.name}
version: ${APP_VERSION:unknown}
environment: ${SPRING_PROFILES_ACTIVE:prod}
node-name: ${HOSTNAME:local}
json:
add:
app_type: spring-boot
stacktrace:
root: first
max-length: 8192
include-common-frames: false
include-hashes: true

这套配置的核心思想是:

  • console 可以 JSON,也可以只给容器采集 stdout。
  • file 可以作为备用落盘,适合传统服务器或排障保底。
  • service.nameservice.versionservice.environmentservice.node-name 必须稳定,否则日志平台按服务聚合会很难看。
  • 堆栈不要无限长,尤其是高频异常,否则日志平台和钱包都会哀嚎。

日志字段模板:不要把业务上下文塞进 message

业务日志最重要的不是“写一句漂亮的话”,而是把关键上下文拆成字段。

基础字段建议如下:

字段 含义 示例
trace_id 一次调用链路的唯一 ID a7f8...
span_id 当前调用片段 ID b21c...
request_id 网关或应用生成的请求 ID REQ-20260601-000001
tenant_id 租户 ID 10001
user_id 操作用户 ID 8899
client_ip 客户端 IP 10.0.0.12
http_method HTTP 方法 POST
uri 请求路径 /api/bills/settle
cost_ms 耗时 32
error_code 业务错误码 BILL_STATUS_INVALID
error_msg 业务错误说明 status not allowed

财务、结算、单据类业务可以再加一组业务字段:

1
2
3
4
5
private static final String[] BIZ_LOG_FIELD_ORDER = new String[] {
"biz", "scene", "step", "phase", "bill_type", "bill_id", "bill_no", "biz_id", "biz_uk",
"status", "expected_status", "from_status", "to_status", "decision", "reason", "result",
"error_code", "error_msg", "changed", "cost_ms", "msg"
};

但要注意:JSON 对字段顺序并不敏感,字段顺序更多是给人读 logfmt 或文本日志时用的。线上更重要的是字段命名稳定、类型稳定、含义稳定。

我的建议是:

  • 技术字段用通用命名:trace_idspan_idrequest_idtenant_id
  • 业务字段用稳定 snake_case:bill_idbill_typefrom_statusto_status
  • message 写一句能看懂的英文摘要,例如 finance bill status changed
  • 不要在 message 里拼 JSON;JSON 外面再包 JSON,属于套娃打工人。

使用 MDC 注入请求上下文

MDC 适合放“贯穿整个请求生命周期”的上下文,例如 trace_idrequest_idtenant_iduser_id

Servlet 项目可以加一个过滤器:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.slf4j.MDC;
import org.springframework.core.Ordered;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.util.StringUtils;
import org.springframework.web.filter.OncePerRequestFilter;

import java.io.IOException;
import java.util.UUID;

@Component
@Order(Ordered.HIGHEST_PRECEDENCE)
public class RequestMdcFilter extends OncePerRequestFilter {

private static final String REQUEST_ID = "request_id";
private static final String TRACE_ID = "trace_id";
private static final String TENANT_ID = "tenant_id";
private static final String USER_ID = "user_id";
private static final String URI = "uri";
private static final String HTTP_METHOD = "http_method";
private static final String CLIENT_IP = "client_ip";

@Override
protected void doFilterInternal(HttpServletRequest request,
HttpServletResponse response,
FilterChain filterChain) throws ServletException, IOException {
String requestId = firstNotBlank(request.getHeader("X-Request-Id"), newId());
String traceId = firstNotBlank(request.getHeader("X-Trace-Id"), requestId);

try {
MDC.put(REQUEST_ID, requestId);
MDC.put(TRACE_ID, traceId);
MDC.put(TENANT_ID, nullToEmpty(request.getHeader("X-Tenant-Id")));
MDC.put(USER_ID, nullToEmpty(request.getHeader("X-User-Id")));
MDC.put(URI, request.getRequestURI());
MDC.put(HTTP_METHOD, request.getMethod());
MDC.put(CLIENT_IP, getClientIp(request));
response.setHeader("X-Request-Id", requestId);
filterChain.doFilter(request, response);
} finally {
MDC.remove(REQUEST_ID);
MDC.remove(TRACE_ID);
MDC.remove(TENANT_ID);
MDC.remove(USER_ID);
MDC.remove(URI);
MDC.remove(HTTP_METHOD);
MDC.remove(CLIENT_IP);
}
}

private static String firstNotBlank(String value, String fallback) {
return StringUtils.hasText(value) ? value : fallback;
}

private static String nullToEmpty(String value) {
return value == null ? "" : value;
}

private static String newId() {
return UUID.randomUUID().toString().replace("-", "");
}

private static String getClientIp(HttpServletRequest request) {
String xff = request.getHeader("X-Forwarded-For");
if (StringUtils.hasText(xff)) {
return xff.split(",")[0].trim();
}
return request.getRemoteAddr();
}
}

如果接了 Micrometer Tracing / OpenTelemetry,traceIdspanId 可能已经自动进入 MDC。此时可以直接复用,也可以用 Spring
Boot 3.4 的 JSON rename 配置做字段名统一:

1
2
3
4
5
6
logging:
structured:
json:
rename:
traceId: trace_id
spanId: span_id

使用 SLF4J 2.0 Fluent API 写业务字段

MDC 适合请求级字段,单条业务日志的字段建议用 SLF4J 2.0 Fluent API。

不要这样写:

1
log.info("bill status changed, billId={}, from={}, to={}, reason={}", billId, fromStatus, toStatus, reason);

这当然能看,但机器只能拿到一整条 message。更推荐这样:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
log.atInfo()
.setMessage("finance bill status changed")
.addKeyValue("biz", "finance_bill")
.addKeyValue("scene", "settlement")
.addKeyValue("step", "status_change")
.addKeyValue("phase", "finish")
.addKeyValue("bill_type", billType)
.addKeyValue("bill_id", billId)
.addKeyValue("from_status", fromStatus)
.addKeyValue("to_status", toStatus)
.addKeyValue("reason", reason)
.addKeyValue("result", "success")
.addKeyValue("cost_ms", costMs)
.log();

进入 JSON 后,这些字段会成为可检索字段。以后查“某个单据从 A 状态变 B 状态失败了多少次”,不再需要和正则表达式大战三百回合。

封装业务日志工具类

项目里最好不要每个 Service 都手写一堆 addKeyValue。可以封一层轻量工具类,让字段稳定下来。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.spi.LoggingEventBuilder;

public final class FinanceBizLog {

private static final Logger BIZ_LOG = LoggerFactory.getLogger("BIZ_FINANCE");

private FinanceBizLog() {
}

public static LoggingEventBuilder settlement(String step) {
return BIZ_LOG.atInfo()
.addKeyValue("biz", "finance_bill")
.addKeyValue("scene", "settlement")
.addKeyValue("step", step);
}

public static void billCalculated(Long billId, String billType, long costMs) {
settlement("calculate")
.setMessage("finance bill calculate success")
.addKeyValue("phase", "finish")
.addKeyValue("bill_id", billId)
.addKeyValue("bill_type", billType)
.addKeyValue("result", "success")
.addKeyValue("cost_ms", costMs)
.log();
}

public static void billSkipped(Long billId, String reason, long costMs) {
settlement("calculate")
.setMessage("finance bill calculate skipped")
.addKeyValue("phase", "decision")
.addKeyValue("bill_id", billId)
.addKeyValue("decision", "skip")
.addKeyValue("reason", reason)
.addKeyValue("changed", false)
.addKeyValue("cost_ms", costMs)
.log();
}
}

这个工具类的价值不是“少写几行代码”,而是统一字段口径。日志字段一旦散了,后面所有日志平台查询语句都会变成考古现场。

线程池、异步任务与 MDC 透传

你只在 Web 入口放 MDC 还不够。只要用了线程池、CompletableFuture、消息消费、异步事件,MDC 就可能丢。

Spring 线程池可以加 TaskDecorator

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
import org.slf4j.MDC;
import org.springframework.core.task.TaskDecorator;

import java.util.Map;

public class MdcTaskDecorator implements TaskDecorator {

@Override
public Runnable decorate(Runnable runnable) {
Map<String, String> capturedContext = MDC.getCopyOfContextMap();
return () -> {
Map<String, String> previousContext = MDC.getCopyOfContextMap();
try {
if (capturedContext != null) {
MDC.setContextMap(capturedContext);
} else {
MDC.clear();
}
runnable.run();
} finally {
if (previousContext != null) {
MDC.setContextMap(previousContext);
} else {
MDC.clear();
}
}
};
}
}

配置到线程池:

1
2
3
4
5
6
7
8
9
10
11
@Bean
public ThreadPoolTaskExecutor applicationTaskExecutor() {
ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
executor.setCorePoolSize(16);
executor.setMaxPoolSize(64);
executor.setQueueCapacity(1000);
executor.setThreadNamePrefix("biz-worker-");
executor.setTaskDecorator(new MdcTaskDecorator());
executor.initialize();
return executor;
}

如果你已经有 TraceRouteCallable / TraceRouteRunnable 之类的封装,思路也是一样:提交任务时复制上下文,执行任务时恢复上下文,执行结束后清理上下文。

从 SLF4J + Logback 迁移到 Log4j2

先纠正一个小拼写:是 SLF4J,不是 Sel4j。它是日志门面,不是具体日志实现。迁移到 Log4j2 时,业务代码仍然建议继续使用 SLF4J
API。

也就是说,代码里这部分不需要改:

1
private static final Logger log = LoggerFactory.getLogger(BillService.class);

真正要替换的是运行时日志实现:

1
2
迁移前:业务代码 -> SLF4J -> Logback
迁移后:业务代码 -> SLF4J -> Log4j2

什么时候值得迁移 Log4j2

值得迁移的场景:

  • 高并发场景下日志量比较大,需要更强的异步日志能力。
  • 需要更灵活的 JSON Template Layout。
  • 团队或公司基础设施已经统一 Log4j2。
  • 已经通过压测证明日志输出是性能瓶颈。

不建议迁移的场景:

  • 只是想输出 JSON:Spring Boot 3.4 + Logback 已经能做。
  • 项目日志量不大:迁移收益可能不明显。
  • 没有压测、没有日志平台字段规范:这时迁移只是换皮,解决不了核心问题。

我的建议很朴素:如果只是结构化日志,先用 Spring Boot 3.4 内置能力;如果日志性能和异步能力确实卡住了,再迁移
Log4j2。别为了换发动机把车拆了,最后发现只是轮胎没气。

Maven 依赖迁移

Spring Boot 默认 starter 会带 spring-boot-starter-logging,它默认使用 Logback。迁移 Log4j2 时,需要排除默认 logging
starter,然后加入 spring-boot-starter-log4j2

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23

<dependencies>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>

<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter</artifactId>
<exclusions>
<exclusion>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-logging</artifactId>
</exclusion>
</exclusions>
</dependency>

<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>
</dependencies>

如果项目里有多个 starter,迁移后一定要检查依赖树:

1
mvn dependency:tree | grep -E "logback|log4j-to-slf4j|log4j-slf4j"

重点排查:

  • 不应该再出现 ch.qos.logback:logback-classic
  • 不应该同时出现 log4j-to-slf4jlog4j-slf4j2-impl
  • 不要手动乱加旧版 log4j-slf4j-impl,Spring Boot 3 / SLF4J 2 应使用 Boot starter 管理的适配依赖。

Gradle 迁移

Gradle 可以直接做 module replacement:

1
2
3
4
5
6
7
8
dependencies {
implementation "org.springframework.boot:spring-boot-starter-log4j2"
modules {
module("org.springframework.boot:spring-boot-starter-logging") {
replacedBy("org.springframework.boot:spring-boot-starter-log4j2", "Use Log4j2 instead of Logback")
}
}
}

或者全局排除:

1
2
3
4
5
6
7
configurations.configureEach {
exclude group: "org.springframework.boot", module: "spring-boot-starter-logging"
}

dependencies {
implementation "org.springframework.boot:spring-boot-starter-log4j2"
}

Log4j2 配置文件建议

如果使用 Spring Boot 的 Log4j2 扩展,配置文件建议命名为:

1
log4j2-spring.xml

不要用普通 log4j2.xml 承载 Spring Profile / Spring Environment 相关能力。log4j2.xml 加载太早,用不到 Spring Boot
扩展,很多配置会看起来“明明写了,但就是不生效”。

Spring Boot 3.4+ 的 Log4j2 模板,见前文。

对应的 application-prod.yml

1
2
3
4
5
6
7
8
9
10
11
12
13
logging:
file:
name: ${LOG_FILE:./logs/${spring.application.name}.json}
structured:
format:
console: ecs
file: ecs
ecs:
service:
name: ${spring.application.name}
version: ${APP_VERSION:unknown}
environment: ${SPRING_PROFILES_ACTIVE:prod}
node-name: ${HOSTNAME:local}

这里的关键点是:

  • StructuredLogLayout 是 Spring Boot 3.4 给 Log4j2 提供的结构化日志布局。
  • CONSOLE_LOG_STRUCTURED_FORMATFILE_LOG_STRUCTURED_FORMAT 来自 logging.structured.format.console/file
  • LOG_FILE 来自 logging.file.name
  • 本地 profile 使用文本日志,生产 profile 使用 JSON 日志。

是否要开启 Log4j2 异步日志

Log4j2 的异步日志是它的重要优势之一,但不要闭眼开。

如果要让所有 Logger 异步,通常需要加 Disruptor 依赖:

1
2
3
4
5
6

<dependency>
<groupId>com.lmax</groupId>
<artifactId>disruptor</artifactId>
<scope>runtime</scope>
</dependency>

然后用 JVM 参数开启:

1
-Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector

注意几点:

  • 异步日志适合削峰,能降低业务线程等待 I/O 的时间。
  • 如果日志持续写入速度超过 Appender 消费速度,队列照样会被打满。
  • 审计日志、资金流水、强一致业务证据日志,不要轻易异步化。
  • 异步日志不要配 %class%line%method 这类位置信息,性能会很难看。

一句话:异步日志是涡轮增压,不是刹车系统。该少打的日志还是要少打。

迁移检查清单

迁移完成后,至少检查这些点:

  • 启动日志里确认使用的是 Log4j2,不再是 Logback。
  • mvn dependency:tree 中没有 logback-classic
  • 没有同时存在 log4j-to-slf4jlog4j-slf4j2-impl
  • local/dev 控制台仍然可读。
  • test/prod 输出是一行一个 JSON,不要 pretty print。
  • JSON 中能看到 trace_idrequest_idtenant_id 等 MDC 字段。
  • 业务日志字段不是塞在 message 里,而是独立字段。
  • 异常堆栈长度受控,避免单条日志巨大。
  • 压测时观察日志 I/O、CPU、GC、磁盘写入和日志队列堆积。

最终推荐方案

如果是 Spring Boot 3.4+ 新项目:

1
2
3
4
5
6
7
8
业务代码:SLF4J API
本地日志:PatternLayout
生产日志:Spring Boot structured logging + ECS
业务字段:SLF4J Fluent API + MDC
日志分组:logging.group 统一管理 Web、持久化、RPC、消息组件级别
滚动策略:按日期 + 大小滚动,设置 maxHistory 与 totalSizeCap
链路字段:Micrometer Tracing / OpenTelemetry + MDC
日志实现:默认 Logback 即可,必要时再换 Log4j2

如果是高并发或日志量大的老项目:

1
2
3
4
5
6
业务代码:保持 SLF4J 不动
日志实现:Logback -> Log4j2
配置文件:logback-spring.xml -> log4j2-spring.xml
生产格式:StructuredLogLayout 或 JsonTemplateLayout
异步能力:压测确认后开启 AsyncLogger
审计日志:保留同步或单独落库

日志打印的15条建议

  1. 选择恰当的日志级别 error warn info debug
  2. 日志要打印出参入参数 方便甩锅
  3. 选择合适的日志格式 时间戳 线程名字 日志级别等
  4. if-else ,switch 等分支语句都建议打印日志,方便排查
  5. 对一些比较低的日志级别进行判断,使用log.isXXXX()方法判断
  6. 不建议直接使用log4j ,logback等日志系统,建议使用slf4j框架,方便统一处理
  7. 建议使用参数占位符{},而不是+拼接,简洁且提升性能
  8. 建议使用异步日志,能有效提升IO性能
  9. 不要使用e.printStackTrace ()打印错误信息,因为太多信息,且是堆栈信息,会使得内存溢出
  10. 异常不要只打一半,要完成输出
  11. 禁止在线上开启debug 会把磁盘打满
  12. 不要记录了异常,又抛出异常
  13. 避免重复打印日志,浪费磁盘空间
  14. 日志文件按用途分离,推荐主日志 + ERROR 镜像;审计、访问日志按职责独立,不必机械地按每个级别拆文件
  15. 核心功能模块,建议打印详细的日志

Mybatis Plus 自定义日志

不常用,不写了,详见参考资料。

参考资料

启示录

富贵岂由人,时会高志须酬。

能成功于千载者,必以近察远。


JAVA日志专辑
https://allendericdalexander.github.io/2024/01/06/java/spring/JAVA_LOG_V3/
作者
AtLuoFu
发布于
2024年1月6日
许可协议