「这是我参与2022首次更文挑战的第 4 天，活动详情查看：2022首次更文挑战」

不恰当的日志打印会造成哪些问题？

降低线上问题排查效率

案例一：错误日志未打印异常栈，问题排查困难

包含如下两种情况：

打印日志时未打印异常体。 在这种情况下，异常信息和异常栈都是缺失的。
打印日志时只打印了异常信息，未打印异常栈。 在这种情况下，像 NullPointerException 打印的结果就是空，无法及时定位线上问题。

解决方案：打印整个异常体。

用 log4j 2 日志打印代码举例如下：

/**
 * 假设这是一个交易流程中的下单处理器
 */
@Slf4j
class CreatOrderProcessor {
    public Long createOrder(Long userId) {
        try {
            // 执行下单流程
            return orderId;
        } catch (Exception e) {
            // 错误情况1
            log.error("下单流程出错，用户Id为{}", userId);
            // 错误情况2
            log.error("下单流程出错，用户Id为{}，异常为{}", userId, e.getMessage());
            // 正确的日志打印方式
            log.error("下单流程出错，用户Id为{}，异常为：", userId, e);
        }
    }
}

案例二：日志打印级别不合理，真正的错误被淹没

主要是这种情况：

将一些不致命的错误打印为 ERROR 级别，导致 ERROR 级别日志泛滥。

这会导致两个问题：

团队人力成本的上升。 错误日志太多，值班的运维同学需要耗费大量的精力来分辨哪些是真正的问题，提取有效信息的难度增加，效率自然会下降。
小流量问题的忽视。 无效日志掩盖了真正的问题，当异常日志过多时，无法保证每一个问题都能被发现。

解决方案：制定并遵循相应的日志打印规范。这个规范可以是业界通用的（参考上篇，推荐的四个打印级别；或者参考「阿里巴巴Java开发手册」），也可以是根据团队业务特点自己制定的，但需要团队通过 Code Review 等形式来保障落地。

附：《阿里巴巴Java开发手册》节选

案例三：日志打印泛滥，排查问题的时间范围受限

主要是这种情况：

INFO 级别日志打印过多，导致存储资源瓶颈，反过来又限制了日志的存储范围。

这会导致两个问题：

应用服务器日志膨胀。

服务器日志一般是根据 log4j 配置文件来打印的。一般情况下，我们会通过配置文件指定日志分片大小（比如达到 512M 就产生一个新的日志文件）、日志文件个数（比如共打印 30 个文件）来限制日志打印的上限。

当日志打印过多时，服务器日志的可追溯时间范围就会变小：比如一天打印 1G 的日志，那么 512M*30 = 15G 的日志上限只能支持 15 天的日志追溯，当需要排查的问题来自第 16 天时，就会很难处理。
日志系统存储成本上升。 生产环境中，通常会将日志远程上报到数据中心，然后通过检索系统做查询。如果上报的日志量过大，数据存储的成本就会上升，同时也会导致日志系统延迟。

解决方案：数据查询类接口（读接口）尽量不打印日志；事务提交类接口（写接口）不重复打印日志、只打印关键日志。

案例四：关键上下文打印缺失或错误，缺少问题排查现场

包含如下两种情况：

关键上下文未打印。 比如一个交易的退款流程中，未打印订单号。
关键上下文对象未重写 toString 方法。 在这种情况下，会直接将对象地址打印出来。

用 log4j 2 日志打印代码举例如下：

/**
 * 假设这是一个交易流程中的退款处理器
 */
@Slf4j
class RefundProcessor {
    public void refund(Long orderId, User user) {
        try {
            // 执行退款流程
        } catch (Exception e) {
            // 错误情况1
            log.error("退款流程出错", e);
            // 错误情况2，假设User对象未重写toString方法
            log.error("退款流程出错，用户为{}，异常为：", userId, e);
            // 正确的日志打印方式，但如果User对象重写了toString方法，按照错误情况2打印即可
            log.error("退款流程出错，用户为{}，异常为：", JacksonUtils.serialize(user), e);
        }
    }
}
// 配合错误情况2的
class User {
    private Long userId;

    public void setUserId(Long userId) {
        this.userId = userId;
    }
    
    public Long getUserId() {
        return this.userId;
    }
}

建议：对于对外提供的数据传输对象（DTO），重写toString方法，以防止调用方日志打印问题。

参考代码如下：

class UserDTO {
    private Long userId;

    public void setUserId(Long userId) {
        this.userId = userId;
    }
    
    public Long getUserId() {
        return this.userId;
    }
    
    @Override
    public String toString() {
        return "UserDTO{" + "userId=" + this.userId + "}";
    }
}

影响系统性能，甚至引发系统故障

造成服务瘫痪。 举例，业务出现故障时产生大量错误日志，导致磁盘 IO 急剧升高，耗费大量 CPU，进而导致服务瘫痪。
导致线程阻塞。 举例，一次鞭辟入里的 Log4j2 异步日志输出阻塞问题的定位
引起内存泄漏。 举例，记一次log4j日志导致线上OOM问题案例
其他性能问题。

怎么解决这些问题？

制定、遵循符合业务特性的日志打印规范。

个人建议：

明确日志分级规范；
异步打印日志；
避免短时间内大量日志打印、避免循环打印日志；
打印关键上下文，但避免日志的重复；
参考《阿里巴巴Java开发手册》，制定符合实际情况的日志规范。

打日志那点儿事（下）你在生产环境遇到过这些问题吗？