日志组件二：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默认的配置，日志输出见最后一行。