总阅读量:次

⭐⭐⭐ Spring Boot 项目实战 ⭐⭐⭐ Spring Cloud 项目实战
《Dubbo 实现原理与源码解析 —— 精品合集》 《Netty 实现原理与源码解析 —— 精品合集》
《Spring 实现原理与源码解析 —— 精品合集》 《MyBatis 实现原理与源码解析 —— 精品合集》
《Spring MVC 实现原理与源码解析 —— 精品合集》 《数据库实体设计合集》
《Spring Boot 实现原理与源码解析 —— 精品合集》 《Java 面试题 + Java 学习指南》

摘要: 原创出处 阿飞的博客 「阿飞」欢迎转载，保留摘要，谢谢！

🙂🙂🙂关注**微信公众号：【芋道源码】**有福利：

  1. RocketMQ / MyCAT / Sharding-JDBC 所有源码分析文章列表
  2. RocketMQ / MyCAT / Sharding-JDBC 中文注释源码 GitHub 地址
  3. 您对于源码的疑问每条留言都将得到认真回复。甚至不知道如何读源码也可以请教噢。
  4. 新的源码解析文章实时收到通知。每周更新一篇左右。
  5. 认真的源码交流微信群。

事故代码

直入主题，生产环境日志级别为warn，请看如下这行代码：

LOGGER.info("the DTO info: {}", JSON.toJSONString(DTO));

先做个小调查，你觉得这段代码会不会有问题。

如果你的答案为“有问题”，并且你有充足的理由，那么这篇文章已经没有往下看的必要了，因为你已经掌握了笔者此文要传达的知识点。如果你的答案为“没有问题”或者“无法分辨”，那么，请继续往下看。

原因分析

这段代码主要有两个需要注意的地方：

  1. 日志级别为info，而线上环境是warn级别。我们可以得出结论，线上环境肯定不会输出这行日志。
  2. 打印日志的行为中有JSON序列化动作。

第二点是此文的关键。我们假设DTO是一个很小的对象，JSON序列化时间以及开销可以忽略不计，那么这行代码依然没有问题。但是，如果DTO是一个很大的对象，比如10k，甚至100k，即使快如fastjson，其耗时依然高达数百毫秒，并且非常消耗CPU。如果是在高并发的系统中，这么大的开销完全不可接受，甚至可能就会拖垮整个系统。

有同学就会说了，我不是info日志么，为什么还会执行这行代码？请继续往下看。我们首先看一下slf4j中logger.info()这个方法是如何申明的：第二个参数为Object类型。我们的代码中传递给第二个参数的值为：JSON.toJSONString(DTO)，很明显这行代码是传递一个String类型的字段给Object arg。那么String如何来呢？答案也很明显，必须先执行JSON序列化才能得到String。那么logger.info这个info在什么时候起作用呢？答案是它只能在输出日志这个动作时起作用：

public void info(String format, Object arg);

解决方案

如何解决这个问题？很简单，在输入日志时加个级别判断（需要说明的是，这种规范很容易被忽略，比如项目成员更替时，很容易引入有问题的代码。所以笔者写了一段脚本：扫描所有Java代码，如果logger.info()中有JSON序列化动作，那么必须判断优先级后才能输出日志。即可以简单的认为它的前一行代码必须是logger.isInfoEnabled()。如果你的项目有CICD环境，那么把这段脚本集成到扫描规范中，才是解决这个问题最完美的方案）：

if (LOGGER.isInfoEnabled()) {
    LOGGER.info("the DTO info: {}", JSON.toJSONString(DTO));
}

当然，需要说明的是，通过上面的分析，如果我们的打印日志那行代码中没有JSON序列化等耗时动作的话，那么日志级别判断就没必要了，比如下面这行代码：

String reqId = "...";
String msg = "...";
LOGGER.info("the DTO info: {}", msg);

文章目录
  1. 1. 事故代码
  2. 2. 原因分析
  3. 3. 解决方案