☰
MyBatis Plus SQL日志打印全攻略:参数替换与慢SQL排查实践
2026/10/3 9:06:52 网站建设 项目流程

排查数据库问题时,看不到完整SQL是件极其痛苦的事情。MyBatis Plus把SQL语句和参数分两处打印,日志一多根本对不上号;线上出个慢查询,想确认到底执行了什么语句,翻日志却发现只有一行“Preparing: SELECT...”加一行“Parameters: 1, 2, 3”,完全没法直接复制去数据库执行。这篇文章就来系统地整理MyBatis Plus打印SQL日志的完整知识,包含实现方式、具体配置、参数占位符转真实值方案、生产环境的坑,以及我实际踩过的一些问题。

适合所有使用MyBatis Plus做持久层开发的Java后端工程师,不管是刚接触框架没多久的初级开发,还是已经写了多年业务代码的老手,都能从中找到能直接用上的内容。

1. 为什么SQL日志如此关键,以及MyBatis Plus默认的日志机制

1.1 SQL日志在开发和排障中的真实价值

很多业务问题归根结底就是“执行的SQL和想的不一样”。举个我处理过的真实案例:某次线上订单金额对不上,业务同学查了半天代码逻辑,发现一处条件判断写反了,但真正让人崩溃的是,MyBatis Plus生成的SQL带有WHERE deleted = 0这个逻辑删除条件,代码里明明没写,SQL里却多出来,让人一度怀疑是不是框架有bug。

当时如果SQL日志清晰可见,一眼就能定位是@TableLogic注解的全局逻辑删除配置生效了,根本不需要翻源码。这就是SQL日志最大的价值——把框架帮你做的事、你又看不见的事,全部摊开在阳光下。

具体来说,SQL日志帮助你实现以下几个核心目标:

  • 验证动态SQL拼接是否正确:MyBatis Plus的QueryWrapper、LambdaQueryWrapper条件拼接逻辑比较复杂,eq、like、in、between等条件组合在一起,是否生成了预期的WHERE子句,只有看到真实SQL才能100%确认。
  • 确认参数绑定顺序和类型:多个条件时参数顺序极其重要,尤其是使用foreach拼接IN列表时,每个参数值的索引位置对不对。
  • 定位慢SQL和性能瓶颈:通过日志中SQL的执行时间,配合数据库的执行计划分析,能快速定位没有走索引的查询。
  • 排查结果集映射问题:日志中显示了查询了哪些字段,但结果对象里某些字段是null,问题往往在于select的列没有涵盖对应字段。

1.2 MyBatis Plus内置的SQL日志输出机制

要彻底搞懂怎么配置SQL日志,首先得知道MyBatis Plus是怎么输出日志的。MyBatis(包括MyBatis Plus,它是在MyBatis基础上的增强)自身的日志输出有一套完整的抽象体系。

MyBatis框架内部通过org.apache.ibatis.logging.Log接口来统一管理日志输出,这个接口有一系列适配器实现,分别对接Logback、Log4j2、SLF4J、JDK logging、Apache Commons Logging、Stdout等不同的日志框架。MyBatis会在启动时自动探测当前classpath下存在哪个日志框架,然后选择对应的适配器。

MyBatis Plus在配置文件中提供了mybatis-plus.configuration.log-impl这个配置项,允许你直接指定使用哪个日志实现类来实现SQL语句的打印。常见的有这么几个:

配置值实现的日志框架输出效果
org.apache.ibatis.logging.stdout.StdOutImplSystem.out控制台直接输出,简单粗暴,不带日志级别
org.apache.ibatis.logging.slf4j.Slf4jImplSLF4J走统一日志门面,受全局日志级别控制
org.apache.ibatis.logging.log4j2.Log4j2ImplLog4j2输出到Log4j2日志系统
org.apache.ibatis.logging.log4j.Log4jImplLog4j旧版Log4j
org.apache.ibatis.logging.nologging.NoLoggingImpl无不输出任何日志

理解了这套机制,后面所有配置就会变得非常清晰。你既可以用log-impl强制指定,也可以利用MyBatis的自动探测机制,完全交给日志框架的级别配置来管理。两种方式各有利弊,下面详细展开。

2. 打印SQL日志的三种主流实现方式

2.1 方式一:通过log-impl配置直接开启控制台输出

最简单、最快的方案就是使用StdOutImpl。在application.yml中配置:

mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.stdout.StdOutImpl

这样配置以后,所有Mapper方法执行时,控制台会直接打印类似下面的内容:

Creating a new SqlSession SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3f0eefde] was not registered for synchronization because synchronization is not active JDBC Connection [jdbc:mysql://localhost:3306/test?useSSL=false&serverTimezone=Asia/Shanghai, UserName=root@localhost, MySQL Connector/J] will not be managed by Spring ==> Preparing: SELECT id,name,email,age FROM user WHERE (age > ? AND name LIKE ?) ==> Parameters: 20(Integer), %张%(String) <== Columns: id, name, email, age <== Row: 1, 张三, zhangsan@example.com, 25 <== Total: 1

这种方式的优点非常明显:配置简单,开箱即用,完全不用动日志框架的配置。项目里哪怕没有任何logback配置,控制台也能看到完整SQL。

但缺点同样明显:所有SQL都通过System.out输出,完全绕过了日志框架,无法写入文件、无法按级别过滤、生产环境开启后无法灵活关闭。而且这个东西在你引入多个数据源时会发现,某些情况下的连接池信息也会掺杂进来,输出比较杂乱。

这种方案适合什么场景呢?小而快的项目、临时的本地调试。如果说你只是想快速看一条SQL长什么样,那直接用这个,一秒搞定,不用想别的。

2.2 方式二:借助日志框架级别控制实现SQL输出

这是我认为最正规、最推荐的方案,核心思路是:MyBatis Plus执行SQL时会通过SLF4J输出日志,日志级别为DEBUG,只需要在你项目的日志框架配置中,将MyBatis的Mapper包或者MyBatis Plus相关的logger级别设置为DEBUG即可。

先看MyBatis自动探测机制下它会输出哪些logger名。回想我在实际项目里看到的输出,打开logback的DEBUG级别后,会看到类似这样的日志:

<logger name="com.example.demo.mapper.UserMapper" level="DEBUG"/>

这里需要解释一个细节。MyBatis的SQL日志是通过Mapper接口的完整类名作为logger name来输出的,也就是说每个Mapper接口都是独立的logger。所以在日志框架里,你可以精确控制“哪些Mapper打印SQL,哪些不打印”,这对大项目来说非常实用。

采用logback配置示例:

<!-- 控制某个具体Mapper的SQL日志 --> <logger name="com.example.demo.mapper.UserMapper" level="DEBUG"/> <!-- 控制整个包下所有Mapper --> <logger name="com.example.demo.mapper" level="DEBUG"/>

如果你使用的是log4j2,对应的配置为:

<Logger name="com.example.demo.mapper" level="DEBUG" additivity="false"> <AppenderRef ref="ConsoleAppender"/> </Logger>

有些项目中还会见到一种更粗暴的配置,将org.mybatis这个包整体设置为DEBUG级,因为MyBatis内部的很多核心链路(org.apache.ibatis.executor、org.apache.ibatis.session等)也都有日志输出。但我不建议这么做,原因在于:org.mybatis包整体DEBUG输出的信息量非常大,包括SqlSession的创建、事务同步注册、连接管理器处理等大量细节,对你的排查并没有帮助,只会刷屏。我自己的标准做法是只配置mapper包路径。

这种方案的好处是:完全融入项目的统一日志体系。SQL日志会和业务日志一起输出到文件,带上时间戳、线程号、traceId,排查问题时能串起来;生产环境想关闭,把级别调回INFO即可,不需要改动任何代码。坏处就是要理解日志框架的配置方式,不像StdOutImpl那样无脑。

2.3 方式三:彻底解决参数占位符问题的p6spy方案

熟悉MyBatis日志的同学都知道,Preparing: SELECT ... WHERE age > ?打印出来的是占位符?,而真实的参数值在下一行Parameters: 20(Integer)单独打出来。单条SQL还好,一旦去分析慢SQL日志,得手动把参数回填进SQL里才能执行,非常麻烦。更重要的是,你没法直接把这行SQL复制到Navicat之类的客户端里跑,因为?在外部不是合法的占位符写法。

p6spy可以解决这个问题。它是一个数据库连接驱动级别的代理工具,拦截底层JDBC调用,能够打印出已经将参数渲染进去的完整可执行SQL。它的核心原理是:在JDBC驱动和你的业务代码之间增加一层代理,当你的应用通过DriverManager或者DataSource获取连接时,p6spy会包装一层代理连接。你的SQL执行时,p6spy能拿到真实的PreparedStatement参数数组,然后渲染出完整的SQL语句。

具体接入步骤为:

第一步,引入依赖:

<dependency> <groupId>p6spy</groupId> <artifactId>p6spy</artifactId> <version>3.9.1</version> </dependency>

第二步,在application.yml中修改数据源驱动和URL:

spring: datasource: driver-class-name: com.p6spy.engine.spy.P6SpyDriver url: jdbc:p6spy:mysql://localhost:3306/test?useSSL=false&serverTimezone=Asia/Shanghai username: root password: root

注意驱动和URL都是成对修改的,URL要在原有JDBC地址前加jdbc:p6spy:前缀,且驱动要换成P6SpyDriver。

第三步,在classpath根目录新增spy.properties文件,核心配置如下:

# 指定真正要驱动的JDBC驱动 driverlist=com.mysql.cj.jdbc.Driver # 日志输出到控制台 appender=com.p6spy.engine.spy.appender.Slf4JLogger # 打印可执行的SQL,把参数渲染进去 logMessageFormat=com.p6spy.engine.spy.appender.CustomLineFormat customLogMessageFormat=%(currentTime)|%(executionTime)|%(sql) # 是否延迟加载 deregisterDrivers=false # 是否使用日志 logReprint=true

配置完成后,你在日志里会看到类似下面这种可直接执行的SQL:

2024-01-15 10:23:45|2|select id,name,email,age from user where (age > 20 and name like '%张%')

这一行直接复制到数据库客户端里就能跑,非常方便。但需要提醒的是,p6spy的输出内容是单行格式,如果SQL特别长,阅读体验反而不如MyBatis自带的多行友好格式。此外,p6spy多了一层代理,在高频调用场景下会有微小的性能损耗,本地调试完全没问题,但不建议在生产环境长期开着。

2.4 三种方式对比总结

方案配置复杂度输出可执行SQL日志写入文件生产环境友好度适用场景
log-impl: StdOutImpl最低否否差本地快速调试
日志框架级别控制中否是好项目标准配置
p6spy中高是是中需要真实SQL、分析慢查询

3. 实操:从零开始为项目配置SQL日志输出

3.1 准备工作:确认MyBatis Plus版本和依赖

先看一眼你项目中的mybatis-plus-boot-starter版本。目前主流项目使用的版本通常有以下分支:

  • 3.4.x系列(如3.4.3.4)
  • 3.5.x系列(如3.5.3、3.5.5、3.5.7)

不同版本在配置上几乎没有差别,configuration节点下的配置项完全兼容。但有一点要注意:3.5.x版本开始,MyBatis Plus内部对MyBatis的依赖版本进行了升级,如果你同时手动依赖了低版本MyBatis,可能导致日志配置意外失效。这是我在一个老项目中遇到过的问题,后面会讲。

依赖示例(Maven):

<dependency> <groupId>com.baomidou</groupId> <artifactId>mybatis-plus-boot-starter</artifactId> <version>3.5.7</version> </dependency>

3.2 最推荐的日志框架级别控制:完整配置过程

下面以Spring Boot 2.7 + MyBatis Plus 3.5.7 + logback为例,完整展示配置过程。这个组合目前在国内企业中的应用面非常广。

在src/main/resources目录下创建或确认logback-spring.xml文件,并加入如下配置:

<?xml version="1.0" encoding="UTF-8"?> <configuration> <!-- 控制台输出 --> <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern> <charset>UTF-8</charset> </encoder> </appender> <!-- 文件输出,生产环境建议持久化 --> <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"> <file>logs/application.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <fileNamePattern>logs/application.%d{yyyy-MM-dd}.log</fileNamePattern> <maxHistory>30</maxHistory> </rollingPolicy> <encoder> <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern> <charset>UTF-8</charset> </encoder> </appender> <!-- 关键配置:定位到Mapper接口的包路径 --> <logger name="com.example.demo.mapper" level="DEBUG" additivity="false"> <appender-ref ref="CONSOLE"/> <appender-ref ref="FILE"/> </logger> <!-- 自定义SQL打印格式的方案,见3.3 --> <logger name="com.example.demo.config.MybatisSqlInterceptor" level="DEBUG" additivity="false"> <appender-ref ref="CONSOLE"/> <appender-ref ref="FILE"/> </logger> <root level="INFO"> <appender-ref ref="CONSOLE"/> <appender-ref ref="FILE"/> </root> </configuration>

注意几个关键点:

  • additivity="false"的含义是这条logger的输出不再向上传递给root logger,避免重复打印。不加也行,但如果root也是DEBUG级别就会打两遍。
  • logger的name是Mapper接口所在的包路径,不一定是com.example.demo.mapper,请替换为你自己项目中的包名。
  • level="DEBUG"是关键,MyBatis输出的SQL语句日志级别是DEBUG,级别设为INFO的时候就看不到SQL了。

Spring Boot中对应的application.yml只需要保证MyBatis Plus不做任何特殊配置(或者不配置log-impl)即可。因为我们要让日志框架来接管SQL输出的开关:

mybatis-plus: configuration: # 注意:这里不要配置log-impl,或者显式配置为Slf4jImpl log-impl: org.apache.ibatis.logging.slf4j.Slf4jImpl

这里再补充说明一下:如果log-impl配置为StdOutImpl,那么上面logback中针对mapper包级别设置的DEBUG就不会生效了,因为SqlSession执行的日志输出逻辑已经不走SLF4J,而是直接System.out.println了。在日志框架级别控制方案中,log-impl应当配置为Slf4jImpl或者干脆不配置。

3.3 让日志读出完整SQL的MyBatis Plus拦截器方案

可能你会觉得p6spy要改驱动和URL,有时候在数据源配置复杂的环境(比如多数据源)中风险比较大,有没有更轻量级的方案呢?有,那就是基于MyBatis的Interceptor接口自定义一个SQL日志拦截器。

MyBatis允许你通过@Intercepts注解拦截Executor或者StatementHandler层的SQL执行。在MyBatis源码中,PreparedStatementHandler中的instantiateStatement等方法会获取到BoundSql,这里面既包含完整的SQL模板(带?),也包含参数映射关系。通过分析ParameterMapping,可以将参数值回填到SQL模板中,生成一条“重建”的真实SQL。

下面给出一个我在项目中实际使用的拦截器代码,它可以把SQL和参数合并后输出为一行:

package com.example.demo.config; import org.apache.ibatis.executor.statement.StatementHandler; import org.apache.ibatis.mapping.BoundSql; import org.apache.ibatis.mapping.ParameterMapping; import org.apache.ibatis.plugin.Interceptor; import org.apache.ibatis.plugin.Intercepts; import org.apache.ibatis.plugin.Invocation; import org.apache.ibatis.plugin.Signature; import org.apache.ibatis.reflection.MetaObject; import org.apache.ibatis.session.Configuration; import org.apache.ibatis.type.TypeHandlerRegistry; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.springframework.stereotype.Component; import java.text.DateFormat; import java.util.Date; import java.util.List; import java.util.Locale; import java.util.regex.Matcher; @Intercepts({ @Signature(type = StatementHandler.class, method = "prepare", args = {java.sql.Connection.class, Integer.class}) }) @Component public class MybatisSqlInterceptor implements Interceptor { private static final Logger log = LoggerFactory.getLogger(MybatisSqlInterceptor.class); @Override public Object intercept(Invocation invocation) throws Throwable { StatementHandler statementHandler = (StatementHandler) invocation.getTarget(); BoundSql boundSql = statementHandler.getBoundSql(); Configuration configuration = statementHandler.getConfiguration(); String sql = showSql(configuration, boundSql); log.debug("SQL: {}", sql); return invocation.proceed(); } private String showSql(Configuration configuration, BoundSql boundSql) { String sql = boundSql.getSql().replaceAll("[\\s]+", " "); List<ParameterMapping> parameterMappings = boundSql.getParameterMappings(); Object parameterObject = boundSql.getParameterObject(); TypeHandlerRegistry typeHandlerRegistry = configuration.getTypeHandlerRegistry(); if (parameterMappings == null || parameterMappings.isEmpty()) { return sql; } for (ParameterMapping parameterMapping : parameterMappings) { Object value = getValue(parameterMapping, parameterObject, configuration); if (value != null) { String valueStr = formatValue(value); sql = sql.replaceFirst("\\?", Matcher.quoteReplacement(valueStr)); } } return sql; } private Object getValue(ParameterMapping parameterMapping, Object parameterObject, Configuration configuration) { if (parameterObject == null) { return null; } String propertyName = parameterMapping.getProperty(); MetaObject metaObject = configuration.newMetaObject(parameterObject); return metaObject.getValue(propertyName); } private String formatValue(Object value) { if (value instanceof String) { return "'" + value + "'"; } else if (value instanceof Date) { DateFormat dateFormat = DateFormat.getDateTimeInstance(DateFormat.DEFAULT, DateFormat.DEFAULT, Locale.CHINA); return "'" + dateFormat.format(value) + "'"; } else if (value instanceof Boolean) { return Boolean.toString((Boolean) value); } else { return value.toString(); } } }

这段代码的逻辑大致是:通过拦截StatementHandler.prepare方法,拿到BoundSql,然后遍历所有的ParameterMapping,从参数对象中逐个取值,替换SQL模板中的?。

有一点必须说明:这个方案只适合数值型、枚举型等简单参数,复杂对象里嵌套list表达式时可能需要进一步改造。真正大型项目中仍然推荐p6spy,因为它的成熟度远高于手写拦截器,能覆盖99%的场景,包括嵌套参数、数组参数、null值处理等。写这个方案主要是让你了解底层原理,同时给某些不能引入新依赖的场景提供一个参考。

3.4 从原生MyBatis使用者的角度理解log-impl的工作机制

有些同学可能会问:MyBatis Plus这么多配置项,我到底需要掌握到什么程度?其实MyBatis Plus的日志配置,根子上是MyBatis框架的能力。理解MyBatis的日志输出链路就够了:

Mapper接口方法调用 → MyBatis的Executor执行器(SimpleExecutor/ReuseExecutor/BatchExecutor) → StatementHandler预编译Statement → PreparedStatementHandler#parameterize设置参数 → DefaultParameterHandler#setParameters 遍历ParameterMapping绑定参数 → 打印Preparing和Parameters日志

JDBC的PreparedStatement在预编译阶段传的是SQL模板,参数是后来通过setString、setInt等方法绑定进去的。所以MyBatis日志里分两行打印是合理的,因为它在预编译完成后还没有参数,等绑定完参数后才由DefaultParameterHandler打印参数列表。这个理解对排查参数错位的问题非常有帮助。

4. 实操过程中高频踩坑记录与排查思路

4.1 配置了log-impl: StdOutImpl,但控制台看不到任何SQL日志

遇到这种情况,我建议按照下面几个方向来排查:

第一,确认执行的操作真的走了MyBatis Plus的Mapper方法。这里有个非常常见的误解:直接注入SqlRunner然后执行会绕过MyBatis的完整代理链路吗?实际上SqlRunner只是封装了SqlSession操作,依然会走日志链路,但如果你是在外部通过JDBC直连执行SQL,那当然不会打印。

第二,确认mybatis-plus的配置节点是否放在了正确的位置。Spring Boot 2.x项目的application.yml中,我的习惯写法是:

mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.stdout.StdOutImpl

如果你的项目是一个@ConfigurationProperties类来配置MyBatis Plus(比如自己写了一个MybatisPlusProperties进行属性注入),那就得看那个类是否生效了。大多数情况下Spring Boot的自动配置是没问题的,但如果项目中存在多个SqlSessionFactory自定义配置,某些配置可能被覆盖。

第三,查看是否有多个数据源或自定义了ConfigurationCustomizer。多个数据源的场景下,通常要为每个数据源单独指定log-impl,只配置在application.yml的mybatis-plus节点,只对默认的数据源生效。

第四,检查MyBatis Plus版本和你的Spring Boot版本是否真的有兼容性问题。比较极端的是Spring Boot 3.x(对应MyBatis Plus 3.5.3+)中,MyBatis的日志初始化原理没有变化,但配置方式稍有不同,如果同时使用了mybatis-plus-spring-boot3-starter,配置节点的前缀有了调整,需要确认你使用的是正确的starter而不是旧版starter。

4.2 配置了logback的mapper包DEBUG,但是SQL没打印

这种情况我遇到过不止一次,分析下来多数是这几种原因导致的:

第一,你的项目实际用的是log4j2,而不是logback。Spring Boot的spring-boot-starter-logging默认引入logback,但是如果又显式引入了log4j2依赖,实际生效的日志框架是log4j2。这时候改logback-spring.xml完全没用。排查方法很简单:启动时看控制台输出最上面有没有LogbackServletContextInitializer或者Log4j2LoggingSystem字样,或者查看日志文件后缀是.log还是Spring Boot默认格式。log4j2的配置要写在log4j2-spring.xml中,格式是<Logger>而不是<logger>。

第二,Spring Boot的logging.level配置优先级覆盖了你写在logback-spring.xml里的设置。正确的是:

logging: level: com.example.demo.mapper: DEBUG

这种配置等效于logback的logger,但Spring Boot在初始化时是有顺序的,如果既在YAML里配置了又在logback-spring.xml里配置了,后者可能在初始化阶段被覆盖。我的建议是全项目统一一种配置方式,别混用。

第三,SQL日志输出的logger name可能不是Mapper接口的完整类名。这是知识盲区:MyBatis在打印SQL时用到的Logger名称,默认取自MapperRegistry中注册的Mapper类型,这个类型名就是所有的@MapperScan扫描到的接口。但有一种情况例外:如果项目里同时存在mybatis.mapper-locations配置且Mapper XML使用了自定义命名空间,那么Executor一层的SQL日志使用的logger是mapper接口全名,但并不是每个版本的MyBatis Plus都如此,有些版本会使用MybatisLogger。这就需要你自己起一条测试SQL,用org.slf4j.LoggerFactory.getLogger来试验:

Logger logger = LoggerFactory.getLogger("com.example.demo.mapper.UserMapper"); logger.debug("test sql log");

如果这条自定义DEBUG日志能打出来,说明框架日志级别配置是通的;如果不能,说明是日志配置本身的问题。

4.3 日志打印了Preparing和Parameters,但是顺序乱掉

一旦系统是高并发场景,多个线程同时执行SQL时,Preparing和Parameters正好是两个独立日志输出点,线程间交错打印会让日志分析变得困难。这不是Bug,而是多线程环境的天然特性。

比较可靠的处理方式是引入traceId,日志模式中加上%X{traceId}之类的MDC占位符,这样同一个请求的所有SQL日志会有相同的traceId标签。再多线程日志也能通过traceId把所有相关SQL串起来看。在logback中配置MDC的示例:

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

然后在你的过滤器中(比如一个简单的OncePerRequestFilter),放入traceId:

MDC.put("traceId", UUID.randomUUID().toString().replace("-", ""));

这是个很实用的小技巧。否则你会面对一个极其难看的日志文件,SQL完全乱序,根本没法梳理某一个请求到底执行了哪些SQL。

4.4 分页查询打印的SQL带了LIMIT,但实际日志不完整

MyBatis Plus的分页插件PaginationInnerInterceptor会在最终SQL执行前做二次处理,把原SQL包装成COUNT查询SQL和实际的分页查询SQL。很多时候你看到的日志是:

==> Preparing: SELECT COUNT(*) FROM user WHERE (age > ?) ==> Parameters: 20(Integer) ==> Preparing: SELECT id,name,email,age FROM user WHERE (age > ?) LIMIT ? ==> Parameters: 20(Integer), 10(Long)

注意这里LIMIT后面的?在Parameters中显示为10(Long),这已经算是完整信息了。但如果你用p6spy方式打印,LIMIT后面的参数会直接写到SQL里,比如LIMIT 10,方便直接执行。两种方式都能接受,看个人习惯。分页插件有个属性叫optimizeCountSql,如果你发现COUNT查询与实际结果不一致,可能要去检查这个配置项,但和日志打印本身没有直接关系。

还有一个我踩过的坑:分页插件失效时,日志依然只是打印原始SQL,不加LIMIT。这种问题通常是因为没有配置MybatisPlusInterceptor或者配置了但顺序不对。看日志是最快的定位手段,如果一个Page查询打印出来的SQL没有任何LIMIT,那你就要先怀疑分页插件是否生效,而不是怀疑日志配置有问题。

4.5 生产环境打印大量日志导致磁盘暴涨

曾经有个同事为了排查线上问题,临时把生产环境的Mapper日志级别调整到了DEBUG,结果一天生成了30GB日志文件,把磁盘直接打满。这事提醒业务团队,SQL日志的开启要有规范。

生产中如果确需开启SQL日志,以下几点建议非常值得注意:

  • 只针对特定Mapper开启:不要一股脑把整个包都设置为DEBUG,只对出问题的那个Mapper设置即可。logback-spring.xml支持<logger name="com.example.demo.mapper.UserMapper" level="DEBUG"/>精确到类。
  • 设置独立的滚动策略和实时容量上限:用maxHistory控制保留天数,用SizeAndTimeBasedRollingPolicy按文件大小拆分,比如单个日志文件达到200MB就滚动。
  • 通过配置中心动态切换:比如使用Nacos Config + logback的动态日志级别功能,可以在不需要重启服务的情况下调整某个Mapper的日志级别,排查完再调回INFO,这样全程不影响大盘日志量。如果你所在公司有配置中心,强烈建议用这个方案。
  • 使用慢SQL日志替代完整SQL日志:MySQL的slow_query_log在生产中比MyBatis层打印所有SQL更温和,它只记录超过long_query_time阈值的SQL,天然过滤掉了大量正常请求。

5. 日志格式的美化与进阶玩法

5.1 配置输出更紧凑的SQL

如果你用MyBatis自带的多行日志,一条复杂的动态SQL可能长达几十行,阅读起来非常费劲。我看到很多项目选择在SQL模板编写时就用<script>标签加空格换行来美化XML。但MyBatis Plus的日志输出源是BoundSql.getSql(),它保持了你写的SQL原始格式,包括换行和缩进。

如果你的SQL模板本身比较整洁,输出自然也会比较整洁。但很多XML里的SQL写了动态条件后,拼接结果会带有大量多余空格。这时可以启动时配置一个ConfigurationCustomizer,把mapUnderscoreToCamelCase等技术配置处理好,但空格问题需要在SQL底层做处理。

p6spy的customLogMessageFormat里可以写一个自定义的消息格式,比如把多条空格压缩成单空格:

customLogMessageFormat=%(sql)

p6spy底层已经处理了多余换行和空格,所以通常输出是单行紧凑的完整SQL,阅读较为舒适。

5.2 配合执行时间的输出定位慢SQL

这里要提一个在MyBatis Plus自带日志中看不出来的信息:SQL的真实执行耗时。MyBatis自带日志中的Preparing、Parameters、Total并不会包含每条SQL的执行时间,所以定位慢SQL必须靠数据库层或者额外手段。

p6spy默认会输出执行时间,在spy.properties中可以通过%(executionTime)占位符将耗时写入日志。我通常会把logMessageFormat配置为:

customLogMessageFormat=%(executionTime) ms | %(sql)

然后结合告警规则,对超过500毫秒的SQL单独拉出分析。这个阈值可以根据自己的业务实际情况调整,高并发系统普遍定100~200ms。

另一种做法是在MyBatis拦截器中记录prepare到query结束的时间差,覆盖所有执行路径。如果不想引入p6spy,这个方法是最可控的。

5.3 自定义MyBatis Plus配置类实现日志开关

有一些项目希望通过一个配置项来控制是否打印SQL日志,而不是来回改logback。这是一种面向更细粒度控制的做法,可以自己写一个MybatisPlusConfig,根据环境判断来动态设置log-impl。

@Configuration public class MybatisPlusConfig { @Value("${app.sql-log-enabled:false}") private boolean sqlLogEnabled; @Bean public ConfigurationCustomizer mybatisConfigurationCustomizer() { return configuration -> { if (sqlLogEnabled) { configuration.setLogImpl(org.apache.ibatis.logging.stdout.StdOutImpl.class); } else { configuration.setLogImpl(org.apache.ibatis.logging.nologging.NoLoggingImpl.class); } }; } }

这种方式的好处是可以配合@Profile("dev")或者Spring Cloud Config的配置项实现环境隔离。但要注意一个细节:configuration.setLogImpl设置的是一个Class对象,MyBatis内部会为这个Log实现创建实例。如果项目里用了多个SqlSessionFactory,每个都要重新配置一遍才行。

6. 多数据源场景下SQL日志的配置细节

6.1 多数据源为什么日志配置容易失效

当项目需要配置多个数据源时(比如读写分离、分库分表),常规的做法是手动创建DataSource、SqlSessionFactory和SqlSessionTemplate。此时Spring Boot的AutoConfig可能被你自己定义的条件覆盖,导致mybatis-plus.configuration.log-impl只对其中一个数据源生效。

下面是一个多数据源配置场景中为什么会失效的例子:如果你自己定义了两个SqlSessionFactory,其中一个设置了MybatisConfiguration为log-implStdOutImpl,另一个没有设置,那么不经意的那个数据源的SQL就不会打印。排查这类问题的思路是:确认每个SqlSessionFactory在构建时是否都调用了configuration.setLogImpl,或者统一在一个Factory PostProcessor中处理。

6.2 动态数据源路由的日志配置建议

国内不少项目会使用@DataSource注解方式实现动态数据源切换(比如基于AbstractRoutingDataSource),在这种情况下,SQL日志的配置方式和主从库并没有本质区别,因为最终还是落到某个SqlSessionFactory上。但如果你的路由在运行时动态切换了DataSource,那么P6SpyDataSource这类代理连接在所有物理连接上统一生效,反而是这类场景中更优的选择,因为它可以在不改动多个SqlSessionFactory的前提下完成对所有数据源的SQL统一打印。

在p6spy方案下,多数据源接入只需确保每个DataSource最终通过P6SpyDataSource或者配置文件里的driver-class-name指定即可,接入相对干净。

7. 从日志到性能优化:SQL日志实践的高级用法

7.1 通过SQL日志验证索引是否生效

如果线上某个接口响应慢,你最先要看的不是代码逻辑,而是实际执行的那条SQL是什么、执行计划是什么。多数情况下问题就出现在SQL没有走索引。

把SQL日志开启后,拿到完整SQL,然后在Navicat里执行EXPLAIN,观察type列和rows列。如果type是ALL(全表扫描)或者rows极大,那就是索引设计有问题。此时再拿这条SQL去优化,效率远远高于对着代码猜。这里给出一个我常用的排查链路:慢接口确认 → 开启当前Mapper的SQL日志 → 拿到真实SQL和参数 → 数据库执行EXPLAIN→ 优化索引或改写SQL → 日志再次验证。

我的一个项目曾经有个查询需要3秒钟,打开SQL日志后发现它查的是一个三张表关联的视图,视图在数据库中本身没有索引可用,后来把这个视图拆成单表查询,时间降到300毫秒。没有SQL日志,这类问题定位会非常困难。

7.2 结合MyBatis Plus的wrapper结构判断日志中的动态条件

使用MyBatis Plus的LambdaQueryWrapper时,代码中写了多个条件,但某些条件下条件参数为null会自动忽略。这时候如果不看SQL日志,根本看不出哪个条件被忽略了。比如:

LambdaQueryWrapper<User> wrapper = Wrappers.lambdaQuery(); wrapper.eq(User::getAge, age) .like(StringUtils.hasText(name), User::getName, name) .between(beginTime != null, User::getCreateTime, beginTime, endTime);

当name为空字符串、beginTime为null时,日志里只会有第一个age条件。看日志能让你瞬间明白为什么查出来的数据和你预期的不一样。反之不看日志你会怀疑是不是框架有bug,白白浪费几个小时的排查时间。

所以我在团队里一直强调一个工作习惯:涉及数据库问题的排查,第一步永远是看SQL日志,而不是读代码。这条习惯帮我避开了很多弯路。日志里的SQL和代码里的Wrapper写法有时会展现出巨大的思维差异,而这种差异正是问题所在。

7.3 自定义慢SQL拦截器与日志联动

在拦截SQL日志的同时,如果顺手把执行时间大于阈值的SQL记录到独立的慢日志文件,对后期性能优化会有极大帮助。这样你可以按天归档慢SQL文件,定期分析是不是有新增的全表扫描查询。

下面给一个简单的思路,基于MetaObject从StatementHandler中拿到BoundSql,再结合PreparedStatement执行后的耗时,将慢SQL输出到专门的日志通道:

long start = System.currentTimeMillis(); Object result = invocation.proceed(); long cost = System.currentTimeMillis() - start; if (cost > 500) { slowSqlLogger.warn("slow sql cost:{} ms, sql:{}", cost, sql); }

这个拦截器可以和控制台SQL日志并存,配置了独立的logger,设置成WARN级别就只输出慢SQL,不影响正常SQL。

8. 一些被问烂了的零碎问题集中解答

8.1 MyBatis Plus 3.5.x为什么有时候看不到Preparing日志

3.5系列从某个版本开始对日志输出做了细节调整,在某些执行路径上(尤其是批量操作)可能只打印一条Total而没有Preparing和Parameters。这是因为批量操作时MyBatis默认不会在每次执行时都把参数打印出来。解决办法是检查是否配置了executorType=BATCH,如果是批量模式,建议临时切回到SIMPLE模式来观察SQL日志,或者直接用p6spy。

8.2 MyBatis Plus的SQL日志能直接体现JOIN查询吗

可以。只要你的Mapper接口中定义的方法包含自定义SQL(注解或XML形式),MyBatis的日志一样会输出Preparing和Parameters,JOIN查询的SQL和参数都完整可见。

8.3 如何让SQL日志带上调用链路信息

将MDC中的traceId集成到日志模式中,然后让SQL日志也带上MDC上下文,就能把一次前端请求的所有数据库操作串联起来。这在微服务排查中甜度极高。具体做法就是在日志框架的pattern中加入%X{traceId},然后通过你的网关或过滤器写入MDC。

8.4 日志太多不想全部输出,只想要慢SQL日志

这种需求建议分两条路走:如果数据库是MySQL,直接用数据库层面的慢查询日志;如果还想要MyBatis层面记录,就参考上文自定义慢SQL拦截器。不要试图通过MyBatis Plus自带配置去实现,因为它没有慢SQL这个维度。

8.5 有没有办法在运行期动态打开SQL日志

当然有,主要思路是利用配置中心的配置动态刷新logback级别。比如使用Nacos/Apollo时,把logger级别的配置放在可刷新的配置文件中,然后在Spring Boot中配置一个LoggingSystem的动态监听。Spring Boot自带logging.level.*端点,通过Actuator的/loggers接口也能动态调整:

POST /actuator/loggers/com.example.demo.mapper.UserMapper {"configuredLevel":"DEBUG"}

使用Actuator调整后立刻生效,排查完再调回INFO即可。

最后分享一段我个人的实操体会

如果你问我在实际项目中最终长期采用的是哪种组合,我的答案是:本地开发完全靠logback的mapper包DEBUG级别输出,配合IDEA控制台直接看Preparing和Parameters;线上环境一般不全局开启SQL日志,只开启某个特定Mapper或遇到性能问题时用p6spy临时打印带参数的真实SQL。这样既保证了排障效率,又把日志量控制在了可接受范围内。

还有一个小技巧值得分享:SQL日志的调优场景永远比调试场景更值得花时间。把日志打开,不是为了看那条SQL执行得对不对,而是为了看出那条SQL到底是怎么被构建出来的。很多同事看日志只看结果,不看拼接过程,这是浪费了SQL日志最宝贵的价值。

另外可以多扩展一步。如果你经常要分析系统的数据库操作逻辑,可以考虑把日志里的SQL定期归档,按小时或者按天存档,用脚本做去重分析。比如找出当前业务中哪几条SQL被调用的次数最多、执行时间最长,据此优化索引或者改写SQL。这一步做得好,有时候比你在代码层面做的优化收益还要大。

希望这篇围绕MyBatis Plus打印SQL日志的梳理对你有用。配置本身不复杂,难的是理解背后的机制,以及结合自己的场景选出合适的方案。配置出错没关系,照着前面的排查思路一步步来,总能找到问题所在。如果你的项目还有更多特殊的日志需求,欢迎顺着这些思路去挖掘,能折腾出来的灵活方案还有很多。

需要专业的网站建设服务?

联系我们获取免费的网站建设咨询和方案报价,让我们帮助您实现业务目标

立即咨询