日志組件二：log4j2

一、背景

　　隨着業務服務（Server App）逐漸增加，我們的業務系統中的日志輸出面臨的問題越來越多，高並發下對磁盤io這塊消耗的越來越大，因此，急需要一個高性能且最好能夠支持異步輸出日志的日志框架，而且能兼容市面上目前主流的日志組件(log4j1.x,logback等)

二、簡介

　　log4j2也是一款日志組件，log4j1.x升級版本，並且log4j2和log4j是同一個作者，但是log4j2是重新架構的。在我的理解中，盡管log4j2相較於log4j有很多優點，但是我采用它放棄log4j最大的理由是：它支持異步輸出，性能秒殺一切的日志組件。

log4j2的配置文件支持xml格式

<?xml version="1.0" encoding="UTF-8"?>
<!-- status=debug 可以查看log4j的裝配過程 -->
<Configuration status="INFO">
    <properties>
        <!--變量定義 -->
        <Property name="baseDir">/data/logs/</Property>
        <property name="log_pattern">%-d{yyyy-MM-dd HH:mm:ss.SSS} [%t:%r] [%F:%L] - [%p] %m%n</property>
        <property name="file_name">info.log</property>
        <property name="error_file_name">error.log</property>
        <property name="warn_file_name">warn.log</property>
        <property name="rolling_file_name">wdmsg-%d{yyyy-MM-dd-HH}.log.%i</property>
        <!-- 日志切割的最小單位 -->
        <property name="every_file_size">100M</property> 
    </properties>

    <Appenders>
        <!--輸出控制台的配置 -->
        <Console name="console" target="SYSTEM_OUT">
            <!--控制台只輸出level及以上級別的信息（onMatch），其他的直接拒絕（onMismatch） -->
            <ThresholdFilter level="INFO" onMatch="ACCEPT" />
            <!--輸出日志的格式 -->
            <PatternLayout pattern="${log_pattern}" />
        </Console>
        
        <!-- 輸出不同級別的日志到不同的文件下 -->
        <RollingFile name="infoFile" fileName="${baseDir}${file_name}" filePattern="${baseDir}${rolling_file_name}">
            <PatternLayout pattern="${log_pattern}" />
            <Filters>
                <ThresholdFilter level="WARN" onMatch="DENY" onMismatch="NEUTRAL" />
                <ThresholdFilter level="INFO" onMatch="ACCEPT" />
            </Filters>
            <SizeBasedTriggeringPolicy size="${every_file_size}" />
        </RollingFile>
        <RollingFile name="warnFile" fileName="${baseDir}${warn_file_name}" filePattern="${baseDir}${rolling_file_name}">
            <PatternLayout pattern="${log_pattern}" />
            <Filters>
                <ThresholdFilter level="ERROR" onMatch="DENY" onMismatch="NEUTRAL" />
                <ThresholdFilter level="WARN" onMatch="ACCEPT" />
            </Filters>
            <SizeBasedTriggeringPolicy size="${every_file_size}" />
        </RollingFile>
        <RollingFile name="errorFile" fileName="${baseDir}${error_file_name}" filePattern="${baseDir}${rolling_file_name}">
            <PatternLayout pattern="${log_pattern}" />
            <ThresholdFilter level="ERROR" onMatch="ACCEPT" />
            <SizeBasedTriggeringPolicy size="${every_file_size}" />
        </RollingFile>
    </Appenders>
    <Loggers>
        <!--建立一個默認的root的logger，需要在root的level中指定輸出的級別， -->
        <Root level="all">
            <appender-ref ref="console" />
            <appender-ref ref="infoFile" />
            <appender-ref ref="warnFile" />
            <appender-ref ref="errorFile" />
        </Root>
    </Loggers>
</Configuration>

1、根節點Configuration：有兩個屬性status和monitorinterval

status：用來指定log4j本身的打印日志級別

monitorinterval：指定log4j自動重新配置的監測間隔時間

2、Appenders節點：有三個子節點，Console、RollingFile、File

　　Console：定義輸出到控制台的Appender

　　RollingFile：用來定義超過指定大小自動刪除舊的創建新的的Appender

　　File：輸出到指定位置的文件的Appender

3、Loggers節點：常用的兩個子節點，Root、Logger

　　Root：用來指定項目的根日志，如果沒有單獨指定Logger，那么就會默認使用該Root日志輸出

　　我自己試驗的結果如下：

2017-05-24 17:16:51,087 main WARN No Root logger was configured, creating default ERROR-level Root logger with Console appender
五月 24, 2017 5:16:51 下午 org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDefinitions
INFO: Loading XML bean definitions from class path resource [META-INF/spring/springContext.xml]
五月 24, 2017 5:16:51 下午 org.springframework.context.support.GenericApplicationContext prepareRefresh
INFO: Refreshing org.springframework.context.support.GenericApplicationContext@465e1377: startup date [Wed May 24 17:16:51 CST 2017]; root of context hierarchy
17:16:51.360 [main] ERROR com.cd.mvc.controller.TestLog4j2 - error message

　　這里最后一行是用Root格式打印的日志

　　Logger：單獨指定日志的形式，如要為jar包下的class指定不同的日志級別。

　　AppenderRef：用來指定該日志輸出到哪個Appender,如果沒有指定，就會默認繼承自Root.如果指定了，那么會在指定的這個Appender和Root的Appender中都會輸出，此時我們可以設置Logger的　　　　                              additivity="false"只在自定義的Appender中進行輸出。

4、Filters

配置文件中有這么一段，我們來詳細解讀下，這個非常重要，涉及到不同級別的日志輸出到對應的日志文件中：

 <Filters>
    <ThresholdFilter level="WARN" onMatch="DENY" onMismatch="NEUTRAL" />
    <ThresholdFilter level="INFO" onMatch="ACCEPT" />
 </Filters>

ThresholdFilter有三個參數：

　　level：將被過濾的日志級別

　　onMatch：默認值為NEUTRAL

　　onMismatch:默認是DENY

如果類中的日志是warn級別，則匹配第一個過濾器，被直接DENY（拒絕），不被記錄到文件中
如果類中的日志是info級別，則不匹配第一個過濾器，由於采用的是中立的策略，會接着走到第二個過濾器，由於匹配第二個，且被accept，則該日志記錄到info日志文件中。這樣就實現的前面提到的不同級別日志輸出到對應的日志文件中。

 三、log4j2的加載

　　Log4j可以在初始化的時候執行自動配置。當Log4j啟動的時候，首先會定位所有的ConfigurationFactory的配置，根據優先級順序進行加載；Log4j包含了四種類型的ConfigurationFactory的實現，JSON，YAML，properties，XML。log4j2查找配置文件的順序：

四、SpringMVC集成log4j2

1、pom.xml

    <!--log4j2-->
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-api</artifactId>
        <version>2.4.1</version>
    </dependency>
    
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-core</artifactId>
        <version>2.0.2</version>
    </dependency>    

跟log4j2相關的只需要這兩個jar包

a、使用默認的配置文件

1、工程目錄

這個工程中，classpath下沒有log4j2.xml的配置文件，web.xml中我也沒有做任何log4j2相關的配置，這里有意讓log4j讀取默認的配置

2、Junit測試類：

package com.cd.mvc.controller;



import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.springframework.test.context.ContextConfiguration;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;


@RunWith(SpringJUnit4ClassRunner.class)
@ContextConfiguration("classpath:META-INF/spring/springContext.xml")
public class TestLog4j2
{
    static Logger logger = LogManager.getLogger(TestLog4j2.class.getName());
    
    @Test
    public void test()
    {
        logger.info("info message");
        logger.warn("warn message");
        logger.error("error message");
    }
}

3、執行結果：

五月 24, 2017 7:11:27 下午 org.springframework.test.context.support.DefaultTestContextBootstrapper getDefaultTestExecutionListenerClassNames
INFO: Loaded default TestExecutionListener class names from location [META-INF/spring.factories]: [org.springframework.test.context.web.ServletTestExecutionListener, org.springframework.test.context.support.DependencyInjectionTestExecutionListener, org.springframework.test.context.support.DirtiesContextTestExecutionListener, org.springframework.test.context.transaction.TransactionalTestExecutionListener, org.springframework.test.context.jdbc.SqlScriptsTestExecutionListener]
五月 24, 2017 7:11:27 下午 org.springframework.test.context.support.DefaultTestContextBootstrapper instantiateListeners
INFO: Could not instantiate TestExecutionListener [org.springframework.test.context.transaction.TransactionalTestExecutionListener]. Specify custom listener classes or make the default listener classes (and their required dependencies) available. Offending class: [org/springframework/transaction/interceptor/TransactionAttributeSource]
五月 24, 2017 7:11:27 下午 org.springframework.test.context.support.DefaultTestContextBootstrapper instantiateListeners
INFO: Could not instantiate TestExecutionListener [org.springframework.test.context.jdbc.SqlScriptsTestExecutionListener]. Specify custom listener classes or make the default listener classes (and their required dependencies) available. Offending class: [org/springframework/transaction/interceptor/TransactionAttribute]
五月 24, 2017 7:11:27 下午 org.springframework.test.context.support.DefaultTestContextBootstrapper getTestExecutionListeners
INFO: Using TestExecutionListeners: [org.springframework.test.context.web.ServletTestExecutionListener@1ed73856, org.springframework.test.context.support.DependencyInjectionTestExecutionListener@43b3a5eb, org.springframework.test.context.support.DirtiesContextTestExecutionListener@47520a06]
ERROR StatusLogger No log4j2 configuration file found. Using default configuration: logging only errors to the console.
五月 24, 2017 7:11:27 下午 org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDefinitions
INFO: Loading XML bean definitions from class path resource [META-INF/spring/springContext.xml]
五月 24, 2017 7:11:27 下午 org.springframework.context.support.GenericApplicationContext prepareRefresh
INFO: Refreshing org.springframework.context.support.GenericApplicationContext@115fae6: startup date [Wed May 24 19:11:27 CST 2017]; root of context hierarchy
19:11:28.065 [main] ERROR com.cd.mvc.controller.TestLog4j2 - error message

最后一行就是采用log4j默認的配置打印出來的日志，我們來看下具體的默認配置：

<?xml version="1.0" encoding="UTF-8"?>
 <Configuration status="WARN">
     <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="error">
             <AppenderRef ref="Console" />
         </Root>
     </Loggers>
 </Configuration>

這里只配置了一個Console的Appender，級別是error，所以我們在控制台上看到了這種格式的error日志。

b、配置文件在根目錄下

1、工程目錄：

 

2、 log4j2.xml配置文件：

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="INFO">
    <properties>
        <!--變量定義 -->
        <Property name="baseDir">/data/logs/</Property>
        <property name="log_pattern">%-d{yyyy-MM-dd HH:mm:ss.SSS} [%t:%r] [%F:%L] - [%p] %m%n</property>
        <property name="file_name">info.log</property>
        <property name="error_file_name">error.log</property>
        <property name="warn_file_name">warn.log</property>
        <property name="rolling_file_name">wdmsg-%d{yyyy-MM-dd-HH}.log.%i</property>
        <!-- 日志切割的最小單位 -->
        <property name="every_file_size">100M</property> 
    </properties>

    <Appenders>
        <!--輸出控制台的配置 -->
        <Console name="console" target="SYSTEM_OUT">
            <!--控制台只輸出level及以上級別的信息（onMatch），其他的直接拒絕（onMismatch） -->
            <ThresholdFilter level="INFO" onMatch="ACCEPT" />
            <!--輸出日志的格式 -->
            <PatternLayout pattern="${log_pattern}" />
        </Console>
        
        <!-- 輸出不同級別的日志到不同的文件下 -->
        <RollingFile name="infoFile" fileName="${baseDir}${file_name}" filePattern="${baseDir}${rolling_file_name}">
            <PatternLayout pattern="${log_pattern}" />
            <Filters>
                <ThresholdFilter level="WARN" onMatch="DENY" onMismatch="NEUTRAL" />
                <ThresholdFilter level="INFO" onMatch="ACCEPT" />
            </Filters>
            <SizeBasedTriggeringPolicy size="${every_file_size}" />
        </RollingFile>
        <RollingFile name="warnFile" fileName="${baseDir}${warn_file_name}" filePattern="${baseDir}${rolling_file_name}">
            <PatternLayout pattern="${log_pattern}" />
            <Filters>
                <ThresholdFilter level="ERROR" onMatch="DENY" onMismatch="NEUTRAL" />
                <ThresholdFilter level="WARN" onMatch="ACCEPT" />
            </Filters>
            <SizeBasedTriggeringPolicy size="${every_file_size}" />
        </RollingFile>
        <RollingFile name="errorFile" fileName="${baseDir}${error_file_name}" filePattern="${baseDir}${rolling_file_name}">
            <PatternLayout pattern="${log_pattern}" />
            <ThresholdFilter level="ERROR" onMatch="ACCEPT" />
            <SizeBasedTriggeringPolicy size="${every_file_size}" />
        </RollingFile>
    </Appenders>
    <Loggers>
        <!--建立一個默認的root的logger，需要在root的level中指定輸出的級別， -->
        <Root level="all">
            <appender-ref ref="console" />
            <appender-ref ref="infoFile" />
            <appender-ref ref="warnFile" />
            <appender-ref ref="errorFile" />
        </Root>
    </Loggers>
</Configuration>

3、測試類與上個例子一樣，測試結果如下：

五月 24, 2017 7:47:42 下午 org.springframework.test.context.support.DefaultTestContextBootstrapper getDefaultTestExecutionListenerClassNames
INFO: Loaded default TestExecutionListener class names from location [META-INF/spring.factories]: [org.springframework.test.context.web.ServletTestExecutionListener, org.springframework.test.context.support.DependencyInjectionTestExecutionListener, org.springframework.test.context.support.DirtiesContextTestExecutionListener, org.springframework.test.context.transaction.TransactionalTestExecutionListener, org.springframework.test.context.jdbc.SqlScriptsTestExecutionListener]
五月 24, 2017 7:47:42 下午 org.springframework.test.context.support.DefaultTestContextBootstrapper instantiateListeners
INFO: Could not instantiate TestExecutionListener [org.springframework.test.context.jdbc.SqlScriptsTestExecutionListener]. Specify custom listener classes or make the default listener classes (and their required dependencies) available. Offending class: [org/springframework/transaction/interceptor/TransactionAttribute]
五月 24, 2017 7:47:42 下午 org.springframework.test.context.support.DefaultTestContextBootstrapper instantiateListeners
INFO: Could not instantiate TestExecutionListener [org.springframework.test.context.transaction.TransactionalTestExecutionListener]. Specify custom listener classes or make the default listener classes (and their required dependencies) available. Offending class: [org/springframework/transaction/interceptor/TransactionAttributeSource]
五月 24, 2017 7:47:42 下午 org.springframework.test.context.support.DefaultTestContextBootstrapper getTestExecutionListeners
INFO: Using TestExecutionListeners: [org.springframework.test.context.web.ServletTestExecutionListener@4f6f76a8, org.springframework.test.context.support.DependencyInjectionTestExecutionListener@1ed73856, org.springframework.test.context.support.DirtiesContextTestExecutionListener@43b3a5eb]
五月 24, 2017 7:47:42 下午 org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDefinitions
INFO: Loading XML bean definitions from class path resource [META-INF/spring/springContext.xml]
五月 24, 2017 7:47:43 下午 org.springframework.context.support.GenericApplicationContext prepareRefresh
INFO: Refreshing org.springframework.context.support.GenericApplicationContext@1a0efbfe: startup date [Wed May 24 19:47:43 CST 2017]; root of context hierarchy
2017-05-24 19:47:43.160 [main:982] [TestLog4j2.java:22] - [INFO] info message
2017-05-24 19:47:43.161 [main:983] [TestLog4j2.java:23] - [WARN] warn message
2017-05-24 19:47:43.161 [main:983] [TestLog4j2.java:24] - [ERROR] error message
五月 24, 2017 7:47:43 下午 org.springframework.context.support.GenericApplicationContext doClose
INFO: Closing org.springframework.context.support.GenericApplicationContext@1a0efbfe: startup date [Wed May 24 19:47:43 CST 2017]; root of context hierarchy

控制台打印正常，看下日志文件，我配置的路徑是：/data/logs/

分別生成了三個文件，我們來看下具體內容：

c、自定義配置文件的路徑

1、工程目錄：

log4j2.xml不是放在根目錄下，而是放在classpath:META-INF/目錄下。

2、web.xml的配置，用於查找配置文件

3、容器啟動后並訪問含有打印日志的類，控制台消息如下：

INFO: Loading XML bean definitions from class path resource [META-INF/spring/springMVC.xml]
ERROR StatusLogger No log4j2 configuration file found. Using default configuration: logging only errors to the console.
五月 26, 2017 10:42:03 上午 org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping register
INFO: Mapped "{[/index/{id}],methods=[GET],params=[age=14]}" onto public java.lang.String com.cd.mvc.controller.DemoController.index(int,javax.servlet.ServletRequest,org.springframework.ui.Model)
五月 26, 2017 10:42:03 上午 org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter initControllerAdviceCache
INFO: Looking for @ControllerAdvice: WebApplicationContext for namespace 'spring-servlet': startup date [Fri May 26 10:42:03 CST 2017]; parent: Root WebApplicationContext
五月 26, 2017 10:42:03 上午 org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter initControllerAdviceCache
INFO: Looking for @ControllerAdvice: WebApplicationContext for namespace 'spring-servlet': startup date [Fri May 26 10:42:03 CST 2017]; parent: Root WebApplicationContext
五月 26, 2017 10:42:03 上午 org.springframework.web.servlet.handler.BeanNameUrlHandlerMapping registerHandler
INFO: Mapped URL path [/out/index] onto handler '/out/index'
五月 26, 2017 10:42:03 上午 org.springframework.web.servlet.handler.SimpleUrlHandlerMapping registerHandler
INFO: Mapped URL path [/**] onto handler 'org.springframework.web.servlet.resource.DefaultServletHttpRequestHandler#0'
五月 26, 2017 10:42:03 上午 org.springframework.web.servlet.DispatcherServlet initServletBean
INFO: FrameworkServlet 'spring': initialization completed in 730 ms
五月 26, 2017 10:42:03 上午 org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8210"]
五月 26, 2017 10:42:03 上午 org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-bio-8009"]
五月 26, 2017 10:42:03 上午 org.apache.catalina.startup.Catalina start
INFO: Server startup in 1921 ms
10:42:11.611 [http-bio-8210-exec-3] ERROR com.cd.mvc.controller.DemoController - error id =33

這個明顯不是預計的結果，這里我折騰的很久，始終沒有找到問題的原因，先在這標記求助下！！！

配置文件log4j2.xml存放的路徑不在根目錄下，但是web.xml中有對應查找文件的相關配置。可是在容器啟動過程中卻提示No log4j2 configuration file found，使用log4j2默認的配置，日志輸出見最后一行。