接手一个老项目,接口慢得离谱,想看看底层 SQL 到底长什么样,结果控制台干干净净,一条日志都没有。翻配置文件,发现 yml 里只写了几句logging.level.root: info,根本没有 MyBatis 相关的配置,于是折腾了半天,最后才算把 MyBatis Plus 的 SQL 日志完全打开。这篇文章就把我这次配置的全过程、踩过的坑和最终的实践建议一起写出来,适合刚接手 MyBatis Plus 项目、或者配置了日志却发现怎么都不生效的开发者。内容不涉及太深原理,都是日常干活直接能用的东西。
1. 先说清楚:日志不打印,问题往往出在哪
1.1 打印SQL日志到底有什么用
很多人一开始不理解,ORM 框架自动生成的 SQL 有什么好看的?等你真遇到问题就知道,MyBatis Plus 的动态 SQL 是根据条件、注解、Wrapper 等一堆逻辑拼出来的,代码层面看到的只是queryWrapper的一堆规则,真正落到数据库的 SQL 是什么样,不打开日志完全看不到。
举几个我实际遇到的场景。某次联调,前端传入一个筛选条件,后端查出来的数据始终多一行,怎么检查 Service 逻辑都看不出问题。最后打开 SQL 日志,发现or和and拼接时优先级不对,MyBatis Plus 生成了一条多了一个OR条件的 SQL,把不该查的行带出来了。还有一次是分页查询突然失效,接口结果越查越多,日志里看到根本没有LIMIT语句,后来才定位到是分页插件没有注册成功。
除了排查问题,日常开发也能用到。比如你写了一个updateById,担心它真的把某些字段更新成null了,SQL 日志里清清楚楚地能看到 SET 子句到底包含了哪些字段。再比如联调阶段要确认参数是否绑定正确,看Parameters那一行就行。总之,SQL 日志相当于炒菜时的火候指示灯,看不到它你永远只能靠猜。
1.2 三个最容易被忽略的前提
配置不生效,百分之八十都是下面三个原因。
第一,配置文件键名不对。很多人会把mybatis-plus.configuration.log-impl误写成mybatis.configuration.log-impl,或者把log-impl写成logImpl、sql-log。前者是原生 MyBatis 的配置,后者是网上各种老文章里抄来的错误写法。MyBatis Plus 的官方配置路径就是mybatis-plus.configuration.log-impl,要严格按这个来。
第二,日志实现类决定了日志归谁管。如果你在配置里写的是StdOutImpl,SQL 日志会直接打到标准控制台,不走 Spring Boot 的日志体系。这时候你调logging.level是完全没用的,因为它根本不经过Logger。只有把日志实现换成Slf4jImpl,SQL 日志才会进入 slf4j 体系,才能被日志框架统一管理。
第三,版本差异。MyBatis Plus 从 3.x 到现在 3.5.x,配置类发生过不少调整,网上很多教程讲的是老版本写法,拿到新版本上就可能失效。最靠谱的办法是打开你自己项目里mybatis-plus-spring-boot-starter的 jar 包,找到自动配置类,看它到底读取哪个配置项,或者直接查看对应版本的官方文档页。
这三个前提没搞清楚,后面的配置怎么写都可能翻车。
2. 最省事的两种配置方式,照着抄就行
2.1 方式一:stdout直接输出,适合本地调试
如果你只是本地联调想看 SQL,最快的方式是在application.yml里写:
mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.stdout.StdOutImpl这一行配置的意思是说:让 MyBatis 在打印 SQL 时,使用StdOutImpl这个日志实现类。这个类的逻辑很简单,直接把格式化好的 SQL 输出到System.out,所以你在 IDEA 的控制台立刻就能看到类似这样的内容:
Creating a new SqlSession SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5f9e5a3] was not registered for synchronization because synchronization is not active JDBC Connection [com.zaxxer.hikari.pool.HikariProxyConnection@4a377fdb wrapping com.mysql.cj.jdbc.ConnectionImpl@1a2b3c4d] will not be managed by Spring ==> Preparing: SELECT id,name,email FROM user WHERE id=? ==> Parameters: 1008(Long) <== Total: 1这种方式的好处是零成本、立刻见效,没有任何日志框架的介入,所以不用担心日志依赖冲突之类的问题。但它也有明显的短处:既然不经过日志框架,你就没法控制它的输出级别,生产环境开了就直接刷屏;也没法写到独立文件里做持久化排查;更没法根据包路径做精细化的开关。
所以我的用法是:本地临时开着,联调完就关掉。它适合"我就想马上看一眼 SQL",不适合"我要把 SQL 日志纳入项目日志体系"。
2.2 方式二:接入slf4j统一日志,适合所有环境
推荐的做法是接入 SLF4J,让 SQL 日志和项目里其他日志走同一个框架。配置如下:
mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.slf4j.Slf4jImpl logging: level: com.example.demo.mapper: debug这里有两部分。第一部分是把 MyBatis 的日志实现切换为Slf4jImpl,这样 MyBatis 向外输出日志时会委托给org.slf4j.Logger。第二部分是设置日志级别,com.example.demo.mapper要换成你自己项目里 mapper 接口所在的包路径。
为什么必须是debug?因为 MyBatis 打印 SQL 时使用的日志级别就是DEBUG。如果你把包级别设成info,SQL 日志就不会显示。这一点经常被忽略,有人配置了Slf4jImpl,但logging.level写的是info,结果控制台啥也没有,还以为是配置有问题。
这种方式最灵活,SQL 日志会出现在工程统一的日志文件里,也可以单独拆出来;可以被logging.level精确控制;生产环境也可以通过改配置实时关闭,不用重新发布。
2.3 两种方式的本质区别
用一张表看对比:
| 对比项 | StdOutImpl | Slf4jImpl + logging.level |
|---|---|---|
| 输出位置 | 仅控制台标准输出 | 日志框架统一输出,可控制台/文件/远程 |
| 受 logging.level 控制 | 不受控制 | 受控制,可按包精确调整 |
| 日志框架依赖 | 无依赖 | 依赖 SLF4J 绑定 |
| 本地联调 | 极简单 | 稍微多两行配置 |
| 生产环境 | 不建议 | 可按需安全开/关 |
| 能否输出到文件 | 不能 | 可以 |
两者本质上是 MyBatisLogFactory在创建日志适配器时选择了不同的实现类。StdOutImpl内部直接把消息丢给System.out.println,而Slf4jImpl是把消息交给 SLF4J 门面,再由底层绑定到 Logback、Log4j2 等具体实现。说白了,前者是"直接喊",后者是"通过总机转接"。
我给大多数项目的建议是:直接用第二种。哪怕你是个纯个人项目,也建议用 Slf4jImpl,因为随着项目变大,迟早会遇到"我要把某几个 mapper 的 SQL 输出到单独文件"这种需求,到时候再改配置就是一个字段的事,但排查日志依赖可能会花上半天。
3. 日志集成与环境隔离:让SQL日志"听话"
3.1 按 mapper 包定向控制日志级别
如果项目里 mapper 很多,全项目统一开debug会让日志量瞬间暴涨,尤其是那些有循环查询的接口,一秒几百条 SQL 刷屏,连业务日志都被淹没。这时候最好的做法是按包定向控制。
logging: level: com.example.demo.mapper: debug com.example.demo.mapper.statistic: info com.example.demo.service: info这样做的好处是职责清晰:需要排查的模块开debug,稳定的模块保持info,日志量完全可控。甚至可以只针对单个 Mapper 接口打开:
logging: level: com.example.demo.mapper.UserMapper: debug注意这里要用 Mapper 接口的全限定名,甚至可以理解为这个接口对应的日志器名称。MyBatis 在打印 SQL 时,logger 的名字就是mapper接口的全限定名 + 当前方法名,所以你定向到类就能控制类里的所有方法,定向到包就能控制包下所有 Mapper。
还有一个细节:即使你不显式配置log-impl,只要项目里有 SLF4J 绑定,MyBatis 通常也会自动探测到 SLF4J 并启用,此时logging.level依然可以控制 SQL 日志。但这个"自动探测"在不同版本、不同依赖组合下行为不完全一致,为了不给排查留隐患,我都会显式写明Slf4jImpl,把不确定性干掉。
3.2 不同环境下的开关策略
很多项目只有一个application.yml,里面配了logging.level...: debug,结果发到生产环境也在打印 SQL。生产环境打印所有 SQL 的问题不只是刷日志,还有数据安全隐患:查询条件里的手机号、身份证号、订单号全部明文落到日志文件里,这玩意儿要是日志被脱库或者被第三方拿到,妥妥的泄露事故。
我习惯按 profile 拆分配置。开发环境:
# application-dev.yml mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.slf4j.Slf4jImpl logging: level: com.example.demo.mapper: debug生产环境:
# application-prod.yml mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.nologging.NoLoggingImplNoLoggingImpl是 MyBatis 自带的"空实现",会把日志全部吞掉。这样 SQL 日志在生产环境完全关闭,零输出,没有任何性能损耗。等线上出问题时,再临时把这一行改回Slf4jImpl并配合按包开debug发布一版,用完再撤回去。
如果你用的配置中心,那就更简单了,直接在配置中心里加一个开关字段来控制log-impl的值就行。注意,改log-impl必须重启应用才能生效,它不是 Spring 配置里可以热更新的日志级别,因为LogFactory是在 MyBatis 初始化阶段创建的。
3.3 配合 Logback 做独立的SQL日志通道
日常联调阶段我们经常要把 SQL 日志单独抽到文件里,方便事后翻查。常见的 Logback 配置:
<appender name="SQL_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"> <file>logs/sql.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <fileNamePattern>logs/sql.%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> </encoder> </appender> <logger name="com.example.demo.mapper" level="debug" additivity="false"> <appender-ref ref="SQL_FILE"/> </logger>这里最重要的一个属性是additivity="false"。如果你不关掉 additivity,mapper 包下的 logger 除了输出到SQL_FILE,还会把日志继续向 root logger 传播,结果就是 SQL 日志在控制台和文件里各出现一次,看着很乱。关掉之后,SQL 日志就只进入SQL_FILE这个管道。
需要注意路径问题:logs/sql.log是相对启动目录的,如果你用 Docker 部署,一定要把/app/logs挂载到宿主机目录,否则容器一重启文件就丢了。如果是本地调试,最好设置成绝对路径。独立文件的好处是排查 slow query 或特定用户的问题时,直接grep这个文件就行,不用在生产日志里海量搜。
4. 看懂SQL日志:Preparing 和 Parameters 到底在说什么
4.1 一条完整SQL日志长什么样
打开了日志,很多人看到这几行就犯迷糊,咱们拆开看。
==> Preparing: SELECT id,name,phone,status FROM user WHERE id=? AND status=? ==> Parameters: 1008(Long), 1(Integer) <== Total: 1第一行的Preparing,就是 MyBatis 告诉数据库"我要执行一条预编译 SQL",后面跟的是 SQL 模板。注意这里用的是问号占位符,SQL 并没有真正拼上参数值。这是 JDBC 里标准的PreparedStatement预编译机制,目的有两个:一是防止 SQL 注入,数据库会把整个模板编译好,参数只作为纯值传入;二是数据库可以复用执行计划,性能更好。
第二行Parameters,是 MyBatis 实际绑定的参数列表,每个参数都会标注类型。1008(Long)表示第一个?绑定的是 Long 类型的 1008,1(Integer)表示第二个?绑定的是 Integer 类型的 1。你看到的?顺序和这里参数的顺序是一一对应的。如果这里出现null,说明你传入的参数是 null,很多空指针问题在这里一眼就能看出来。
第三行Total,表示这次查询返回的结果条数。对于update或delete,它显示的是受影响的行数。比如你执行updateById,想确认是否真的更新了记录,看这个数字就行。如果update的Total是 0,说明主键没匹配上,那大概率又是人为的 bug。
还有一个常被问的点:上面还有个<== Total前面的耗时去哪了?MyBatis 原生日志不会直接打印执行耗时,只有通过性能分析插件或第三方拦截器才能看到。如果你特别在意每条 SQL 的执行时间,等下看 6.1 节。
4.2 打印真实执行SQL的两种额外方案
Preparing和Parameters分开打印的设计很好,但有时候你需要看到"真实的完整 SQL",也就是把参数填充进去的语句。这里有两种额外方案。
第一种是使用 p6spy。p6spy 是一个 JDBC 层的代理工具,它在数据库驱动之上做了一层拦截,日志里可以直接输出参数替换后的完整 SQL,还能带执行耗时。配置思路大概这样:引入依赖后准备一份spy.properties:
appender=com.p6spy.engine.spy.appender.Slf4JLogger logMessageFormat=com.p6spy.engine.spy.appender.SingleLineFormat databaseDialect=mysql autoflush=true然后把数据源地址改成 p6spy 的前缀:
spring: datasource: url: jdbc:p6spy:mysql://localhost:3306/demo driver-class-name: com.p6spy.engine.spy.P6SpyDriver这样日志里出现的不再是?,而是SELECT id,name FROM user WHERE id=1008这样的完整 SQL。需要注意的是 p6spy 有额外的性能损耗,每条 SQL 都要经过代理层做日志格式化,所以生产环境不建议开。
第二种方案是打开数据库自身的general_log,例如 MySQL 的通用日志。它能记录所有到达数据库的语句,但也把其他来源的语句全记录了,日志量极大,而且生产环境开 general_log 对磁盘和 [ ] 性能都是负担,只建议在本地排查疑难杂症时临时使用。
日常开发我推荐直接看 MyBatis 的Preparing+Parameters,完全够用。只有当你需要精确分析某条 SQL 性能时,才临时用 p6spy 把它打开,用完立刻关掉。
5. 踩坑实录:配置不生效的典型现场
5.1 配置键拼写与版本差异
第一个坑是最常见的:配置了log-impl但 SQL 日志死活不出来。网上随便一搜,能搜到各种五花八门的写法,有mybatis-plus.sql-log: true的,有mybatis-plus.log-impl的,还有mybatis-plus.configuration.logImpl这种驼峰写法。
先说结论:以官方文档为准,MyBatis Plus 3.x 的正确写法就是:
mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.slf4j.Slf4jImpl关于驼峰还是短横线,mybatis-plus.configuration.logImpl这种写法在 Spring Boot 的松散绑定下通常也能生效,但不同版本行为不完全一致。老项目里有时候会因为自定义了配置类导致绑定不上,我用log-impl这种短横线写法到现在没有翻过车。
另外要特别注意,mybatis-plus.sql-log: true这种写法是某些老教程里"想当然"的配置,根本不在此处生效。如果你项目里还有旧版的mybatis-plus-boot-starter和mybatis-plus-extension混用,配置类读取的配置项可能都不一样,这时候最好统一为一个 starter 版本,比如mybatis-plus-spring-boot-starter。
排查方法很简单:打开 jar 包里MybatisPlusProperties类,看看字段上标注的@ConfigurationProperties前缀和字段名,再对照自己的 yml。自己直接读源码,比在网上搜任何答案都可靠。
5.2 自定义 SqlSessionFactory 导致配置丢失
有些项目为了做特殊配置,会手动创建 SqlSessionFactory:
@Bean public SqlSessionFactory sqlSessionFactory(DataSource dataSource) throws Exception { MybatisSqlSessionFactoryBean factoryBean = new MybatisSqlSessionFactoryBean(); factoryBean.setDataSource(dataSource); factoryBean.setConfiguration(new org.apache.ibatis.session.Configuration()); return factoryBean.getObject(); }这种写法会让 Spring Boot 对 MyBatis Plus 的自动配置失效,因为你完全自己控制了一个Configuration。你新建的这个Configuration是裸的,没有经过 MP 的自动配置流程,log-impl配置自然就没被读进去。表现就是你明明在 yml 里写了log-impl: Slf4jImpl,但 SQL 日志还是不出来,或者 mapper 下划线转驼峰等功能也莫名其妙失效。
解决办法有两个。一是不要手动创建 SqlSessionFactory,让 MyBatis Plus 的自动配置去生成,关键配置全部写在 yml 里。二是如果真的需要自定义,就在你手动创建的时候把配置项同步进去,比如设置一下日志实现:
org.apache.ibatis.session.Configuration configuration = new org.apache.ibatis.session.Configuration(); configuration.setLogImpl(org.apache.ibatis.logging.slf4j.Slf4jImpl.class); factoryBean.setConfiguration(configuration);但这个方法要小心,setLogImpl之后你会发现,就算logging.level设成 debug,SQL 也不一定打印。因为 MyBatis Configuration 里有个logPrefix和logImpl的组合问题,你要么在 yml 里配,要么在代码里配,别两边都配造成混乱。实际项目里九成不需要手动创建 SqlSessionFactory,能不用就不用。
5.3 日志依赖冲突与绑定异常
第三种情况是依赖冲突。Spring Boot 默认用的是 Logback,SLF4J 作为门面,这个组合通常没问题。但有些项目为了性能或特殊需求,会额外引入slf4j-simple、log4j-slf4j-impl等实现,结果启动时控制台会打出类似这样的提示:
SLF4J: Class path contains multiple SLF4J bindings.一旦出现多绑定,MyBatis 在调用 SLF4J 时具体走了哪个实现就不可控了,SQL 日志可能出现在控制台,也可能跑到奇怪的位置,甚至干脆没有输出。这种情况的根治方法是清理依赖,保留一个日志实现就够。用 Maven 的话,用mvn dependency:tree看一下是谁引入了多余的绑定,然后在对应依赖上排除掉。
还有一个隐蔽的问题:项目里本身没有任何日志实现时,MyBatis 的LogFactory在启动时会逐个探测可用日志组件,探测不到就 fallback 到NoLogging,也就是所有日志都静默。在 Spring Boot 场景不太可能出现,但如果你写了一个非 Spring Boot 的简单工具,只引了mybatis-plus没引日志,可能就是这个结果。此时logging.level配得再好也没用,先把日志实现依赖补上。
6. 进阶玩法:慢SQL、多数据源与日志安全
6.1 慢SQL发现与性能拦截器
前面说过,MyBatis 原生日志不输出每条 SQL 的耗时。但实际排查性能问题的时候,我们希望"超过阈值的 SQL 能单独被标记"。MyBatis Plus 提供了性能分析相关的 InnerInterceptor,不同版本类名有一定差异,我以常见版本为例:
@Bean public MybatisPlusInterceptor mybatisPlusInterceptor() { MybatisPlusInterceptor interceptor = new MybatisPlusInterceptor(); // 部分版本叫 PerformanceInnerInterceptor,部分版本叫 PerformanceAnalyzer // 具体以你本地 jar 包里实际类名为准 interceptor.addInnerInterceptor(new PerformanceInnerInterceptor()); return interceptor; }配置之后,通过日志可以输出每条 SQL 的执行耗时,比如:
[Performance] SQL: SELECT * FROM user WHERE id=1008 Time: 1023 ms如果超过默认阈值,还会输出更醒目的 block 日志。这套机制适合开发环境调优用。注意一点:这类性能插件本质上是给 SQL 执行加了一层拦截,对极端性能敏感的业务有微小损耗,生产环境可以关闭。如果想在生产环境长期监控慢 SQL,建议交给 APM 系统和数据库自带的慢查询日志,而不是依赖应用层拦截器。
另外,一个实用小习惯是:平时开着 MyBatis 的Total日志,遇到某个接口耗时严重,第一反应就是翻 SQL 日志,看看是不是出现了循环查询、大查询或者是没有走索引的查询。SQL 日志 + 数据库EXPLAIN组合,定位问题比瞎猜快得多。
6.2 多数据源场景下的日志区分
多数据源项目里,SQL 日志同样可以按包区分。假设你有主、从两个数据源,对应两个不同的 mapper 包:
logging: level: com.example.demo.mapper.primary: debug com.example.demo.mapper.secondary: warn这样主库的 SQL 日志能看到,从库的 SQL 日志不输出,排查问题时不至于混在一起。但如果两个数据源共用同一个 mapper 接口,比如用某个动态数据源组件根据@DS注解切换数据源,那 SQL 日志在输出时都出自同一个 logger,就不好区分了。此时我一般是临时在 Service 层打一条日志,标识当前线程用的是哪个数据源,再通过执行顺序把 SQL 日志串起来。如果你用的是动态数据源框架,通常它自己会在切换数据源时输出提示日志,结合起来看也行。
多数据源场景更要注意的是,把log-impl设置为Slf4jImpl后,数据源切换的日志和 MyBatis SQL 日志都会进入同一个日志体系,建议在日志 pattern 里加上线程名。SQL 日志的输出中[http-nio-8080-exec-3]这个线程标识对于按请求追查非常有价值。
6.3 敏感参数与链路 traceId 的日志实践
SQL 日志里能看到的参数往往很敏感。一个查询用户订单的接口,可能把手机号、身份证号全部打出来。本地开发无所谓,生产环境如果长期开着debug,这些明文数据就留在了日志文件里,一旦日志被导出或泄露,就是安全事故。所以生产环境要么直接把log-impl设为NoLoggingImpl,要么开debug但只开个别必要接口,且明确设置日志文件的访问权限。
如果你的业务确实需要在生产环境打印部分 SQL,而对参数脱敏有硬性要求,可以考虑在日志框架层面对包含敏感参数的日志做替换。简单思路是在 Logback 的 Encoder 层写一个自定义过滤器,匹配Parameters行中的手机号规则,替换成1************。这个方案不完美,但对降低泄露风险是有意义的。另一个更彻底的方向是使用自定义类型处理器或在业务层对查询条件做限制,让敏感参数本身就不出现在 SQL 里。
另外,微服务链路追踪场景下,我觉得很有价值的一个实践是给日志 pattern 加上 traceId。比如用 Logback pattern:
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] [%X{traceId}] %-5level %logger{50} - %msg%n</pattern>这样 SQL 日志会和上半场的业务日志串到同一个 traceId 下。排查问题时,拿一个用户请求的 traceId,能一口气拉全这个请求经历的所有服务、所有 SQL,效率提升不止一个量级。如果你用链路组件,它会自动往 MDC 里塞 traceId,你要做的只是把%X{traceId}写进 pattern。
最后分享一个我的个人习惯。每次开工新需求,我先把 yml 里的 mapper 包日志开到 debug,联调通过再关掉或者改成 info 收工。这个习惯帮我避免了很多"本地跑不通、前端等着看效果、后端不知道数据从哪来"的尴尬时刻。SQL 日志这种东西,配置上花五分钟调稳,后面省下来的可能就是几个小时的排查时间,值得每个做后端的人认真对待。