SLF4j 居然不是編譯時繫結?日誌又該如何正確的分檔案輸出?——原理與總結篇
各位新年快樂,過了個新年,休(hua)息(shui)了三週,不過我又回來更新了,經過前面四篇想必小夥伴已經瞭解日誌的使用以及最佳實踐了,這個系列的文章也差不多要結束了,今天我們來總結一下。
概覽
這篇文章我們討論一下 SLF4j 的設計,以及 SLF4j 好在哪,之後進行一些答疑與前系列文章勘誤,最最後我們來了解一下如何正確的分檔案輸出日誌。
分析設計
SLF4j 並沒有使用網上所謂的編譯時繫結,實際上是採用了約定俗成的方式,如何做的?很簡單,就是直接載入org/slf4j/impl/StaticLoggerBinder.class
,找到一個直接使用,沒找到或者找到多個報警告,,分析一下原始碼:
我們一起來看一個個 Logger 例項是如何建立的:
org.slf4j.LoggerFactory#getLogger(java.lang.String)
,獲取 logger 例項的真正入口ch.qos.logback.classic.LoggerContext#getLogger(java.lang.String)
,呼叫了 logback 的LoggerContext
(實現 LoggerFactory),具體如何呼叫到這裡下面解析)- 可以看到
childLogger = logger.createChildByName(childName);
建立了 loggger例項,繼續跟進 - 在
ch.qos.logback.classic.Logger#createChildByName
childLogger = new Logger(childName, this, this.loggerContext);
,至此我們目的也達到了,logger 是 new 出來的並不是所謂的編譯時繫結。
我們繼續來跟蹤如何呼叫到 logback 的 LoggerContext
(LogggerFactory),並且來驗證一下是否真的是所謂的編譯時繫結:
-
還是
org.slf4j.LoggerFactory#getLogger(java.lang.String)
方法,這次我們跟進到org.slf4j.LoggerFactory#getILoggerFactory
方法中發現呼叫了performInitialization
bind
,繼續跟進發現呼叫了findPossibleStaticLoggerBinderPathSet
方法在當前ClassPath下查詢了所有名為org/slf4j/impl/StaticLoggerBinder.class
類路徑返回 -
真正程式碼如下,註釋寫的很明確:
Set<URL> staticLoggerBinderPathSet = null; // skip check under android, see also // http://jira.qos.ch/browse/SLF4J-328 if (!isAndroid()) { staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet(); reportMultipleBindingAmbiguity(staticLoggerBinderPathSet); } // the next line does the binding StaticLoggerBinder.getSingleton();
StaticLoggerBinder
這個類就是繫結的關鍵,點進去發現根本不是 SLF4j 的類,而是來自於 Logback,也就是說,SLF4j 使用了第三方(Logback、Log4j 等)提供的中介類,(Spring Boot 自動配置也部分使用了這種思想,以後的全棧系列文章將會有詳細解析,歡迎關注),如果出出現NoClassDefFoundError
則提示一下使用者,然後不再處理日誌。SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder". SLF4J: Defaulting to no-operation (NOP) logger implementation SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
結論:
給出結論之前我們先來明確一下 Java 的繫結(Binding)的概念,Java 本身只支援靜態(static)繫結與執行時(runtime)繫結,直到與 JDK 1.6 版本一起釋出的 JSR269 才能進行編譯時繫結,員外理解的編譯時繫結類似於 lomok 在編譯過程中修改位元組碼。SFL4j 的 logger 例項是 new 出來的,繫結 LogContext
的 StaticLoggerBinder
(中介類) 是寫死的,編譯時並沒有處理任何邏輯,也談不上什麼編譯時繫結,員外翻遍了 SLF4j 文件也沒有找到任何有關編譯時繫結的材料,官方只提到了 “static binding”, 所以回到文章標題,網上流傳的編譯時繫結根本就是錯的,SLF4j使用的是 Convention over Configuration(CoC)– 慣例優於配置原則,我不管你是什麼日誌框架,我只載入org.slf4j.impl.StaticLoggerBinder
。這完美契合了軟體設計的 KISS(Keep It Simple, Stupid)原則,而 Commons-logging 魔法(magic)一樣的動態載入雖然設計很高大上,在應用領域卻直接被打臉,低效率、與 OSGi 共同使用所導致的 ClassLoader 問題更是火上澆油,所以員外與大家共勉,寫程式碼切勿炫技。
以上是本文核心,略過的讀者勞煩再讀一次。
為什麼SLF4j 更好
先了解一下為什麼說 SLF4j 更好,下面兩段話來自於Spring 4.x 官方文件:
docs.spring.io/spring/docs…
Not Using Commons Logging
Unfortunately, the runtime discovery algorithm in
commons-logging
, while convenient for the end-user, is problematic. If we could turn back the clock and start Spring now as a new project it would use a different logging dependency. The first choice would probably be the Simple Logging Facade for Java ( SLF4J), which is also used by a lot of other tools that people use with Spring inside their applications.不幸的是,
commons-logging
的執行時發現演算法雖然對使用者很方便,但卻有問題。 如果我們有後悔藥能夠將 Spring 作為一個新專案重新啟動,首選可能是 Simple Logging Facade for Java(SLF4J),Spring 所依賴的其他工具也能使用它。
That might seem like a lot of dependencies just to get some logging. Well it is, but it is optional, and it should behave better than the vanilla
commons-logging
with respect to classloader issues, notably if you are in a strict container like an OSGi platform. Allegedly there is also a performance benefit because the bindings are at compile-time not runtime.這看起來好像僅僅為了日誌就需要很多依賴。但這些依賴都是可選的,在類載入器問題方面,它應該比普通的 Commons-logging 表現得更好,特別是如果您在 OSGi 平臺這樣的嚴格容器中。據說效能還有優勢,因為繫結是在編譯時而不是執行時。
這兩段文字可謂是肺腑之言,公平公正,員外也沒有到處去驗證,所謂效能優勢我認為作為static final
級別變數,效能優勢也不會太大。員外認為 SLF4j 本質上更好的原因在於其提供市面上所有日誌框架的相容解決方案。
勘誤
第一篇文章「Java日誌體系居然這麼複雜?——架構篇」其中 Spring Boot的使用依賴,我寫到“Spring已經寫好了一個log4j2-starter但缺少橋接包”是不對的,員外出於好奇驗證一下,之所以 Spring 沒有依賴 jcl-over-slf4j 是因為 Spring Boot 2.x 版本以後依賴了其自己實現的 Spring-jcl 橋接,而 1.x 版本則帶有 jcl-over-slf4j 依賴,所以抱歉,我的文章這裡寫錯了,望各位周知。
第二篇文章「五年Java經驗,面試還是說不出日誌該怎麼寫更好?——日誌規範與最佳實踐篇」其中 Log4j2配置檔案那一段有誤,缺了一個名為 STDOUT 的控制檯Appender,程式碼如下:
<Console name="STDOUT"> <PatternLayout pattern="[%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n"/> </Console>
第四篇文章「這麼香的日誌動態級別與輸出,你確定不進來看看?——生產環境動態輸入日誌級別、檔案」
這篇文章也是有一個配置檔案貼上錯位置了,不過原始碼是正確的,請各位下載github原始碼,以原始碼為準。
答疑
第一個答疑是讀者的一個小要求,問我能不能寫一個YAML格式的 Log4j2 配置檔案,當然可以了,下面是手寫的,請測試一下再進入生產使用:
Configuration: status: debug name: YAMLConfig properties: property: name: baseDir value: logs appenders: RollingFile: - name: RollingFile fileName: ${baseDir}/log.log filePattern: "${baseDir}/$${date:yyyy-MM}/log-%d{yyyy-MM-dd-HH}-%i.log.gz" PatternLayout: pattern: "%d{yyyy-MM-dd HH:mm:ss.SSS} %5p %pid --- [%t] %-40.40c{1.} : %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD}" Policies: - TimeBasedTriggeringPolicy: true SizeBasedTriggeringPolicy: size: 250 MB DefaultRollOverStrategy: max: 100 Delete: basePath: ${baseDir} maxDepth: 2 IfFileName: glob: "*/app-*.log.gz" IfLastModified: age: 30d IfAny: IfAccumulatedFileSize: exceeds: 100 GB IfAccumulatedFileCount: exceeds: 10 Console: name: STDOUT PatternLayout: Pattern: "[%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n" Filters: ThresholdFilter: level: debug Loggers: logger: - name: org.apache.logging.log4j.test2 level: debug additivity: false AppenderRef: ref: RollingFile Root: level: trace AppenderRef: ref: STDOUT
另外一個小夥伴在我的文章下提出了幾個問題:
每個日誌檔案大小,如何分割?日期分割?一天一個? 是一天一個目錄還是一天一個檔案? 還是一週一個目錄? 區不區分error和info日誌在不同檔案?打不列印其他級別日誌? 能不能動態修改日誌級別不停機?是否需要非同步日誌,你們的訪問量到了默認同步日誌扛不住的地步了麼?怎麼非同步日誌?
雖然這個小夥伴態度不是很好,但是問題還是很好的:
-
每個日誌檔案大小,如何分割?日期分割?一天一個? 是一天一個目錄還是一天一個檔案? 還是一週一個目錄?
每個檔案大小我喜歡250M這個數字,也這麼配的,日期分割這個就不應該我來講了,我說一個月一分割,一般應用都好幾百個G了,我說一分鐘一分割,好多應用還不到1M,所以按照自己線上的需求慢慢調整才行。
-
區不區分error和info日誌在不同檔案?
員外堅決反對按照日誌級別分檔案,設想一下回溯現場的時候,info、warn、error 級別都是有用日誌,如果分開了,是不是逐個去看?如果讓我逐個去定位錯誤位置,我想我會罵孃的,至於如何正確的分檔案輸出日誌,後面我會有補充,見下文。
-
打不列印其他級別日誌?
打不列印其他級別日誌根本就是個偽問題,不需要列印其他級別也就不需要那麼多日誌級別了,這個問題是不是可以理解為日誌應該開到什麼級別,我一般開 info 級別,我也見過線上只開 error 的,然後業務裡的日誌輸出都是error的(反面教材)。
-
能不能動態修改日誌級別不停機?
能的,參考我上一篇文章,而且這方面應該沒有人做的比我文章裡寫的更好了。
-
是否需要非同步日誌,怎麼非同步日誌?
我個人不傾向於非同步日誌,磁碟IO滿了,開了非同步也是緩衝區滿,緩衝區滿了要麼阻塞,要麼拋棄,至於開了非同步所帶來的效能優勢並不大。怎麼非同步日誌我文章裡也有寫,請參閱公眾號。
-
你們的訪問量到了默認同步日誌扛不住的地步了麼?
日誌扛不住了要先考慮是不是過多,如果實在沒法減少日誌,就考慮將日誌輸出路徑單獨掛載磁碟、更換更好的磁碟等等。
正確的分檔案輸出日誌
讀過員外的文章就知道,員外是贊成分檔案輸出日誌的,不過員外反對按照級別來輸出檔案。如何正確的按檔案輸出日誌呢?以前文章沒有寫過,這裡來補充一下。
很簡單,配置多個appender,然後可以按照 loggger 來分檔案,程式碼如下:
<Logger name="com.jiyuanwai.log.xxx" level="info" additivity="false"> <appender-ref ref="XXXFile"/> </Logger> <Logger name="com.jiyuanwai.log.yyy" level="info" additivity="false"> <appender-ref ref="YYYFile"/> </Logger>
這個倒是很簡單,但是還有一個問題,單個類如果有多種日誌想要輸出到多個位置,該怎麼辦,解決方案有兩種,一個類持有多個 logger 例項:
class A { static final Logger log = LoggerFactory.getLogger("com.jiyuanwai.log.xxx"); static final Logger log = LoggerFactory.getLogger("com.jiyuanwai.log.yyy"); ... }
這種辦法實現簡單,但是不優雅,我們來嘗試拿出另外一套方案,就是 Maker 配合 Filter 來實現,當然根據以前的文章瞭解到我們還可以使用 Sift 配合 MDC 來實現,但員外不推薦,至於為什麼,作為公眾號粉絲福利可以關注公眾號回覆 “Sift” 來獲取答案,我們來繼續看 demo:
// Marker 也可以考慮 static final Marker file1 = MarkerFactory.getMarker("file1"); Marker file2 = MarkerFactory.getMarker("file2"); log.info(file1, "A file 1 log."); log.info(file2, "A file 2 log.");
配置檔案如下:
<appender name="FILE1" class="ch.qos.logback.core.FileAppender"> <file>${LOG_PATH}/testFile1.log</file> <append>true</append> <filter class="ch.qos.logback.core.filter.EvaluatorFilter"> <evaluator class="ch.qos.logback.classic.boolex.OnMarkerEvaluator"> <marker>file1</marker> </evaluator> <!-- 不匹配 NEUTRAL不處理,ACCEPT接收,DENY拋棄 --> <OnMismatch>DENY</OnMismatch> <!-- 匹配處理方式 NEUTRAL不處理,ACCEPT接收,DENY拋棄 --> <OnMatch>ACCEPT</OnMatch> </filter> <encoder> <pattern>${FILE_LOG_PATTERN}</pattern> </encoder> </appender> <appender name="FILE2" class="ch.qos.logback.core.FileAppender"> <file>${LOG_PATH}/testFile2.log</file> <append>true</append> <filter class="ch.qos.logback.core.filter.EvaluatorFilter"> <evaluator class="ch.qos.logback.classic.boolex.OnMarkerEvaluator"> <!-- 此處可以配置多個 marker--> <marker>file2</marker> </evaluator> <!-- 不匹配 NEUTRAL不處理,ACCEPT接收,DENY拋棄 --> <OnMismatch>DENY</OnMismatch> <!-- 匹配處理方式 NEUTRAL不處理,ACCEPT接收,DENY拋棄 --> <OnMatch>ACCEPT</OnMatch> </filter> <encoder> <pattern>${FILE_LOG_PATTERN}</pattern> </encoder> </appender> <logger name="com.jiyuanwai.logging.LoggingApplication" additivity="false"> <appender-ref ref="FILE1"/> <appender-ref ref="FILE2"/> </logger>
結束語
以上只是拋磚引玉,日誌分檔案輸出還可以寫更多邏輯,小夥伴需要自己動手發掘。
至此日誌系列就算是告一段落了,如果還有疑問小夥伴可以留言討論,接下來一系列我們進入Spring Boot + Vue 的全棧之路,敬請關注。
以上是個人觀點,如果有問題或錯誤,歡迎留言討論指正,碼字不易,如果覺得寫的不錯,求關注、求點贊、求轉發。
掃碼關注公眾號,第一時間獲得更新