日志输出格式:Pattern 布局、时间戳、线程名、类名、行号的定制
日志格式这东西,看着不起眼,但真出了问题你就知道它有多重要了。我记得有一次线上排查一个死锁问题,几十个线程的日志混在一起,时间戳只精确到秒,线程名全是默认的"Thread-1"、"Thread-2"……那叫一个痛苦。从那以后,我对日志格式的要求就变得特别苛刻。
说白了,日志格式就是你的"现场还原工具"。格式定得好,问题定位快三倍。今天我们就聊聊怎么定制一个靠谱的日志输出格式。
4.1 Pattern 布局的核心要素
Logback 和 Log4j2 都支持通过 Pattern 来定制日志输出格式。我个人习惯用 Logback,但核心概念是通用的。一个完整的 Pattern 布局,至少应该包含下面这几个要素:
| 要素 | 占位符 | 说明 | 我踩过的坑 |
|---|---|---|---|
| 时间戳 | %d{yyyy-MM-dd HH:mm:ss.SSS} |
精确到毫秒,用于时间线还原 | 少写了毫秒,排查慢查询时根本对不上 |
| 日志级别 | %-5level |
左对齐,固定5字符宽度 | 不固定宽度的话,排版会乱 |
| 线程名 | %thread |
区分并发请求的关键 | 默认线程名没业务含义,后面会讲怎么改 |
| 类名 | %logger{36} |
缩短包名,保留36字符 | 太长的话一行就占了大半 |
| 行号 | %line |
精确到代码行,快速定位 | 生产环境慎用,有性能开销 |
| 消息体 | %msg%n |
日志内容 + 换行 | 别忘了 %n,否则日志全粘一起 |
我常用的一个 Pattern 是这样的:
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36}:%line - %msg%n</pattern>
输出效果:
2025-03-21 14:32:18.456 [http-nio-8080-exec-3] INFO com.example.OrderService:127 - 订单创建成功,订单号: ORD20250321001
嗯,这个格式我用了好几年,基本没改过。你想想看,一行日志里,时间、谁打的、什么级别、哪个类的哪一行、说了什么,全有了。
4.2 时间戳的精度与格式选择
时间戳是日志里最重要的字段,没有之一。为什么?因为你要还原事件发生的先后顺序。
我曾经遇到过一个场景:两台机器的系统时间差了3秒,结果日志里A机器的"请求到达"时间比B机器的"响应返回"还晚,排查了半天才发现是时间不同步。从那以后,我要求所有服务器必须启用 NTP 同步,并且日志时间戳统一使用 UTC。
时间戳的格式选择,我建议遵循几个原则:
- 必须包含毫秒:
SSS不能省。高并发场景下,同一秒内可能有上千条日志,没毫秒根本分不清先后。 - 使用 ISO 8601 格式:
yyyy-MM-dd'T'HH:mm:ss.SSSZ带时区信息,跨团队协作时不会产生歧义。 - 避免使用默认格式:Logback 默认的
%d输出的是 "2025-03-21 14:32:18,456",逗号分隔毫秒,看着别扭。
4.3 线程名的定制与业务关联
线程名这个东西,默认的 http-nio-8080-exec-3 只能告诉你这是第几个工作线程,但无法关联到具体的业务请求。你想想看,如果同时有100个请求在处理,日志里全是 exec-1 到 exec-100,你根本不知道哪个线程在处理哪个用户的请求。
我建议的做法是:在请求入口处,把线程名改成有业务含义的名称。
// 在 Filter 或 Interceptor 中
String originalName = Thread.currentThread().getName();
String businessName = "order-" + orderId + "-" + UUID.randomUUID().toString().substring(0, 8);
Thread.currentThread().setName(businessName);
try {
// 处理业务逻辑
} finally {
// 记得恢复
Thread.currentThread().setName(originalName);
}
这样日志就变成了:
2025-03-21 14:32:18.456 [order-ORD20250321001-a3f8c2d1] INFO ...
看到线程名,你就知道这条日志属于哪个订单。排查问题时,直接 grep 这个线程名,就能把整个请求链路的所有日志捞出来。
4.4 类名与行号的取舍
类名和行号是定位代码位置的关键。但这里有个矛盾:行号是通过动态生成字节码来实现的,有性能开销。
我做过一个压测对比:
| 配置 | QPS | CPU 额外开销 | 适用场景 |
|---|---|---|---|
带行号 %line |
基准值 - 15% | 约 8-12% | 开发、测试、预发环境 |
| 不带行号 | 基准值 | 0% | 生产环境(高并发) |
仅类名 %logger |
基准值 - 3% | 约 2% | 生产环境(中等并发) |
我的建议是:
- 开发环境:带上行号,方便快速定位。
- 生产环境:去掉行号,用类名 + 方法名代替。或者只在 WARN/ERROR 级别带行号,INFO 级别不带。
Logback 支持按级别设置不同的 Pattern:
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>WARN</level>
</filter>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36}:%line - %msg%n</pattern>
</encoder>
</appender>
<appender name="FILE_INFO" class="ch.qos.logback.core.rolling.RollingFileAppender">
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>INFO</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
这样 WARN 和 ERROR 日志带行号,方便排查;INFO 日志不带行号,减少性能损耗。
4.5 日志格式的整体设计原则
说了这么多,最后总结一下我设计日志格式的几个原则:
- 可读性优先:格式对齐,固定宽度,不要一行日志长得像天书。
- 信息完整:时间、线程、级别、位置、消息,一个都不能少。
- 性能可接受:生产环境去掉行号,或者按级别区分。
- 统一规范:整个团队、所有服务使用相同的格式,方便统一采集和分析。
核心观点:日志格式不是写给自己看的,是写给未来的自己和同事看的。花10分钟把格式定好,能省下未来10小时的排查时间。
下面这张图是我对日志格式设计思路的总结,你可以参考一下:
嗯,日志格式这块就聊这么多。记住一句话:好的日志格式,是排查问题的第一道防线。花点心思把它配好,后面你会感谢自己的。