java基礎學習總結（二十五）：logback詳解

阿新 • • 發佈：2018-11-05

為什麼使用logback

logback大約有以下的一些優點：

核心重寫、測試充分、初始化記憶體載入更小，這一切讓logback效能和log4j相比有諸多倍的提升
logback非常自然地直接實現了slf4j，這個嚴格來說算不上優點，只是這樣，再理解slf4j的前提下會很容易理解logback，也同時很容易用其他日誌框架替換logback
logback有比較齊全的200多頁的文件
logback當配置檔案修改了，支援自動重新載入配置檔案，掃描過程快且安全，它並不需要另外建立一個掃描執行緒
支援自動去除舊的日誌檔案，可以控制已經產生日誌檔案的最大數量

總而言之，如果大家的專案裡面需要選擇一個日誌框架，那麼我個人非常建議使用logback。

logback載入

我們簡單分析一下logback載入過程，當我們使用logback-classic.jar時，應用啟動，那麼logback會按照如下順序進行掃描：

在系統配置檔案System Properties中尋找是否有logback.configurationFile對應的value
在classpath下尋找是否有logback.groovy（即logback支援groovy與xml兩種配置方式）
在classpath下尋找是否有logback-test.xml
在classpath下尋找是否有logback.xml

以上任何一項找到了，就不進行後續掃描，按照對應的配置進行logback的初始化，具體程式碼實現可見ch.qos.logback.classic.util.ContextInitializer類的findURLOfDefaultConfigurationFile方法。

當所有以上四項都找不到的情況下，logback會呼叫ch.qos.logback.classic.BasicConfigurator的configure方法，構造一個ConsoleAppender用於向控制檯輸出日誌，預設日誌輸出格式為"%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n"。

logback的configuration

logback的重點應當是Appender、Logger、Pattern，在這之前先簡單瞭解一下logback的<configuration>，<configuration>只有三個屬性：

scan：當scan被設定為true時，當配置檔案發生改變，將會被重新載入，預設為true
scanPeriod：檢測配置檔案是否有修改的時間間隔，如果沒有給出時間單位，預設為毫秒，當scan=true時這個值生效，預設時間間隔為1分鐘
debug：當被設定為true時，將打印出logback內部日誌資訊，實時檢視logback執行資訊，預設為false

<logger>與<root>

先從最基本的<logger>與<root>開始。

<logger>用來設定某一個包或者具體某一個類的日誌列印級別、以及指定<appender>。<logger>可以包含零個或者多個<appender-ref>元素，標識這個appender將會新增到這個logger。<logger>僅有一個name屬性、一個可選的level屬性和一個可選的additivity屬性：

name：用來指定受此logger約束的某一個包或者具體的某一個類
level：用來設定列印級別，五個常用列印級別從低至高依次為TRACE、DEBUG、INFO、WARN、ERROR，如果未設定此級別，那麼當前logger會繼承上級的級別
additivity：是否向上級logger傳遞列印資訊，預設為true

<root>也是<logger>元素，但是它是根logger，只有一個level屬性，因為它的name就是ROOT，關於這個地方，有朋友微信上問起，原始碼在LoggerContext中：

public LoggerContext() {
    super();
    this.loggerCache = new ConcurrentHashMap<String, Logger>();

    this.loggerContextRemoteView = new LoggerContextVO(this);
    this.root = new Logger(Logger.ROOT_LOGGER_NAME, null, this);
    this.root.setLevel(Level.DEBUG);
    loggerCache.put(Logger.ROOT_LOGGER_NAME, root);
    initEvaluatorMap();
    size = 1;
    this.frameworkPackages = new ArrayList<String>();
}

Logger的建構函式為：

Logger(String name, Logger parent, LoggerContext loggerContext) {
    this.name = name;
    this.parent = parent;
    this.loggerContext = loggerContext;
}

看到第一個引數就是Root的name，而這個Logger.ROOT_LOGGER_NAME的定義為final public String ROOT_LOGGER_NAME = "ROOT"，由此可以看出<root>節點的name就是"ROOT"。

接著寫一段程式碼來測試一下：

public class Slf4jTest {

    @Test
    public void testSlf4j() {
        Logger logger = LoggerFactory.getLogger(Object.class);
        logger.trace("=====trace=====");  
        logger.debug("=====debug=====");  
        logger.info("=====info=====");  
        logger.warn("=====warn=====");  
        logger.error("=====error=====");  
    }
    
}

logback.xml的配置為：

<?xml version="1.0" encoding="UTF-8" ?>
<configuration scan="false" scanPeriod="60000" debug="false">
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
        </layout>
    </appender>
    
    <root level="info">
        <appender-ref ref="STDOUT" />
    </root>
    
</configuration>

root將列印級別設定為"info"級別，<appender>暫時不管，控制檯的輸出為：

2018-10-23 21:51:21.746 [main] INFO  java.lang.Object - =====info=====
2018-10-23 21:51:21.748 [main] WARN  java.lang.Object - =====warn=====
2018-10-23 21:51:21.748 [main] ERROR java.lang.Object - =====error=====

logback.xml的意思是，當Test方法執行時，root節點將日誌級別大於等於info的交給已經配置好的名為"STDOUT"的<appender>進行處理，"STDOUT"將資訊列印到控制檯上。

接著理解一下<logger>節點的作用，logback.xml修改一下，加入一個只有name屬性的<logger>：

<?xml version="1.0" encoding="UTF-8" ?>
<configuration scan="false" scanPeriod="60000" debug="false">

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
        </layout>
    </appender>
     
    <logger name="java" />
      
     <root level="debug">
         <appender-ref ref="STDOUT" />
     </root>
      
</configuration>

注意這個name表示的是LoggerFactory.getLogger(XXX.class)，XXX的包路徑，包路徑越少越是父級，我們測試程式碼裡面是Object.class，即name="java"是name="java.lang"的父級，root是所有<logger>的父級。看一下輸出為：

2018-10-23 21:55:28.064 [main] DEBUG java.lang.Object - =====debug=====
2018-10-23 21:55:28.066 [main] INFO  java.lang.Object - =====info=====
2018-10-23 21:55:28.066 [main] WARN  java.lang.Object - =====warn=====
2018-10-23 21:55:28.066 [main] ERROR java.lang.Object - =====error=====

出現這樣的結果是因為：

<logger>中沒有配置level，即繼承父級的level，<logger>的父級為<root>，那麼level=debug
沒有配置additivity，那麼additivity=true，表示此<logger>的列印資訊向父級<root>傳遞
沒有配置<appender-ref>，表示此<logger>不會打印出任何資訊

由此可知，<logger>的列印資訊向<root>傳遞，<root>使用"STDOUT"這個<appender>打印出所有大於等於debug級別的日誌。舉一反三，我們將<logger>的additivity配置為false，那麼控制檯應該不會打印出任何日誌，因為<logger>的列印資訊不會向父級<root>傳遞且<logger>沒有配置任何<appender>，大家可以自己試驗一下。

接著，我們再配置一個<logger>：

<?xml version="1.0" encoding="UTF-8" ?>
<configuration scan="false" scanPeriod="60000" debug="false">
 
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
        </layout>
    </appender>
     
    <logger name="java" additivity="false" />
    <logger name="java.lang" level="warn">
        <appender-ref ref="STDOUT" />
    </logger>
    
    <root level="debug">
        <appender-ref ref="STDOUT" />
    </root>
     
</configuration>

如果讀懂了上面的例子，那麼這個例子應當很好理解：

LoggerFactory.getLogger(Object.class)，首先找到name="java.lang"這個<logger>，將日誌級別大於等於warn的使用"STDOUT"這個<appender>打印出來
name="java.lang"這個<logger>沒有配置additivity，那麼additivity=true，列印資訊向上傳遞，傳遞給父級name="java"這個<logger>
name="java"這個<logger>的additivity=false且不關聯任何<appender>，那麼name="java"這個<appender>不會列印任何資訊

由此分析，得出最終的列印結果為：

2018-10-23 21:59:26.129 [main] WARN  java.lang.Object - =====warn=====
2018-10-23 21:59:26.131 [main] ERROR java.lang.Object - =====error=====

舉一反三，上面的name="java"這個<appender>可以把additivity設定為true試試看是什麼結果，如果對前面的分析理解的朋友應該很容易想到，有兩部分日誌輸出，一部分是日誌級別大於等於warn的、一部分是日誌級別大於等於debug的。

<appender>

接著看一下<appender>，<appender>是<configuration>的子節點，是負責寫日誌的元件。<appender>有兩個必要屬性name和class：

name指定<appender>的名稱

class指定<appender>的全限定名

<appender>有好幾種，上面我們演示過的是ConsoleAppender，ConsoleAppender的作用是將日誌輸出到控制檯，配置示例為：

 <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
     <encoder>
         <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
     </encoder>
 </appender>

其中，encoder表示對引數進行格式化。我們和上一部分的例子對比一下，發現這裡是有所區別的，上面使用了<layout>定義<pattern>，這裡使用了<encoder>定義<pattern>，簡單說一下：

<encoder>是0.9.19版本之後引進的，以前的版本使用<layout>，logback極力推薦的是使用<encoder>而不是<layout>
最常用的FileAppender和它的子類的期望是使用<encoder>而不再使用<layout>

關於<encoder>中的格式下一部分再說。接著我們看一下FileAppender，FileAppender的作用是將日誌寫到檔案中，配置示例為：

<appender name="FILE" class="ch.qos.logback.core.FileAppender">  
    <file>D:/123.log</file>  
    <append>true</append>  
    <encoder>  
        <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>  
    </encoder>  
</appender>

它的幾個節點為：

<file>表示寫入的檔名，可以使相對目錄也可以是絕對目錄，如果上級目錄不存在則自動建立
<appender>如果為true表示日誌被追加到檔案結尾，如果是false表示清空檔案
<encoder>表示輸出格式，後面說
<prudent>如果為true表示日誌會被安全地寫入檔案，即使其他的FileAppender也在向此檔案做寫入操作，效率低，預設為false

接著來看一下RollingFileAppender，RollingFileAppender的作用是滾動記錄檔案，先將日誌記錄到指定檔案，當符合某個條件時再將日誌記錄到其他檔案，RollingFileAppender配置比較靈活，因此使用得更多，示例為：

<appender name="ROLLING-FILE-1" class="ch.qos.logback.core.rolling.RollingFileAppender">   
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">   
        <fileNamePattern>rolling-file-%d{yyyy-MM-dd}.log</fileNamePattern>   
        <maxHistory>30</maxHistory>    
    </rollingPolicy>   
    <encoder>   
        <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>   
    </encoder>   
</appender>

這種是僅僅指定了<rollingPolicy>的寫法，<rollingPolicy>的作用是當發生滾動時，定義RollingFileAppender的行為，其中上面的TimeBasedRollingPolicy是最常用的滾動策略，它根據時間指定滾動策略，既負責滾動也負責觸發滾動，有以下節點：

<fileNamePattern>，必要節點，包含檔名及"%d"轉換符，"%d"可以包含一個Java.text.SimpleDateFormat指定的時間格式，如%d{yyyy-MM}，如果直接使用%d那麼格式為yyyy-MM-dd。RollingFileAppender的file子節點可有可無，通過設定file可以為活動檔案和歸檔檔案指定不同的位置
<maxHistory>，可選節點，控制保留的歸檔檔案的最大數量，如果超出數量就刪除舊檔案，假設設定每個月滾動且<maxHistory>是6，則只儲存最近6個月的檔案

向其他還有SizeBasedTriggeringPolicy，用於按照檔案大小進行滾動，可以自己查閱一下資料。

非同步寫日誌

日誌通常來說都以檔案形式記錄到磁碟，例如使用<RollingFileAppender>，這樣的話一次寫日誌就會發生一次磁碟IO，這對於效能是一種損耗，因此更多的，對於每次請求必打的日誌（例如請求日誌，記錄請求API、引數、請求時間），我們會採取非同步寫日誌的方式而不讓此次寫日誌發生磁碟IO，阻塞執行緒從而造成不必要的效能損耗。（不要小看這個點，可以網上查一下服務端效能優化的文章，只是因為將日誌改為非同步寫，整個QPS就有了大幅的提高）。

<?xml version="1.0" encoding="UTF-8" ?>
<configuration scan="false" scanPeriod="60000" debug="false">

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
        </encoder>
    </appender>
    
    <appender name="ROLLING-FILE-1" class="ch.qos.logback.core.rolling.RollingFileAppender">   
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">   
              <fileNamePattern>D:/rolling-file-%d{yyyy-MM-dd}.log</fileNamePattern>   
              <maxHistory>30</maxHistory>    
        </rollingPolicy>   
        <encoder>
              <pattern>%-4relative [%thread] %-5level %lo{35} - %msg%n</pattern>   
        </encoder>   
    </appender>
    
    <!-- 非同步輸出 -->  
    <appender name ="ASYNC" class= "ch.qos.logback.classic.AsyncAppender">  
        <!-- 不丟失日誌.預設的,如果佇列的80%已滿,則會丟棄TRACT、DEBUG、INFO級別的日誌 -->  
        <discardingThreshold>0</discardingThreshold>  
        <!-- 更改預設的佇列的深度,該值會影響效能.預設值為256 -->  
        <queueSize>256</queueSize>  
        <!-- 新增附加的appender,最多隻能新增一個 -->  
        <appender-ref ref ="ROLLING-FILE-1"/>  
    </appender>
    
    <logger name="java" additivity="false" />
    <logger name="java.lang" level="DEBUG">
        <appender-ref ref="ASYNC" />
    </logger>
    
    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root>
    
</configuration>

即，我們引入了一個AsyncAppender，先說一下AsyncAppender的原理，再說一下幾個引數：

當我們配置了AsyncAppender，系統啟動時會初始化一條名為"AsyncAppender-Worker-ASYNC"的執行緒

當Logging Event進入AsyncAppender後，AsyncAppender會呼叫appender方法，appender方法中再將event填入Buffer（使用的Buffer為BlockingQueue，具體實現為ArrayBlockingQueye）前，會先判斷當前Buffer的容量以及丟棄日誌特性是否開啟，當消費能力不如生產能力時，AsyncAppender會將超出Buffer容量的Logging Event的級別進行丟棄，作為消費速度一旦跟不上生產速度導致Buffer溢位處理的一種方式。

上面的執行緒的作用，就是從Buffer中取出Event，交給對應的appender進行後面的日誌推送

從上面的描述我們可以看出，AsyncAppender並不處理日誌，只是將日誌緩衝到一個BlockingQueue裡面去，並在內部建立一個工作執行緒從佇列頭部獲取日誌，之後將獲取的日誌迴圈記錄到附加的其他appender上去，從而達到不阻塞主執行緒的效果。因此AsyncAppender僅僅充當的是事件轉發器，必須引用另外一個appender來做事。

從上述原理，我們就能比較清晰地理解幾個引數的作用了：

discardingThreshold，假如等於20則表示，表示當還剩20%容量時，將丟棄TRACE、DEBUG、INFO級別的Event，只保留WARN與ERROR級別的Event，為了保留所有的events，可以將這個值設定為0，預設值為queueSize/5
queueSize比較好理解，BlockingQueue的最大容量，預設為256
includeCallerData表示是否提取呼叫者資料，這個值被設定為true的代價是相當昂貴的，為了提升效能，預設當event被加入BlockingQueue時，event關聯的呼叫者資料不會被提取，只有執行緒名這些比較簡單的資料
appender-ref表示AsyncAppender使用哪個具體的<appender>進行日誌輸出

<encoder>

<encoder>節點負責兩件事情：

把日誌資訊轉換為位元組陣列
把位元組陣列寫到輸出流

目前PatternLayoutEncoder是唯一有用的且預設的encoder，有一個<pattern>節點，就像上面演示的，用來設定日誌的輸入格式，使用“%+轉換符"的方式，如果要輸出"%"則必須使用"\%"對"%"進行轉義。

<encoder>的一些可用引數用表格表示一下：

看到最後一列是"是否避免使用"，這是因為這些資訊是無法直接拿到的（比如請求行號、呼叫方法名），logback必須通過一些特殊手段去獲取這些資料（比如在日誌打印出產生一個堆疊資訊），這種操作會比較影響效率，因此除非必要，否則不建議列印這些資料。

Filter

最後來看一下<filter>，<filter>是<appender>的一個子節點，表示在當前給到的日誌級別下再進行一次過濾，最基本的Filter有ch.qos.logback.classic.filter.LevelFilter和ch.qos.logback.classic.filter.ThresholdFilter，首先看一下LevelFilter：

<configuration scan="false" scanPeriod="60000" debug="false">

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
        </encoder>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>WARN</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>
    
    <logger name="java" additivity="false" />
    <logger name="java.lang" level="DEBUG">
        <appender-ref ref="STDOUT" />
    </logger>
    
    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root>
    
</configuration>

看一下輸出：

2018-10-24 10:37:41.720 [main] WARN  java.lang.Object - =====warn=====

看到儘管<logger>配置的是DEBUG，但是輸出的只有warn，因為在<filter>中對匹配到WARN級別時做了ACCEPT（接受），對未匹配到WARN級別時做了DENY（拒絕），當然只能打印出WARN級別的日誌。

再看一下ThresholdFilter，配置為：

<?xml version="1.0" encoding="UTF-8" ?>
<configuration scan="false" scanPeriod="60000" debug="false">

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
        </encoder>
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>INFO</level>
        </filter>
    </appender>
    
    <logger name="java" additivity="false" />
    <logger name="java.lang" level="DEBUG">
        <appender-ref ref="STDOUT" />
    </logger>
    
    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root>
    
</configuration>

看一下輸出為：

2018-10-24 10:41:17.859 [main] INFO  java.lang.Object - =====info=====
2018-10-24 10:41:17.861 [main] WARN  java.lang.Object - =====warn=====
2018-10-24 10:41:17.861 [main] ERROR java.lang.Object - =====error=====

因為ThresholdFilter的策略是，會將日誌級別小於<level>的全部進行過濾，因此雖然指定了DEBUG級別，但是隻有INFO及以上級別的才能被打印出來。

java基礎學習總結（二十五）：logback詳解

java基礎學習總結（二十五）：logback詳解

java基礎學習總結（二十四）：slf4j作用及其實現原理

java基礎學習總結（二十一）：自己寫一個java.lang.reflect.Proxy代理的實現

java基礎學習總結（二十二）：Cglib及其基本使用

java基礎學習總結（二十）：多執行緒上下文切換

Linux 學習總結（二十五）系統管理4

python OpenCV學習筆記（二十五）：傅立葉變換（Fourier Transform ）

Unity3D學習筆記（二十五）：文件操作

Java學習總結（二十四）——前端：CSS樣式設計（CSS引入，選擇器，盒子模型，浮動元素）

java基礎學習總結（二十三）：什麼要使用AOP

Java學習筆記（二十一）：類型轉換和instanceof關鍵字

Linux學習總結（二十一）正則三劍客之awk

Linux學習筆記（二十五）shell特殊符號、 sort_wc_uniq、tee_tr_split

Linux學習總結（二十六）防火墻規則之firewalld

Linux學習總結（二十八）數據同步工具 rsync

Linux學習總結（二十九）系統日誌

Linux學習總結（三十五）lamp之訪問日誌配置

Linux學習總結（四十五）mysql 基本操作上篇

Linux學習總結（六十五）tomcat啟動腳本

Linux學習總結（七十五）非關系型數據庫之memcached

java基礎學習總結（二十五）：logback詳解

相關推薦