Spring Boot 应用系列 5 -- Spring Boot 2 整合logback

Posted 2021-01-06 光焱

上一篇我们梳理了Spring Boot 2 整合log4j2的配置过程，其中讲到了Spring Boot 2原装适配logback，并且在非异步环境下logback和log4j2的性能差别不大，所以对于那些日志量不算太高的项目来说，选择logback更简单方便。

1. pom.xml

pom.xml不需要添加任何依赖。

2. logback的配置文件

系统启动时，logback按照下列顺序加载第一个找到的配置文件：

(1) classpath: logback-test.xml

(2) classpath: logback.groovy

(3) classpath: logback.xml

(4) 查询com.qos.logback.classic.spi.Configurator接口的实现

(5) 如果以上均未找到，则加载默认配置。

但是与Spring Boot集成时，上面的配置文件加载较早，Spring Boot为logback提供了很多扩展(比如<springProfile>节点)，这些扩展的加载要晚于上面的配置文件，所以Spring Boot建议使用logback-spring.xml作为配置文件。

3. 配置目标

类似上一篇整合log4j2时的情况，我们希望达成以下目标：

(1) 所有级别的日志均可以通过控制台打印；

(2) 日志的存储目录格式为“/yyyy-MM/dd/”(“年-月/日/”)，日志文件名称包含小时；

(3) error级别的日志存储在“/yyyy-MM/dd/app-error-{HH}.log”中，其中HH是日志发生的小时；

(4) 其他级别的日志存储在“/yyyy-MM/dd/app-other-{HH}.log”中；

(5) 所有级别的日志同时以html格式存储备份；

(6) 所有日志文件按照小时归档，一个小时一套文件(三个具体文件error，other)；

(7) 设置日志文件的size上限，如果某一小时出现的日志特别多，超过size limit之后自动生成带数字后缀的文件。

4. logback-spring.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true">
    <property name="Log_Home" value="logs" />
    <property name="Log_Pattern" value="[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%thread] %-5level %logger - %msg%n" />

    <appender name="Console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <Pattern>${Log_Pattern}</Pattern>
            <charset>UTF-8</charset>
        </encoder>
    </appender>

    <appender name="RollingFile_Error" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <prudent>true</prudent>
        <encoder>
            <pattern>${Log_Pattern}</pattern>
            <charset>UTF-8</charset>
        </encoder>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <FileNamePattern>${Log_Home}/%d{yyyy-MM}/%d{dd}/app-error-%d{HH-mm}.%i.log</FileNamePattern>
            <maxFileSize>10MB</maxFileSize>
            <maxHistory>10080</maxHistory>
        </rollingPolicy>
    </appender>

    <appender name="RollingFile_Other" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <prudent>true</prudent>
        <encoder>
            <pattern>${Log_Pattern}</pattern>
            <charset>UTF-8</charset>
        </encoder>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>DENY</onMatch>
            <onMismatch>NEUTRAL</onMismatch>
        </filter>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <FileNamePattern>${Log_Home}/%d{yyyy-MM}/%d{dd}/app-other-%d{HH-mm}.%i.log</FileNamePattern>
            <maxFileSize>10MB</maxFileSize>
            <maxHistory>10080</maxHistory>
        </rollingPolicy>
    </appender>

    <appender name="RollingFile_HTML" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <prudent>true</prudent>
        <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
            <layout class="ch.qos.logback.classic.html.HTMLLayout">
                <pattern>%relative%thread%mdc%level%logger%msg</pattern>
            </layout>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <FileNamePattern>${Log_Home}/%d{yyyy-MM}/%d{dd}/app-%d{HH-mm}.%i.html</FileNamePattern>
            <maxFileSize>10MB</maxFileSize>
            <maxHistory>10080</maxHistory>
        </rollingPolicy>
    </appender>

    <root level="info">
        <appender-ref ref="Console" />
        <appender-ref ref="RollingFile_Error" />
        <appender-ref ref="RollingFile_Other" />
        <appender-ref ref="RollingFile_HTML" />
    </root>
</configuration>

(1) logback的日志等级跟slf4j保持一致包括TRACE, DEBUG, INFO, WARN 和 ERROR；

(2) <configuration>节点设置debug="true"属性会在系统启动时打印logback加载的状态信息，如果logback加载过程中出现错误也会被打印出来，另外一种起同样作用的配置为在<configuration>节点中配置：

<statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener" />

(3) <property>节点属于xml级别的全局配置变量；

(4) <appender>节点中的<encoder>节点是日志事件的输出格式化配置，其中<Pattern>属性存储格式化规则，其中的符号含义分别为：

[%d{yyyy-MM-dd HH:mm:ss.SSS}]: 时间格式；

[%thread]: 输出日志的线程；

%-5level: 日志级别；

%logger: 日志调用者；

%msg: 日志内容；

%n: 换行符。

(5) <prudent>节点默认值为false，如果设置为true可确保在多线程下对同一日志文件的操作的线程安全性，但是打开之后写日志的性能会下降大约三倍。参考官网描述：

In prudent mode, FileAppender will safely write to the specified file, even in the presence of other FileAppender instances running in different JVMs, potentially running on different hosts. The default value for prudent mode is false.
Prudent mode can be used in conjunction with RollingFileAppender although some restrictions apply.

Prudent mode implies that append property is automatically set to true.

Prudent more relies on exclusive file locks. Experiments show that file locks approximately triple (x3) the cost of writing a logging event. On an "average" PC writing to a file located on a local hard disk, when prudent mode is off, it takes about 10 microseconds to write a single logging event. When prudent mode is on, it takes approximately 30 microseconds to output a single logging event. This translates to logging throughput of 100\'000 events per second when prudent mode is off and approximately 33\'000 events per second in prudent mode.

此外，prudent功能还有两个限制：

a. 日志文件不能被压缩；

b. 不能在<FileAppender>节点上设置file属性。

(6) <filter>节点用来配置过滤器，本例针对两个appender分别配置了两个<filter>，第一个filter只打印ERROR级别的日志，第二个filter只打印非ERROR级别的日志。此外logback还提供多种过滤器详见logback官网。

关于onMatch和onMismatch，请看logback源码：

1   /**
2    * Logback: the reliable, generic, fast and flexible logging framework.
3    * Copyright (C) 1999-2015, QOS.ch. All rights reserved.
4    *
5    * This program and the accompanying materials are dual-licensed under
6    * either the terms of the Eclipse Public License v1.0 as published by
7    * the Eclipse Foundation
8    *
9    *   or (per the licensee\'s choosing)
10   *
11   * under the terms of the GNU Lesser General Public License version 2.1
12   * as published by the Free Software Foundation.
13   */
14  package ch.qos.logback.core.filter;
15  
16  import ch.qos.logback.core.spi.FilterReply;
17  
18  public abstract class AbstractMatcherFilter<E> extends Filter<E> {
19  
20      protected FilterReply onMatch = FilterReply.NEUTRAL;
21      protected FilterReply onMismatch = FilterReply.NEUTRAL;
22  
23      final public void setOnMatch(FilterReply reply) {
24          this.onMatch = reply;
25      }
26  
27      final public void setOnMismatch(FilterReply reply) {
28          this.onMismatch = reply;
29      }
30  
31      final public FilterReply getOnMatch() {
32          return onMatch;
33      }
34  
35      final public FilterReply getOnMismatch() {
36          return onMismatch;
37      }
38  }

1   /**
2    * Logback: the reliable, generic, fast and flexible logging framework.
3    * Copyright (C) 1999-2015, QOS.ch. All rights reserved.
4    *
5    * This program and the accompanying materials are dual-licensed under
6    * either the terms of the Eclipse Public License v1.0 as published by
7    * the Eclipse Foundation
8    *
9    *   or (per the licensee\'s choosing)
10   *
11   * under the terms of the GNU Lesser General Public License version 2.1
12   * as published by the Free Software Foundation.
13   */
14  package ch.qos.logback.core.spi;
15  
16  /**
17   *
18   * This enum represents the possible replies that a filtering component
19   * in logback can return. It is used by implementations of both 
20   * {@link ch.qos.logback.core.filter.Filter Filter} and
21   * ch.qos.logback.classic.turbo.TurboFilter abstract classes.
22   * 
23   * Based on the order that the FilterReply values are declared,
24   * FilterReply.ACCEPT.compareTo(FilterReply.DENY) will return 
25   * a positive value.
26   *
27   * @author Sébastien Pennec
28   */
29  public enum FilterReply {
30      DENY, NEUTRAL, ACCEPT;
31  }

简单来讲onMatch和onMismatch的取值都有三个分别是DENY(拒绝)，NEUTRAL(进入下一个filter)，ACCEPT(接受，跳过所有剩下的filter)。

(7) rollingPolicy节点配置日志文件的存档策略，本例后三个appender都是每分钟(不超过10MB)存储一个文件；

注意如果存档日志文件数量超过maxHistory值，最老的日子文件会被删除。

(8) 最后说一下<encoder>里面的<layout>，它是logback中的一个组件负责将日志事件转成字符串，先看一下它的接口定义：

public interface Layout<E> extends ContextAware, LifeCycle {
  String doLayout(E event);
  String getFileHeader();
  String getPresentationHeader();
  String getFileFooter();
  String getPresentationFooter();
  String getContentType();
}

继承该接口你就可以自定义自己的layout:

package chapters.layouts;

import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.LayoutBase;
public class MySampleLayout extends LayoutBase<ILoggingEvent> {
  public String doLayout(ILoggingEvent event) {
    StringBuffer sbuf = new StringBuffer(128);
    sbuf.append(event.getTimeStamp() - event.getLoggingContextVO.getBirthTime());
    sbuf.append(" ");
    sbuf.append(event.getLevel());
    sbuf.append(" [");
    sbuf.append(event.getThreadName());
    sbuf.append("] ");
    sbuf.append(event.getLoggerName();
    sbuf.append(" - ");
    sbuf.append(event.getFormattedMessage());
    sbuf.append(CoreConstants.LINE_SEP);
    return sbuf.toString();
  }
}

然后使用你自定义的layout:

<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
      <layout class="chapters.layouts.MySampleLayout" />
    </encoder>
  </appender>
  <root level="DEBUG">
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

本例使用了logback自带的HTMLLayout。

5. logback不同环境不同配置

有两种实现方式：

(1) 按环境将配置文件拆分为logback-production.xml和logback-dev.xml等，然后在application.properties里面配置：

logging.config: classpath:logback-dev.xml

(2) 第二种是使用<springProfile>标签，在logback-spring.xml中配置：

<!-- develop -->
<springProfile name="dev">
    <root level="DEBUG">
        <appender-ref ref="CONSOLE" />
    </root>
</springProfile>
    
<!-- production -->
<springProfile name="prod">
    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root>
</springProfile>

同时也有两种方式指定使用的环境：

a. 在application.properties里配置：

spring.profiles.active: dev
spring.profiles.active: prod

b. 启动时指定：

java -jar xxx.jar --spring.profiles.active=dev

6. 应用

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public abstract class BaseController {
    protected static Logger logger = LoggerFactory.getLogger(BaseController.class);
}

import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
@RequestMapping("/log")
public class LogController extends BaseController {
    @RequestMapping("/all")
    public String all(String message) {
        logger.trace(message);
        logger.debug(message);
        logger.info(message);
        logger.warn(message);
        logger.error(message);
        System.out.println(message);

        try {
            System.out.println(3 / 0);
        } catch (Exception e) {
            logger.error(null, e);
        }

        return message;
    }
}