3. 日志最佳实践
3.1 强制
1. 打印日志的代码不允许失败,阻断流程!
一定要确保不会因为日志打印语句抛出异常造成业务流程中断,如下图所示,shop为null的会导致抛出NPE。
public void doSth(){ log.info("do sth and print log: {}", shop.getId()); // 业务逻辑 ... }
2. 禁止使用System.out.println()输出日志
反例:
public void doSth(){ System.out.println("doSth..."); // 业务逻辑 ... }
分析:
- 通过分析System.out.println源码可知,System.out.println是一个同步方法,在高并发的情况下,大量执行println方法会严重影响性能。
public void println(String x) { synchronized (this) { print(x); newLine(); } }
- 不能实现日志按等级输出。具体来说就是不能和日志框架一样,有 debug,info,error等级别的控制。
- System.out、System.error打印的日志都并没有打印在日志文件中,而是直接打印在终端,无法对日志进行收集。
正例:
在日常开发或者调试的过程中,尽量使用标准日志记录系统log4j2或者logback(但不要直接使用其中的API),异步的进行日志统一收集。
public void doSth(){ log.info("doSth..."); // 业务逻辑 ... }
3. 禁止直接使用日志系统(Log4j、Logback)中的API
应用中不可直接使用日志系统(Log4j、Logback)中的API,而应依赖使用日志框架 (SLF4J、JCL--Jakarta Commons Logging)中的API。
分析:
直接使用Log4j或者Logback中的API会导致系统代码实现强耦合日志系统,后续需要切换日志实现时会产生比较大的改造成本,统一使用SLF4J或者JCL等日志框架的API,其是使用门面模式的日志框架,可以做到解耦具体日志实现的作用,有利于后续维护和保证各个类的日志处理方式统一。
正例:
// 使用 SLF4J: import org.slf4j.Logger; import org.slf4j.LoggerFactory; private static final Logger logger = LoggerFactory.getLogger(xxx.class); // 使用 JCL: import org.apache.commons.logging.Log; import org.apache.commons.logging.LogFactory; private static final Log log = LogFactory.getLog(xxx.class);
4. 声明日志工具对象Logger应声明为private static final
分析:
- 声明为private防止logger对象被其他类非法使用。
- 声明为static是为了防止重复new出logger对象;防止logger被序列化,导致出现安全风险;处于资源考虑,logger的构造方法参数是Class,决定了logger是根据类的结构来进行区分日志,所以一个类只要一个logger,故static。
- 声明为final是因为在类的生命周期无需变更logger,避免程序运行期对logger进行修改。
正例:
private static final Logger LOGGER = LoggerFactory.getLogger(xxx.class);
5. 对于trace/debug/info级别的日志输出,必须进行日志级别的开关判断
反例:
public void doSth(){ String name = "xxx"; logger.trace("print debug log" + name); logger.debug("print debug log" + name); logger.info("print info log" + name); // 业务逻辑 ... }
分析:
如果配置的日志级别是warn的话,上述日志不会打印,但是会执行字符串拼接操作,如果name是对象, 还会执行toString()方法,浪费了系统资源,执行了上述操作,最终日志却没有打印,因此建议加日志开关判断。
正例:
在trace、debug、info级别日志打印前加上对应级别的日志开关判断,通常可以将开关判断逻辑包装在日志工具类中,统一实现。
public void doSth(){ if (logger.isTraceEnabled()) { logger.trace("print trace log {}", name); } if (logger.isDebugEnabled()) { logger.debug("print debug log {}", name); } if (logger.isInfoEnabled()) { logger.info("print info log {}", name; } // 业务逻辑 ... }
6. 捕获异常后不要使用e.printStackTrace()打印日志
反例:
public void doSth(){ try{ // 业务逻辑 ... } catch (Exception e){ e.printStackTrace(); } }
分析:
- e.printStackTrace()打印出的堆栈日志跟业务代码日志是交错混合在一起的,通常排查异常日志不太方便。
- e.printStackTrace()语句产生的字符串记录的是堆栈信息,如果信息太长太多,字符串常量池所在的内存块没有空间了,即内存满了,系统请求将被阻塞。
正例:
public void doSth(){ try{ // 业务逻辑 ... } catch (Exception e){ log.error("execute failed", e); } }
7. 打印异常日志一定要输出全部错误信息
反例:
- 没有打印异常e,无法定位出现什么类型的异常
public void doSth(){ try{ // 业务逻辑 ... } catch (Exception e){ log.error("execute failed"); } }
- 没有记录详细的堆栈异常信息,只记录错误基本描述信息,不利于排查问题。
public void doSth(){ try{ // 业务逻辑 ... } catch (Exception e){ log.error("execute failed", e.getMessage()); } }
正例:
一般日志框架中的warn、error级别均有存在传递Throwable异常类型的API,可以直接将抛出的异常传入日志API中。
void error(String var1, Throwable var2); public void doSth(){ try{ // 业务逻辑 ... } catch (Exception e){ log.error("execute failed", e); } }
8. 日志打印时禁止直接用JSON工具将对象转换成String
反例:
public void doSth(){ log.info("do sth and print log, data={}", JSON.toJSONString(data)); // 业务逻辑 ... }
分析:
- fastjson等序列化组件是通过调用对象的get方法将对象进行序列化,如果对象里某些get方法被覆写,存在抛出异常的情况,则可能会因为打印日志而影响正常业务流程的执行。
- 打日志过程中对一些对象的序列化过程也是比较耗性能的。首先序列化过程本身时一个计算密集型过程,费cpu。其次这个过程会产生很多中间对象,对内存也不太友好。
正例:
可以使用对象的toString()方法打印对象信息,如果代码中没有对toString()有定制化逻辑的话,可以使用apache的ToStringBulider工具。
public void doSth(){ log.info("do sth and print log, data={}", data.toString()); log.info("do sth and print log, data={}", ToStringBuilder.reflectionToString(data, ToStringStyle.SHORT_PREFIX_STYLE)); }
9. 不要打印无意义(无业务上下文、无关联日志链路id)的日志
反例:
- 不带任何业务信息的日志,对排查故障毫无意义。
public void doSth(){ log.info("do sth and print log"); // 业务逻辑 ... }
- 对于无异常分支的代码打印日志,一般流程下,异常分支都会打日志,如果没有出现异常,那就说明正常执行了。
public void doSth(){ doIt1(); log.info("do sth 111"); doIt2(); log.info("do sth 222"); }
正例:
- 日志一定要带相关的业务信息,有利于排查问题快速定位到原因。
public void doSth(){ log.info("do sth and print log, id={}", id); // 业务逻辑 ... }
- 对于打印过多的无意义日志,可以直接干掉或者以debug级别打印。
10. 不要在循环中打印INFO级别日志
反例:
public void doSth(){ for(String s : strList) { log.info("do sth and print log: {}", s); // 业务逻辑 ... } }
11. 不要打印重复的日志
反例:
public void doSth(String s){ log.info("do sth and print log: {}", s); doStep(s); } private void doStep(String s){ log.info("do sth and print log: {}", s); // 业务逻辑 ... }
public void doSth(String s) { try { doStep(s); } catch (Exception e){ log.error("something wrong", e); } } private void doStep(String s){ try { // 业务逻辑 } catch (Exception e){ log.error("something wrong", e); throw e; } }
分析:
- 在每一个嵌套环节都打印了重复的日志。
- 不要记录日志后又抛出异常。抛出去的异常,一般外层会处理。如果不处理,那为什么还要抛出去?原则是,无论是否发生异常,都不要在不同地方重复记录针对同一事件的日志消息。
正例:
直接干掉或者将日志降级成debug级别日志
12. 避免敏感信息输出
13. 日志单行大小必须不超过200K
3.2 推荐
1. 日志语言尽量使用英文
建议:尽量在打印日志时输出英文,防止中文编码与终端不一致导致打印出现乱码的情况,对故障定位和排查存在一定的干扰。
2. 重要方法可以记录调用日志
建议在重要方法入口记录方法调用日志,出口打印出参,对于排查问题会有很大的帮助。
public String doSth(String id, String type){ log.info("start: {}, {}", id, type); String res = process(id, type); log.info("end: {}, {}, {}", id, type, res}; }
3. 在核心业务逻辑中遇到if...else等条件,尽量每个分支首行都打印日志
在编写核心业务逻辑代码时,如遇到if...else...或者switch这样的条件,可以在分支的首行就打印日志,这样排查问题时,就可以通过日志,确定进入了哪个分支,代码逻辑更清晰,也更方便排查问题了。
建议:
public void doSth(){ if(user.isVip()){ log.info("该用户是会员,Id:{},开始处理会员逻辑",user,getUserId()); //会员逻辑 }else{ log.info("该用户是非会员,Id:{},开始处理非会员逻辑",user,getUserId()) //非会员逻辑 } }
4. 建议只打印必要的参数,不要整个对象打印
反例:
public void doSth(){ log.info("print log, data={}", data.toString()); // 业务逻辑 ... }
分析:
首先分析下自己是否必须把所有对象里的字段打印出来?如果对象中有50个字段,但只需其中两个参数就可以定位具体的原因,那么全量打印字段将浪费内容空间且因为字段过多,影响根因排查。
正例:
public void doSth(){ log.info("print log, id={}, type={}", data.getId(), data.getType()); // 业务逻辑 ... }
使用这个种方法需及时防止npe,并考虑是否核心场景,核心场景建议还是打全,避免漏打、少打影响线上问题定位&排查。