06-07 15:51 兰州大学算法工程师发布于广东

关注

打印高质量日志的10条军规

想获取更多高质量的Java技术文章？欢迎访问技术小馆官网，持续更新优质内容，助力技术成长!

你以为打日志是小事？也许正是这种轻视，让你在凌晨三点被生产事故电话吵醒。一个优秀的工程师和普通码农的区别，往往体现在那些看似微不足道的细节上。

日志就是这样一个细节。我曾经目睹一个团队花了整整一周时间排查一个本可以在10分钟内解决的问题，只因为他们的日志像一团乱麻。更荒谬的是，很多人自认为写的日志"足够好"，却不知道他们的日志实际上像是没调音的二胡，不仅没有帮助，反而制造了混乱。在经历了无数次"日志救火"和"日志灾难"后，我总结出了这10条日志军规，它们来自血与泪的教训，也来自顶级互联网公司的最佳实践。遵循这些规则，你将彻底改变打日志的方式，并可能在下一次生产事故中成为团队的英雄。

一、日志的根本目的与常见误区

1. 日志是为了"读"

很多开发者的第一反应就是"日志当然是为了排查问题"，但问题是：谁来读这些日志？

大多数日志的命运是：要么无人问津，要么在深夜被迫阅读。在你敲下每一行日志代码时，请想象凌晨三点被吵醒的自己（或者可怜的值班同事）需要从海量日志中找出线索。

// 糟糕的日志示例
log.info("处理开始");
// 大量业务逻辑...
log.info("处理结束");

// 改进后的日志
log.info("开始处理用户支付请求 userId={}, orderId={}, amount={}", userId, orderId, amount);
// 业务逻辑...
log.info("用户支付请求处理完成 userId={}, orderId={}, result={}", userId, orderId, result);

2. 多打日志是一个危险的建议

"多打点日志吧"是技术leader最常给的建议之一。但这句话就像"多喝点水"一样空泛。没有目的的狂打日志，只会让真正有价值的信息淹没在日志的海洋中。

我见过一个Java项目，5分钟产生了50MB的日志文件，打开一看，全是：

log.debug("进入方法A");
log.debug("退出方法A");
log.debug("进入方法B");
log.debug("退出方法B");
// ...无穷无尽...

这不是日志，这是垃圾。记住，每一行日志都有成本：存储成本、I/O成本、阅读成本。

3. 用户视角 vs 开发视角

日志应该从谁的视角出发？大多数日志都是从开发者视角编写的：

log.info("用户数据解析完毕，开始更新缓存");

但真正有价值的日志应该结合业务视角：

log.info("用户{}的订单{}状态从{}变更为{}", userId, orderId, oldStatus, newStatus);

这样的日志不仅技术人员看得懂，产品和运营同事也能大致理解，这在跨团队沟通时非常关键。

二、日志的等级艺术

1. 何时使用哪种级别？

ERROR：系统无法正常运行，需要立即关注
WARN：潜在的问题，但不影响当前功能
INFO：重要的业务事件，用于追踪系统的工作流程
DEBUG：用于开发调试的详细信息
TRACE：最详尽的信息，通常只在跟踪代码执行路径时使用

2. 为什么90%的ERROR级别日志都用错了

大多数开发者会在catch块里机械地写：

try {
    // 业务逻辑
} catch (Exception e) {
    log.error("处理失败", e);
}

但这是错的！很多异常是预期内的业务异常，不是系统错误。例如用户输入了错误的密码，这是业务逻辑，不是ERROR级别的系统故障。

try {
    authService.login(username, password);
} catch (InvalidCredentialsException e) {
    // 这是预期内的业务场景，用INFO记录
    log.info("用户{}登录失败：密码错误", username);
    return "密码错误";
} catch (Exception e) {
    // 这是意外异常，用ERROR记录
    log.error("用户{}登录过程发生系统异常", username, e);
    return "系统异常";
}

3. 如何正确划分日志级别的边界

简单的判断标准：

ERROR：需要人工介入处理的问题
WARN：今天不处理，明天可能变成ERROR的问题
INFO：标记重要业务节点，帮助理解系统运行状态
DEBUG/TRACE：临时排查问题用，生产环境通常关闭

4. 不同环境的日志级别策略

开发环境：DEBUG或更详细，帮助开发者调试
测试环境：INFO，关注业务流程是否正确
生产环境：WARN或INFO，取决于系统规模和性能要求

大型系统建议：

# 生产环境配置示例
logging.level.root=WARN
logging.level.com.yourcompany.core=INFO
logging.level.com.yourcompany.thirdparty=ERROR

三、日志内容的军规

1. 一条好日志的必备要素

一条完美的日志应包含：

时间（日志框架通常自动提供）
环境/实例标识（在分布式系统中尤其重要）
请求标识（如TraceId）
操作主体（谁做了什么）
关键业务参数
操作结果

// 差的日志
log.info("支付成功");

// 好的日志
log.info("[订单中心] 用户{}完成订单{}支付 金额={} 渠道={} 耗时={}ms", 
    userId, orderId, amount, channel, costTime);

2. 避免日志污染的7个实用技巧

避免在循环中打印日志

// 糟糕的实践
for (Item item : items) {
    log.info("处理商品: {}", item);  // 可能输出成千上万条
}

// 改进
log.info("开始处理{}个商品", items.size());
// 处理逻辑
log.info("完成处理{}个商品, 成功={}, 失败={}", items.size(), successCount, failCount);

使用占位符，而不是字符串拼接

// 错误方式
log.debug("处理用户: " + user.getName() + ", ID: " + user.getId());  // 即使日志级别关闭，仍会执行字符串拼接

// 正确方式
log.debug("处理用户: {}, ID: {}", user.getName(), user.getId());  // 日志级别关闭时，不会执行参数计算

警惕大对象输出

// 危险操作
log.debug("用户数据: {}", user);  // 可能输出大量无用信息

// 更好的做法
log.debug("用户基本信息: id={}, name={}, type={}", user.getId(), user.getName(), user.getType());

使用日志脱敏工具
引入SLF4J MDC机制关联同一请求的日志
定期清理不再使用的日志
使用断言判断是否需要打印复杂日志

if (log.isDebugEnabled()) {
    log.debug("复杂对象详情: {}", generateExpensiveDebugInfo(obj));
}

3. 敏感信息处理

这是最容易被忽视的问题，却可能导致最严重的后果。请务必从日志中去除：

密码、密钥、令牌
身份证、手机号、银行卡
用户地址等个人信息

// 危险的日志
log.info("用户登录: username={}, password={}", username, password);

// 安全的日志
log.info("用户登录: username={}, password=****", username);

// 更好的做法：使用专业的日志脱敏工具
log.info("用户信息: {}", LogSensitiveUtils.mask(userInfo));

四、结构化日志的威力

1. 为什么说非结构化日志正在被淘汰

传统日志是为人类阅读设计的，但现代系统规模已经超出人类直接阅读的能力范围。结构化日志（如JSON格式）具有以下优势：

机器可读，便于自动化分析
字段明确，不会混淆
易于索引和搜索
支持复杂数据结构

2. JSON日志格式的实现方法

在Spring Boot项目中配置JSON日志：

# application.properties
logging.pattern.console=
logging.config=classpath:logback-spring.xml

<!-- logback-spring.xml -->
<configuration>
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="net.logstash.logback.encoder.LogstashEncoder"/>
    </appender>
    
    <root level="INFO">
        <appender-ref ref="CONSOLE" />
    </root>
</configuration>

输出示例：

{
  "timestamp": "2023-01-01T12:00:00.000Z",
  "level": "INFO",
  "thread": "http-nio-8080-exec-1",
  "logger": "com.example.OrderService",
  "message": "用户支付成功",
  "userId": "12345",
  "orderId": "ORD9876",
  "amount": 99.99,
  "channel": "wechat"
}

五、日志与性能的选择

1. 日志为何会影响性能

日志操作是典型的I/O密集型操作，主要性能瓶颈在于：

磁盘I/O（写入速度有限）
文件系统缓存
字符串处理（格式化、拼接）
线程同步（在多线程环境下）

测试表明，大量日志可能导致应用吞吐量下降30%-50%！

2. 异步日志的正确实现方式

通过异步方式将日志写入从主线程分离：

<!-- logback异步配置 -->
<configuration>
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 配置省略 -->
    </appender>
    
    <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="FILE" />
        <queueSize>512</queueSize>
        <discardingThreshold>0</discardingThreshold>
        <includeCallerData>false</includeCallerData>
    </appender>
    
    <root level="INFO">
        <appender-ref ref="ASYNC" />
    </root>
</configuration>

3. 高并发场景下的日志实现

采样日志：只记录部分请求的详细信息

// 简单的采样实现
if (Math.random() < 0.01) {  // 1%采样率
    log.info("详细请求信息: request={}, headers={}", request, headers);
}

批量日志：将多条日志合并为一条写入
异步非阻塞日志：使用Disruptor等高性能队列
日志缓冲区调优：增加缓冲区大小，减少刷盘频率

六、日志的运维与治理

1. 日志轮转与归档策略

日志文件不能无限增长，需要设置轮转策略：

<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>app.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
        <fileNamePattern>app-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
        <maxFileSize>100MB</maxFileSize>
        <maxHistory>30</maxHistory>
        <totalSizeCap>3GB</totalSizeCap>
    </rollingPolicy>
    <encoder>
        <pattern>%d %p %c{1} [%t] %m%n</pattern>
    </encoder>
</appender>

2. 集中式日志平台的选择

现代系统普遍采用ELK（Elasticsearch + Logstash + Kibana）或EFK（Elasticsearch + Fluentd + Kibana）栈来集中管理日志。

简单架构：

应用 -> Filebeat -> Logstash -> Elasticsearch -> Kibana

关键是在应用层面保证日志格式统一、字段规范，才能充分利用日志平台的能力。

3. 日志监控告警的设计原则

基于日志的监控策略：

错误率监控：ERROR日志量突增
关键字监控：特定异常类型或错误码
模式识别：异常的日志模式变化
缺失检测：预期日志未出现（如定时任务未执行）

设置合理的告警阈值和降噪规则，避免"狼来了"效应。

七、实战案例解析

1. 日志缺失导致的灾难性后果

某电商平台在618期间遭遇支付系统故障，用户支付后无法收到订单确认，导致大量重复下单。系统日志竟然只有：

2023-06-18 10:30:15 ERROR Process failed
2023-06-18 10:30:17 ERROR Process failed
2023-06-18 10:30:22 ERROR Process failed

没有任何上下文信息，技术团队不得不手动比对数据库数据排查问题。最终发现是支付回调接口超时，但由于缺乏有效日志，排查过程耗时4小时，造成直接经济损失超过100万。

改进后的日志：

2023-09-01 14:22:15 ERROR [PaymentService] 支付回调处理失败 orderId=ORD123456 userId=10001 paymentId=PAY789012 channel=alipay amount=1299.00 errorCode=TIMEOUT errorMsg=第三方接口连接超时 traceId=c7d2eb9f14ce

有了详细日志后，类似问题10分钟内可确定根因并采取补救措施。

2. 从日志优化看系统设计的演进

某社交应用的消息推送服务日志优化经历：

第一阶段：简单文本日志

2022-01-01 12:00:00 INFO 推送消息成功

第二阶段：添加基本参数

2022-03-01 12:00:00 INFO 推送消息成功 userId=123 msgId=456

第三阶段：结构化JSON日志 + 分布式追踪

{
  "timestamp": "2022-06-01T12:00:00.000Z",
  "level": "INFO",
  "service": "push-service",
  "instance": "push-pod-3",
  "traceId": "abc123def456",
  "message": "消息推送成功",
  "data": {
    "userId": "123",
    "msgId": "456",
    "channel": "app",
    "deviceType": "iOS",
    "latency": 24
  }
}

第四阶段：引入业务指标和日志聚合

{
  "timestamp": "2022-10-01T12:00:00.000Z",
  "level": "INFO",
  "service": "push-service",
  "instance": "push-pod-3",
  "traceId": "abc123def456",
  "message": "批量消息推送完成",
  "data": {
    "batchId": "batch789",
    "totalMessages": 1000,
    "successCount": 950,
    "failCount": 50,
    "avgLatency": 28,
    "p95Latency": 42,
    "errorBreakdown": {
      "TIMEOUT": 30,
      "DEVICE_OFFLINE": 15,
      "PERMISSION_DENIED": 5
    }
  }
}

这种演进不仅改进了日志本身，还反过来优化了系统的可观测性设计，最终使整个系统更加健壮和可维护。