日志

硅碳合伙人大约 12 分钟

日志：看不见的代码生命线

代码上线之后，你唯一能依赖的排查手段就是日志。日志打得好，线上问题十分钟定位；日志打得烂，一个 bug 排查一整天。这篇文章从日志框架选型讲到分布式日志系统，帮你建立完整的日志知识体系。

一、日志框架选型：门面 + 实现

Java 的日志生态有两类工具，理解它们的关系是一切的基础：

日志框架（实现层）：真正干活的，负责把日志写到文件、控制台或远程服务器。代表：Log4j、Logback、Log4j2
日志门面（抽象层）：提供统一的 API，屏蔽底层框架差异。代表：SLF4J、Commons Logging

生活类比：日志门面就像餐厅的服务员，你只需要告诉服务员"来一盘番茄炒蛋"；至于后厨是 A 厨师（Logback）还是 B 厨师（Log4j2）来做，你不需要关心。换了厨师，你的点菜方式（代码）一行都不用改。

最佳实践：SLF4J + Logback（或 Log4j2）。

代码中只依赖 SLF4J 的 API，底层实现通过 jar 包切换即可更换。这是《阿里巴巴 Java 开发手册》中的强制要求。

为什么不直接用 Log4j 的 API？

因为耦合。如果你的代码里到处写着 org.apache.log4j.Logger，有一天想换成 Logback——对不起，每个 import、每个 API 调用都得改。几百个文件改一遍，改完还不确定有没有遗漏。

而用 SLF4J，你的代码始终只写：

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

private static final Logger logger = LoggerFactory.getLogger(UserService.class);

底层从 Logback 换成 Log4j2？换个 jar 包就行，一行代码都不用动。这就是门面模式的价值——解耦。

用软件设计领域的一句名言来说：计算机科学领域的任何问题都可以通过增加一个间接的中间层来解决。日志门面就是这个"中间层"。

四大日志框架对比

框架	出现时间	作者	特点
j.u.l	JDK 1.4	Sun	Java 原生，功能简陋，性能差，基本没人用
Log4j	2001	Ceki Gulcu	最早流行的日志框架，已停止维护
Logback	2006	Ceki Gulcu	Log4j 作者重写之作，性能更好，原生支持 SLF4J
Log4j2	2014	Apache	完全重写（不是 Log4j 的简单升级），异步日志性能最强

有趣的是，SLF4J、Log4j、Logback 都出自同一个人之手——Ceki Gulcu。他先写了 Log4j，觉得不够好，又写了 SLF4J + Logback。

目前新项目推荐 SLF4J + Logback 或 SLF4J + Log4j2。 Spring Boot 默认用的是 Logback。

SLF4J 的几个优势

去掉了 FATAL 级别：SLF4J 认为 ERROR 和 FATAL 没有实质区别，只保留 TRACE/DEBUG/INFO/WARN/ERROR 五级
占位符语法：用 {} 避免不必要的字符串拼接

// 反面：不管 debug 是否开启，字符串拼接都会执行
logger.debug("User " + userId + " login from " + ip);

// 正面：debug 未开启时，占位符不会被求值，零开销
logger.debug("User {} login from {}", userId, ip);

不会犯 "toString" 的错：直接传对象就好，SLF4J 会在需要时才调用 toString()
MDC 支持：方便在日志中携带链路追踪信息

二、日志级别设计

2.1 为什么要用 isXxxEnabled()

你可能在 Spring、Dubbo 等框架源码中经常看到这样的写法：

if (logger.isWarnEnabled()) {
    logger.warn("Request failed: " + JSON.toJSONString(request));
}

为什么不直接写 logger.warn(...) ？

因为即使 warn 级别没有开启，JSON.toJSONString(request) 这个方法调用和字符串拼接仍然会执行——白白浪费 CPU 和内存。先用 isWarnEnabled() 判断一下，就可以完全跳过这些无用的计算。

在高频调用的路径上（比如每秒几万次的核心链路），这个优化效果非常明显。

不过如果你用 SLF4J 的 {} 占位符语法，就不需要手动加 isXxxEnabled() 了——SLF4J 内部会在级别未开启时跳过参数求值。所以这也是推荐用 SLF4J 的另一个原因。

2.2 日志级别怎么用

级别	用途	示例	线上是否开启
ERROR	系统出错，需要立即关注	数据库连接失败、支付接口调用异常	是
WARN	潜在问题，暂时不影响功能	重试成功、降级触发、配置缺失用了默认值	是
INFO	关键业务节点的正常记录	用户登录、订单创建、支付完成	是
DEBUG	开发调试信息	方法入参出参、中间变量值	否（按需临时开启）
TRACE	最细粒度的追踪信息	循环内部每次迭代的值	否

线上环境通常只开到 INFO 级别。 DEBUG 和 TRACE 在开发/预发环境使用。

几个日志最佳实践：

ERROR 日志必须有上下文信息（请求参数、异常堆栈），让人看到这条日志就能定位问题
不要在循环里打 INFO 日志，否则一个请求可能产生几千条日志
敏感信息（密码、手机号、身份证号）要脱敏后再打印
日志内容要有区分度，不要写 "error occurred" 这种等于没说的信息

三、性能优化：异步日志与降级

核心链路上，1-2ms 的日志写入延迟都可能成为瓶颈。两个解决思路：异步和降级。

3.1 异步日志

同步写日志 = 每次都等磁盘 IO 完成才继续执行。如果磁盘 IO 慢（比如磁盘忙），主线程就被阻塞了。

异步写日志 = 主线程把日志丢到一个内存队列里就走，后台线程从队列中取出日志慢慢写磁盘。

Logback 配置异步日志：

<configuration>
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>application.log</file>
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="FILE" />
        <queueSize>512</queueSize>
        <discardingThreshold>0</discardingThreshold>
        <neverBlock>true</neverBlock>
    </appender>

    <root level="INFO">
        <appender-ref ref="ASYNC" />
    </root>
</configuration>

几个关键参数：

参数	说明	默认值	建议
queueSize	异步队列容量（BlockingQueue）	256	高并发场景调大到 512 或 1024
discardingThreshold	队列剩余容量低于此比例时丢弃 DEBUG/INFO	20%	设为 0 表示不丢弃任何级别
neverBlock	队列满时是否阻塞线程	false	true = 不阻塞，队列满就丢弃日志

Log4j2 的异步性能更强，它底层用了 Disruptor 无锁队列，比 Logback 的 BlockingQueue 快一个数量级。如果对日志性能有极致要求，可以考虑 Log4j2。

3.2 异步日志的坑：丢失 traceId

异步日志的后台线程和业务线程不是同一个线程，ThreadLocal 中存储的 traceId 就拿不到了——日志里的 traceId 会变成空。

解决办法：

方案一：自定义 Appender，在写入前把 traceId 通过 MDC 传递过去：

MDC.put("traceId", threadPoolTaskData.toString());

方案二：使用 logback-mdc-ttl 库，基于 TransmittableThreadLocal 自动传递 MDC 上下文。这个方案更优雅，不需要手动操作 MDC。

3.3 日志降级

大促场景下，如果日志量暴增导致磁盘 IO 成为瓶颈，可以通过预案开关紧急干预：

调高日志级别：从 INFO 调到 WARN 或 ERROR，瞬间减少 90% 的日志量
关闭非关键日志：某些非核心业务的日志直接关闭
采样打印：只打 1% 的请求日志。但老实说，采样和不打差别不大

这些手段一般配合运维预案系统使用，平时不动，大促或故障时紧急开启。

有些团队还会做动态日志级别调整——通过配置中心下发新的日志级别，不需要重启应用就能生效。比如线上出了一个 bug，临时把某个类的日志级别调成 DEBUG 来追踪，排查完再调回 INFO。

四、分布式日志系统：ELK

单机时代看日志 tail -f 就够了。微服务时代，一个请求经过 5 个服务、分布在 10 台机器上——你去哪台机器看日志？

分布式日志系统就是把所有机器的日志统一收集、存储、查询。

ELK 三件套：

组件	职责	说明
Logstash	日志采集、过滤、转换	支持多种输入源和输出目标，可以做日志格式化
Elasticsearch	分布式搜索引擎	日志存储和全文检索，支持复杂的条件查询和聚合
Kibana	Web 界面	图形化查询、Dashboard、报警可视化

实际生产中，Logstash 比较重（Java 进程，占资源多），通常会用 Filebeat（Go 写的轻量级采集器）替代 Logstash 做日志采集，变成 EFK 架构。

一个好的分布式日志系统应该具备：

集中化管理：所有节点的日志统一存储，一个界面搞定
准实时查询：日志写入后几秒钟就可以被搜索到
链路追踪：通过 traceId 把一个请求在所有服务中的日志串起来
监控报警：ERROR 日志突增时自动报警
日志审计：关键操作的日志长期保存，满足合规要求

选型建议：预算充足上云产品（如阿里云 SLS、AWS CloudWatch），预算有限自建 ELK/EFK。云产品的优势是免运维、弹性扩容，自建的优势是数据完全掌控在自己手里。

五、面试高频题

题目一：为什么要用 SLF4J，不直接用 Log4j？

解耦。SLF4J 是日志门面，只提供 API，不提供实现。代码中只依赖 SLF4J，底层框架（Log4j/Logback/Log4j2）随时可以通过换 jar 包切换，一行业务代码都不用改。这是门面模式的典型应用——在业务代码和日志实现之间加一层抽象。

题目二：记录日志影响性能怎么办？

两个方向：异步和降级。异步日志（AsyncAppender / Log4j2 Disruptor）让主线程不等磁盘 IO；降级则是在极端场景下通过预案开关调高日志级别或关闭非关键日志。编码层面，SLF4J 的 {} 占位符语法避免不必要的字符串拼接开销，源码级别可以用 isXxxEnabled() 做前置判断。

题目三：什么是分布式日志系统？

集中收集、存储和查询分布式系统中所有节点的日志。主流方案是 ELK（Logstash/Filebeat 采集 + Elasticsearch 存储检索 + Kibana 可视化），云上可以用阿里云 SLS。核心价值是把分散在几十台机器上的日志统一管理，支持全文检索和链路追踪，配合 traceId 可以把一个请求跨多个服务的日志串起来排查。

小结

知识点	一句话记忆
SLF4J	日志门面，解耦业务代码和日志实现
Logback vs Log4j2	都好用，Log4j2 异步性能更强（Disruptor）
isXxxEnabled()	避免无用的字符串拼接和方法调用
{} 占位符	SLF4J 占位符内部自动处理，不需要手动判断
异步日志	主线程不等 IO，注意 traceId 传递问题
日志降级	大促时调高级别或关闭非关键日志
ELK	Logstash 采集 + ES 存储 + Kibana 查询

日志不是可有可无的"附属品"，而是代码的生命线。打好日志，就是给未来排查问题的自己（或同事）留一条生路。

补充：日志实战中的常见问题

日志文件切割策略

生产环境中，日志文件不能无限增长，否则磁盘迟早被撑爆。Logback 提供了灵活的切割策略：

按时间切割（最常用）：

<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>logs/app.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
        <!-- 每天生成一个新文件 -->
        <fileNamePattern>logs/app.%d{yyyy-MM-dd}.log</fileNamePattern>
        <!-- 保留最近 30 天的日志 -->
        <maxHistory>30</maxHistory>
        <!-- 所有日志文件总大小上限 -->
        <totalSizeCap>10GB</totalSizeCap>
    </rollingPolicy>
    <encoder>
        <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
    </encoder>
</appender>

按大小 + 时间切割：

<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
    <fileNamePattern>logs/app.%d{yyyy-MM-dd}.%i.log</fileNamePattern>
    <maxFileSize>100MB</maxFileSize>
    <maxHistory>30</maxHistory>
    <totalSizeCap>10GB</totalSizeCap>
</rollingPolicy>

这样每个日志文件最大 100MB，超过后自动切割，文件名中用 %i 区分同一天的多个文件。

日志格式设计

一条好的日志应该包含足够的上下文信息，让你不需要翻代码就能理解发生了什么：

2024-01-15 10:30:45.123 [http-nio-8080-exec-1] INFO  c.e.s.OrderService - 
[traceId=abc123] 创建订单成功 | userId=10086 | orderId=202401150001 | amount=299.00

推荐的格式要素：

时间戳：精确到毫秒
线程名：排查并发问题时必不可少
日志级别：INFO/WARN/ERROR
类名：知道是哪个类输出的
traceId：链路追踪的关键
业务信息：用 | 分隔的 key=value 格式，方便后续 ELK 做结构化查询

日志与链路追踪

在微服务架构下，一个用户请求可能经过网关 → 用户服务 → 订单服务 → 支付服务 → 消息服务，跨越 5 个服务、10+ 台机器。如果没有链路追踪，排查问题就像大海捞针。

traceId 是链路追踪的核心：在请求入口生成一个全局唯一的 traceId，随请求传递到每个服务，每条日志都带上这个 traceId。这样在 ELK 中搜索一个 traceId，就能看到这个请求在所有服务中的完整日志链路。

实现方式：

网关层生成 traceId，放到 HTTP Header 中
每个服务收到请求后，从 Header 中取出 traceId，放到 MDC（Mapped Diagnostic Context）中
日志 Pattern 中配置 %X{traceId} 自动输出
服务间调用（RPC/HTTP）时，把 traceId 传递下去

// 拦截器：从 Header 中取 traceId 放到 MDC
public class TraceInterceptor implements HandlerInterceptor {
    @Override
    public boolean preHandle(HttpServletRequest request, 
                             HttpServletResponse response, Object handler) {
        String traceId = request.getHeader("X-Trace-Id");
        if (traceId == null) {
            traceId = UUID.randomUUID().toString().replace("-", "");
        }
        MDC.put("traceId", traceId);
        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request, 
                                HttpServletResponse response, 
                                Object handler, Exception ex) {
        MDC.clear(); // 请求结束后清理，避免内存泄漏
    }
}

常见的日志反模式

吞掉异常：catch(Exception e) { logger.error("出错了"); } ——没有打印堆栈，出了问题根本查不到原因。正确做法：logger.error("出错了", e);
日志中打印密码和敏感信息：logger.info("用户登录: {}", JSON.toJSONString(user)); ——如果 User 对象包含 password 字段，密码就被打到日志里了。要做字段脱敏或者只打必要字段。
循环里打 INFO：一个请求处理 10000 条数据，每条都打一行 INFO——一个请求产生 10000 行日志，磁盘和 ELK 都受不了。应该批量汇总后打一条。
日志信息没有区分度：logger.error("error occurred"); ——哪里出错了？什么错？完全没有有效信息。
过度日志：每个 getter/setter 都打日志——噪音太多，真正有用的信息被淹没。