使用logback实现日志记录

在开发中打印内容，使用 System.out.println() 和 Log4j 应当是人人皆知的方法了。 

其实在开发中我们不建议使用 System.out 因为大量的使用 System.out 会增加资源的消耗。 

而Log4j 更为灵活在性能上也相比 System.out 要高，我们可以配置输出级别，可以指定多个日志文件分别记录不同的日志。 

使用 System.out 是在当前线程执行的，写入文件也是写入完毕后才继续执行下面的程序。而使用Log工具不但可以控制日志是否输出，怎么输出，它的处理机制也是通知写日志，继续执行后面的代码不必等日志写完。 

如非必要，建议大家不要使用控制台输出，因为控制台输出没有优先级会显得输出太乱。

个人推荐使用 SLF4J（Simple Logging Facade For Java）的logback来输出日志， Logback 是log4j框架的作者开发的新一代日志框架，它效率更高、能够适应诸多的运行环境，同时天然支持SLF4J。

本章概要

1、源码概要；

2、通过默认配置实现日志记录；

3、配置不同环境下的日志等级应用；

4、控制台日志输出；

5、文件日志输出；

6、war包部署严重；

7、不同部署环境下生成日志文件路径；

8、高级特性异步记录；

9、日志输出存储至DB（两种配置连接方式）；

先跟踪下springboot默认的配置，在sprint-boot-1.4.0.RELEASE.jar包下，如下截图，

其中，自定义的配置文件路径通过查看源码如下（在DefaultLogbackConfiguration下也有部分默认属性设置）：

下面给出实践案例:

1、采用SpringBoot默认配置：

<?xml version="1.0" encoding="UTF-8"?>

<configuration>

<include resource="org/springframework/boot/logging/logback/base.xml"/>

<logger name="org.springframework.web" level="DEBUG"/>

<logger name="com.shf.springboot" level="DEBUG"/>

</configuration>

注：红色部分为自定义的需要日志记录的包路径。

以上可以include默认的日志记录配置base.xml（源码贴出）:

<?xml version="1.0" encoding="UTF-8"?>

<!--

Base logback configuration provided for compatibility with Spring Boot 1.1

-->

<included>

<include resource="org/springframework/boot/logging/logback/defaults.xml" />

<property name="LOG_FILE" value="${LOG_FILE:-${LOG_PATH:-${LOG_TEMP:-${java.io.tmpdir:-/tmp}}}/spring.log}"/>

<include resource="org/springframework/boot/logging/logback/console-appender.xml" />

<include resource="org/springframework/boot/logging/logback/file-appender.xml" />

<root level="INFO">

<appender-ref ref="CONSOLE" />

<appender-ref ref="FILE" />

</root>

</included>

Spring Boot的日志系统预先定义了一些系统变量：

PID ，当前进程 ID {LOG_FILE}，Spring Boot配置文件（application.properties|.yml）中logging.file的值 

${LOG_PATH}, Spring Boot配置文件中logging.path的值 

同时默认情况下包含另个appender—— 一个是控制台，一个是文件 ，分别定义在console-appender.xml和file-appender.xml中。同时对于应用的日志级别也可以通过application.properties进行定义：

logging.level.org.springframework.web=DEBUGlogging.level.org.springboot.sample=TRACE

这样相当于我们在logback.xml 中配置的对应的日志级别。名称以logging.level开头，后面跟要输入日志的包名。

* 如果在 logback.xml 和 application.properties 中定义了相同的配置（如都配置了 org.springframework.web）但是输出级别不同，则实际上 application.properties 的优先级高于 logback.xml *

2、在之前的启动自执行代码中添加如下测试代码：

logger.debug(">>>>>>>>>>>>>>>服务启动执行，执行加载数据等操作<<<<<<<<<<<<<");

logger.debug(">>>>>>>>>>>>>>>111111111111111111111111111111<<<<<<<<<<<<<");

启动服务验证：

3、 之前也进行实践，在springboot中，我们可以根据不同环境来定义一些参数的设置等，那么此时我们可以设置不同的日志输出，在 logback-spring.xml 中使用 springProfile 节点来定义，方法如下： 

注意文件名称不是logback.xml，想使用spring扩展profile支持，要以logback-spring.xml命名：

3.1、首先修改启动类中日志的打印如下：

logger.debug("DEBUG>>>>>>>>>>>>>>>服务启动执行，执行加载数据等操作<<<<<<<<<<<<<");

logger.debug("DEBUG>>>>>>>>>>>>>>>111111111111111111111111111111<<<<<<<<<<<<<");

logger.info("INFO>>>>>>>>>>>>>>>服务启动执行，执行加载数据等操作<<<<<<<<<<<<<");

logger.info("INFO>>>>>>>>>>>>>>>111111111111111111111111111111<<<<<<<<<<<<<");

3.2、创建logback-spring.xml配置：

<configuration>

<include resource="org/springframework/boot/logging/logback/base.xml"/>

<logger name="org.springframework.web" level="DEBUG"/>

<logger name="com.shf.springboot" level="TRACE"/>

<springProfile name="production">

<logger name="com.shf.springboot" level="DEBUG" />

</springProfile>

<springProfile name="dev">

<logger name="com.shf.springboot" level="INFO" />

</springProfile>

</configuration>

3.3、此时我们设置的dev环境下仅打印INFO级别的日志：

3.4、我们简单的修改下配置，我们打印日志级别设置为DEBUG：

<springProfile name="production">

<logger name="com.shf.springboot" level=" INFO" />

</springProfile>

<springProfile name=" dev">

<logger name="com.shf.springboot" level=" DEBUG" />

</springProfile>

浅析：

1、根据3.3和3.4两次的实验验证说明，我们克薏发现配置的springProfile 生效，会在不同的环境下应用不同的level；

2、此时我们用到了DEBUG和INFO两个级别的设置，DEBUG级别低于INFO，故DEBUG下能够打印INFO级别信息。（ Logger可以被分配级别。级别包括：TRACE、DEBUG、INFO、WARN和ERROR，定义于ch.qos.logback.classic.Level类。程序会打印高于或等于所设置级别的日志，设置的日志等级越高，打印出来的日志就越少。如果设置级别为INFO，则优先级高于等于INFO级别（如：INFO、 WARN、ERROR）的日志信息将可以被输出,小于该级别的如DEBUG将不会被输出。为确保所有logger都能够最终继承一个级别，根logger总是有级别，默认情况下，这个级别是DEBUG。）

4、ConsoleAppender：控制台输出是最常见的日志输出方式

4.1、配置logback-spring.xml如下，删除默认配置，添加自定义配置：

<?xml version="1.0" encoding="UTF-8"?>

<configuration>

<springProfile name="production">

<logger name="com.shf.springboot" level="INFO" />

</springProfile>

<springProfile name="dev">

<!-- 日志输出的优先级在appender基础上，但对于定义的包路径其输出级次的优先级高于root -->

<logger name="com.shf.springboot.runner.MyStartupRunner1" level="DEBUG" />

</springProfile>

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">

<encoder>

<Pattern>[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%5level] [%thread] %logger{36} - %msg%n</Pattern>

<charset>UTF-8</charset>

</encoder>

<filter class="ch.qos.logback.classic.filter.ThresholdFilter">

<level>DEBUG</level> <!-- 第一级过滤打印显示级次的日志级别 -->

</filter>

</appender>

<!-- 此处对于下面映射的appender再次进行日志级别的过滤，此时过滤仅在appender基础上进行，故小于等于appender级次即可。 -->

<!-- 如果定义了<logger name="com.s***" level="DEBUG" />则对应包路径下的日志输出级别以logger为更高优先级，同时也是在appender基础上进行过滤.

非定义的包路径仍然采用此root定义的level -->

<root level="INFO">

<appender-ref ref="STDOUT"/>

</root>

</configuration>

浅析encoder：

<encoder> 表示对日志进行编码：

• %d{yyyy-MM-dd HH:mm:ss.SSS}——日志输出时间
• %thread——输出日志的进程名字，这在Web应用以及异步任务处理中很有用
• %5level——日志级别，并且使用5个字符靠右对齐
• %logger{36}——日志输出者的名字
• %msg——日志消息
• %n——平台的换行符

4.2、修改启动自执行类方法如下：；

@Component

@Order(value=1)

public class MyStartupRunner1 implements CommandLineRunner {

public static Logger logger = LoggerFactory.getLogger(MyStartupRunner1.class);

@Override

public void run(String... arg0) throws Exception {

logger. debug("DEBUG>>>>>>>>>>>>>>>服务启动执行，执行加载数据等操作<<<<<<<<<<<<<");

logger.debug("DEBUG>>>>>>>>>>>>>>>111111111111111111111111111111<<<<<<<<<<<<<");

logger. info("INFO>>>>>>>>>>>>>>>服务启动执行，执行加载数据等操作<<<<<<<<<<<<<");

logger.info("INFO>>>>>>>>>>>>>>>111111111111111111111111111111<<<<<<<<<<<<<");

}

}

@Component

@Order(value=2)

public class MyStartupRunner2 implements CommandLineRunner {

public static Logger logger = LoggerFactory.getLogger(MyStartupRunner2.class);

@Override

public void run(String... arg0) throws Exception {

logger. debug("DEBUG>>>>>>>>>>>>>>>服务启动执行，执行加载数据等操作<<<<<<<<<<<<<");

logger.debug("DEBUG>>>>>>>>>>>>>>>222222222222222222222222222222<<<<<<<<<<<<<");

logger. info("INFO>>>>>>>>>>>>>>>服务启动执行，执行加载数据等操作<<<<<<<<<<<<<");

logger.info("INFO>>>>>>>>>>>>>>>222222222222222222222222222222<<<<<<<<<<<<<");

}

}

4.3、查看控制台打印：

输出的内容对应了我们设置的pattern，并且此时系统默认的均只输出INFO级别，仅有通过logger设置的路径下debug、info均打印。

4.4、稍作修改：

<configuration>

<springProfile name="production">

<logger name="com.shf.springboot" level="INFO" />

</springProfile>

<springProfile name="dev">

<!-- 日志输出的优先级在appender基础上，但对于定义的包路径其输出级次的优先级高于root -->

<logger name="com.shf.springboot.runner.MyStartupRunner1" level=" INFO" />

</springProfile>

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">

<encoder>

<Pattern>[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%5level] [%thread] %logger{36} - %msg%n</Pattern>

<charset>UTF-8</charset>

</encoder>

<filter class="ch.qos.logback.classic.filter.ThresholdFilter">

<level> DEBUG</level><!-- 第一级过滤打印显示级次的日志级别 -->

</filter>

</appender>

<!-- 此处对于下面映射的appender再次进行日志级别的过滤，此时过滤仅在appender基础上进行，故小于等于appender级次即可。 -->

<!-- 如果定义了<logger name="com.s***" level="DEBUG" />则对应包路径下的日志输出级别以logger为更高优先级，同时也是在appender基础上进行过滤.

非定义的包路径仍然采用此root定义的level -->

<root level=" DEBUG">

<appender-ref ref="STDOUT"/>

</root>

</configuration>

输出所有的debug、info级别的日志，同时通过logger设置的路径下仅输出INFO级别。

4.5、再次修改：

<configuration>

<springProfile name="production">

<logger name="com.shf.springboot" level="INFO" />

</springProfile>

<springProfile name="dev">

<!-- 日志输出的优先级在appender基础上，但对于定义的包路径其输出级次的优先级高于root -->

<logger name="com.shf.springboot.runner.MyStartupRunner1" level=" DEBUG" />

</springProfile>

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">

<encoder>

<Pattern>[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%5level] [%thread] %logger{36} - %msg%n</Pattern>

<charset>UTF-8</charset>

</encoder>

<filter class="ch.qos.logback.classic.filter.ThresholdFilter">

<level> INFO</level><!-- 第一级过滤打印显示级次的日志级别 -->

</filter>

</appender>

<!-- 此处对于下面映射的appender再次进行日志级别的过滤，此时过滤仅在appender基础上进行，故小于等于appender级次即可。 -->

<!-- 如果定义了<logger name="com.s***" level="DEBUG" />则对应包路径下的日志输出级别以logger为更高优先级，同时也是在appender基础上进行过滤.

非定义的包路径仍然采用此root定义的level -->

<root level=" DEBUG">

<appender-ref ref="STDOUT"/>

</root>

</configuration>

此时输出的日志仅为INFO级别的。

注：通过上述的4.3、4.4、4.5不同的配置对应了不同的打印，很好的验证了配置中注释的部分，其优先级管理。此时我们还用到了过滤器ThresholdFilter，此过滤器为临界值过滤器。常用过滤器：

ThresholdFilter：   临界值过滤器，过滤掉低于指定临界值的日志 。当日志级别等于或高于临界值时，过滤器返回NEUTRAL；当日志级别低于临界值时，日志会被拒绝。

LevelFilter：   级别过滤器 ，根据日志级别进行过滤。如果日志级别等于配置级别，过滤器会根据onMath 和 onMismatch接收或拒绝日志。有以下子节点：

<level>:设置过滤级别

<onMatch>:用于配置符合过滤条件的操作

<onMismatch>:用于配置不符合过滤条件的操作

EvaluatorFilter：  求值过滤器，评估、鉴别日志是否符合指定条件。有一下子节点：

<evaluator>:

鉴别器，常用的鉴别器是JaninoEventEvaluato，也是默认的鉴别器，它以任意的java布尔值表达式作为求值条件，求值条件在配置文件解释过成功被动态编译，布尔值表达式返回true就表示符合过滤条件。evaluator有个子标签<expression>，用于配置求值条件。

<onMatch>:用于配置符合过滤条件的操作

<onMismatch>:用于配置不符合过滤条件的操作

4.6、在configuration 中除了子节点 appender、logger、root外我们还会进行如下配置：

<configuration scan ="true" scanPeriod ="60 second" debug ="false">

其中：

scan:当此属性设置为true时，配置文件如果发生改变，将会被重新加载，默认值为true

scanPeriod:设置监测配置文件是否有修改的时间间隔，如果没有给出时间单位，默认单位是毫秒。当scan为true时，此属性生效。默认的时间间隔为1分钟

debug:当此属性设置为true时，将打印出logback内部日志信息，实时查看logback运行状态。默认值为false。

5、RollingFileAppender： 常见的日志输出到文件，随着应用的运行时间越来越长，日志也会增长的越来越多，将他们输出到同一个文件并非一个好办法。RollingFileAppender用于切分文件日志：

5.1、添加配置如下：

<appender name=" dailyRollingFileAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">

<File>data/log/app.log</File>

<filter class="ch.qos.logback.classic.filter.ThresholdFilter">

<level>INFO</level>

</filter>

<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">

<FileNamePattern>log.%d{yyyy-MM-dd}.log</FileNamePattern>

<maxHistory>30</maxHistory>

</rollingPolicy>

<encoder>

<Pattern>[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%5level] [%thread] %logger{36} - %msg%n</Pattern>

<charset>UTF-8</charset>

</encoder>

</appender>

<root level="DEBUG">

<appender-ref ref="STDOUT"/>

<appender-ref ref="dailyRollingFileAppender"/><!-- 不添加则无法生成日志文件-->

</root>

注：

5.1. 1、日志文件的保存路径：data/log/app.log

5.1. 2、 rollingPolicy的定义，上例中log.%d{yyyy-MM-dd}.log定义了日志的切分方式——把每一天的日志归档到一个文件中，30表示只保留最近30天的日志，以防止日志填满整个磁盘空间。同理，可以使用%d{yyyy-MM-dd_HH-mm}来定义精确到分的日志切分方式。

5.1. 3、发出一个请求，查看日志内容：

6、采用war包进行部署测试验证：

在WINDOWS下部署应用启动服务发现会中文乱码，

正是由于WINDOWS下系统编码为GBK，故需要调整配置中控制台输出的charset为GBK，此时控制台显示即可正常。

7、Logback不建议采用相对路径配置日志文件的路径，此时我们采用的相对路径对于不同环境下其日志文件究竟在什么路径下呢：

7.1、Eclipse中：

7.2、通过jar方式启动：

7.3、通过常规容器tomcat部署启动服务：

8、异步记录日志(AsyncAppender)：在多线程场景下，会出现阻塞死锁，可以通过异步方式记录日志。AsyncAppender并不处理日志，只是将日志缓冲到一个BlockingQueue里面去，并在内部创建一个工作线程从队列头部获取日志，之后将获取的日志循环记录到附加的其他appender上去，从而达到不阻塞主线程的效果。因此AsynAppender仅仅充当事件转发器，必须引用另一个appender来做事。修改配置如下即可：

<!-- 异步输出 -->

<appender name=" ASYNC" class= "ch.qos.logback.classic.AsyncAppender">

<!-- 不丢失日志.默认的,如果队列的80%已满,则会丢弃TRACT、DEBUG、INFO级别的日志，故设置为0 -->

<discardingThreshold>0</discardingThreshold>

<!-- 更改默认的队列的深度,该值会影响性能.默认值为256 -->

<queueSize>512</queueSize>

<!-- 添加附加的appender,最多只能添加一个 -->

<appender-ref ref ="dailyRollingFileAppender"/>

</appender>

<root level="DEBUG">

<appender-ref ref=" ASYNC"/>

<appender-ref ref="STDOUT"/>

</root>

9、Logback同样提供了直接将日志存储至DB的功能：

9.1、修改POM文件添加相关依赖包，主要是数据库连接驱动以及连接池依赖：

<dependency>

<groupId>com.mchange</groupId>

<artifactId>c3p0</artifactId>

<version>0.9.5.1</version>

</dependency>

<!-- jdbc driver -->

<dependency>

<groupId>mysql</groupId>

<artifactId>mysql-connector-java</artifactId>

<version>5.1.13</version>

<scope>runtime</scope>

</dependency>

<dependency>

<groupId>com.microsoft.sqlserver</groupId>

<artifactId>sqljdbc41</artifactId>

<version>4.1</version>

</dependency>

9.2、配合logback-spring.xml，添加DBAppender配置（方式一： sql数据库+DriverManagerConnectionSource）：

<!--日志异步到数据库 -->

<appender name="DB" class="ch.qos.logback.classic.db.DBAppender">

<filter class="ch.qos.logback.classic.filter.ThresholdFilter">

<level>INFO</level>

</filter>

<!--日志异步到数据库 -->

<connectionSource class="ch.qos.logback.core.db. DriverManagerConnectionSource">

<driverClass>com.microsoft.sqlserver.jdbc.SQLServerDriver</driverClass>

<url>jdbc:sqlserver://127.0.0.1:1433;DatabaseName=cloudsea</url>

<user>sa</user>

<password></password>

</connectionSource>

</appender>

<root level="DEBUG">

<appender-ref ref=" DB"/>

<appender-ref ref="ASYNC"/>

<appender-ref ref="STDOUT"/>

</root>

9.3、此时启动服务，查看控制台以及数据库：

9.3.1、控制台会有如下提示：

故在此目录下添加对应jar依赖包。

9.3.2、此提醒并未影响日志的记录

所有通过临界值过滤高于等于INFO级别的均自动存储至数据库。此时我们将缺失的依赖包放置需要的目录重启服务，此时控制台无上述warn，数据库日志记录增加：

9.4、在9.2中我们采用的书sql+DriverManagerConnectionSource方式，本次我们采用mysql+DataSourceConnectionSource+c3p0方式验证：

9.4.1、修改我们的logback-spring.xml：

<!--日志异步到数据库 -->

<appender name="DB" class="ch.qos.logback.classic.db.DBAppender">

<filter class="ch.qos.logback.classic.filter.ThresholdFilter">

<level>INFO</level>

</filter>

<!--日志异步到数据库 -->

<connectionSource class="ch.qos.logback.core.db. DataSourceConnectionSource">

<!--连接池 -->

<dataSource class=" com.mchange.v2.c3p0.ComboPooledDataSource">

<driverClass>com.mysql.jdbc.Driver</driverClass>

<jdbcUrl>jdbc:mysql://127.0.0.1:3306/springboot1</jdbcUrl>

<user>root</user>

<password>root</password>

</dataSource>

</connectionSource>

</appender>

9.4.2、启动服务验证结果，一切正常：

注：

1、如果我们启动服务无异常，且确认数据库运行也正常，但数据库无日志记录，则有可能是数据库表结构不匹配，具体的表结构可以在

中直接提取在数据库执行即可。

2、本案例采用INFO级别作为临界值过滤，减少大量DEBUG级别记录，具体可以根据实际业务需要决定。

3、应用场景中我们可以将日志数据库与业务数据库分离，同时也可以通过扩展自定义的Appender（继承UnsynchronizedAppenderBase）实现mongodb日志的收集。