一、背景
最近几个业务遇到服务假死的情况，通过排查，我们发现是因为业务在线上使用了日志框架的ConsoleAppender所致。
请尊重作者劳动成果，转载请标明原文链接：https://www.cnblogs.com/waterystone/p/11170540.html
二、排查过程
2.1 被block线程的堆栈
我们跟进后通过jsack把线程的堆栈打出来，发现大量线程被同一把monitor锁block住了（at org.apache.logging.log4j.core.layout.TextEncoderHelper.copyDataToDestination），其中一个完整的线程堆栈如下：
通过堆栈我们可以看到，线程执行到TextEncoderHelper.copyDataToDestination()时，需要获取一把OutputStreamManager对象的锁，但这个锁被其他线程锁住了。源码如下（注：OutputStreamManager是ByteBufferDestination的子类）：
2.2 获取锁的线程的堆栈
那么这把锁被哪个线程锁住了呢？这个线程又在干什么呢？进一步排查，获取该锁的线程堆栈如下：
我们发现，业务线程在使用ConsoleAppender打印日志时，需要同步获取到OutputStreamManager对象的monitor锁，然后同步调用PrintStream.write() → BufferedOutputStream.write() → FileOutputStream.write() ，接着flush()，等写到Console成功后，才会释放锁，而其他需要获取该锁的业务线程在此期间只能阻塞等待。其调用时序如下：
2.3 console日志性能分析
从前两步我们看到，在打印console日志时，需要先获取到OutputStreamManager对象的monitor锁，然后同步调用PrintStream.write() → BufferedOutputStream.write() → FileOutputStream.write() ，接着flush()，等写到Console成功后，才会释放锁。这期间其他打印console日志的线程都要被该monitor锁block住。
那么我们就有理由怀疑同步块中调用这些write()操作效率太低，从而导致大量其他业务线程被block住。通过官网查证，打印console日志，效率还真不是一般的低！！！如下所示：
三、AsyncLogger
从以上分析我们可以看到，业务通过同步Logger使用ConsoleAppender时会阻塞业务线程。其实通过同步Logger使用RollingRandomAccessFileAppender也会阻塞业务线程，只不过其同步块的处理效率更高些而已。那么有没有其他更高效的解决方案呢？有！AsyncLogger！！！
log4j2框架通过引入高性能环形消息队列框架Disruptor，将打印日志操作异步化，解除对业务线程的同步阻塞，极大加快业务线程的响应时间。
详细信息参考官网：https://logging.apache.org/log4j/2.x/manual/async.html。
其工作时序如下：
从上图可以看出，业务线程在使用AsyncLogger打印日志时，将日志消息放到disruptor的环形队列后即返回，这里也不会涉及到锁的同步竞争，极大加快了业务线程的响应时间。Disruptor会有一个专门的线程池来负责监听环形队列的消息事件，并将其落地。
AsyncLogger具有超强的性能，官方数据如下：
3.1 如何接入
AsyncLogger这么好用，如何接入呢？
1）在log4j2框架下，额外引入disruptor。
<dependency> <groupId>com.lmax</groupId> <artifactId>disruptor</artifactId> <version>3.4.2</version> </dependency>
2）log4j2.xml配置成如下方式：
<Loggers> <!-- 将spring日志设置成info --> <AsyncLogger name="org.springframework" level="ERROR" includeLocation="true" /> <asyncRoot level="INFO" includeLocation="true"> <AppenderRef ref="INFO" /> <AppenderRef ref="WARN" /> <AppenderRef ref="ERROR" /> </asyncRoot> </Loggers>
四、总结
- 线上业务，严禁使用ConsoleAppender；
- 线上业务，强烈推荐AsyncLogger；
- 线上业务，可以使用同步Logger，但不推荐。以性能较高的RollingRandomAccessFileAppender为例，其在打印日志时同样也需要获取RollingRandomAccessFileManager对象的monitor锁，只不过该同步块中的处理效率较高，不像OutputStreamManager锁块那么低效而已。
看到这里，你还有什么理由使用ConsoleAppender呢？？？还有什么理由不使用AsyncLogger呢？！