給，你們要的高性能日志記錄工具 Log4j 2

作者：沉默王二 2020-11-04 12:33:08

Log4j 介紹過(guò)了，SLF4J 介紹過(guò)了，Logback 也介紹過(guò)了，你以為日志系列的文章就到此終結(jié)了?

不不不，我告訴你，還有一個(gè) Log4j 2，顧名思義，它就是 Log4j 的升級(jí)版，就好像手機(jī)里面的 Pro 版。我作為一個(gè)寫(xiě)文章方面的工具人，或者叫打工人，怎么能不寫(xiě)完這最后一篇。

Log4j、SLF4J、Logback 是一個(gè)爹——Ceki Gulcu，但 Log4j 2 卻是例外，它是 Apache 基金會(huì)的產(chǎn)品。

SLF4J 和 Logback 作為 Log4j 的替代品，在很多方面都做了必要的改進(jìn)，那為什么還需要 Log4j 2 呢?我只能說(shuō) Apache 基金會(huì)的開(kāi)發(fā)人員很閑，不，很拼，要不是他們這種精益求精的精神，這個(gè)編程的世界該有多枯燥，畢竟少了很多可以用“拿來(lái)就用”的輪子啊。

上一篇也說(shuō)了，老板下死命令要我把日志系統(tǒng)切換到 Logback，我順利交差了，老板很開(kāi)心，夸我這個(gè)打工人很敬業(yè)。為了表達(dá)對(duì)老板的這份感謝，我決定偷偷摸摸地試水一下 Log4j 2，盡管它還不是個(gè)成品，可能會(huì)會(huì)項(xiàng)目帶來(lái)一定的隱患。但誰(shuí)讓咱是一個(gè)敬崗愛(ài)業(yè)的打工人呢。

01、Log4j 2 強(qiáng)在哪

1)在多線程場(chǎng)景下，Log4j 2 的吞吐量比 Logback 高出了 10 倍，延遲降低了幾個(gè)數(shù)量級(jí)。這話(huà)聽(tīng)起來(lái)像吹牛，反正是 Log4j 2 官方自己吹的。

Log4j 2 的異步 Logger 使用的是無(wú)鎖數(shù)據(jù)結(jié)構(gòu)，而 Logback 和 Log4j 的異步 Logger 使用的是 ArrayBlockingQueue。對(duì)于阻塞隊(duì)列，多線程應(yīng)用程序在嘗試使日志事件入隊(duì)時(shí)通常會(huì)遇到鎖爭(zhēng)用。

下圖說(shuō)明了多線程方案中無(wú)鎖數(shù)據(jù)結(jié)構(gòu)對(duì)吞吐量的影響。Log4j 2 隨著線程數(shù)量的擴(kuò)展而更好地?cái)U(kuò)展：具有更多線程的應(yīng)用程序可以記錄更多的日志。其他日志記錄庫(kù)由于存在鎖競(jìng)爭(zhēng)的關(guān)系，在記錄更多線程時(shí)，總吞吐量保持恒定或下降。這意味著使用其他日志記錄庫(kù)，每個(gè)單獨(dú)的線程將能夠減少日志記錄。

性能方面是 Log4j 2 的最大亮點(diǎn)，至于其他方面的一些優(yōu)勢(shì)，比如說(shuō)下面這些，可以忽略不計(jì)，文字有多短就代表它有多不重要。

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

3)支持 Lambda 表達(dá)式。

4)支持自動(dòng)重載配置。

02、Log4j 2 使用示例

廢話(huà)不多說(shuō)，直接實(shí)操開(kāi)干。理論知識(shí)有用，但不如上手實(shí)操一把，這也是我多年養(yǎng)成的一個(gè)“不那么良好”的編程習(xí)慣：在實(shí)操中發(fā)現(xiàn)問(wèn)題，解決問(wèn)題，尋找理論基礎(chǔ)。

第一步，在 pom.xml 文件中添加 Log4j 2 的依賴(lài)：

<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>

(這個(gè) artifactId 還是 log4j，沒(méi)有體現(xiàn)出來(lái) 2，而在 version 中體現(xiàn)，多少叫人誤以為是 log4j)

第二步，來(lái)個(gè)最簡(jiǎn)單的測(cè)試用例：

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"); 
    } 
}

運(yùn)行 Demo 類(lèi)，可以在控制臺(tái)看到以下信息：

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

Log4j 2 竟然沒(méi)有在控制臺(tái)打印“ log4j2”，還抱怨我們沒(méi)有為它指定配置文件。在這一點(diǎn)上，我就覺(jué)得它沒(méi)有 Logback 好，畢竟人家會(huì)輸出。

這對(duì)于新手來(lái)說(shuō)，很不友好，因?yàn)樾率衷谟龅竭@種情況的時(shí)候，往往不知所措。日志里面雖然體現(xiàn)了 ERROR，但代碼并沒(méi)有編譯出錯(cuò)或者運(yùn)行出錯(cuò)，憑什么你不輸出?

那作為編程老鳥(niǎo)來(lái)說(shuō)，我得告訴你，這時(shí)候最好探究一下為什么。怎么做呢?

我們可以復(fù)制一下日志信息中的關(guān)鍵字，比如說(shuō)：“No log4j2 configuration file found”，然后在 Intellij IDEA 中搜一下，如果你下載了源碼和文檔的話(huà)，不出意外，你會(huì)在 ConfigurationFactory 類(lèi)中搜到這段話(huà)。

可以在方法中打個(gè)斷點(diǎn)，然后 debug 一下，你就會(huì)看到下圖中的內(nèi)容。

通過(guò)源碼，你可以看得到，Log4j 2 會(huì)去尋找 4 種類(lèi)型的配置文件，后綴分別是 properties、yaml、json 和 xml。前綴是 log4j2-test 或者 log4j2。

得到這個(gè)提示后，就可以進(jìn)行第三步了。

第三步，在 resource 目錄下增加 log4j2-test.xml 文件(方便和 Logback 做對(duì)比)，內(nèi)容如下所示：

<?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>

1)配置 appender，也就是配置日志的輸出目的地。

有 Console，典型的控制臺(tái)配置信息上面你也看到了，我來(lái)簡(jiǎn)單解釋一下里面 pattern 的格式：

%d{HH:mm:ss.SSS} 表示輸出到毫秒的時(shí)間
%t 輸出當(dāng)前線程名稱(chēng)
%-5level 輸出日志級(jí)別，-5 表示左對(duì)齊并且固定輸出 5 個(gè)字符，如果不足在右邊補(bǔ)空格
%logger 輸出 logger 名稱(chēng)，最多 36 個(gè)字符
%msg 日志文本
%n 換行

順帶補(bǔ)充一下其他常用的占位符：

%F 輸出所在的類(lèi)文件名，如 Demo.java
%L 輸出行號(hào)
%M 輸出所在方法名
%l 輸出語(yǔ)句所在的行數(shù), 包括類(lèi)名、方法名、文件名、行數(shù)
%p 輸出日志級(jí)別
%c 輸出包名，如果后面跟有 {length.} 參數(shù)，比如說(shuō) %c{1.}，它將輸出報(bào)名的第一個(gè)字符，如 com.itwanger 的實(shí)際報(bào)名將只輸出 c.i

再次運(yùn)行 Demo 類(lèi)，就可以在控制臺(tái)看到打印的日志信息了：

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

2)配置 Loggers，指定 Root 的日志級(jí)別，并且指定具體啟用哪一個(gè) Appenders。

3)自動(dòng)重載配置。

Logback 支持自動(dòng)重載配置，Log4j 2 也支持，那想要啟用這個(gè)功能也非常簡(jiǎn)單，只需要在 Configuration 元素上添加 monitorInterval 屬性即可。

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

注意值要設(shè)置成非零，上例中的意思是至少 30 秒后檢查配置文件中的更改。最小間隔為 5 秒。

03、Async 示例

除了 Console，還有 Async，可以配合文件的方式來(lái)異步寫(xiě)入，典型的配置信息如下所示：

<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>

對(duì)比 Logback 的配置文件來(lái)看，Log4j 2 真的復(fù)雜了一些，不太好用，就這么直白地說(shuō)吧!但自己約的，含著淚也得打完啊。把這個(gè) 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>

再次運(yùn)行 Demo 類(lèi)，可以在項(xiàng)目根路徑下看到一個(gè) debug.log 文件，內(nèi)容如下所示：

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

04、RollingFile 示例

當(dāng)然了，Log4j 和 Logback 我們都配置了 RollingFile，Log4j 2 也少不了。RollingFile 會(huì)根據(jù) Triggering(觸發(fā))策略和 Rollover(過(guò)渡)策略來(lái)進(jìn)行日志文件滾動(dòng)。如果沒(méi)有配置 Rollover，則使用 DefaultRolloverStrategy 來(lái)作為 RollingFile 的默認(rèn)配置。

觸發(fā)策略包含有，基于 cron 表達(dá)式(源于希臘語(yǔ)，時(shí)間的意思，用來(lái)配置定期執(zhí)行任務(wù)的時(shí)間格式)的 CronTriggeringPolicy;基于文件大小的 SizeBasedTriggeringPolicy;基于時(shí)間的 TimeBasedTriggeringPolicy。

過(guò)渡策略包含有，默認(rèn)的過(guò)渡策略 DefaultRolloverStrategy，直接寫(xiě)入的 DirectWriteRolloverStrategy。一般情況下，采用默認(rèn)的過(guò)渡策略即可，它已經(jīng)足夠強(qiáng)大。

來(lái)看第一個(gè)基于 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>

為了驗(yàn)證文件的滾動(dòng)策略，我們調(diào)整一下 Demo 類(lèi)，讓它多打印點(diǎn)日志：

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

再次運(yùn)行 Demo 類(lèi)，可以看到根目錄下多了 3 個(gè)日志文件：

結(jié)合日志文件名，再來(lái)看 RollingFile 的配置，就很容易理解了。

1)fileName 用來(lái)指定文件名。

2)filePattern 用來(lái)指定文件名的模式，它取決于過(guò)渡策略。

由于配置文件中沒(méi)有顯式指定過(guò)渡策略，因此 RollingFile 會(huì)啟用默認(rèn)的 DefaultRolloverStrategy。

先來(lái)看一下 DefaultRolloverStrategy 的屬性：

再來(lái)看 filePattern 的值 rolling-%d{yyyy-MM-dd}-%i.log，其中 %d{yyyy-MM-dd} 很好理解，就是年月日;其中 %i 是什么意思呢?

第一個(gè)日志文件名為 rolling.log(最近的日志放在這個(gè)里面)，第二個(gè)文件名除去日期為 rolling-1.log，第二個(gè)文件名除去日期為 rolling-2.log，根據(jù)這些信息，你能猜到其中的規(guī)律嗎?

其實(shí)和 DefaultRolloverStrategy 中的 max 屬性有關(guān)，目前使用的默認(rèn)值，也就是 7，那就當(dāng) rolling-8.log 要生成的時(shí)候，刪除 rolling-1.log。可以調(diào)整 Demo 中的日志輸出量來(lái)進(jìn)行驗(yàn)證。

3)SizeBasedTriggeringPolicy，基于日志文件大小的時(shí)間策略，大小以字節(jié)為單位，后綴可以是 KB，MB 或 GB，例如 20 MB。

再來(lái)看一個(gè)日志文件壓縮的示例，來(lái)看配置：

<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>