講武德，你們要的高效能日誌工具 Log4j2，來了

沉默王二發表於2020-11-23

Log4j 介紹過了，SLF4J 介紹過了，Logback 也介紹過了，你以為日誌系列的文章就到此終結了？

不不不，我告訴你，還有一個 Log4j 2，顧名思義，它就是 Log4j 的升級版，就好像手機裡面的 Pro 版。我作為一個寫文章方面的工具人，或者叫打工人，怎麼能不寫完這最後一篇。

Log4j、SLF4J、Logback 是一個爹——Ceki Gulcu，但 Log4j 2 卻是例外，它是 Apache 基金會的產品。

SLF4J 和 Logback 作為 Log4j 的替代品，在很多方面都做了必要的改進，那為什麼還需要 Log4j 2 呢？我只能說 Apache 基金會的開發人員很閒，不，很拼，要不是他們這種精益求精的精神，這個程式設計的世界該有多枯燥，畢竟少了很多可以用“拿來就用”的輪子啊。

上一篇也說了，老闆下死命令要我把日誌系統切換到 Logback，我順利交差了，老闆很開心，誇我這個打工人很敬業。為了表達對老闆的這份感謝，我決定偷偷摸摸地試水一下 Log4j 2，儘管它還不是個成品，可能會會專案帶來一定的隱患。但誰讓我們是一個敬崗愛業的打工人呢。

01、Log4j 2 強在哪

1）在多執行緒場景下，Log4j 2 的吞吐量比 Logback 高出了 10 倍，延遲降低了幾個數量級。這話聽起來像吹牛，反正是 Log4j 2 官方自己吹的。

Log4j 2 的非同步 Logger 使用的是無鎖資料結構，而 Logback 和 Log4j 的非同步 Logger 使用的是 ArrayBlockingQueue。對於阻塞佇列，多執行緒應用程式在嘗試使日誌事件入隊時通常會遇到鎖爭用。

下圖說明了多執行緒方案中無鎖資料結構對吞吐量的影響。 Log4j 2 隨著執行緒數量的擴充套件而更好地擴充套件：具有更多執行緒的應用程式可以記錄更多的日誌。其他日誌記錄庫由於存在鎖競爭的關係，在記錄更多執行緒時，總吞吐量保持恆定或下降。這意味著使用其他日誌記錄庫，每個單獨的執行緒將能夠減少日誌記錄。

效能方面是 Log4j 2 的最大亮點，至於其他方面的一些優勢，比如說下面這些，可以忽略不計，文字有多短就代表它有多不重要。

2）Log4j 2 可以減少垃圾收集器的壓力。

3）支援 Lambda 表示式。

4）支援自動過載配置。

02、Log4j 2 使用示例

廢話不多說，直接實操開幹。理論知識有用，但不如上手實操一把，這也是我多年養成的一個“不那麼良好”的程式設計習慣：在實操中發現問題，解決問題，尋找理論基礎。

第一步，在 pom.xml 檔案中新增 Log4j 2 的依賴：

<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-api</artifactId>
    <version>2.5</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
    <version>2.5</version>
</dependency>

（這個 artifactId 還是 log4j，沒有體現出來 2，而在 version 中體現，多少叫人誤以為是 log4j）

第二步，來個最簡單的測試用例：

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class Demo {
    private static final Logger logger = LogManager.getLogger(Demo.class);
    public static void main(String[] args) {
        logger.debug("log4j2");
    }
}

執行 Demo 類，可以在控制檯看到以下資訊：

ERROR StatusLogger No log4j2 configuration file found. Using default configuration: logging only errors to the console.

Log4j 2 竟然沒有在控制檯列印“ log4j2”，還抱怨我們沒有為它指定配置檔案。在這一點上，我就覺得它沒有 Logback 好，畢竟人家會輸出。

這對於新手來說，很不友好，因為新手在遇到這種情況的時候，往往不知所措。日誌裡面雖然體現了 ERROR，但程式碼並沒有編譯出錯或者執行出錯，憑什麼你不輸出？

那作為程式設計老鳥來說，我得告訴你，這時候最好探究一下為什麼。怎麼做呢？

我們可以複製一下日誌資訊中的關鍵字，比如說：“No log4j2 configuration file found”，然後在 Intellij IDEA 中搜一下，如果你下載了原始碼和文件的話，不除意外，你會在 ConfigurationFactory 類中搜到這段話。

可以在方法中打個斷點，然後 debug 一下，你就會看到下圖中的內容。

通過原始碼，你可以看得到，Log4j 2 會去尋找 4 種型別的配置檔案，字尾分別是 properties、yaml、json 和 xml。字首是 log4j2-test 或者 log4j2。

得到這個提示後，就可以進行第三步了。

第三步，在 resource 目錄下增加 log4j2-test.xml 檔案（方便和 Logback 做對比），內容如下所示：

<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
        </Console>
    </Appenders>
    <Loggers>
        <Root level="DEBUG">
            <AppenderRef ref="Console"/>
        </Root>
    </Loggers>
</Configuration>

Log4j 2 的配置檔案格式和 Logback 有點相似，基本的結構為 < Configuration> 元素，包含 0 或多個 < Appenders> 元素，其後跟 0 或多個 < Loggers> 元素，裡面再跟最多隻能存在一個的 < Root> 元素。

1）配置 appender，也就是配置日誌的輸出目的地。

有 Console，典型的控制檯配置資訊上面你也看到了，我來簡單解釋一下里面 pattern 的格式：

%d{HH:mm:ss.SSS} 表示輸出到毫秒的時間
%t 輸出當前執行緒名稱
%-5level 輸出日誌級別，-5 表示左對齊並且固定輸出 5 個字元，如果不足在右邊補空格
%logger 輸出 logger 名稱，最多 36 個字元
%msg 日誌文字
%n 換行

順帶補充一下其他常用的佔位符：

%F 輸出所在的類檔名，如 Demo.java
%L 輸出行號
%M 輸出所在方法名
%l 輸出語句所在的行數, 包括類名、方法名、檔名、行數
%p 輸出日誌級別
%c 輸出包名，如果後面跟有 {length.} 引數，比如說 %c{1.}，它將輸出報名的第一個字元，如 com.itwanger 的實際報名將只輸出 c.i

再次執行 Demo 類，就可以在控制檯看到列印的日誌資訊了：

10:14:04.657 [main] DEBUG com.itwanger.Demo - log4j2

2）配置 Loggers，指定 Root 的日誌級別，並且指定具體啟用哪一個 Appenders。

3）自動過載配置。

Logback 支援自動過載配置，Log4j 2 也支援，那想要啟用這個功能也非常簡單，只需要在 Configuration 元素上新增 monitorInterval 屬性即可。

<Configuration monitorInterval="30">
...
</Configuration>

注意值要設定成非零，上例中的意思是至少 30 秒後檢查配置檔案中的更改。最小間隔為 5 秒。

03、Async 示例

除了 Console，還有 Async，可以配合檔案的方式來非同步寫入，典型的配置資訊如下所示：

<Configuration>
  <Appenders>
    <File name="DebugFile" fileName="debug.log">
      <PatternLayout>
        <Pattern>%d %p %c [%t] %m%n</Pattern>
      </PatternLayout>
    </File>
    <Async name="Async">
      <AppenderRef ref="DebugFile"/>
    </Async>
  </Appenders>
  <Loggers>
    <Root level="debug">
      <AppenderRef ref="Async"/>
    </Root>
  </Loggers>
</Configuration>

對比 Logback 的配置檔案來看，Log4j 2 真的複雜了一些，不太好用，就這麼直白地說吧！但自己約的，含著淚也得打完啊。把這個 Async 加入到 Appenders：

<Configuration>
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
        </Console>
        <File name="DebugFile" fileName="debug.log">
            <PatternLayout>
                <Pattern>%d %p %c [%t] %m%n</Pattern>
            </PatternLayout>
        </File>
        <Async name="Async">
            <AppenderRef ref="DebugFile"/>
        </Async>
    </Appenders>
    <Loggers>
        <Root level="DEBUG">
            <AppenderRef ref="Console"/>
            <AppenderRef ref="Async"/>
        </Root>
    </Loggers>
</Configuration>

再次執行 Demo 類，可以在專案根路徑下看到一個 debug.log 檔案，內容如下所示：

2020-10-30 09:35:49,705 DEBUG com.itwanger.Demo [main] log4j2

04、RollingFile 示例

當然了，Log4j 和 Logback 我們都配置了 RollingFile，Log4j 2 也少不了。RollingFile 會根據 Triggering（觸發）策略和 Rollover（過渡）策略來進行日誌檔案滾動。如果沒有配置 Rollover，則使用 DefaultRolloverStrategy 來作為 RollingFile 的預設配置。

觸發策略包含有，基於 cron 表示式（源於希臘語，時間的意思，用來配置定期執行任務的時間格式）的 CronTriggeringPolicy；基於檔案大小的 SizeBasedTriggeringPolicy；基於時間的 TimeBasedTriggeringPolicy。

過渡策略包含有，預設的過渡策略 DefaultRolloverStrategy，直接寫入的 DirectWriteRolloverStrategy。一般情況下，採用預設的過渡策略即可，它已經足夠強大。

來看第一個基於 SizeBasedTriggeringPolicy 和 TimeBasedTriggeringPolicy 策略，以及預設 DefaultRolloverStrategy 策略的配置示例：

<Configuration>
  <Appenders>
    <RollingFile name="RollingFile" fileName="rolling.log"
                 filePattern="rolling-%d{yyyy-MM-dd}-%i.log">
      <PatternLayout>
        <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
      </PatternLayout>
      <Policies>
        <SizeBasedTriggeringPolicy size="1 KB"/>
      </Policies>
    </RollingFile>
  </Appenders>
  <Loggers>
    <Root level="debug">
      <AppenderRef ref="RollingFile"/>
    </Root>
  </Loggers>
</Configuration>

為了驗證檔案的滾動策略，我們調整一下 Demo 類，讓它多列印點日誌：

for (int i = 1;i < 20; i++) {
    logger.debug("微信搜尋「{}」，回覆關鍵字「{}」，有驚喜哦","沉默王二", "java");
}

再次執行 Demo 類，可以看到根目錄下多了 3 個日誌檔案：

結合日誌檔名，再來看 RollingFile 的配置，就很容易理解了。

1）fileName 用來指定檔名。

2）filePattern 用來指定檔名的模式，它取決於過渡策略。

由於配置檔案中沒有顯式指定過渡策略，因此 RollingFile 會啟用預設的 DefaultRolloverStrategy。

先來看一下 DefaultRolloverStrategy 的屬性：

再來看 filePattern 的值 rolling-%d{yyyy-MM-dd}-%i.log，其中 %d{yyyy-MM-dd} 很好理解，就是年月日；其中 %i 是什麼意思呢？

第一個日誌檔名為 rolling.log（最近的日誌放在這個裡面），第二個檔名除去日期為 rolling-1.log，第二個檔名除去日期為 rolling-2.log，根據這些資訊，你能猜到其中的規律嗎？

其實和 DefaultRolloverStrategy 中的 max 屬性有關，目前使用的預設值，也就是 7，那就當 rolling-8.log 要生成的時候，刪除 rolling-1.log。可以調整 Demo 中的日誌輸出量來進行驗證。

3）SizeBasedTriggeringPolicy，基於日誌檔案大小的時間策略，大小以位元組為單位，字尾可以是 KB，MB 或 GB，例如 20 MB。

再來看一個日誌檔案壓縮的示例，來看配置：

<RollingFile name="RollingFileGZ" fileName="gz/rolling.log"
             filePattern="gz/%d{yyyy-MM-dd-HH}-%i.rolling.gz">
    <PatternLayout>
        <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
    </PatternLayout>
    <Policies>
        <SizeBasedTriggeringPolicy size="1 KB"/>
    </Policies>
</RollingFile>