一、背景
最近幾個業務遇到服務假死的情況，通過排查，我們發現是因為業務在線上使用了日志框架的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呢？！