前言

logback應(yīng)該是目前最流行的日志打印框架了，畢竟Spring Boot中默認(rèn)的集成的日志框架也是logback。

在實(shí)際項(xiàng)目開(kāi)發(fā)過(guò)程中，常常會(huì)遇到由于打印大量日志而導(dǎo)致程序并發(fā)降低，QPS降低的問(wèn)題，而通過(guò)logback異步日志輸出則能很大程度上解決這個(gè)問(wèn)題。

一、什么是Appender？

• logback官方文檔：https://logback.qos.ch/manual/appenders.html
• logback中文文檔

官方介紹：

Logback 將編寫(xiě)日志事件的任務(wù)委托給名為 Appenders 的組件，Appenders 必須實(shí)現(xiàn)ch.qos.logback.core.Appender的接口。

簡(jiǎn)單來(lái)說(shuō)，Appender就是用來(lái)處理logback框架下日志輸出事件的組件。

• Appender接口的核心方法如下：

package ch.qos.logback.core;
  
import ch.qos.logback.core.spi.ContextAware;
import ch.qos.logback.core.spi.FilterAttachable;
import ch.qos.logback.core.spi.LifeCycle;
  

public interface Appender<E> extends LifeCycle, ContextAware, FilterAttachable {

  public String getName();
  
  public void setName(String name);

 //核心方法：處理日志事件
  void doAppend(E event);
  
}

其中doAppend()方法是 logback 框架中最重要的方法。它負(fù)責(zé)將日志事件以適當(dāng)?shù)母袷捷敵龅竭m當(dāng)?shù)妮敵鲈O(shè)備。

二、Appender類(lèi)圖

說(shuō)明：

OutputStreamAppender 是另外三個(gè)附加程序的超類(lèi)，即 ConsoleAppender 和 FileAppender，后者又是 RollingFileAppender 的超類(lèi)。

下一個(gè)圖說(shuō)明了 OutputStreamAppender 及其子類(lèi)的類(lèi)圖。

1、控制臺(tái)日志輸出 ConsoleAppender

• 配置示例：

<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%-4relative [%thread] %-5level %logger{35} - %msg %n</pattern>
    </encoder>
  </appender>
  <root level="DEBUG">
       <appender-ref ref="STDOUT" />
  </root>
  </configuration>

說(shuō)明：

控制臺(tái)日志輸出主要是在開(kāi)發(fā)環(huán)境采用，比如在IDEA中開(kāi)發(fā)時(shí)，可以清楚直觀(guān)得在控制臺(tái)看到運(yùn)行日志，更方便程序調(diào)試。

當(dāng)應(yīng)用發(fā)布到測(cè)試環(huán)境、生產(chǎn)環(huán)境時(shí)，建議關(guān)閉控制臺(tái)日志輸出，以提高日志輸出的吞吐量，減少不必要的性能開(kāi)銷(xiāo)。

2、單日志文件輸出 FileAppender

• 配置示例：

<configuration>
  <appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <!-- 日志文件名稱(chēng) -->
    <file>testFile.log</file>
    <!-- 是否追加輸出 -->
    <append>true</append>
    <!-- 立即刷新，設(shè)置成false可以提高日志吞吐量 -->
    <immediateFlush>true</immediateFlush>
    <encoder>
     <!-- 日志輸出格式 -->
      <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
    </encoder>
  </appender>
        
  <root level="DEBUG">
    <appender-ref ref="FILE" />
  </root>
</configuration>

弊端：

采用單日志文件輸出日志，很容易導(dǎo)致日志文件的體積一直膨脹，不利于日志文件的管理和查看。

一般很少采用。

3、滾動(dòng)日志文件輸出 RollingFileAppender

• 配置示例：

<configuration>
  <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <!-- 日志文件名稱(chēng) -->
    <file>logFile.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <!-- 按天滾動(dòng)生成歷史日志文件 -->
      <fileNamePattern>logFile.%d{yyyy-MM-dd}.log</fileNamePattern>

      <!-- 歷史日志文件保存的天數(shù)和容量大小-->
      <maxHistory>30</maxHistory>
      <totalSizeCap>3GB</totalSizeCap>
    </rollingPolicy>

    <encoder>
      <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
    </encoder>
  </appender> 

  <root level="DEBUG">
    <appender-ref ref="FILE" />
  </root>
</configuration>

說(shuō)明：

通過(guò)rollingPolicy 配置日志文件的滾動(dòng)生成策略，以及歷史日志文件保存的天數(shù)和總?cè)萘看笮。?/p>

是測(cè)試環(huán)境和生產(chǎn)環(huán)境最推薦的日志輸出方式。

三、同步輸出和異步輸出比較

同步輸出

• 傳統(tǒng)的日志打印采用的是同步輸出的方式，所謂同步日志，即當(dāng)輸出日志時(shí)，必須等待日志輸出語(yǔ)句執(zhí)行完畢后，才能執(zhí)行后面的業(yè)務(wù)邏輯語(yǔ)句。
• 使用logback的同步日志進(jìn)行日志輸出，日志輸出語(yǔ)句與程序的業(yè)務(wù)邏輯語(yǔ)句將在同一個(gè)線(xiàn)程運(yùn)行。
• 在高并發(fā)場(chǎng)景下，日志數(shù)量不但激增，作為磁盤(pán)IO來(lái)說(shuō)，容易產(chǎn)生瓶頸，導(dǎo)致線(xiàn)程卡頓在生成日志過(guò)程中，會(huì)影響程序后續(xù)的主業(yè)務(wù)，降低程序的性能。

異步輸出

• 使用異步日志進(jìn)行輸出時(shí)，日志輸出語(yǔ)句與業(yè)務(wù)邏輯語(yǔ)句并不是在同一個(gè)線(xiàn)程中運(yùn)行，而是有專(zhuān)門(mén)的線(xiàn)程用于進(jìn)行日志輸出操作，處理業(yè)務(wù)邏輯的主線(xiàn)程不用等待即可執(zhí)行后續(xù)業(yè)務(wù)邏輯。
• 這樣即使日志沒(méi)有完成輸出，也不會(huì)影響程序的主業(yè)務(wù)，從而提高了程序的性能。

四、異步日志實(shí)現(xiàn)原理AsyncAppender

logback異步輸出日志是通過(guò)AsyncAppender實(shí)現(xiàn)的。AsyncAppender可以異步的記錄 ILoggingEvents日志事件。

但是這里需要注意，AsyncAppender只充當(dāng)事件分配器，它必須引用另一個(gè)Appender才能完成最終的日志輸出。

示意圖：

Logback的異步輸出采用生產(chǎn)者消費(fèi)者的模式，將生成的日志放入消息隊(duì)列中，并將創(chuàng)建一個(gè)線(xiàn)程用于輸出日志事件，有效的解決了這個(gè)問(wèn)題，提高了程序的性能。

logback中的異步輸出日志使用了AsyncAppender這個(gè)appender，通過(guò)看AsyncAppender源碼，跟到它的父類(lèi)AsyncAppenderBase，可以看到它有幾個(gè)重要的成員變量：

AppenderAttachableImpl<E> aai = new AppenderAttachableImpl<E>();
BlockingQueue<E> blockingQueue;
AsyncAppenderBase<E>.Worker worker = new AsyncAppenderBase.Worker();

lockingQueue是一個(gè)隊(duì)列，Worker是一個(gè)消費(fèi)線(xiàn)程，基本可以判定是個(gè)生產(chǎn)者消費(fèi)者模式。

• 再看消費(fèi)者（work）的主要代碼：

while (parent.isStarted()) {
    try {
        E e = parent.blockingQueue.take();    //單條循環(huán)
        aai.appendLoopOnAppenders(e);
    } catch (InterruptedException ie) {
        break;
    }
}

使用的是while單條循環(huán) ，即logback異步輸出是由一個(gè)消費(fèi)者循環(huán)單條寫(xiě)入日志文件，工作流程如下圖：

五、異步日志配置

配置示例：

配置異步輸出日志的方式很簡(jiǎn)單，添加一個(gè)基于異步寫(xiě)日志的 appender，并指向原先配置的 appender即可。

<configuration>
	  <appender name="FILE" class="ch.qos.logback.core.FileAppender">
	    <file>myapp.log</file>
	    <encoder>
	      <pattern>%logger{35} - %msg%n</pattern>
	    </encoder>
	  </appender>

	  <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
	     <appender-ref ref="FILE" />
         <!-- 設(shè)置異步阻塞隊(duì)列的大小，為了不丟失日志建議設(shè)置的大一些，單機(jī)壓測(cè)時(shí)100000是沒(méi)問(wèn)題的，應(yīng)該不用擔(dān)心OOM -->
        <queueSize>10000</queueSize>
        <!-- 設(shè)置丟棄DEBUG、TRACE、INFO日志的閥值，不丟失 -->
        <discardingThreshold>0</discardingThreshold>
        <!-- 設(shè)置隊(duì)列入隊(duì)時(shí)非阻塞，當(dāng)隊(duì)列滿(mǎn)時(shí)會(huì)直接丟棄日志，但是對(duì)性能提升極大 -->
        <neverBlock>true</neverBlock>
	  </appender>

	  <root level="DEBUG">
	    <appender-ref ref="ASYNC" />
	  </root>
 </configuration>

核心配置參數(shù)說(shuō)明：

默認(rèn)情況下，event queue配置最大容量為256個(gè)events。如果隊(duì)列已經(jīng)滿(mǎn)了，那么應(yīng)用程序線(xiàn)程將被阻塞，無(wú)法記錄新事件，直到工作線(xiàn)程有機(jī)會(huì)分派一個(gè)或多個(gè)事件。當(dāng)隊(duì)列不再達(dá)到最大容量時(shí)，應(yīng)用程序線(xiàn)程可以再次開(kāi)始記錄事件。因此，當(dāng)應(yīng)用程序在其事件緩沖區(qū)的容量或附近運(yùn)行時(shí)，異步日志記錄就變成了偽同步。

這未必是件壞事，AsyncAppender異步追加器設(shè)計(jì)目的是允許應(yīng)用程序繼續(xù)運(yùn)行，盡管需要稍微多一點(diǎn)的時(shí)間來(lái)記錄事件，直到附加緩沖區(qū)的壓力減輕。

優(yōu)化 appenders 事件隊(duì)列的大小以獲得最大的應(yīng)用程序吞吐量取決于幾個(gè)因素。

下列任何或全部因素都可能導(dǎo)致出現(xiàn)偽同步行為：

• 大量的應(yīng)用程序線(xiàn)程
• 每個(gè)應(yīng)用程序調(diào)用都有大量的日志事件
• 每個(gè)日志事件都有大量數(shù)據(jù)
• 子級(jí)appenders的高延遲

為了保持事情的進(jìn)展，增加隊(duì)列的大小通常會(huì)有所幫助，代價(jià)是減少應(yīng)用程序可用的堆。

為了減少阻塞，在缺省情況下，當(dāng)隊(duì)列容量保留不到20% 時(shí)，AsyncAppender 將丟失 TRACE、 DEBUG 和 INFO 級(jí)別的事件，只保留 WARN 和 ERROR 級(jí)別的事件。

這種策略確保了對(duì)日志事件的非阻塞處理(因此具有優(yōu)異的性能) ，同時(shí)在隊(duì)列容量小于20% 時(shí)減少 TRACE、 DEBUG 和 INFO 級(jí)別的事件。事件丟失可以通過(guò)將丟棄閾值屬性設(shè)置為0(零)來(lái)防止。

六、性能測(cè)試

這部分自己還沒(méi)時(shí)間做測(cè)試，引用網(wǎng)上的一些測(cè)試數(shù)據(jù)。

既然能提高性能的話(huà)，必須進(jìn)行一次測(cè)試比對(duì)，同步和異步輸出日志性能到底能提升多少倍？

服務(wù)器硬件

• CPU 六核
• 內(nèi)存 8G

測(cè)試工具

• Apache Jmeter

1、同步輸出日志

• 線(xiàn)程數(shù)：100
• Ramp-Up Loop(可以理解為啟動(dòng)線(xiàn)程所用時(shí)間) ：0 可以理解為100個(gè)線(xiàn)程同時(shí)啟用
• 測(cè)試結(jié)果：

重點(diǎn)關(guān)注指標(biāo) Throughput【TPS】 吞吐量：系統(tǒng)在單位時(shí)間內(nèi)處理請(qǐng)求的數(shù)量，在同步輸出日志中 TPS 為 44.2/sec

2、異步輸出日志

• 線(xiàn)程數(shù) 100
• Ramp-Up Loop：0
• 測(cè)試結(jié)果：

TPS 為 497.5/sec ， 性能提升了10多倍?。?！

總結(jié)

以上為個(gè)人經(jīng)驗(yàn)，希望能給大家一個(gè)參考，也希望大家多多支持腳本之家。