日志组件logback使用详解

背景

问题定位是日常程序开发过程中不可或缺的一部分，能高效的定位程序中的问题能大大提高开发的效率。目前程序中所存在的问题大致有以下两种类型:

• 1、代码本身有问题,这类问题通常会有比较常见的错误提醒，如UnsupportedOperationException不支持的操作,IllegalArgumentException非法参数,IndexOutOfBoundsException索引出界及NullPointerException空指针异常。通常这类错误都能快速的定位,当然如果遇到比较自己觉得比较生僻的异常,万能的google会有你想要的答案。
•  2、代码的逻辑问题，这类问题一般是指代码的逻辑与目前的业务逻辑不匹配,并不是程序本身的错误,所以程序不会抛出任何异常及报错,定位起来异常困难。当然我们也可以利用代码工具的debug功能来跟踪代码，但是这个比较适用于本地及测试环境，对于线上问题很难用此方法。此时需要一些特定的日志来追踪。

    基于上述,开发者需要一个比较完善的日志组件来实现日志记录的功能，目前比较流行的有两个日志框架,log4j,logback 这两个组件都是对slf4j接口的实现。这两个组件都同一作者开发的,logback相对log4j而言有了相对多的改进。但是两者的用法几乎差别不大。下面是logback的优势：

• 更快的执行速度
• 充分的测试
• 可以使用使用XML配置文件或者Groovy
• 自动重新载入配置文件
• 优雅地从I/O错误中恢复
• 自动清除旧的日志归档文件
• 自动压缩归档日志文件
  

目前企业级的应用基本上都是使用logback,所以下文主要是对logbcak进行详解

一、使用logback日志框架我们需要引入如下maven依赖

        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-classic</artifactId>
            <version>1.2.3</version>
        </dependency>

        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-core</artifactId>
            <version>1.2.3</version>
        </dependency>

        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>1.7.5</version>
        </dependency>

注：由于有时候需要用到比较新的特性，所以建议最好使用比较新的jar包

二、使用详解

logback基本配置文件基本内容如下：

<?xml version="1.0" encoding="GB2312"?>
<configuration scan="true" scanPeriod="30 seconds" debug="false">

   <property name="LOG_HOME" value="/home/logs"/>

    <!-- 每日 轮转LOG配置 -->
    <appender name="DAILY" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <File>${LOG_HOME}/logback-daily.log</File>
        <encoder>
            <pattern>[%-5p]%d,[%c{0}], %m%n%rEx{3}</pattern>
            <charset>UTF-8</charset>
        </encoder>

        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_HOME}/logback-daily-%d{yyyy-MM-dd}.log.gz</fileNamePattern>
            <maxHistory>10</maxHistory>
        </rollingPolicy>
    </appender>
   
    <logger name="org.apache.ibatis" level="error" additivity="false"/>

    <root level="debug">
        <appender-ref ref="DAILY"/>
    </root>

</configuration>

其配置文件基本结构如下表示：

根节点是 configuration，可包含0个或多个 appender，0个或多个 logger，最多一个 root。

1、如果 logback 在启动时，解析配置文件时，出现了需要警告的信息或者错误信息，那 logback 会自动先打印出自身的状态信息。

如果希望正常情况下也打印出状态信息，可以在配置文件中，指定 configuration 的 debug 属性为 true。这个属性不配置默认为false

2、logback配置可实现自动加载，如果我们需要使用自动加载方式,需在configuration中加入如下属性

<configuration scan="true" scanPeriod="30 seconds" > 
  ...
</configuration>

注：扫描间隔要加上单位，可用的单位是 milliseconds，seconds，minutes 和 hours。如果只指定了数字，但没有指定单位，这默认单位为 milliseconds。

3、设置变量<property>,可以通过这个标签来设置变量，这个标签有两个属性，name与value，name指变量名，value指变量值。在整个logback.xml文件中可以通过"${}"来使用变量

4、设置logger  <logger> 用来设置某一个包或者具体某个类的日志打印级别以及指定<appender>,logger具有name(用来指定受此loger约束的某一个包或者具体的某一个类)属性，一个可选的level(用来设置打印级别，大小写无关：TRACE, DEBUG, INFO, WARN, ERROR, ALL 和OFF,如果未设置此属性，那么当前loger将会继承上级的级别。)和一个可选的addtivity(是否向上级loger传递打印信息。默认是true。)属性。

5、日志打印级别

TRACE < DEBUG < INFO <  WARN < ERROR
如果一个 logger 允许打印一条具有某个日志级别的信息，那么它也必须允许打印具有比这个日志级别更高级别的信息，而不允许打印具有比这个日志级别更低级别的信息。

6、appender详解

<appender>是<configuration>的子节点，是负责写日志的组件,<appender>有两个必要属性name和class。name指定appender名称，class指定appender的全限定名。

a、ConsoleAppender:把日志添加到控制台，有以下节点 <encoder>:对日志进行格式化，target 字符串，System.out,System.err默认为System.out

配置如：

<configuration>  
  
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">  
    <encoder>  
      <pattern>%-4relative [%thread] %-5level %logger{35} - %msg %n</pattern>  
    </encoder>  
  </appender>  
  
  <root level="DEBUG">  
    <appender-ref ref="STDOUT" />  
  </root>  
</configuration>  

b、FileAppender 把日志添加到文件，有以下子节点，

• <file>：被写入的文件名，可以是相对目录，也可以是绝对目录，如果上级目录不存在会自动创建，没有默认值。
• <append>：如果是 true，日志被追加到文件结尾，如果是 false，清空现存文件，默认是true。
• <encoder>：对记录事件进行格式化。（具体参数稍后讲解 ）
• <prudent>：如果是 true，日志会被安全的写入文件，即使其他的FileAppender也在向此文件做写入操作，效率低，默认是 false。

配置如：

<configuration>  
  
  <appender name="FILE" class="ch.qos.logback.core.FileAppender">  
    <file>testFile.log</file>  
    <append>true</append>  
    <encoder>  
      <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>  
    </encoder>  
  </appender>  
          
  <root level="DEBUG">  
    <appender-ref ref="FILE" />  
  </root>  
</configuration> 

c、RollingFileAppender滚动记录文件，先将日志记录到指定文件，当符合某个条件时，将日志记录到其他文件。有以下子节点：

• <file>：被写入的文件名，可以是相对目录，也可以是绝对目录，如果上级目录不存在会自动创建，没有默认值。
• <append>：如果是 true，日志被追加到文件结尾，如果是 false，清空现存文件，默认是true。
• <encoder>：对记录事件进行格式化。（具体参数稍后讲解 ）
• <rollingPolicy>:当发生滚动时，决定 RollingFileAppender 的行为，涉及文件移动和重命名。
• <triggeringPolicy >: 告知 RollingFileAppender 合适激活滚动。
• <prudent>：当为true时，不支持FixedWindowRollingPolicy。支持TimeBasedRollingPolicy，但是有两个限制，1不支持也不允许文件压缩，2不能设置file属性，必须留空。

 主要有以下rollingPolicy:

    TimeBasedRollingPolicy： 最常用的滚动策略，它根据时间来制定滚动策略，既负责滚动也负责出发滚动。有以下子节点：

• <fileNamePattern>:必要节点，包含文件名及“%d”转换符， “%d”可以包含一个 java.text.SimpleDateFormat指定的时间格式，如：%d{yyyy-MM}。如果直接使用 %d，默认格式是 yyyy-MM-dd。 RollingFileAppender 的file字节点可有可无，通过设置file，可以为活动文件和归档文件指定不同位置，当前日志总是记录到file指定的文件（活动文件），活动文件的名字不会改变；如果没设置file，活动文件的名字会根据fileNamePattern 的值，每隔一段时间改变一次。“/”或者“\”会被当做目录分隔符。
• <maxHistory>:可选节点，控制保留的归档文件的最大数量，超出数量就删除旧文件。假设设置每个月滚动，且 <maxHistory>是6，则只保存最近6个月的文件，删除之前的旧文件。注意，删除旧文件是，那些为了归档而创建的目录也会被删除。

     FixedWindowRollingPolicy： 根据固定窗口算法重命名文件的滚动策略。有以下子节点：

• <minIndex>:窗口索引最小值
• <maxIndex>:窗口索引最大值，当用户指定的窗口过大时，会自动将窗口设置为12。
• <fileNamePattern >:必须包含“%i”例如，假设最小值和最大值分别为1和2，命名模式为 mylog%i.log,会产生归档文件mylog1.log和mylog2.log。还可以指定文件压缩选项，例如，mylog%i.log.gz 或者 没有log%i.log.zip

配置如：

<configuration>   
  <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">   
      
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">   
      <fileNamePattern>logFile.%d{yyyy-MM-dd}.log</fileNamePattern>   
      <maxHistory>30</maxHistory>    
    </rollingPolicy>   
   
    <encoder>   
      <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>   
    </encoder>   
  </appender>    
   
  <root level="DEBUG">   
    <appender-ref ref="FILE" />   
  </root>   
</configuration> 

7、encoder :主要执行两个功能，将一个event事件转换成一组byte数组，将转换后的字节数据输出到文件中。encoder下面有pattern这个子节点，这个子节点主要用于定义日志输出的格式,日志格式说明如下：

• %p 输出优先级，即DEBUG，INFO，WARN，ERROR，FATAL
• %r 输出自应用启动到输出该log信息耗费的毫秒数
• %c 输出所属的类目，通常就是所在类的全名
• %t 输出产生该日志事件的线程名
• %n 输出一个回车换行符，Windows平台为“\r\n”，Unix平台为“\n”
• %d 输出日志时间点的日期或时间，默认格式为ISO8601，也可以在其后指定格式，比如：%d{yyy MMM dd HH:mm:ss,SSS}，
• 输出类似：2002年10月18日 22：10：28，921
• %l 输出日志事件的发生位置，包括类目名、发生的线程，以及在代码中的行数。举例：Testlog4.main(TestLog4.java:10)

更多详细可以参考：https://logback.qos.ch/manual/encoders.html

三、使用过程中相关问题

1、%l 输出日志事件的发生位置,这个配置一定要慎用，%l是需要遍历调用栈，性能消耗比较大。在线上环境中，如果日志量比较大时很容易影响业务线程

2、对于并发量比较高或日志量比较大的服务，如果发现服务load比较高时，可以通过jvm的jstack打印出具体的调用栈信息，如果发现如下问题

 则表示日志输出线程已经被阻塞了，这时会影响主要的业务线程，这时我们可以使用logback的一个比较高级的属性，异步日志输出，异步日志输出配置样例如下：（注：这种可能会导致日志丢失,需要自己评估,该功能需要高版本才能支持如 1.0.11)

<?xml version="1.0" encoding="GB2312"?>
<configuration scan="true" scanPeriod="30 seconds">
    
    <property name="LOG_HOME" value="/home/logs">
  
    <appender name="RELAY_DAILY" class="ch.qos.logback.core.rolling.RollingFileAppender">
      
        <layout class="ch.qos.logback.classic.PatternLayout">
            <charset>UTF-8</charset>
            <pattern>[%-5p]%d,[%c{0}], %m%n%rEx{4}</pattern>
        </layout>
      
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_HOME}/wzpm/wzpm-daily-%d{yyyy-MM-dd}.log.gz</fileNamePattern>
            <maxHistory>20</maxHistory>
        </rollingPolicy>
    </appender>

    <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
        <!-- 更改默认的队列的深度,该值会影响性能.默认值为256 -->
        <queueSize>256</queueSize>
        <!-- 添加附加的appender,最多只能添加一个 -->
        <appender-ref ref="RELAY_DAILY"/>
    </appender>

    <root level="INFO">
        <appender-ref ref="ASYNC"/>
    </root>

</configuration>

AsyncAppender主要有以下属性:

属性名	类型	描述
queueSize	int	BlockingQueue的最大容量，默认情况下，大小为256。
discardingThreshold	int	默认情况下，当BlockingQueue还有20%容量，他将丢弃TRACE、DEBUG和INFO级别的event，只保留WARN和ERROR级别的event。为了保持所有的events，设置该值为0。
includeCallerData	boolean	提取调用者数据的代价是相当昂贵的。为了提升性能，默认情况下，当event被加入到queue时，event关联的调用者数据不会被提取。默认情况下，只有"cheap"的数据，如线程名。

异步日志的工作原理可以参看：http://blog.csdn.net/chenjie2000/article/details/8902727