Java日志框架梳理－SLF4J+logback

xktx
3,113 阅读4分钟

　　logback主要由三个部分组成：logback-core、logback-classic、logback-access，logback-core是其他模块的基础设施，其他模块基于它构建，logback-classic时log4j的一个改进版，它完整实现了SLF4J，logback-access主要作为一个与Servlet容器交互的模块，比如tomcat或者jetty，提供一些与HTTP访问相关的功能。

　　添加如下适配器绑定配置后会自动拉下来两个依赖库，分别是: logback-core-1.2.3和slf4j-api-1.7.25。

　　在不添加配置文件情况下测试：

public class Test {

    public static void main(String [] args) {

        Logger logger  = LoggerFactory.getLogger(Test.class);
        logger.debug( " this is {} debug log", Test.class.getName() );
        logger.error( " this is {} error log", Test.class.getName());

        //打印 Logback 内部状态
        LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
        StatusPrinter.print(lc);
    }
}

输出结果：
09:37:09.808 [main] DEBUG com.xiaofan.test.Test -  this is com.xiaofan.test.Test debug log
09:37:09.819 [main] ERROR com.xiaofan.test.Test -  this is com.xiaofan.test.Test error log
09:37:09,731 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
09:37:09,731 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
09:37:09,731 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.xml]
09:37:09,738 |-INFO in ch.qos.logback.classic.BasicConfigurator@14514713 - Setting up default configuration.

　　注意到，在不添加默认配置，也不添加配置文件的情况下，logback也可以正常在控制台输出，这等同于log4j添加了BasicConfigurator。这种情况下，打印logback内部状态，可知在没有显示指定外部配置文件的情况下，logback默认会加载logback-test.xml、logback.groovy、logback.xml 文件，如果这三个文件也找不到，则加载控制台默认配置。

自动打印警告和错误信息

　　可以不在代码中调用StatusPrinter，而是在配置文件里进行配置，方法是设置configureation元素的debug属性为true，注意debug属性只与状态数据有关，它不影响logback里的配置，更不会影响纪录级别，如下:

<configuration debug="true">
...
</configuration>

配置文件自动重新加载

　　如果配置文件设置为自动重新加载，logback-classic会扫描配置文件里的变化，并且在发生变化后进行重新配置，默认情况下，每隔一分钟扫描一次，configuration元素的scanPeriod属性可控制扫描周期，其值可带时间单位包括：milliseconds、seconds、minutes、hours。配置如下：

<configuration debug="false" scan="true" scanPeriod="20 seconds">
...
</configuration>

encoder

　　encoder负责两件事，一是把event事件转换为byte数组，而是把byte数组写入输出流。在logback0.9.19版本引入，在之前的版本中logback依赖layout元素把event事件转换字符串并输出，自0.9.19版本起，FileAppender和其子类使用encoder元素，不在接受layout元素。

　　encoder元素的class属性是必要的，标示呗实例化的encoder类的全限定名，当class属性省略时，class属性默认制定PatternLayoutEncoder，PatternLayoutEncoder扩展了LayoutWrappingEncoder，它仅使用PatternLayout。如下:

...
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>logs/log.log</file>
        <encoder>
            <pattern>
                %date %level [%thread] %logger{10}[%file:%line] %msg%n
            </pattern>
        </encoder>
    </appender>
...

　　 　　logback-classic只处理ch.qos.logback.classic.spi.ILoggingEvent 类型时间，通过继承LayoutBase可自定义layout，假设自定义Layout为MyLayout，使用方式如下：

...   
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>${logDir}/log.log</file>
        <append>true</append>
        <encoder class="h.qos.logback.core.encoder.LayoutWrappingEncoder">
            <layout class="com.xiaofan.test.MyLayout" />
        </encoder>
    </appender>
...

上下文名称和变量

　　每个logger都关联到logger上下文，logger上下文名称通过元素设置，默认值为“default”。此外，在logger上下文中，还可以通过元素设置属性，对所有记录事件可用，通过元素设置当前时间戳。使用范例如下：

...
<configuration debug="false">

    <contextName>XF-APP</contextName>
    <property name="logDir" value="logs" ></property>
    <timestamp key="bySecond" datePattern="yyyyMMdd'T'HHmmss" />

    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>${logDir}/log-${bySecond}.log</file>
        <encoder>
            <pattern>
                %contextName %date %level [%thread] %logger{10}[%file:%line] %msg%n
            </pattern>
        </encoder>
    </appender>

...

</configuration>
...

条件化处理

　　logback支持在配置文件里进行条件化处理，元素内任何地方都支持条件话处理，支持if-then-else语句。元素的condition属性是Java表达式，只能访问上下文和系统属性，对于作为参数传递的键，可通过property()或p()方法读取。

Appender

　　Appender是configuration的子节点，是负责写日志的组件。常用的Appder有三个：ConsoleAppender、FileAppende、RollingFileAppder，它们来自同一个超类OutputStreamAppender。RollingFileAppender需要搭配相应的滚动策略（rolliingPolicy）和触发策略（tripggringPolicy）使用。一个随日期滚动的配置如下：

...
    <appender name="ROL_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${logDir}/rolLog.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 按秒滚动纪录 -->
            <fileNamePattern>${logDir}/rolLog.%d{yyyy-MM-dd_HH-mm-ss}.log</fileNamePattern>
            <!-- 保留近30份滚动数据 -->
            <maxHistory>30</maxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
        </encoder>
    </appender>
...

　　以上按秒滚动纪录日志的配置，间隔调用三次测试代码，在logs文件夹下生成三个文件：

rolLog.2017-07-30_14-37-45.log
rolLog.2017-07-30_14-37-33.log  
rolLog.log

Filter

　　logback过滤器基于三值逻辑，允许把多个过滤器组装或成链，从而组成任意的复合过滤策略。这里所指的三值逻辑是指过滤器返回的枚举值只能是：ACCEPT、DENY和NEUTRAL。返回值含义如下：

枚举值 含义
ACCEPT 事件被立即处理，不再经过剩余过滤器
NEUTRAL 把权限交给有序列表中的下一个过滤器
DENY 事件被立即抛弃，不再经过剩余过滤器

　　logback-classic提供良种类型的过滤器：常规过滤器和TurboFilter过滤器。常规过滤器类型有：级别过滤器（LevelFilter）、临界值过滤器（ThresholdFilter）、求值过滤器（EvaluatorFilter）等，也可以自定义过滤器；TurboFilter跟普通Filter相似，但是有如下两点区别：1.TurboFilter会试图纪录上下文环境，因此它们不仅在指定appender时调用，也会在每次logging请求产生时调用，2.TurboFilter不需要日志事件的实例来做过滤，因此它可以在日志事件创建前调用。普通过滤器处理链示例如下：

　　自定义过滤器：

package com.xiaofan.test;

import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.filter.Filter;
import ch.qos.logback.core.spi.FilterReply;
import org.apache.commons.lang.StringUtils;

/**
 * Created by Jerry on 17/7/30.
 */
public class TestFilter extends Filter<ILoggingEvent>{

    public FilterReply decide(ILoggingEvent iLoggingEvent) {

        if(StringUtils.isNotBlank(iLoggingEvent.getMessage()) && iLoggingEvent.getMessage().contains("test")) {
            return FilterReply.NEUTRAL;
        }

        return FilterReply.DENY;
    }
}

　　logback过滤链配置：

...
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <filter class="com.xiaofan.test.TestFilter" />
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>INFO</level>
        </filter>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>NEUTRAL</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <!--EvaluatorFilter依赖于Janino library-->
        <filter class="ch.qos.logback.core.filter.EvaluatorFilter">
            <evaluator>
                <matcher>
                    <Name>odd</Name>
                    <!-- 过滤掉序号为奇数的语句-->
                    <regex>statement [13579]</regex>
                </matcher>
                <expression>odd.matches(formattedMessage)</expression>
            </evaluator>
            <OnMismatch>NEUTRAL</OnMismatch>
            <OnMatch>DENY</OnMatch>
        </filter>
        <encoder>
            <pattern>
                %d{HH:mm:ss.SSS} [%thread] %-5level %logger{35}- %msg%n
            </pattern>
        </encoder>
    </appender>
...

　　测试代码：

/**
 * Created by Jerry on 17/7/24.
 */
public class Test {

    public static void main(String [] args) {

        Logger logger  = LoggerFactory.getLogger(Test.class);
        logger.debug( " this is {} debug log", Test.class.getName() );
        logger.info( " test this is {} info log", Test.class.getName());
        logger.error( " test this is {} error log", Test.class.getName());
    }
}

结果：
12:36:26.155 [main] ERROR com.xiaofan.test.Test-  test this is com.xiaofan.test.Test error log

MDC(Mapped Diagnostic Contexts)

　　logback的设计目标之一是审查和调试复杂的分布式应用程序。在一个典型的多线程方式实现的分布式系统里，不同的线程处理不同的客户端请求，区分不同客户端请求的可行方式是为每个请求创建一个独立的logger，这种方式会导致大量新增logger且管理开销增大。为了应对这一问题，映射诊断环境（MDC）应运而生，它允许为每一个客户端请求添加一个唯一戳，把环境信息放到MDC中。

　　MDC使用也很简单，在配置文件中使用%X{key}调用即可，其中key对应为MDC中存的key值。使用范例如下：

　　配置文件：

...
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>
                thread_name:%X{thread_info}, %d{HH:mm:ss.SSS} %-5level %logger{35}- %msg%n
            </pattern>
        </encoder>
    </appender>
...

　　测试代码：

/**
 * Created by Jerry on 17/7/24.
 */
public class Test {

    public static void main(String [] args) {

        Logger logger  = LoggerFactory.getLogger(Test.class);

        MDC.put("thread_info", Thread.currentThread().getName());

        logger.error( " test this is {} error log", Test.class.getName());
    }
}

输出结果：
thread_name:main, 14:01:03.504 ERROR com.xiaofan.test.Test-  test this is com.xiaofan.test.Test error log

　　当我们在web应用中，对服务所有请求进行filter拦截，把用户信息添加到MDC中，就可以在输出的日志中清楚滴看到某个用户的操作流程。

一份完整的logback.xml配置文件

　　一份完整的logback.xml配置文件如下：

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false" scan="true" scanPeriod="20 seconds">

    <contextName>XF-APP</contextName>
    <property name="logDir" value="logs" ></property>
    <timestamp key="bySecond" datePattern="yyyyMMdd'T'HHmmss" />

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <filter class="com.xiaofan.test.TestFilter" />
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>INFO</level>
        </filter>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>NEUTRAL</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <encoder>
            <pattern>
                thread_name:%X{thread_info}, %d{HH:mm:ss.SSS} %-5level %logger{35}- %msg%n
            </pattern>
        </encoder>
    </appender>

    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>${logDir}/log-${bySecond}.log</file>
        <append>true</append>
        <encoder>
            <pattern>
                %contextName %date %level [%thread] %logger{10}[%file:%line] %msg%n
            </pattern>
        </encoder>
    </appender>

    <appender name="ROL_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${logDir}/rolLog.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 按秒滚动纪录 -->
            <fileNamePattern>${logDir}/rolLog.%d{yyyy-MM-dd_HH-mm-ss}.log</fileNamePattern>
            <!-- 保留近30份滚动数据 -->
            <maxHistory>30</maxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
        </encoder>
    </appender>

    <logger name="com.xiaofan.test" level="debug" additivity="false">
        <appender-ref ref="FILE" />
        <appender-ref ref="ROL_FILE" />
    </logger>

    <root level="debug">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

　　测试及输出：

 public class Test {

    public static void main(String [] args) {
        Logger logger  = LoggerFactory.getLogger(Test.class);
        MDC.put("thread_info", Thread.currentThread().getName());
        logger.debug( " this is {} debug log", Test.class.getName() );
        logger.info( " test this is {} info log", Test.class.getName());
        logger.error( " test this is {} error log", Test.class.getName());
    }
}

TestFilter 见上。

结果：
logs文件夹下生成如下几个日志文件：
    log-20170730T145358.log     rolLog.2017-07-30_14-53-59.log
    log-20170730T145410.log     rolLog.2017-07-30_14-54-11.log
    log-20170730T145429.log     rolLog.log

rolLog.log日志内容为：
    482  [main] DEBUG com.xiaofan.test.Test -  this is com.xiaofan.test.Test debug log
    490  [main] INFO  com.xiaofan.test.Test -  test this is com.xiaofan.test.Test info log
    492  [main] ERROR com.xiaofan.test.Test -  test this is com.xiaofan.test.Test error log

log-20170730T145358.log日志内容为：
    XF-APP 2017-07-30 14:53:58,779 DEBUG [main] c.x.t.Test[Test.java:17]  this is com.xiaofan.test.Test debug log
    XF-APP 2017-07-30 14:53:58,784 INFO [main] c.x.t.Test[Test.java:18]  test this is com.xiaofan.test.Test info log
    XF-APP 2017-07-30 14:53:58,784 ERROR [main] c.x.t.Test[Test.java:19]  test this is com.xiaofan.test.Test error log
avatar
文章
阅读
粉丝

友情链接：