1. 程式人生 > >java日誌系統框架(轉載)

java日誌系統框架(轉載)

參考:(方便記錄,直接將內容貼過來了。如有侵權,請留言刪除,此致敬意!)

首先,在日誌系統的森林裡面理理頭緒,修煉內功。參考文章如下:

1.https://www.cnblogs.com/gavanwanggw/p/7305218.html

2.https://www.cnblogs.com/gavanwanggw/p/7305218.html

 

Java日誌系統確實比較豐富,常用的有log4j、JUL、logback等等,同時伴隨著日誌系統的發展,出現了日誌框架commons-logging和slf4j。

簡短地描述下日誌發展,最先出現的是apache開源社群的log4j,這個日誌確實是應用最廣泛的日誌工具,成為了java日誌的事實上的標準。然而,當時Sun公司在jdk1.4中增加了JUL日誌實現,企圖對抗log4j,但是卻造成了混亂,這個也是被人詬病的一點。當然也有其他日誌工具的出現,這樣必然造成開發者的混亂,因為這些日誌系統互相沒有關聯,替換和統一也就變成了比較棘手的一件事。想象下你的應用使用log4j,然後使用了一個其他團隊的庫,他們使用了JUL,你的應用就得使用兩個日誌系統了,然後又有第二個庫出現了,使用了simplelog。這個時候估計讓你崩潰了,這是要鬧哪樣?這個狀況交給你來想想辦法,你該如何解決呢?進行抽象,抽象出一個介面層,對每個日誌實現都適配或者轉接,這樣這些提供給別人的庫都直接使用抽象層即可。不錯,開源社群提供了commons-logging抽象,被稱為JCL,也就是日誌框架了,確實出色地完成了相容主流的日誌實現(log4j、JUL、simplelog),基本一統江湖,就連頂頂大名的spring也是依賴了JCL。看起來事物確實是美好,但是美好的日子不長,接下來另一個優秀的日誌框架slf4j的加入導致了更加混亂的場面。比較巧的是slf4j的作者(Ceki Gülcü)就是log4j的作者,他覺得JCL不夠優秀,所以他要自己搞一套更優雅的出來,於是slf4j日誌體系誕生了,併為slf4j實現了一個親子——

logback,確實更加優雅,但是由於之前很多程式碼庫已經使用JCL,雖然出現slf4j和JCL之間的橋接轉換,但是整合的時候問題依然多多,對很多新手來說確實會很懊惱,因為比單獨的log4j時代“複雜”多了,可以關注下這個,抱怨聲確實很多。到此本來應該完了,但是Ceki Gülcü覺得還是得回頭拯救下自己的“大阿哥”——log4j,於是log4j2誕生了,同樣log4j2也參與到了slf4j日誌體系中,想必將來會更加混亂。接下來詳細解讀日誌系統的配合使用問題。

 

JCL的實現原理,使用JCL一般(如果是log4j可以不需要)需要一個配置commons-logging.properties在classpath上,這個檔案有一行程式碼:

org.apache.commons.logging.LogFactory= org.apache.commons.logging.impl.LogFactoryImpl

 這個是告訴JCL使用哪個日誌實現,JCL會在classpath下去載入對應的日誌工廠實現類,具體的日誌工廠實現類可以是log4j實現,可以是jul實現等等。使用者只需要依賴JCL的api即可,對日誌系統的替換隻需要修改下commons-logging.properties檔案切換到對應的日誌工廠實現即可。但是我們也可以看到因為JCL是執行時去載入classpath下的實現類,會有classloader問題。而且因為log4j尚不支援引數佔位符打日誌的方式,所以JCL也會更加無力。

 

slf4j的設計確實比較優雅,採用比較熟悉的方式——介面和實現分離,有個純粹的介面層——slf4j-api工程,這個裡邊基本完全定義了日誌的介面,所以對於開發來說,只需要使用這個即可。有介面就要有實現,比較推崇的實現是logback,logback完全實現了slf4j-api的介面,並且效能也比log4j更好,同時實現了變參佔位符日誌輸出方式等等新特性。剛剛也提到log4j的使用比較普遍,所以支援這批使用者依然是必須的,slf4j-log4j12也實現了slf4j-api,這個算是對log4j的介面卡。同樣推理,也會有對JUL的介面卡slf4j-jdk14等等。為了使使用JCL等等其他日誌系統後者實現的使用者可以很簡單地切換到slf4j上來,給出了各種橋接工程,比如:jcl-over-slf4j會把對JCL的呼叫都橋接到slf4j上來,可以看出jcl-over-slf4j的api和JCL是相同的,所以這兩個jar是不能共存的。jul-to-slf4j是把對jul的呼叫橋接到slf4j上,log4j-over-slf4j是把對log4j的呼叫橋接到slf4j。下邊用一個圖來表示下這個家族的大致成員


 
 如上圖,最上層表示橋階層,下層表示具體的實現層,中間是介面層,可以看出這個圖中所有的jar都是圍繞著slf4j-api活動的,其中slf4j-jul的jar名稱是slf4j-jdk14。slf4j-api和具體的實現層是怎麼繫結的呢?這個其實是在編譯時繫結的,這個可能不好理解,最直接的表達方式是不需要想jcl那樣配置一下,只需要把slf4j-api和slf4j-log4j放到classpath上,即實現繫結。原理可以下載slf4j-api的原始碼檢視,這個設計還是很巧妙的,slf4j-api中會去呼叫StaticLoggerBinder這個類獲取繫結的工廠類,而每個日誌實現會在自己的jar中提供這樣一個類,這樣slf4j-api就實現了編譯時繫結實現。但是這樣介面的原始碼編譯需要依賴具體的實現了,不太合理吧?當時我也有這樣的迷惑,因為開啟slf4j-api的jar,看不到StaticLoggerBinder,就查看了slf4j-api的原始碼,在原始碼中看到了StaticLoggerBinder這個類,猜想應該是slf4j-api在打包過程中有動作,刪除了自己保重的那個類,結果不出所料,確實是pom中的ant-task給處理了,pom中處理方式如下:

 

Xml程式碼 

<plugin>  
    <groupId>org.apache.maven.plugins</groupId>  
    <artifactId>maven-antrun-plugin</artifactId>  
    <executions>  
       <execution>  
         <phase>process-classes</phase>  
         <goals>  
            <goal>run</goal>  
         </goals>  
       </execution>  
    </executions>  
    <configuration>  
       <tasks>  
         <echo>Removing slf4j-api's dummy StaticLoggerBinder and StaticMarkerBinder</echo>  
         <delete dir="target/classes/org/slf4j/impl"/>  
       </tasks>  
    </configuration>  
</plugin>  

打出來的slf4j-api是不完整的,只有找到包含StaticLoggerBinder這個類的包才可以,於是slf4j-log4j和logback-classic都提供了這個類。另外,slf4j-log4j和logback以及slf4j-jdk14是不能同時和slf4j共存的,也就是說只能有一個實現存在,不然啟動會提示有多個繫結,判斷多個實現的程式碼也很簡單,如下:

private static String STATIC_LOGGER_BINDER_PATH="org/slf4j/impl/StaticLoggerBinder.class";  
  
  private static void singleImplementationSanityCheck() {  
    try {  
      ClassLoader loggerFactoryClassLoader = LoggerFactory.class  
          .getClassLoader();  
      Enumeration paths;  
      if (loggerFactoryClassLoader == null) {  
        paths = ClassLoader.getSystemResources(STATIC_LOGGER_BINDER_PATH);  
      } else {  
        paths = loggerFactoryClassLoader  
            .getResources(STATIC_LOGGER_BINDER_PATH);  
      }  
      //use Set instead of list in order to deal with  bug #138  
      //LinkedHashSet appropriate here because it preserves insertion order during 
      //iteration  
      Set implementationSet = new LinkedHashSet();  
      while (paths.hasMoreElements()) {  
        URL path = (URL) paths.nextElement();  
        implementationSet.add(path);  
      }  
      if (implementationSet.size() > 1) {  
        Util.report("Class path contains multiple SLF4J bindings.");  
        Iterator iterator = implementationSet.iterator();  
        while(iterator.hasNext()) {  
          URL path = (URL) iterator.next();  
          Util.report("Found binding in [" + path + "]");  
        }  
        Util.report("See " + MULTIPLE_BINDINGS_URL + " for an explanation.");  
      }  
    } catch (IOException ioe) {  
      Util.report("Error getting resources from path", ioe);  
    }  
  }  

 

同時這個圖中橋階層和對應的實現jar是不能共存的,比如log4j-over-slf4j和slf4j-log4j,jul-to-slf4j和slf4j-jdk14,這個很好理解,會有死迴圈,啟動也會報錯。這種想象也就是說jar之前有互斥性,怎麼使用maven有效解決“全域性排除”會在以後的博文中講解。jcl-over-slf4j是把對jcl的呼叫橋接到slf4j上,前文說到它和jcl是互斥的。圖中的紅線就表示互斥關係。

當然slf4j也提供了可以把對slf4j的呼叫橋接到JCL上的工程包——slf4j-jcl,可以看出slf4j的設計者考慮非常周到,想想這樣的情況:遺留系統使用的是JCL+log4j,因為系統功能演進,依賴了其他業務線的庫,恰好那個庫依賴了slf4j-api,並且應用需要關心這個庫的日誌,那麼就需要轉接日誌到JCL上即可。細心的你可能一經發現,slf4j-jcl和jcl-over-slf4j也是互斥的,太多互斥的了:(。

對於log4j2的加入,也很簡單,和logback是很相似的,如下圖:



 紅線依然表示依賴的互斥,當然log4j-slf4j-impl也會和logback-classic、slf4j-log4j、slf4j-jdk14互斥。

 

常見的問題:

1.slf4j-api和實現版本不對應,尤其是1.6.x和1.5.x不相容,如果沒有特殊需求,直接升級到最新版本。

2.slf4j的多個實現同時存在,比如slf4j-log4j和logback-classic,排除其中一個即可。

3.log4j和logback不能同時使用?可以同時使用,這兩個並不矛盾,遺留系統可能直接使用了log4j的程式碼,並且不能通過log4j-over-slf4j橋接,那麼可以讓他繼續使用log4j,這裡有詳細的介紹。

4.該如何選用這些呢?建議在非特殊情況下,都使用slf4j-api+logback,不要直接使用日誌實現,效能沒什麼影響。對於要提供給別人的類庫,建議使用slf4j-api,使用方可以自由選擇具體的實現,並且建議類庫不要依賴具體的日誌實現。對於自己的桌面小應用,可以直接使用log4j,畢竟只是隨便做做。

5.logback因為木有spring提供的啟動listener,所以要自己寫?可以看看這裡,開源社群已經做好了。

6.日誌系統一般不會影響到系統性能,除非你的系統對效能非常苛刻,如果這樣你可以考慮使用Blitz4j,這個是Netflix社群對log4j的效能改進版,不過他們依然建議去使用log4j或者logback。

 

內功修煉第二階段:

https://www.cnblogs.com/gavanwanggw/p/7305218.html

 

1、概述

眼下java應用日誌收集都是採用日誌框架(slf4j、apache commons logging)+日誌系統(log4j、log4j2、LogBack、JUL等)的方式。而針對在分散式環境須要實時分析統計的日誌,一般採用apache flume、facebook scribe等分散式日誌收集系統。

 

日誌框架:提供日誌呼叫的介面,實際的日誌輸出託付給日誌系統實現。

 

  • JCL(Jakarta Commons Logging):比較流行的日誌框架,非常多框架都依賴JCL,比如Spring等。
  • SLF4j:提供新的API,初衷是配合Logback使用,但同一時候相容Log4j。

日誌系統:負責輸出日誌

  • Log4j:經典的一種日誌解決方式。內部把日誌系統抽象封裝成Logger 、appender 、pattern 等實現。我們能夠通過配置檔案輕鬆的實現日誌系統的管理和多樣化配置。
  • Log4j2:Log4j的2.0版本號。對Log4j進行了優化。比方支援引數API、支援非同步appender、外掛式架構等
  • Logback:Log4j的替代產品。須要配合日誌框架SLF4j使用
  • JUL(java.util.logging):JDK提供的日誌系統。較混亂,不經常使用

眼下我們的應用大部分都是使用了SLF4j作為門面,然後搭配log4j或者log4j2日誌系統。

 

 

以下將介紹slf4j + Log4j2 日誌元件的引入、以及配置和使用

2、Maven依賴

</pre><pre name="code" class="html">
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>1.7.13</version>
        </dependency>
        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-slf4j-impl</artifactId>
            <version>2.4.1</version>
        </dependency>
        <!--相容log4j-->
        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-1.2-api</artifactId>
            <version>2.0</version>
        </dependency>
        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-api</artifactId>
            <version>2.4.1</version>
        </dependency>
        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-core</artifactId>
            <version>2.4.1</version>
        </dependency>
        <!--log4j2 非同步appender須要-->
        <dependency>
            <groupId>com.lmax</groupId>
            <artifactId>disruptor</artifactId>
            <version>3.2.0</version>
        </dependency>

3、配置

  • Appenders:也被稱為Handlers。負責將日誌事件記錄到目標位置。在將日誌事件輸出之前,Appenders使用Layouts來對事件進行格式化處理。
  • Layouts:也被稱為Formatters,它負責對日誌事件中的資料進行轉換和格式化。Layouts決定了資料在一條日誌記錄中的終於形式。
  • Loggers:Logger負責捕捉事件並將其傳送給合適的Appender。

當Logger記錄一個事件時。它將事件轉發給適當的Appender。

然後Appender使用Layout來對日誌記錄進行格式化,並將其傳送給控制檯、檔案或者其他目標位置。另外。Filters能夠讓你進一步指定一個Appender能否夠應用在一條特定的日誌記錄上。在日誌配置中,Filters並非必需的,但能夠讓你更靈活地控制日誌訊息的流動。

3.1 Appender

3.1.1 ConsoleAppender

ConsoleAppender是最經常使用的Appenders之中的一個。它僅僅是將日誌訊息顯示到控制檯上。

很多日誌框架都將其作為預設的Appender。而且在主要的配置中進行預配置。

比如,在Log4j中ConsoleAppender的配置引數例如以下所看到的。


引數

描寫敘述

filter

用於決定是否須要使用該Appender來處理日誌事件

layout

用於決定怎樣對日誌記錄進行格式化,預設情況下使用“%m%n”。它會在每一行顯示一條日誌記錄

follow

用於決定Appender是否須要瞭解輸出(system.out或者system.err)的變化,預設情況是不須要跟蹤這樣的變化

name

用於設定Appender的名字

ignoreExceptions

用於決定是否須要記錄在日誌事件處理過程中出現的異常

target

用於指定輸出目標位置。預設情況下使用SYSTEM_OUT。但也能夠改動成SYSTEM_ERR
<!--這個輸出控制檯的配置-->
        <Console name="Console" target="SYSTEM_OUT">
            <!--控制檯僅僅輸出level及以上級別的資訊(onMatch)。其它的直接拒絕(onMismatch)-->
            <ThresholdFilter level="DEBUG" onMatch="ACCEPT" onMismatch="DENY"/>
            <!--這個都知道是輸出日誌的格式-->
            <PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level %class{36} %L %M - %msg%xEx%n"/>
        </Console>


3.1.2 FileAppender

 

FileAppenders將日誌記錄寫入到檔案裡。它負責開啟、關閉檔案。向檔案裡追加日誌記錄,並對檔案進行加鎖。以免資料被破壞或者覆蓋。

 

在Log4j中,假設想建立一個FileAppender,須要指定目標檔案的名字。寫入方式是追加還是覆蓋。以及是否須要在寫入日誌時對檔案進行加鎖:

<File name="File" fileName="fileAppender.log" append="true" locking="true">

    <PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level %class{36} %L %M - %msg%xEx%n"/>

</File>


3.1.3 RollingFileAppender

 

RollingFileAppender跟FileAppender的基本使用方法一樣。

但RollingFileAppender能夠設定log檔案的size(單位:KB/MB/GB)上限、數量上限,當log檔案超過設定的size上限,會自己主動被壓縮。

RollingFileAppender能夠理解為滾動輸出日誌,假設log4j 2記錄的日誌達到上限,舊的日誌將被刪除,騰出的空間用於記錄新的日誌。

<!--這個會打印出全部的資訊。每次大小超過size,則這size大小的日誌會自己主動存入按年份-月份建立的目錄以下並進行壓縮,作為存檔-->

<RollingFile name="RollingFile1" fileName="logs/log1.log"

filePattern="logs/$${date:yyyy-MM}/log-%d{MM-dd-yyyy}-%i.log">

    <PatternLayout pattern="%d{yyyy-MM-dd 'at' HH:mm:ss z} %-5level %class{36} %L %M - %msg%xEx%n"/>

    <SizeBasedTriggeringPolicy size="100MB"/>

</RollingFile>


​​​

 

3.1.5 其它appender

我們已經介紹了一些經經常使用到的Appenders,還有非常多其他Appender。

它們加入了新功能或者在其他的一些Appender基礎上實現了新功能。比如,Log4j中的RollingFileAppender擴充套件了FileAppender。它能夠在滿足特定條件時自己主動建立新的日誌檔案。SMTPAppender會將日誌內容以郵件的形式傳送出去;FailoverAppender會在處理日誌的過程中,假設一個或者多個Appender失敗,自己主動切換到其他Appender上。

假設想了解其它能夠參考:https://logging.apache.org/log4j/2.0/manual/appenders.html

3.2 Layouts

Layouts將日誌記錄的內容從一種資料形式轉換成第二種。日誌框架為純文字、HTML、syslog、XML、JSON、序列化以及其他日誌提供了Layouts。

 

這裡貼一篇文章簡介下我們經常使用的PatternLayout :http://wiki.jikexueyuan.com/project/log4j/log4j-patternlayout.html

其它的layouts配置能夠參考:https://logging.apache.org/log4j/2.0/manual/layouts.html

 

<PatternLayout pattern="%d{yyyy-MM-dd 'at' HH:mm:ss z} %-5level %class{36} %L %M - %msg%xEx%n"/>


3.3 Loggers

 

Logger負責捕捉事件並將其傳送給合適的Appender。Logger之間是有繼承關係的。

總是存在一個rootLogger,即使沒有顯示配置也是存在的,而且預設輸出級別為DEBUG。其他的logger都繼承自這個rootLogger。
Log4J中的繼承關係是通過名稱能夠看出來,如"A"、"A.B"、"A.B.C",A.B繼承A。A.B.C繼承A.B,比較類似於包名.

<loggers>
        <logger name="com.sankuai" level="info" includeLocation="true" additivity="true">
            <appender-ref ref="RollingFile2"/>
            <appender-ref ref="RollingFile1"/>
        </logger>
		<logger name="com.sankuai.meituan" level="error" includeLocation="true" additivity="true">
            <appender-ref ref="RollingFile2"/>
            <appender-ref ref="RollingFile1"/>
        </logger>
        <!--建立一個預設的root的logger-->
        <root level="error">
            <appender-ref ref="Console"/>
            <appender-ref ref="RollingFile1"/>
        </root>
    </loggers>


additivity是 子Logger 是否繼承 父Logger 的 輸出源(appender) 的標誌位。詳細說,預設情況下 子Logger 會繼承 父Logger 的appender,也就是說 子Logger 會在 父Logger 的appender裡輸出。若是additivity設為false,則 子Logger 僅僅會在自己的appender裡輸出。而不會在 父Logger 的appender裡輸出。 

 

3.4 日誌級別

DEBUG , INFO ,WARN ,ERROR四種,分別相應Logger類的四種方法
debug(Object message ) ;
info(Object message ) ;
warn(Object message ) ;
error(Object message ) ;
假設設定級別為INFO。則優先順序大於等於INFO級別(如:INFO、WARN、ERROR)的日誌資訊將能夠被輸出,
小於該級別的如:DEBUG將不會被輸出

4、Log4j2 AsyncLogger與AsyncAppender

先上圖

第一張圖能夠看出Log4j2的asyncLogger的效能較使用asyncAppender和sync模式有很大的提升。特別是執行緒越多的時候。

第二張圖是將log4j2的非同步日誌機制和其它日誌系統進行對照,log4j2的asyncLogger 效能也是非常有優勢。

這裡主要涉及了兩個概念AsyncLogger和AysncAppender。是支援非同步的Logger和Appender,以下分別簡要介紹下這兩個概念。

 

4.1 AsyncAppender

AsyncAppender持有其它的配置了aysnc的appender引用列表(appender須要通過配置註冊成非同步的)。當其它的logger須要打日誌的時候(logEvent事件),asyncAppender會接收logEvent,快取到queue中,然後用單獨的執行緒完畢從queue中取logEvent列印到目的appender,這個邏輯比較簡單,看下原始碼就能明確這個流程。ps. AsyncAppender是Log4j 和Log4j2 都有的,不是新東西,但從上面的效能對照上還是有一點點差異的。基本的原因是:(引用官方說法)Asynchronous Appenders already existed in Log4j 1.x, but have been enhanced to flush to disk at the end of a batch (when the queue is empty).

關於AsyncAppender能提高效能的場景。能夠看下這個篇文章。

 http://littcai.iteye.com/blog/316605

怎樣配置一個AsyncAppender:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn" name="MyApp" packages="">
  <Appenders>
    <File name="MyFile" fileName="logs/app.log">
      <PatternLayout>
        <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
      </PatternLayout>
    </File>
    <Async name="Async">
      <AppenderRef ref="MyFile"/>
    </Async>
  </Appenders>
  <Loggers>
    <Root level="error">
      <AppenderRef ref="Async"/>
    </Root>
  </Loggers>
</Configuration>
@Plugin(name = "Async", category = "Core", elementType = "appender", printObject = true)
public final class AsyncAppender extends AbstractAppender {
    private static final long serialVersionUID = 1L;
    private static final int DEFAULT_QUEUE_SIZE = 128;
    private static final String SHUTDOWN = "Shutdown";
    private static final AtomicLong THREAD_SEQUENCE = new AtomicLong(1);
    private static ThreadLocal<Boolean> isAppenderThread = new ThreadLocal<>();
    private final BlockingQueue<Serializable> queue;
    private final int queueSize;
    private final boolean blocking;
    private final long shutdownTimeout;
    private final Configuration config;
    private final AppenderRef[] appenderRefs;
    private final String errorRef;
    private final boolean includeLocation;
    private AppenderControl errorAppender;
    private AsyncThread thread;
    private AsyncAppender(final String name, final Filter filter, final AppenderRef[] appenderRefs,
            final String errorRef, final int queueSize, final boolean blocking, final boolean ignoreExceptions,
            final long shutdownTimeout, final Configuration config, final boolean includeLocation) {
        super(name, filter, null, ignoreExceptions);
        this.queue = new ArrayBlockingQueue<>(queueSize);
        this.queueSize = queueSize;
        this.blocking = blocking;
        this.shutdownTimeout = shutdownTimeout;
        this.config = config;
        this.appenderRefs = appenderRefs;
        this.errorRef = errorRef;
        this.includeLocation = includeLocation;
    }
    @Override
    public void start() {
        final Map<String, Appender> map = config.getAppenders();
        final List<AppenderControl> appenders = new ArrayList<>();
        for (final AppenderRef appenderRef : appenderRefs) {
            final Appender appender = map.get(appenderRef.getRef());
            if (appender != null) {
                appenders.add(new AppenderControl(appender, appenderRef.getLevel(), appenderRef.getFilter()));
            } else {
                LOGGER.error("No appender named {} was configured", appenderRef);
            }
        }
        if (errorRef != null) {
            final Appender appender = map.get(errorRef);
            if (appender != null) {
                errorAppender = new AppenderControl(appender, null, null);
            } else {
                LOGGER.error("Unable to set up error Appender. No appender named {} was configured", errorRef);
            }
        }
        if (appenders.size() > 0) {
            thread = new AsyncThread(appenders, queue);
            thread.setName("AsyncAppender-" + getName());
        } else if (errorRef == null) {
            throw new ConfigurationException("No appenders are available for AsyncAppender " + getName());
        }
        thread.start();
        super.start();
    }
    @Override
    public void stop() {
        super.stop();
        LOGGER.trace("AsyncAppender stopping. Queue still has {} events.", queue.size());
        thread.shutdown();
        try {
            thread.join(shutdownTimeout);
        } catch (final InterruptedException ex) {
            LOGGER.warn("Interrupted while stopping AsyncAppender {}", getName());
        }
        LOGGER.trace("AsyncAppender stopped. Queue has {} events.", queue.size());
    }
    /**
     * Actual writing occurs here.
     * 
     * @param logEvent The LogEvent.
     */
    @Override
    public void append(LogEvent logEvent) {
        if (!isStarted()) {
            throw new IllegalStateException("AsyncAppender " + getName() + " is not active");
        }
        if (!(logEvent instanceof Log4jLogEvent)) {
            if (!(logEvent instanceof RingBufferLogEvent)) {
                return; // only know how to Serialize Log4jLogEvents and RingBufferLogEvents
            }
            logEvent = ((RingBufferLogEvent) logEvent).createMemento();
        }
        logEvent.getMessage().getFormattedMessage(); // LOG4J2-763: ask message to freeze parameters
        final Log4jLogEvent coreEvent = (Log4jLogEvent) logEvent;
        boolean appendSuccessful = false;
        if (blocking) {
            if (isAppenderThread.get() == Boolean.TRUE && queue.remainingCapacity() == 0) {
                // LOG4J2-485: avoid deadlock that would result from trying
                // to add to a full queue from appender thread
                coreEvent.setEndOfBatch(false); // queue is definitely not empty!
                appendSuccessful = thread.callAppenders(coreEvent);
            } else {
                final Serializable serialized = Log4jLogEvent.serialize(coreEvent, includeLocation);
                try {
                    // wait for free slots in the queue
                    queue.put(serialized);
                    appendSuccessful = true;
                } catch (final InterruptedException e) {
                    // LOG4J2-1049: Some applications use Thread.interrupt() to send
                    // messages between application threads. This does not necessarily
                    // mean that the queue is full. To prevent dropping a log message,
                    // quickly try to offer the event to the queue again.
                    // (Yes, this means there is a possibility the same event is logged twice.)
                    //
                    // Finally, catching the InterruptedException means the
                    // interrupted flag has been cleared on the current thread.
                    // This may interfere with the application's expectation of
                    // being interrupted, so when we are done, we set the interrupted
                    // flag again.
                    appendSuccessful = queue.offer(serialized);
                    if (!appendSuccessful) {
                        LOGGER.warn("Interrupted while waiting for a free slot in the AsyncAppender LogEvent-queue {}",
                                getName());
                    }
                    // set the interrupted flag again.
                    Thread.currentThread().interrupt();
                }
            }
        } else {
            appendSuccessful = queue.offer(Log4jLogEvent.serialize(coreEvent, includeLocation));
            if (!appendSuccessful) {
                error("Appender " + getName() + " is unable to write primary appenders. queue is full");
            }
        }
        if (!appendSuccessful && errorAppender != null) {
            errorAppender.callAppender(coreEvent);
        }
    }
    /**
     * Create an AsyncAppender.
     * 
     * @param appenderRefs The Appenders to reference.
     * @param errorRef An optional Appender to write to if the queue is full or other errors occur.
     * @param blocking True if the Appender should wait when the queue is full. The default is true.
     * @param shutdownTimeout How many milliseconds the Appender should wait to flush outstanding log events
     *                        in the queue on shutdown. The default is zero which means to wait forever.
     * @param size The size of the event queue. The default is 128.
     * @param name The name of the Appender.
     * @param includeLocation whether to include location information. The default is false.
     * @param filter The Filter or null.
     * @param config The Configuration.
     * @param ignoreExceptions If {@code "true"} (default) exceptions encountered when appending events are logged;
     *            otherwise they are propagated to the caller.
     * @return The AsyncAppender.
     */
    @PluginFactory
    public static AsyncAppender createAppender(@PluginElement("AppenderRef") final AppenderRef[] appenderRefs,
            @PluginAttribute("errorRef") @PluginAliases("error-ref") final String errorRef,
            @PluginAttribute(value = "blocking", defaultBoolean = true) final boolean blocking,
            @PluginAttribute(value = "shutdownTimeout", defaultLong = 0L) final long shutdownTimeout,
            @PluginAttribute(value = "bufferSize", defaultInt = DEFAULT_QUEUE_SIZE) final int size,
            @PluginAttribute("name") final String name,
            @PluginAttribute(value = "includeLocation", defaultBoolean = false) final boolean includeLocation,
            @PluginElement("Filter") final Filter filter, @PluginConfiguration final Configuration config,
            @PluginAttribute(value = "ignoreExceptions", defaultBoolean = true) final boolean ignoreExceptions) {
        if (name == null) {
            LOGGER.error("No name provided for AsyncAppender");
            return null;
        }
        if (appenderRefs == null) {
            LOGGER.error("No appender references provided to AsyncAppender {}", name);
        }
        return new AsyncAppender(name, filter, appenderRefs, errorRef, size, blocking, ignoreExceptions,
                shutdownTimeout, config, includeLocation);
    }
    /**
     * Thread that calls the Appenders.
     */
    private class AsyncThread extends Thread {
        private volatile boolean shutdown = false;
        private final List<AppenderControl> appenders;
        private final BlockingQueue<Serializable> queue;
        public AsyncThread(final List<AppenderControl> appenders, final BlockingQueue<Serializable> queue) {
            this.appenders = appenders;
            this.queue = queue;
            setDaemon(true);
            setName("AsyncAppenderThread" + THREAD_SEQUENCE.getAndIncrement());
        }
        @Override
        public void run() {
            isAppenderThread.set(Boolean.TRUE); // LOG4J2-485
            while (!shutdown) {
                Serializable s;
                try {
                    s = queue.take();
                    if (s != null && s instanceof String && SHUTDOWN.equals(s.toString())) {
                        shutdown = true;
                        continue;
                    }
                } catch (final InterruptedException ex) {
                    break; // LOG4J2-830
                }
                final Log4jLogEvent event = Log4jLogEvent.deserialize(s);
                event.setEndOfBatch(queue.isEmpty());
                final boolean success = callAppenders(event);
                if (!success && errorAppender != null) {
                    try {
                        errorAppender.callAppender(event);
                    } catch (final Exception ex) {
                        // Silently accept the error.
                    }
                }
            }
            // Process any remaining items in the queue.
            LOGGER.trace("AsyncAppender.AsyncThread shutting down. Processing remaining {} queue events.",
                    queue.size());
            int count = 0;
            int ignored = 0;
            while (!queue.isEmpty()) {
                try {
                    final Serializable s = queue.take();
                    if (Log4jLogEvent.canDeserialize(s)) {
                        final Log4jLogEvent event = Log4jLogEvent.deserialize(s);
                        event.setEndOfBatch(queue.isEmpty());
                        callAppenders(event);
                        count++;
                    } else {
                        ignored++;
                        LOGGER.trace("Ignoring event of class {}", s.getClass().getName());
                    }
                } catch (final InterruptedException ex) {
                    // May have been interrupted to shut down.
                    // Here we ignore interrupts and try to process all remaining events.
                }
            }
            LOGGER.trace("AsyncAppender.AsyncThread stopped. Queue has {} events remaining. "
                    + "Processed {} and ignored {} events since shutdown started.", queue.size(), count, ignored);
        }
        /**
         * Calls {@link AppenderControl#callAppender(LogEvent) callAppender} on all registered {@code AppenderControl}
         * objects, and returns {@code true} if at least one appender call was successful, {@code false} otherwise. Any
         * exceptions are silently ignored.
         *
         * @param event the event to forward to the registered appenders
         * @return {@code true} if at least one appender call succeeded, {@code false} otherwise
         */
        boolean callAppenders(final Log4jLogEvent event) {
            boolean success = false;
            for (final AppenderControl control : appenders) {
                try {
                    control.callAppender(event);
                    success = true;
                } catch (final Exception ex) {
                    // If no appender is successful the error appender will get it.
                }
            }
            return success;
        }
        public void shutdown() {
            shutdown = true;
            if (queue.isEmpty()) {
                queue.offer(SHUTDOWN);
            }
        }
    }
    /**
     * Returns the names of the appenders that this asyncAppender delegates to as an array of Strings.
     * 
     * @return the names of the sink appenders
     */
    public String[] getAppenderRefStrings() {
        final String[] result = new String[appenderRefs.length];
        for (int i = 0; i < result.length; i++) {
            result[i] = appenderRefs[i].getRef();
        }
        return result;
    }
    /**
     * Returns {@code true} if this AsyncAppender will take a snapshot of the stack with every log event to determine
     * the class and method where the logging call was made.
     * 
     * @return {@code true} if location is included with every event, {@code false} otherwise
     */
    public boolean isIncludeLocation() {
        return includeLocation;
    }
    /**
     * Returns {@code true} if this AsyncAppender will block when the queue is full, or {@code false} if events are
     * dropped when the queue is full.
     * 
     * @return whether this AsyncAppender will block or drop events when the queue is full.
     */
    public boolean isBlocking() {
        return blocking;
    }
    /**
     * Returns the name of the appender that any errors are logged to or {@code null}.
     * 
     * @return the name of the appender that any errors are logged to or {@code null}
     */
    public String getErrorRef() {
        return errorRef;
    }
    public int getQueueCapacity() {
        return queueSize;
    }
    public int getQueueRemainingCapacity() {
        return queue.remainingCapacity();
    }
}

AsyncLogger是Log4j2引入的新特性,業務程式碼呼叫Logger.log的時候直接返回。而不須要等到appender輸出到日誌目的地後才返回。

Log4j2的Asynclogger是通過LMAX Disruptor取代queue實現的非同步(無鎖的併發框架,http://ifeve.com/disruptor/Disruptor簡單介紹),達到更高的併發和lower latency。

4.2 AsyncLogger

 

1,Disruptor使用了一個RingBuffer替代佇列,用生產者消費者指標替代鎖。

 

2,生產者消費者指標使用CPU支援的整數自增。無需加鎖而且速度非常快。Java的實如今Unsafe package中。

 

雖然AsyncLogger 可以大幅度的提高效能。可是也會帶來一些問題。以下是翻譯官方的文件的Trade-offs:

Benefits

  • Higher throughput,達到相對於sync logger的6-68倍的吞吐量
  • Lower logging latency,latency是呼叫Logger.log直到return的時間。asyncLogger的latency比syncLogger以及基於queue的aysncAppender都要低,不僅平均latency低,並且99%、95%latency 也都低於後兩者
  • 減少極端大的日誌量時候的延遲尖峰

Drawbacks

  • Error handling, 假設在列印日誌的時候出現錯誤,使用asyncLogger。業務是不知道異常的(能夠通過配置ExceptionHandler處理異常)。假設列印日誌是業務邏輯的一部分,不建議使用asyncLogger
  • 列印一些可變的內容的時候。使用asyncLogger 會出現故障。大部分時間,不須要操心這點。Log4j確保了類似於 logger.debug("My object is {}", myObject),使用myObject在列印日誌的時刻的版本號列印(Log4j 全部列印都日誌都是封裝到Message的實現類裡,儲存在 final String裡),無論之後是否改變。可是log4j也支援一些了可變的Message,如 MapMessage and StructuredDataMessage 。這些假設在列印日誌時候改變,就有問題了

全域性配置非同步Logger

配置全部Logger都為AsyncLogger,僅僅須要新增disruptor包,然後配置一個system property,-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector。Log4j的配置檔案不須要改動。

 

混合使用同步和非同步Logger

單獨配置某個logger為async的,通過<asyncRoot>或者<asyncLogger>

<Configuration status="WARN">
  <Appenders>
    <!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. -->
    <RandomAccessFile name="RandomAccessFile" fileName="asyncWithLocation.log"
              immediateFlush="false" append="false">
      <PatternLayout>
        <Pattern>%d %p %class{1.} [%t] %location %m %ex%n</Pattern>
      </PatternLayout>
    </RandomAccessFile>
  </Appenders>
  <Loggers>
    <!-- pattern layout actually uses location, so we need to include it -->
    <AsyncLogger name="com.foo.Bar" level="trace" includeLocation="true">
      <AppenderRef ref="RandomAccessFile"/>
    </AsyncLogger>
    <Root level="info" includeLocation="true">
      <AppenderRef ref="RandomAccessFile"/>
    </Root>
  </Loggers>
</Configuration>


ps. location的問題

 

當layouts配置了輸出%C or $class, %F or %file, %l or %location, %L or %line, %M or %method,或者HTML locationInfo,  log4j會獲取location的一個快照,而這對於sync 和async的logger都是一個耗時的操作(官方文件上說syncLogger會慢1.3~5倍。async會慢4-20倍)。所以預設都是不會輸出location資訊,除非Logger配置了includeLocation="true"(官方文件這麼說的,可是我測試的是預設是輸出的,無論了。反正當日誌出現慢的時候,能夠考慮通過配置includeLocation控制是否輸出location資訊)。

 

 

 

=====================================以下為作者自己探究================

由於上面的架構圖,只是描述了關係。為了實際使用,我們不可能同時使用以上系統中的多個,只能選一個。我在這裡選擇了log4j2作為springmvc專案的日誌記錄系統。

我們知道log4j與log4j2實際上並不是連貫的一套日誌系統,因為log4j2不相容log4j.因此,當我們使用log4j2的時候,就必須避開log4j版本的jar包。

log4j2專案是apache專案,具體官網下載地址:

https://www.apache.org/dyn/closer.lua/logging/log4j/2.10.0/apache-log4j-2.10.0-bin.zip

這裡下載之後,解壓發現裡面有居多jar包,而不僅僅是一個。

 

具體有這一些。

當使用springmvc專案的時候,是需要配置filter,servlet的。所以,

<!-- log4j配置,檔案路徑,因為是跟隨專案啟動 -->
 <context-param>
  <param-name>log4jConfigLocation</param-name>
  <param-value>/WEB-INF/log4j2.xml</param-value>
 </context-param>
 <!-- log4j2-begin -->
 <listener>
  <listener-class>org.apache.logging.log4j.web.Log4jServletContextListener</listener-class>
 </listener>
 <filter>
  <filter-name>log4jServletFilter</filter-name>
  <filter-class>org.apache.logging.log4j.web.Log4jServletFilter</filter-class>
 </filter>
 <filter-mapping>
  <filter-name>log4jServletFilter</filter-name>
  <url-pattern>/*</url-pattern>
  <!-- <dispatcher>REQUEST</dispatcher> <dispatcher>FORWARD</dispatcher> 
   <dispatcher>INCLUDE</dispatcher> <dispatcher>ERROR</dispatcher> -->
 </filter-mapping>
 <!-- log4j2-end -->

 

在web.xml中需要加上這段程式碼。

 

pom檔案記錄如下:

<properties>
  <slf4j.version>1.7.25</slf4j.version>
  <log4j.version>2.8.2</log4j.version>
  <spring.version>4.3.14.RELEASE</spring.version>
 </properties>

<!-- 日誌開始 -->
  <dependency>
   <groupId>org.slf4j</groupId>
   <artifactId>slf4j-api</artifactId>
   <version>${slf4j.version}</version>
  </dependency>
  <dependency>
   <groupId>org.apache.logging.log4j</groupId>
   <artifactId>log4j-slf4j-impl</artifactId>
   <version>${log4j.version}</version>
  </dependency>
  <!--相容log4j -->
  <dependency>
   <groupId>org.apache.logging.log4j</groupId>
   <artifactId>log4j-1.2-api</artifactId>
   <version>2.0</version>
  </dependency>
  <dependency>
   <groupId>org.apache.logging.log4j</groupId>
   <artifactId>log4j-api</artifactId>
   <version>${log4j.version}</version>
  </dependency>
  <dependency>
   <groupId>org.apache.logging.log4j</groupId>
   <artifactId>log4j-core</artifactId>
   <version>${log4j.version}</version>
  </dependency>
  <dependency>
   <groupId>org.apache.logging.log4j</groupId>
   <artifactId>log4j-web</artifactId>
   <version>${log4j.version}</version>
  </dependency>

  <!--log4j2 非同步appender須要 -->
  <dependency>
   <groupId>com.lmax</groupId>
   <artifactId>disruptor</artifactId>
   <version>3.2.0</version>
  </dependency>

  <!--日誌結束 -->

 

注意:這裡不僅需要log4j-core,還需要log4j-web.jar。這都是log4j的部分。所以,可以把圖上的jar包根據情況進行新增。

日誌配置檔案:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="off" monitorInterval="1800">
 <properties>
  <property name="LOG_HOME">d://logs/tomcat-8081</property>
  <property name="FILE_NAME">springRedisCloudTest</property>
 </properties>
 <Appenders>
  <Console name="Console" target="SYSTEM_OUT">
   <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n" />
  </Console>
  <RollingRandomAccessFile name="running-log"
   fileName="${LOG_HOME}/${FILE_NAME}.log"
   filePattern="${LOG_HOME}/$${date:yyyy-MM}/${FILE_NAME}-%d{yyyy-MM-dd}-%i.log.gz">
   <PatternLayout
    pattern="%date{yyyy-MM-dd HH:mm:ss.SSS} %level [%thread][%file:%line] - %msg%n" />
   <Policies>
    <TimeBasedTriggeringPolicy />
    <SizeBasedTriggeringPolicy size="10 MB" />
   </Policies>
   <DefaultRolloverStrategy max="20" />
  </RollingRandomAccessFile>
 </Appenders>
 <Loggers>
  <Logger name="springRedisCloudTest" level="info"
   additivity="true">
   <AppenderRef ref="running-log" />
  </Logger>
  <Root level="info">
   <AppenderRef ref="Console" />
  </Root>
 </Loggers>
</Configuration>

 

使用:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

private Logger logger = LoggerFactory.getLogger(RedisController.class);

logger.info("PRINT A MARK IN THE METHOD");