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實現了一個親子——
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");