打印日志的正确姿势和最佳实践！
你知道的越多，不知道的就越多，业余的像一棵小草！
你来，我们一起精进！你不来，我和你的竞争对手一起精进！
编辑：业余草
zhuanlan.zhihu.com/p/109237510
推荐：https://www.xttblog.com/?p=5116
背景
有一次我用一个 requestId 去查日志，发现就一个 requestId 的日志够 20 几 M 了，对查日志来说真的是痛苦，因为你发现 90% 都是垃圾日志，找你要找关键日志非常难。
又有一次中台金融组问我们传什么数据给他们，给了我一个 requestId 去查日志，，直接蒙圈了......，真的好没面子啊，竟然查不到日志，翻了一下代码，这个开发人员代码里一行日志没留，连 debug 日志的影子都没有。
我想应该不仅我有这痛苦，好多人都一样碰到过，可见打好日志是多么重要，因为打好日志非常有助于排查问题，打不好呢，坏外就太多了，谈谈我看到的问题和我的使用习惯；
日志级别与配置
很多人像真的像“神”一样的存在，开发环境竟然配置的是 info 或是 warn，且是全局配置的info 或 warn，一般来说 info 或以上级别打出的日志并不多，在开发阶段还真不建议全局info，因为你这样的话很多如 SQL，或是在开发阶段的跟踪信息没有，着实很痛苦，而且 debug 的正确方式是优先使用日志，而不是一来就开 IDE 做 debug，这样的效率会很低，另外，生产上不可能给你这么玩；
如果是全局配置最好还是 debug 吧，以 logback 为例吧：(输出到控制台，全局 debug 模式)。
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{5} - %msg%n</pattern>
</encoder>
</appender>
<root level="DEBUG">
<appender-ref ref="STDOUT" />
</root>
</configuration>如果很多人认为 debug 日志太多了，我只想打关键信息呢，可使用反选方式和正选方式两种。
可以全局输出为 debug，把其它的不需要的包使用 info 或 warn，相当于过滤掉不需要的包：比如我不想看 org.springframework 下太多 debug 信息，我就将这个包单独设置成 info 或 warn。
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{5} - %msg%n</pattern>
</encoder>
</appender>
<root level="DEBUG">
<appender-ref ref="STDOUT" />
</root>
<!-- 不想看到spring包下这么多信息，以warn输出这个包下的日志 -->
<logger name="org.springframework" level="WARN"/>
</configuration>可以全局输出为 info，把需要的包设置成 debug，相当于只看我需要的包下的 debug 信息，其它包的日志为 info 级别，比如我只想看自己项目包中的 debug 信息如 me.ele.ebu。
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{5} - %msg%n</pattern>
</encoder>
</appender>
<root level="INFO">
<appender-ref ref="STDOUT" />
</root>
<!-- 我想设置我项目下主包名的级别为debug --!>
<logger name="me.ele.ebu" level="DEBUG"/>
</configuration>输出关键日志要点
抓住“时间，地点，人物，事件”四大角色。
时间：一般是产生日志时间log会自带，不一定是输出时间，有些是异步输出的；地点：一般指代码的行数，或是方法名等；人物：可以使用requestId或线程信息来代替人物的角色；事件：就是开发输出的日志信息，输出的最好是关键信息，能助我们排查问题的关键信息；
何为关键日志，在我看来关键日志应该是，我个人觉得至少在开发阶段可以不仅限于以下几种：出入参数，流程步骤，验证的结果信息，异常处理信息。
当异常时输出参数，而不仅是堆栈信息
但如果是生产上，这些日志确实有点多了，但是至少有一种是必须输出的，就是出现异常的信息，必须将参数输出来，因为 90% 以上的问题都是通过异常触发的，而这些参数方便我们回溯。
不推荐这么输：
try{
//code
}catch(Exception e){
log.error("异常：",e);
}推荐这么输：
try{
//code
}catch(Exception e){
log.error("添加员工异常：{}",params,e);
}思考：出了异常但只有堆栈信息，没有参数时，也是很绝望的，你总是要问别人传了什么？生产不能老是问用户传什么了吧。
打日志不要影响到性能
曾经有一次排查一个问题，发现生产 cpu 和 io 暴涨，结果排查下来是一个较高的并发+日志产生的问题，而且是一个 debug 输出，按理说 debug 在生产不输出，怎么会出问题？
不要直接使用+拼接打日志
log.debug("参数信息："+obj1+obj2);原因：虽然是 debug，会先执行 "参数信息：" + obj1 + obj2，生成一个新的 String 对象，然后传入 log.debug 方法，log.debug 发现日志其实是 info 级别的不需要输出这个新生成的 String 对象，这个新生成的对象操作就是无用功；
针对对象有操作，也不要直接使用log输出
log.debug("参数信息：{}",JSON.toJsonString(obj));原因：和 1 有点类似，好不容易转成 json，发现里边是 info 级别，且此处还对对象有操作，这个可能很危险，如果是复杂，耗时的对象操作，可能还会导致高 cpu 和高 io；
正确的打法是：log 的占位符号 + 合理利用对象的 toString（当然需要重写 toString，可以使用生成工具或是 lombok@data 注解）或是先判断是否是对应日志级别再打：
log.debug("参数信息：{},{}",obj1,obj2); //合理利用Object的toString
//如果对输出对象有操作，请先判断是否为对应的日志级别，避免白操作对象
//当然如果是info以上的我觉得可以不用判断，因为日志级别一般都会<=info级别
if(log.isDebugEable()){
log.debug("日志信息：{},{}",JSON.toJsonString(obj1),JSON.toJsonString(obj2));
}巧用 aop，针对输入输出及异常时输出不同级别的日志。
网上一讲到 AOP 就是前后日志的例子，何不放到应用中一试呢，前后输出日志为 debug，当异常时输出 error 级别并带上参数，信手拈来一个例子：
@Around("within(@org.springframework.stereotype.Service)")
public Object trace(ProceedingJoinPoint joinPoint) throws Throwable {
log.debug("params:{}",joinPoint.getArgs());
try {
retVal = joinPoint.proceed();
log.debug("result:{}",retVal);
} catch (Exception e) {
log("系统处理异常:params:{}", joinPoint.getArgs(),e);
throw e;
}
}再谈生产日志
我们都知道过多的生产日志确实也会影响到性能，比起开发环境，生产环境的日志就是取舍重要日志的过程。
以下三条是我的习惯，提供参考：
- 普通链路上，不需要的所有的出入口输出，但至少在入口出保留一条参数的输出，可以不用全部参数，但至少是是重要参数，如id这些可以定位全局参数的数据，当然日志也要注意脱敏；
- 重要链路上，关键点应该打出一些参数日志，特别是如果不落库的，短暂性信息，更应该首先考虑；
- 异常捕获时，最好输出参数日志和异常堆栈信息，因为这些参数是帮我们定位出问题的最直接证据。