log4j日誌異步化大幅提高系統性能

時間 2019-11-21

標籤 log4j log 日誌異步大幅提高系統性能欄目 Log4j 简体版

原文原文鏈接

、log4j已成爲大型系統必不可少的一部分，log4j能夠很方便的幫助咱們在程序的任何位置輸出所要打印的信息，便於咱們對系統在調試階段和正式運行階段對問題分析和定位。因爲日誌級別的不一樣，對系統的性能影響也是有很大的差距，日誌級別越高，性能越高。

二、log4j主要分爲error,warn,info,debug四個級別，也是使用最多的四種，日誌級別從左至右依次增長。

三、log4j對系統性能的影響程度主要體如今如下幾方面：
  a、日誌輸出的目的地，輸出到控制檯的速度比輸出到文件系統的速度要慢。
   b、日誌輸出格式不同對性能也會有影響，如簡單輸出佈局(SimpleLayout)比格式化輸出佈局(PatternLayout)輸出速度要快。能夠根據須要儘可能採用簡單輸出佈局格式輸出日誌信息。
   c、日誌級別越低輸出的日誌內容就越多，對系統系能影響很大。
   d、日誌輸出方式的不一樣，對系統系能也是有必定影響的，採用異步輸出方式比同步輸出方式性能要高。
   e、每次接收到日誌輸出事件就打印一條日誌內容比當日志內容達到必定大小時打印系能要低。

四、針對以上幾點對系能的影響中的第4,5點，對日誌配置文件作以下配置：
   a、設置日誌緩存，以及緩存大小
     數據庫

    Java代碼   
    
  
 log4j.appender.A3.BufferedIO=true   
      #Buffer單位爲字節，默認是8K，IO BLOCK大小默認也是8K    
      log4j.appender.A3.BufferSize=8192   

  以上配置說明，當日志內容達到8k時，纔會將日誌輸出到日誌輸出目的地。

b、設置日誌輸出爲異步方式
apache

    Java代碼   
    
  
 <appender name="DRFOUT" class="org.apache.log4j.DailyRollingFileAppender">    
      <param name="File" value="logs/brws.log" />    
      <param name="Append" value="true" />    
      <param name="DatePattern" value="yyyy_MM_dd'.'" />    
      <layout class="org.apache.log4j.PatternLayout">    
          <param name="ConversionPattern" value="%d [%t] %-5p %l %x - %m%n" />    
      </layout>    
  </appender>    
   
  <appender name="ASYNCOUT" class="org.apache.log4j.AsyncAppender">    
      <param name="BufferSize" value="512" />    
    <appender-ref ref="DRFOUT" />    
  </appender>    

同步狀況：各線程直接得到輸出流進行輸出(線程間不須要同步)。
異步狀況：1.各線程將日誌寫到緩存，繼續執行下面的任務(這裏是異步的)

2.日誌線程發現須要記日誌時獨佔緩存(與此同時各線程等待，此時各線程是被阻塞住的)，從緩存中取出日誌信息，得到輸出流進行輸出，將緩存解鎖(各線程收到提醒，能夠接着寫日誌了)

   衆所周知，磁盤IO操做、網絡IO操做、JDBC操做等都是很是耗時的，日誌輸出的主要性能瓶頸也就是在寫文件、寫網絡、寫JDBC的時候。日誌是確定要記的，而要採用異步方式記，也就只有將這些耗時操做從主線程當中分離出去才真正的實現性能提高，也只有在線程間同步開銷小於耗時操做時使用異步方式才真正有效！

    如今咱們接着分別來看看這幾種記錄日誌的方式：

    a、將日誌記錄到本地文件一樣都是寫本地文件Log4j自己有一個buffer處理入庫，採用異步方式並不必定能提升性能(主要是如何配置好緩存大小)；而線程間的同步開銷則是很是大的！所以在使用本地文件記錄日誌時不建議使用異步方式。
    b、將日誌記錄到JMS JMS自己是支持異步消息的，若是不考慮JMS消息建立的開銷，也不建議使用異步方式。
   c、將日子記錄到SOCKET 將日誌經過Socket發送，純網絡IO操做不須要反饋，所以也不會耗時
    d、將日誌記錄到數據庫衆所周知JDBC是幾種方式中最耗時的：網絡、磁盤、數據庫事務，都使JDBC操做異常的耗時，在這裏採用異步方式入庫卻是一個不錯的選擇。
   e、將日誌記錄到SMTP 同JDBC

五、異步輸出日誌工做原理
   AsyncAppender採用的是生產者消費者的模型進行異步地將Logging Event送到對應的Appender中。

a、生產者：外部應用了Log4j的系統的實時線程，實時將Logging Event傳送進AsyncAppender裏

b、中轉：Buffer和DiscardSummary

c、消費者：Dispatcher線程和appenders
工做原理：

1） Logging Event進入AsyncAppender，AsyncAppender會調用append方法，在append方法中會去把logging Event填入Buffer中，當消費能力不如生產能力時，AsyncAppender會把超出Buffer容量的Logging Event放到DiscardSummary中，做爲消費速度一旦跟不上生成速度，中轉buffer的溢出處理的一種方案。

2） AsyncAppender有個線程類Dispatcher，它是一個簡單的線程類，實現了Runnable接口。它是AsyncAppender的後臺線程。

Dispatcher所要作的工做是：

① 鎖定Buffer，讓其餘要對Buffer進行操做的線程阻塞。

② 看Buffer的容量是否滿了，若是滿了就將Buffer中的Logging Event所有取出，並清空Buffer和DiscardSummary；若是沒滿則等待Buffer填滿Logging Event，而後notify Disaptcher線程。

③ 將取出的全部Logging Event交給對應appender進行後面的日誌信息推送。

緩存

以上是AsyncAppender類的兩個關鍵點：append方法和Dispatcher類，經過這兩個關鍵點實現了異步推送日誌信息的功能，這樣若是大量的Logging Event進入AsyncAppender，就能夠遊刃有餘地處理這些日誌信息了。網絡

************************************************************************************************************************************************************************併發

************************************************************************************************************************************************************************
app

log4j.rootLogger=ERROR,fileout,stdout
log4j.logger.monitorLogger=INFO,monitorAppender
log4j.additivity.monitorLogger=false

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d (%F:%L) %-5p %c - %m%n

log4j.appender.fileout=org.apache.log4j.DailyRollingFileAppender
log4j.appender.fileout.File=logs/server_log.txt
log4j.appender.fileout.layout=org.apache.log4j.PatternLayout
log4j.appender.fileout.layout.ConversionPattern=%d [%t] (%F:%L) %-5p %c - %m%n

log4j.appender.monitorAppender=org.apache.log4j.DailyRollingFileAppender
log4j.appender.monitorAppender.File=mtlogs/mt_log.txt
log4j.appender.monitorAppender.layout=org.apache.log4j.PatternLayout
log4j.appender.monitorAppender.layout.ConversionPattern=%m%n
log4j.appender.monitorAppender.DatePattern='.'yyyy-MM-dd-HH
log4j.appender.monitorAppender.BufferedIO=true
#Buffer單位爲字節，默認是8K
log4j.appender.monitorAppender.BufferSize=8192

log4j.additivity.monitorLogger=false
這個選項用於控制監控logger的日誌不會輸出到rootlogger，不然不管會產生許多重複的數據，同時也會影響性能；

2）log4j.appender.monitorAppender.DatePattern='.'yyyy-MM-dd-HH
這個選項用於告訴

3）log4j.appender.monitorAppender.BufferedIO=true
log4j.appender.monitorAppender.BufferSize=8192
這個選項用於告訴log4j輸出日誌的時候採用緩衝的方式，而不是即時flush方式，而且設定了緩衝爲8K，8K是默認值，能夠根據日誌輸出的狀況來修改。這個選項很重要，在測試中發現，當併發訪問很高，例如每一秒100個併發以上，使用緩存跟不使用緩衝差距很大。具體數字我這裏就不列出來了。
另外我想說的是，log4j輸出緩衝日誌是以8K爲單位的，由於磁盤的一個block爲8K，這樣能夠減小碎片，也就是說假設你設置緩存爲18K，log4j在16K（8K*2)的時候就會輸出），而不是18K。

4）組裝輸出內容以前可對logger的輸出級別先進行判斷而不要徹底依賴log4j控制，由於組裝輸出日誌內容也是要損耗效率的。
        //若log4j並未開啓info級日誌記錄，直接返回
        if(!monitorLogger.isInfoEnabled()){
            return;
        }
        StringBuilder log = new StringBuilder();
        logSql.append(logPk+" ");
        ...

5）使用異步輸出 org.apache.log4j.AsyncAppender，異步輸出必須使用xml方式配置才能支持，我把上面properties形式的配置文件用xml表達一下：
<?xml version="1.0" encoding="UTF-8"?>
<log4j:configuration debug="true">

    <appender name="stdout"
        class="org.apache.log4j.ConsoleAppender">
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d (%F:%L) %-5p %c - %m%n" />
        </layout>
    </appender>

    <appender name="fileout"
        class="org.apache.log4j.DailyRollingFileAppender">
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d [%t] (%F:%L) %-5p %c - %m%n" />
        </layout>
        <param name="File"
            value="logs/server_log.txt" />
    </appender>

    <appender name="monitorAppender"
        class="org.apache.log4j.DailyRollingFileAppender">
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%m%n" />
        </layout>
        <param name="DatePattern" value="'.'yyyy-MM-dd-HH" />
        <param name="File" value="mtlogs/mt_log.txt" />
        <param name="BufferedIO" value="true" />
        
        <param name="BufferSize" value="8192" />     </appender>     <appender name="async" class="org.apache.log4j.AsyncAppender">         <appender-ref ref="monitorAppender"/>     </appender>          <root>         <priority value="error" />         <appender-ref ref="stdout" />         <appender-ref ref="fileout" />     </root>          <category name="com.danga.MemCached">         <priority value="error" />         <appender-ref ref="fileout" />     </category >          <category name="com.opensymphony">         <priority value="error" />         <appender-ref ref="fileout" />     </category >          <category name="monitorLogger" additivity="false">         <priority value="info" />         <appender-ref ref="async" />     </category > </log4j:configuration> 配置中紅色的部分就是用於支持異步輸出的，在用jmeter測試的過程當中發覺使用異步方式，工做的不是很穩定。性能的提高也不顯著。因此最後並無採用。 InputStream in=null;         try {              in = Log4jConfigLocator.class.getResourceAsStream(fileName);              if(fileName.endsWith(".xml")){                  //載入XML格式的配置文件                  Document doc = DocumentBuilderFactory.newInstance().newDocumentBuilder().parse(in);                  DOMConfigurator.configure(doc.getDocumentElement());              }else{                  //載入properties格式的配置文件                  Properties props = new Properties();                  props.load(in);                  PropertyConfigurator.configure(props);              } 異步