天天看點
傳回

Log4j1更新Log4j2實戰1、背景2、log4j2說明3、更新方式4、參考資料

這是在公司内部的一次更新實踐，删除了很多隐私的内容，是以可能不是很完整。

1、背景

在任何系統中，日志都是非常重要的組成部分，它是反映系統運作情況的重要依據，也是排查問題時的必要線索。絕大多數人都認可日志的重要性，但是又有多少人仔細想過該怎麼打日志，日志對性能的影響究竟有多大呢？

新的Log4j 2.0版本有了大幅的性能提升、新的插件系統，以及配置設定方面的很多改善。Log4j 1.x 在高并發情況下出現死鎖導緻cpu使用率異常飙升，而Log4j2.0基于LMAX Disruptor的異步日志在多線程環境下性能會遠遠優于Log4j 1.x和logback ——官方測試結果。

本次更新是以thrift服務化項目為例子進行的，後續會在其他項目中進行，本次工作内容為：Log4j1.x 更新到 Log4j2（如果不想了解原理，可以直接跳到：3、更新方式）

2、log4j2說明

2.1 特性

  • API分離: Log4j2将API與實作分離開來(log4j-api： 作為日志接口層，用于統一底層日志系統,log4j-core : 作為上述日志接口的實作，是一個實際的日志架構)
  • 改進的特定: Log4j2的性能在某些關鍵領域比Log4j 1.x更快，而且大多數情況下與Logback相當。
  • 多個API支援：Log4j2提供最棒的性能的同時，還支援SLF4J和公共日志記錄API。
  • 自動配置加載：像Logback一樣，一旦配置發生改變，Log4j2可以自動載入這些更改後的配置資訊，又與Logback不同，配置發生改變時不會丢失任何日志事件。
  • 進階過濾功能：與Logback類似，Log4j2可以支援基于上下文資料、标記，正規表達式以及日志事件中的其他元件的過濾。
  • 插件架構：所有可以配置的元件都以Log4j插件的形式來定義。無需修改任何Log4j代碼就可以建立新的Appender、Layout、Pattern Convert 等等。Log4j自動識别預定義的插件，如果在配置中引用到這些插件，Log4j就自動載入使用。
  • 屬性支援：屬性可以在配置檔案中引用，也可以直接替代或傳入潛在的元件，屬性在這些元件中能夠動态解析。屬性可以是配置檔案，系統屬性，環境變量，線程上下文映射以及事件中的資料中定義的值。使用者可以通過增加自己的Lookup插件來定制自己的屬性。
  • log4j2配置: 不支援properties檔案,但卻可以以json檔案作為配置

2.2 性能

吞吐量測試

Log4j1更新Log4j2實戰1、背景2、log4j2說明3、更新方式4、參考資料

image.png

平均耗時

Log4j1更新Log4j2實戰1、背景2、log4j2說明3、更新方式4、參考資料

image.png

其中：

Loggers mixed sync/async: 同步與異步logger可以混合使用，分别由标簽<logger> <asyncLogger> 指定

異步Logger與異步Appender差別：AsyncAppender使用ArrayBlockingQueue來處理message，AsyncLogger使用LMAX Disruptor

  • AsyncAppender的做法是：應用線程建立LogEvent将其塞入Queue，消費線程取出LogEvent寫磁盤。在這種架構的可擴充性不好，當加倍消費線程時各個線程的吞吐量會減半，是以總吞吐量并不會得到增加。原因是，并發queue是标準java庫的一部分，會使用鎖來保證資料傳遞的正确性。
  • LMAX Disruptor是一個無鎖資料結構，可以線上程間傳遞消息。詳細介紹可通路其網站：https://github.com/LMAX-Exchange/disruptor/wiki/Introduction

更多性能測試資訊可參考官方報告：

http://logging.apache.org/log4j/2.x/manual/async.html#Performance

http://logging.apache.org/log4j/2.x/performance.html

2.3 主要元件

Log4j1更新Log4j2實戰1、背景2、log4j2說明3、更新方式4、參考資料

image.png

2.4 配置

Configuration

示例：

<?xml version="1.0" encoding="UTF-8"?>
<Configuration>

    <Properties>
        <Property name="pattern_layout">%d %-5p (%F:%L) - %m%n</Property>
        <Property name="LOG_HOME">/var/***/logs</Property>
    </Properties>

    <Appenders>
        <Console name="console" target="SYSTEM_OUT" follow="true">
            <PatternLayout pattern="${pattern_layout}"/>
        </Console>

        <RollingRandomAccessFile name="file"
                                 fileName="${LOG_HOME}/${sys:app.key}.log"
                                 filePattern="${LOG_HOME}/${sys:app.key}.log.%d{yyyy-MM-dd}">
            <PatternLayout pattern="${pattern_layout}"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
            </Policies>
        </RollingRandomAccessFile>

        <RollingRandomAccessFile name="access_kpi"
                                 fileName="${LOG_HOME}/${sys:app.key}_access_kpi.log"
                                 filePattern="${LOG_HOME}/${sys:app.key}_access_kpi.log.%d{yyyy-MM-dd}">
            <PatternLayout pattern="${pattern_layout}"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
            </Policies>
        </RollingRandomAccessFile>


        <RollingRandomAccessFile name="jmonitorappender"
                                 fileName="${LOG_HOME}/${sys:app.key}.jmonitor.log"
                                 filePattern="${LOG_HOME}/${sys:app.key}.jmonitor.%d{yyyy-MM-dd}.log.gz">
            <PatternLayout pattern="${pattern_layout}"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
            </Policies>
        </RollingRandomAccessFile>

        <RollingRandomAccessFile name="jmonitorlogstoreappender"
                                 fileName="${LOG_HOME}/${sys:app.key}.jmonitor.logstore.log"
                                 filePattern="${LOG_HOME}/${sys:app.key}.jmonitor.logstore.%d{yyyy-MM-dd}.log.gz">
            <PatternLayout pattern="${pattern_layout}"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
            </Policies>
        </RollingRandomAccessFile>

        <Scribe name="errorLog">
            <ThresholdFilter level="error" onMatch="ACCEPT" onMismatch="DENY"/>
            <Property name="hostname">${sys:app.key}</Property>
            <Property name="scribeHost">127.0.0.1</Property>
            <Property name="scribePort">4252</Property>
            <Property name="scribeCategory">cos_errorlog</Property>
            <Property name="printExceptionStack">false</Property>
            <Property name="addStackTraceToMessage">false</Property>
            <Property name="timeToWaitBeforeRetry">6000</Property>
            <Property name="sizeOfInMemoryStoreForward">100</Property>
            <PatternLayout
                    pattern="%d %p $${sys:app.host} $${sys:app.ip} errorlog appkey=$${sys:app.key} location=%F:%L rawlog=%replace{%replace{%m}{=}{:}}{\n|\t}{<br/>} rawexception=%replace{%replace{%ex}{=}{:}}{\n|\t}{<br/>}%n"/>
        </Scribe>


    </Appenders>

    <Loggers>
       

        <Logger name="access_kpi" level="INFO" includeLocation="true" additivity="false">
            <AppenderRef ref="access_kpi"/>
        </Logger>

      

        <!-- tair Loggers -->
        <Logger name="com.taobao.tair3.client"  level="WARN" includeLocation="true" additivity="false">
            <AppenderRef ref="file"/>
            <AppenderRef ref="errorLog"/>
        </Logger>

        <!-- 3rdparty Loggers -->
        <Logger name="org.springframework" level="WARN"/>
        <Logger name="org.apache.zookeeper" level="ERROR"/>
        <Logger name="org.springframework.web" level="WARN"/>

        <!-- Root Logger -->
        <Root level="INFO" includeLocation="true">
            <AppenderRef ref="file"/>
            <AppenderRef ref="console"/>
            <AppenderRef ref="errorLog"/>
        </Root>
    </Loggers>
</Configuration>

複制

我們先看看Configuration的一些特性：
  • Configuration代表Log4j2的配置檔案，它和LoggerContext元件一一對應（關于LoggerContext請看下文），它維護Log4j2各個元件之間的關系，其中，一個Configuration對應多個LoggerConfig元件。
  • Configuration可以通過四種方式配置：a）配置檔案（XML、JSON和YAML）；b）建立ConfigurationFactory和Configuration實作；c）通過代碼調用Configuration的API構造；d）在Logger内部調用API函數構造。
  • Configuration能夠在應用程式初始化的過程中進行自動裝配，其配置内容按照一定的順序擷取，詳見：AutomaticConfiguration。
  • 當我們給Configuration設定monitorInterval時，這可以使得log4j2階段性的讀取配置檔案，并重新構造Configuration。在這一過程中，log4j2不會丢失日志事件。

Configuration标簽 

<Configuration status="WARN">
  ...
</Configuration>

複制

該片段表明log4j2配置檔案的所有内容都在這個标簽内，其status屬性為“WARN”說明：log4j2内部的日志會将日志級别大于WARN的日志列印到Console。除了該字段，Configuration還包括其他屬性，詳見：ConfigurationSyntax。

Appenders标簽 

<Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
    </Console>
</Appenders>

複制

所有的Appender将在<Appenders>和</Appenders>之間定義。上述例子定義了ConsoleAppender并關聯PatternLayout，關于Appender和Layout請看上述相關小節。

Logger标簽 

<Loggers>
    <Logger name="com.foo.Bar" level="trace" additivity="false" includeLocation="true">
      <AppenderRef ref="Console"/>
    </Logger>
    <Root level="error">
      <AppenderRef ref="Console"/>
    </Root>
</Loggers>

複制

所有的Logger将在<Loggers>和</Loggers>之間定義。上述例子通過<Root>定義了所有Logger的根結點(RootLogger)，并通過<AppenderRef>标簽關聯名稱為“Console”的Appender，關于Logger請看上述相關小節。

此處有必要說明additivity字段，通過配置該字段，我們可以規定是否将日志事件傳遞到Logger的父結點處理，其預設值為true（即預設交給parent Logger處理）。

Logger預設不會擷取location資訊，是以，若我們的Layout或Filter等需要location資訊，我們必須給相應的設定“includeLocation=true”

Filters标簽 

<Filters>
    <Marker marker="EVENT" onMatch="ACCEPT" onMismatch="NEUTRAL"/>
    <DynamicThresholdFilter key="loginId" defaultThreshold="ERROR" onMatch="ACCEPT" onMismatch="NEUTRAL">
      <KeyValuePair key="User1" value="DEBUG"/>
    </DynamicThresholdFilter>
</Filters>

複制

log4j2還有一個很重要的元件——Filter，詳見Filter小節。此處通過<Filters>和</Filters>表明這是一個組合Filter，裡邊包括MarkerFilter和DynamicThresholdFilter。onMatch表示和onMismatch表示經過Filter過濾後的結果，該結果有三個取值：ACCEPT、NEUTRAL和DENY。log4j2在處理LogEvents時，會通過該Filter進行過濾，若傳回結果為ACCEPT，則直接處理（略過其它Filter和日志級别的過濾）；若傳回DENY則直接終止該LogEvents；若傳回NEUTRAL，則不做決策，讓後續代碼做處理。

此處，Filter是通過Configuration的直接子元素配置，是以，LogEvents若被該Filter過濾之後則不會傳遞給Logger處理。

2.5 異步日志

Log4j2提供了異步Logger，通過不同線程實作I/O操作，目的在于為我們的應用程式提高性能。我們先來看一看它主要在哪些方面做改進：

  1. Asynchronous Loggers。異步日志器是Log4j2新增的日志器，它的目的是讓我們的應用程式在調用Logger.log()列印日志時立馬傳回。我們可以在程式中全部使用異步日志器，也可以使用混合的日志器，前者能給我們的程式帶來很大的性能提升，而後者讓我們的程式足夠靈活。
  2. LMAX Disruptor技術。異步日志器在其内部實作采用了Disruptor技術，相對于使用BlockingQueue，它提高了吞吐量和降低延時。
  3. Asynchronous Appender。該元件在Log4j1.x已經存在，但是Log4j2實作的異步Appender使得每次寫入磁盤時，都會進行flush操作，效果和配置“immediateFlush=true”一樣。該異步Appender内部采用ArrayBlockingQueue的方式，是以不需要引入disruptor依賴。
  4. RandomAccessFileAppender。該Appender采用ByteBuffer+RandomAccessFile替代了BufferedOutputStream，官方給出的測試資料是它将速度提升了20-200%。

AsyncLoggers雖然帶來了極大的性能提升，我們應該經常使用。不過，它也有一些缺點，是以，我們要根據具體的應用場景決定使用同步還是異步的方式，詳見：Trade-offs。

3、更新方式

以下開始說明***服務化項目如何由：Log4j1.x 更新到 Log4j2

3.1 排除對log4j的依賴

需要确定項目pom檔案中依賴的其他的jar中也不再依賴log4j及slf4j-log4j12，具體方式可以通過IDE提供的功能或者直接使用mvn dependency:tree确定依賴關系。

由于引用的jar中很多依然使用的為log4j，是以已經更新過log4j2的項目，每次在新增依賴的時候，一定需要确定一下，引用的jar是否含有對低版本的依賴，并且exclusion掉。 
<exclusions>
    <exclusion>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-log4j12</artifactId>
    </exclusion>
    <exclusion>
        <groupId>log4j</groupId>
        <artifactId>log4j</artifactId>
    </exclusion>
</exclusions>

複制

3.2 添加對log4j2的依賴 

<properties>
    <org.slf4j-version>1.7.12</org.slf4j-version>
    <log4j2-version>2.3</log4j2-version>
</properties>
 
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>jcl-over-slf4j</artifactId>
    <version>${org.slf4j-version}</version>
    <scope>runtime</scope>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-1.2-api</artifactId>
    <version>${log4j2-version}</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-slf4j-impl</artifactId>
    <version>${log4j2-version}</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-api</artifactId>
    <version>${log4j2-version}</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
    <version>${log4j2-version}</version>
</dependency>
<dependency>
    <groupId>com.lmax</groupId>
    <artifactId>disruptor</artifactId>
    <version>3.2.0</version>
</dependency>
<dependency>
    <groupId>com.sankuai.meituan</groupId>
    <artifactId>scribe-log4j2</artifactId>
    <version>1.0.9</version>
</dependency>

複制

3.3 JVM參數

在JVM啟動參數中增加 -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector 開啟異步日志。（目前針對scribe的appender為同步appender，如果不開啟異步機制會導緻線程block）

3.4 XML配置

删除原log4j.xml配置檔案，新增log4j2.xml，注意：需要保證log4j2.xml在resource根目錄内，否則會導緻配置檔案加載不到（即log4j2.xml需要在class根目錄内）

注意事項

  1. includeLocation:Logger預設不會擷取location資訊，是以，若我們的Layout或Filter等需要location資訊，我們必須給相應的設定“includeLocation=true”
  2. additivity:通過配置該字段，我們可以規定是否将日志事件傳遞到Logger的父結點處理，其預設值為true
  3. file檔案的路徑，由于啟動腳本及伺服器變量配置等的不确定性，是以該處建議直接配置絕對路徑，可以使用<Property name="LOG_HOME">/var/***/logs</Property>配置在xml中，也可以通過JVM參數 -Dapp.logdir=$LOG_HOME等方式
  4. AsyncLogger為異步日志，需要添加JVM參數-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
  5. 服務化項目啟動腳本裡如果對啟動日志做重定向了“>> $LOGDIR/$LOGFILE 2>&1”，請不要使用Console輸出日志，否則會導緻重定向的日志檔案将重複列印所有日志資訊
  6. 服務化項目不需要配置access_kpi的日志列印
  7. Scribe說明（線上異常監控接入說明#線上異常監控接入說明-log4j2.0）
    • hostname：這裡擷取的是java啟動時配置的系統參數
    • scribeCategory：這裡寫死“cos_errorlog”，這樣資料組才知道這套日志需要發送給sg-errlog系統
    • pattern：按照資料組的要求列印日志，同時将“等号”和“回車”等替換為對應的占位符
    • scribeHost:scribeHost:測試環境為10.4.232.70,如果伺服器上有采集器監聽,則可以配置127.0.0.1

3.5 Log定義 

private static final Logger LOGGER = LoggerFactory.getLogger(Boot.class);

複制

使用slf4j進行log的定義，注意需要保證項目中不再依賴于slf4j1。如果啟動時有如下提示，說明依然依賴了多個slf4j

Log4j1更新Log4j2實戰1、背景2、log4j2說明3、更新方式4、參考資料

image.png

4、參考資料 

http://logging.apache.org/log4j/2.x/manual/migration.html#Configuring_Log4j_2
http://logging.apache.org/log4j/2.x/guidelines.html
http://logging.apache.org/log4j/2.x/performance.html
http://www.infoq.com/cn/articles/things-of-java-log-performance
http://www.infoq.com/cn/news/2014/08/apache-log4j2

複制

上一篇: 觸屏事件傳遞機制disPatchTouchEvent onInterceptTouchEvent onTouchEvent
下一篇: 幾種優化算法入門 目錄