SpringBoot打印Mybatis执行SQL及slf4j

发表于

最近在springboot项目的代码问题定位时需要知道mybatis的执行SQL，所以查了下如何配置，并顺道整理下之前一直忽略的日志内容。

1 日志框架介绍

23种设计模式中有一种模式叫门面模式。

image-20211128105530398.png

在这个结构图中，出现了两个角色：

  • 门面(Facade)角色 ： 客户端可以调用这个角色的方法。此角色知晓相关的（一个或者多个）子系统的功能和责任。在正常情况下，本角色会将所有从客户端发来的请求委派到相应的子系统去。
  • 子系统(SubSystem)角色 ： 可以同时有一个或者多个子系统。每个子系统都不是一个单独的类，而是一个类的集合（如上面的子系统就是由ModuleA、ModuleB、ModuleC三个类组合而成）。每个子系统都可以被客户端直接调用，或者被门面角色调用。子系统并不知道门面的存在，对于子系统而言，门面仅仅是另外一个客户端而已。

使用门面模式具有以下优点：

  • 松散耦合: 门面模式松散了客户端与子系统的耦合关系，让子系统内部的模块能更容易扩展和维护。
  • 简单易用: 门面模式让子系统更加易用，客户端不再需要了解子系统内部的实现，也不需要跟众多子系统内部的模块进行交互，只需要跟门面类交互就可以了。
  • 更好的划分访问层次: 通过合理使用Facade，可以帮助我们更好地划分访问的层次。有些方法是对系统外的，有些方法是系统内部使用的。把需要暴露给外部的功能集中到门面中，这样既方便客户端使用，也很好地隐藏了内部的细节。

日志框架也采用门面模式来设计，其中JCL(Jakarta Commons Logging)和SLF4J(Simple Logging Facade for Java)是日志门面，JUL(Java Util Logging)、Log4j、Logback和Log4j2则是日志实现。

参考资料：JCL、SLF4J、Log4J、Log4J2、LogBack和JUL之间的关系，你搞清楚了吗？

1.1 日志门面

日志门面中JCL最后一次更新是在2014年，目前基本都是使用SLF4J日志门面，所以只介绍SLF4J的内容。

1.1.1 SLF4J

SLF4J日志门面可以搭配JUL、Log4j、Logback和Log4j2中任何一个日志实现使用，使用SLF4J门面只需要引入slf4j-api-${project.version}.jar包即可。搭配不同日志实现也是通过在项目中引入对应的jar即可，具体如下：

  • slf4j-simple-${latest.stable.version}.jar：绑定Simple 日志实现，仅仅在很简单的项目中使用。
  • slf4j-nop-${latest.stable.version}.jar：绑定 NOP, 用于丢弃所有日志。
  • slf4j-jdk14-${latest.stable.version}.jar：绑定java.util.logging，即JDK 1.4版本的日志实现。
  • slf4j-log4j12-${latest.stable.version}.jar：绑定log4j 1.2版本的日志实现。
  • logback-classic-logback.version.jar(requireslogback−core−{logback.version}.jar (requires logback-core-logback.version.jar(requireslogback−core−{logback.version}.jar) ：绑定logback日志实现。

要切换不同的日志实现，只需要替换不同的日志实现jar包就可以。以下SLF4J官网的图展示了门面和实现的绑定关系。

image-20211128115701184.png

SLF4J日志门面绑定日志实现是在编译阶段完成的，而且只能绑定一个日志实现。由于SLF4J门面不依赖任何的类加载机制，所以不存在JCL(Jakarta Commons Logging)日志门面遇到的类加载器或内存泄漏问题。

参考资料：SLF4J user manual

1.2 日志实现

目前通常使用Logback。Log4j2作为Log4j的升级版，有更好的异步日志性能，只是现在的使用面还不如Logback。

1.2.1 Log4j

Apache Log4j是一个基于Java的日志记录工具，由Ceki Gülcü首创的，现在则是Apache软件基金会的一个项目，该项目已不再维护。

1.2.2 Logback

Logback是Ceki Gülcü将Log4j捐献给Apache基金会后另外写的日志框架。作者同时写了SLF4J和Logback，所以Logback原生就支持SLF4J的API。Logback是SpringBoot选用的默认日志实现。

Logback分为3个模块：logback-core、logback-classic和logback-access。logback-core是另外两个模块的基础。logback-classic原生就实现了SLF4J的API，也是我们日常开发中会引入的依赖。logback-access用于和Tomcat、Jetty等Servlet容器集成的，提供了HTTP访问日志的功能。

相比Log4j，Logback具有以下优点：

  • 执行速度快，内存占用少。
  • 测试更加充分，虽然Log4j也进行过测试，但是和Logback的测试程度相比，不在一个量级。Logback的稳定性更有保证。
  • Logback原生就支持SLF4J的API，而Log4j要使用SLF4J的API则需要通过slf4j-log4j12-${latest.stable.version}.jar作为适应层。
  • 可以从I/O错误中快速恢复。
  • 自动移除旧版本的日志文件、异步自动压缩日志文件。

1.2.3 Log4j2

Log4j2作为Log4j的升级版，借鉴了Logback的优点并修复了Logback内在的结构缺陷。相比Logback，Logback的异步输出性能有明显优势。

2 日志框架使用

接下来介绍如何在SpringBoot项目中分别使用SLF4J+Logback和SLF4J+Log4j2。

Logback和Log4j2的日志配置的常见格式都按下图的层次来定义。Appenders中选用不同的Appender来设置将日志输出什么位置，Loggers中通过Logger指定代码中package和class的日志输出级别以及采用定义的哪些appender组件来记录日志。

image-20211128145511779.png

所使用的SpringBoot项目参考：

  • org.spring.springboot.controller.CityRestController内容：
1
2
3
4
5
6
7
8
9
10
11
12
13
14
kotlin复制代码@RestController
public class CityRestController {
    private final Logger LOG = LoggerFactory.getLogger(CityRestController.class);
    @Autowired
    private CityService cityService;
    @RequestMapping(value = "/api/city", method = RequestMethod.GET)
    public City findOneCity(@RequestParam(value = "cityName", required = true) String cityName) {
        LOG.debug(">>>>>>>>>>Enter Controller");
        LOG.info(">>>>>>>>>>Enter Controller");
        LOG.warn(">>>>>>>>>>Enter Controller");
        LOG.error(">>>>>>>>>>Enter Controller");
        return cityService.findCityByName(cityName);
    }
}
  • org.spring.springboot.service.impl.CityServiceImpl内容：
1
2
3
4
5
6
7
8
9
10
11
12
13
java复制代码@Service
public class CityServiceImpl implements CityService {
    private final Logger LOG = LoggerFactory.getLogger(CityServiceImpl.class);
    @Autowired
    private CityDao cityDao;
    public City findCityByName(String cityName) {
        LOG.debug(">>>>>>>>>>Enter Servie");
        LOG.info(">>>>>>>>>>Enter Servie");
        LOG.warn(">>>>>>>>>>Enter Servie");
        LOG.error(">>>>>>>>>>Enter Servie");
        return cityDao.findByName(cityName);
    }
}
  • org.spring.springboot.dao.CityDao内容：
1
2
3
less复制代码public interface CityDao {
    City findByName(@Param("cityName") String cityName);
}

2.1 Log4j2使用

鱿鱼SpringBoot默认采用Logback日志框架，所以要改用Log4j2，需要对pom文件做改动，具体如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
xml复制代码        <!-- Spring Boot Web 依赖 -->
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
            <exclusions>
                <exclusion>
                    <groupId>org.springframework.boot</groupId>
                    <artifactId>spring-boot-starter-logging</artifactId>
                </exclusion>
            </exclusions>
        </dependency>
​
        <!-- 引入Log4j2的starter依赖 -->
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-log4j2</artifactId>
        </dependency>

在SpringBoot项目中，Log4j2的日志配置文件名为log4j2.xml或者log4j2-spring.xml时，项目启动时会自动读取到里面的配置，读取顺序是：先读log4j2.xml，再读application.yaml，然后是log4j2-spring.xml，所以如果在日志配置文件中引用了application.yaml文件的内容，日志文件名不能是log4j2.xml。如果日志配置文件名既不是log4j2.xml，也不是log4j2-spring.xml，则需要在application.yaml中指定日志配置文件，配置如下：

1
2
3
yaml复制代码## 日志配置
logging:
  config: classpath:log4j2-demo.xml

日志配置文件log4j2-demo.xml内容如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
xml复制代码<?xml version="1.0" encoding="UTF-8"?>
<!--Configuration后面的status，这个用于设置log4j2自身内部的信息输出，可以不设置，当设置成trace时，你会看到log4j2内部各种详细输出-->
<!--monitorInterval：Log4j能够自动检测修改配置 文件和重新配置本身，设置间隔秒数-->
<configuration monitorInterval="5">
<!--日志级别以及优先级排序: OFF > FATAL > ERROR > WARN > INFO > DEBUG > TRACE > ALL -->
​
<!--变量配置-->
<Properties>
    <!-- 格式化输出：%date表示日期，%thread表示线程名，%-5level：级别从左显示5个字符宽度 %msg：日志消息，%n是换行符-->
    <!-- %logger{36} 表示 Logger 名字最长36个字符 -->
    <property name="LOG_PATTERN" value="%date{yyyy-MM-dd HH:mm:ss, SSS} [%thread] %-5level %logger{36} - %msg%n" />
    <!-- 定义日志存储的路径，不要配置相对路径 -->
    <property name="FILE_PATH" value="logs" />
    <property name="FILE_NAME" value="logs" />
</Properties>
​
<appenders>
    <console name="Console" target="SYSTEM_OUT">
        <!--输出日志的格式-->
        <PatternLayout pattern="${LOG_PATTERN}"/>
    </console>
​
    <!--文件会打印出所有信息，这个log每次运行程序会自动清空，由append属性决定，适合临时测试用-->
    <File name="FileLog" fileName="${FILE_PATH}/${FILE_NAME}-all.log" append="false">
        <PatternLayout pattern="${LOG_PATTERN}"/>
    </File>
​
    <!-- 这个会打印出所有的debug及以上级别的信息，每次大小超过size，则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩，作为存档-->
    <RollingFile name="RollingFileDebug" fileName="${FILE_PATH}/${FILE_NAME}-debug.log" filePattern="${FILE_PATH}/${FILE_NAME}-DEBUG-%d{yyyy-MM-dd}_%i.log.gz">
        <!--只接收level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
        <ThresholdFilter level="debug" onMatch="ACCEPT" onMismatch="DENY"/>
        <PatternLayout pattern="${LOG_PATTERN}"/>
        <Policies>
            <!--interval属性用来指定多久滚动一次，默认是1 hour-->
            <TimeBasedTriggeringPolicy interval="1"/>
            <SizeBasedTriggeringPolicy size="10MB"/>
        </Policies>
        <!-- DefaultRolloverStrategy属性如不设置，则默认为最多同一文件夹下7个文件开始覆盖-->
        <DefaultRolloverStrategy max="15"/>
    </RollingFile>
​
    <!-- 这个会打印出所有的info及以上级别的信息，每次大小超过size，则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩，作为存档-->
    <RollingFile name="RollingFileInfo" fileName="${FILE_PATH}/${FILE_NAME}-info.log" filePattern="${FILE_PATH}/${FILE_NAME}-INFO-%d{yyyy-MM-dd}_%i.log.gz">
        <!--只接收level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
        <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
        <PatternLayout pattern="${LOG_PATTERN}"/>
        <Policies>
            <!--interval属性用来指定多久滚动一次，默认是1 hour-->
            <TimeBasedTriggeringPolicy interval="1"/>
            <SizeBasedTriggeringPolicy size="10MB"/>
        </Policies>
        <!-- DefaultRolloverStrategy属性如不设置，则默认为最多同一文件夹下7个文件开始覆盖-->
        <DefaultRolloverStrategy max="15"/>
    </RollingFile>
​
    <!-- 这个会打印出所有的error及以上级别的信息，每次大小超过size，则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩，作为存档-->
    <RollingFile name="RollingFileError" fileName="${FILE_PATH}/${FILE_NAME}-error.log" filePattern="${FILE_PATH}/${FILE_NAME}-ERROR-%d{yyyy-MM-dd}_%i.log.gz">
        <!--控制台只输出level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
        <ThresholdFilter level="error" onMatch="ACCEPT" onMismatch="DENY"/>
        <PatternLayout pattern="${LOG_PATTERN}"/>
        <Policies>
            <!--interval属性用来指定多久滚动一次，默认是1 hour-->
            <TimeBasedTriggeringPolicy interval="1"/>
            <SizeBasedTriggeringPolicy size="10MB"/>
        </Policies>
        <!-- DefaultRolloverStrategy属性如不设置，则默认为最多同一文件夹下7个文件开始覆盖-->
        <DefaultRolloverStrategy max="15"/>
    </RollingFile>
</appenders>
​
<!--Logger节点用来单独指定日志的形式，比如要为指定包下的class指定不同的日志级别等。-->
<!--然后定义loggers，只有定义了logger并引入的appender，appender才会生效-->
<loggers>
    <!--过滤掉spring和mybatis的一些无用的DEBUG信息-->
    <logger name="org.mybatis" level="info" additivity="false">
        <AppenderRef ref="Console"/>
    </logger>
​
    <!--设置为debug级别以打印mybatis执行SQL-->
    <!--若是additivity设为false，则 子Logger 只会在自己的appender里输出，而不会在 父Logger 的appender里输出-->
    <Logger name="org.spring.springboot.dao" level="debug" additivity="true">
        <AppenderRef ref="Console"/>
        <appender-ref ref="FileLog"/>
        <appender-ref ref="RollingFileDebug"/>
    </Logger>
​
    <root level="info">
        <appender-ref ref="Console"/>
        <appender-ref ref="FileLog"/>
        <appender-ref ref="RollingFileInfo"/>
        <appender-ref ref="RollingFileError"/>
    </root>
</loggers>
</configuration>
​

日志打印结果：

  • 在工程目录下生成了四个日志文件，是四个Appender组件的输出结果。
  • 在logs-all日志文件中mybatis执行SQL打印了2次，这是因为日志配置文件中第二个Logger引用了FileLog Appender组件记录日志，同时Logger的additivity属性为true，表示将当前日志传递给父Logger。作为父Logger的root也引用了FileLog Appender组件，虽然root的日志级别为info，但是对于子Logger传递上来的日志，父Logger不做过滤，直接交给Appende处理。而Mybatis执行SQL日志级别为Debug，符合FileLog Appender组件的记录条件，所以Mybatis执行SQL就在logs-all日志文件记录了两次。
  • 控制台也输出两次Mybatis执行SQL，原因同上。

image-20211128152836786.png

2.2 Logback使用

Logback的使用和Log4j2类似，首先pom文件配置如下（也是Springboot项目的默认配置）：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
xml复制代码        <!-- Spring Boot Web 依赖 -->
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
<!--            <exclusions>-->
<!--                <exclusion>-->
<!--                    <groupId>org.springframework.boot</groupId>-->
<!--                    <artifactId>spring-boot-starter-logging</artifactId>-->
<!--                </exclusion>-->
<!--            </exclusions>-->
        </dependency>
​
        <!-- 引入Log4j2的starter依赖 -->
<!--        <dependency>-->
<!--            <groupId>org.springframework.boot</groupId>-->
<!--            <artifactId>spring-boot-starter-log4j2</artifactId>-->
<!--        </dependency>-->

然后按照logback的配置格式创建配置文件logback-demo.xml，并修改application.yaml的配置项（文件名如果是logback.xml或者logback-spring.xml也不需要该配置项）。

1
2
3
yaml复制代码## 日志配置
logging:
  config: classpath:spring-demo.xml

logback日志配置文件可参考：

看完这个不会配置 logback ，请你吃瓜！

logback 配置详解（一）——logger、root

logback最详细配置讲解，及命名规范

本文转载自: 掘金

开发者博客 – 和开发相关的 这里全都有

0%