在 用SLF4j/Logback打印日志-1 和 用SLF4j/Logback打印日志-2 中分别介绍了Logback记录日志的基本原理并重点介绍了输出源配置。本篇介绍一些性能和技巧性的东西。
性能
在查看线上业务代码的时候有时候会发现类似这样的代码:
logger.debug("This " + this + " and " + that);
在对性能有要求的系统中,这种写法是非常不利的,虽然在配置线上系统的时候不会打印 DEBUG 级别的日志,但是在进入函数之前会先计算 "This " + this + " and " + that 这个字符串造成无畏的资源浪费。
在Logback中可以采用类似这样的API来解决拼字符串问题:
logger.debug("This {} and {}", this, that);
这种语法可以解决绝大部分由于拼字符串造成的性能问题,但是在某些情况下,比如还要计算一些数值,这样方案就不行了。
logger.debug("This {} and {} with {} ", this, that, compute());
这段代码虽然解决了拼字符的问题,但是调用 compute() 方法依然会造成资源浪费。在Java8之前大多数的解决方案是这样的:
if (logger.isDebugEnabled()) {
logger.debug("This {} and {} with {} ", this, that, compute());
}
在打印日志之前先判断是否需要打印相应级别的日志,这种写法可以解决任何由于日志打印造成的性能问题。但是代码却变得不够优雅,几乎需要在每个调用logger.debug(..) 方法之前掉一次 if (logger.isDebugEnabled()) {.. ,在Java8之后可以用lambda表达式完美解决这个问题。
logger.debug("I am logging that {} happened.", () -> compute());
这种写法把compute() 封装到一个匿名类里面传递给了debug方法,只有Debug方法内部执行的时候才会执行 compute() 。但是如果函数有多个参数,这种写法就变得有些怪异,因为它要求每个参数都要是lambda表达式,而写出来的代码就会变成这样:
logger.debug("This {} and {} with {} ", () -> this, () -> that, () -> compute());
Java8的lambda是非常低效的,如果方法参数较多这种写法会在每次调用的时候创建3个匿名类,反而会降低程序的性能。综合考虑,一般参数较少并且有耗时计算任务的时候考虑用java8的特性。
日志分析
通常情况下,我们会约定日志的打印格式,以便日后的分析。默认情况下,logback是用空格分隔不同的日志字段的。
%d %-5p %t %c{2} %m%n
这种约定不利于日志的机器分析,如果被打印的消息里面也包含空格,那么解析就会出错。简单的方案是重新约定日志的格式,比如用,号分隔日志,并保证打印的消息里面不再包含,号,类似这样 - %d, %-5p, %t, %c{2}, %m%n。逗号分隔只是比空格分隔略好一点,毕竟逗号出现在消息体里面的机会少一些。延续这种思路可能会进入一个误区,我们需要寻找一种尽可能稀有的分隔符来分隔日志的字段。
其实我们完全可以直接约定一种协议格式来打印日志,比如JSON。这样就不会担心消息和协议冲突的问题,但是也会带来新的新能问题。综合考虑,如果需要日志比较简单,那么可以采用简单的分隔符分隔日志,如果日志较多比较复杂,那么可以封装一些API来打印特有协议的日志,而性能问题可以考虑上一节的方案。
MDC
MDC 是 Mapped Diagnostic Context 的缩写,“映射诊断上下文”看起来高大上的样子,其实是非常简单的,就是一个临时存放k-v对的容器。和普通Map的区别是它是基于ThreadLocal实现的,所以不存在资源竞争问题,可以放心的往里面放东西。
假如我们有一个类似网关的应用,同一时间有很多的请求会发送到本系统。一般情况下,为了追踪每个请求的处理情况我们会在请求中加一个字段叫“TraceId” - 一个普通的UID用来区别每一个请求。那么怎么在日志中打印出TraceId呢,一般可以在打印消息的时候,把TraceId作为参数拼凑到日志消息中,这样有两个不好的地方:
- 需要写额外的代码拼凑消息
- 需要在每个打印消息的地方维护一个全局的TraceId变量
如果使用MDC问题就可以简化很多,在接收到请求后,解析出TraceId然后放入MDC,在配置文件中配置打印MDC,之后所有调用打印消息的日志都会自动包含TraceId了。
// 解析请求,取出TraceId放入MDC
MDC.put("traceid", xxxxx);
//配置XML
%d, %-5p, %t, %c{2}, %X{traceid}, %m%n
非常的简单而且自然有没有!!!
PS:如果使用的是log4j需要1.2版本以上。