Java日志框架梳理-SLF4J+logback

阅读 1357
收藏 36
2017-08-03
原文链接:blog.csdn.net

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