前阵子接手一个老项目,线上慢查询频发,DBA甩来一条执行时间超过3秒的SQL,我盯着控制台翻了几分钟也没找到它在代码里的哪个位置。后来我养成一个习惯:在开发和联调阶段,把项目里的SQL日志和查询结果完整打出来,问题基本都能当场暴露。这次就围绕“Spring Boot项目打印SQL日志和结果”这个主题,把我的实操经验完整记录下来,既包括最简单的配置文件方案,也有用Logback做精细化控制,还有用p6spy和自定义拦截器查看完整可执行SQL与结果集的高级玩法。如果你也经常被Mapper里的SQL“吞掉”问题困扰,照着这篇文章配置一遍,基本能解决八成日志相关的问题。
1. 项目背景与核心需求解析
1.1 这里的“SQL日志和结果”到底指什么
很多人一听到“打印SQL日志”,第一反应就是控制台能输出几条SQL语句。但实际上,一次完整的数据库操作日志应该包含四个维度的信息:SQL原文、预编译参数、执行耗时、查询结果。SQL原文用来确认框架生成的语句是否符合预期;预编译参数用来排查动态条件是否拼接正确;执行耗时用来定位慢查询;查询结果则能直接告诉我返回的行数或记录内容是否符合业务逻辑。
以MyBatis为例,默认情况下框架会把SQL和执行参数分两行输出,例如Preparing行显示“select * from user where id = ?”,Parameters行显示“1”。如果你只看SQL不看Parameters,可能会被带偏。而结果集信息往往隐藏在更深的日志级别里,这就是为什么很多开发者觉得“配置了却打不出来”。
理解这点之后,再回头看你手头的项目,就能明白为什么单纯在配置文件里加一行logging.level并不能解决所有问题。不同框架输出日志的Logger名称不同,输出级别也不同,只有对症下药,才能完整拿到SQL和结果。
这里还有一层隐含需求:这些日志大多数时候只在开发、联调和测试阶段需要,生产环境必须能灵活关闭或降级,否则高并发请求下每条SQL都输出,日志文件很快就会被撑爆。所以方案不能是“永远打开”,而是“能开能关、能看能收”。
1.2 方案选型:配置文件、Logback、第三方组件各管什么
先给结论:如果你的项目只是简单调试,几分钟就能解决,用Spring Boot自带的logging.level加MyBatis的log-impl配置就够了;如果项目规模比较大、需要持续观察SQL执行情况,或者想把SQL单独沉淀到一个文件,就必须引入自定义Logback配置文件;如果还想看完整可执行SQL、参数自动内联、慢SQL告警,那就要考虑p6spy这类JDBC层代理工具。
下面这个表格是我在实际项目中做选型时最常用的对比维度:
| 方案 | 配置成本 | 能看到参数 | 能看到结果集 | 慢SQL耗时 | 适合场景 |
|---|---|---|---|---|---|
| 配置文件logging.level | 极低 | 部分(占位符与参数分两行) | 少量 | 无 | 临时调试、单个问题定位 |
| Logback自定义配置 | 中等 | 部分 | 少量 | 无 | 需要按文件、按级别定制输出的长期工程 |
| p6spy | 较低 | 完整内联 | 可控 | 可以 | 联调、预发环境观察完整SQL |
| 自定义MyBatis拦截器 | 高 | 完整内联 | 可控 | 可以 | 需要深度定制、不想引额外依赖 |
选型的关键是不要一上来就堆重型方案。我见过有人为了看一条SQL,直接引入p6spy,结果数据源连接串改错,半天起不来服务,反而耽误事。正确做法是从配置文件方案开始,确实不够用了再往上升级,每一步都能在这篇文章里找到对应的操作。
需要模型API调用? 免费领10W Token,多模型网关一键接入 Claude、DeepSeek 等主流模型。
2. 环境准备与基础配置
2.1 项目依赖与版本选择
要做这个主题的实践,先确认项目基础环境。Spring Boot 2.x和3.x在日志配置上的差别其实不大,核心依赖是持久层框架整合包和日志依赖。这里以市面上用得最多的MyBatis体系为例,如果你的项目用的是Spring Data JPA,配置逻辑也类似,只是Logger名称不同。
在pom.xml里至少要有下面这些依赖:
xml复制<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>
<dependency>
<groupId>org.mybatis.spring.boot</groupId>
<artifactId>mybatis-spring-boot-starter</artifactId>
<version>3.0.3</version>
</dependency>
<dependency>
<groupId>com.mysql</groupId>
<artifactId>mysql-connector-j</artifactId>
<scope>runtime</scope>
</dependency>
Spring Boot默认使用Logback日志框架,所以不需要单独引logback依赖。有一点要注意,如果你的项目里另配了其他日志实现,比如log4j2,那下面的logging.level配置仍然有效,但自定义logback-spring.xml就不会生效了,两者不能混用。我在一个老项目里就吃过这个亏,一直以为文件没生效,其实是被log4j2抢占了实现。
再说版本选择。MyBatis Spring Boot Starter 3.x适配Spring Boot 3.x和MyBatis 3.5.x;如果项目还在JDK 8、Spring Boot 2.7上,建议用2.3.x。版本不一致往往会导致日志Logger名称变化,后面排查时容易多绕路。最简单的办法就是先跑起来,再用下面的命令看当前MySQL驱动版本和MyBatis版本是否与预期一致。
2.2 最基础的配置:application.yml里的日志级别
直接给代码,这是我在项目里的最小可用配置:
yaml复制spring:
datasource:
url: jdbc:mysql://localhost:3306/demo_db?useUnicode=true&characterEncoding=utf8
username: root
password: demo
driver-class-name: com.mysql.cj.jdbc.Driver
logging:
level:
root: info
com.example.project.mapper: debug
logging.level的作用就是给指定的Logger设置日志级别。com.example.project.mapper是你Mapper接口所在的包,例如com.example.project.mapper.UserMapper。当MyBatis执行这条Mapper对应的SQL时,Preparing、Parameters、Total等日志都会以DEBUG级别输出到控制台。
如果你是Spring Data JPA项目,则把Logger名称换成org.hibernate.SQL: debug,同时为了看到参数值,还要加一条org.hibernate.type.descriptor.sql.BasicBinder: trace。这一对配置在官方文档里经常出现,但很多人只设置了第一行,结果只看到SQL带?占位符,看不到参数,误以为是配置失效。
设置级别之后最好重启服务跑一个接口验证一下。注意,root: info是基础日志级别,它会决定全局输出,某个包单独提升为debug后,只有那个包内的日志会打印更详细的信息,不会影响其他模块。
2.3 logback-spring.xml如何被加载
Spring Boot项目默认会在classpath下查找logback-spring.xml或logback.xml,找到后就会用它替换默认日志配置。两者相比,强烈推荐logback-spring.xml,因为它支持Spring Boot的springProfile标签,可以按环境激活不同配置,而logback.xml是Logback原生配置,无法直接使用Spring的profile机制。
如果你的日志配置文件放在外部,也想让Spring Boot识别,需要在application.yml里指定:
yaml复制logging:
config: file:/data/config/logback-spring.xml
注意,这个优先级高于classpath下的同名文件。我一般在生产环境把日志文件路径放到/data/logs,然后通过这个外部配置启动,方便运维直接修改滚动策略,而不需要重新打镜像。
还有一个容易被忽略的点:如果classpath下同时存在logback.xml和logback-spring.xml,Spring Boot会优先使用logback-spring.xml。但如果你引入了某些第三方组件,里面自带logback.xml,就会造成冲突。排查手段很简单,启动日志里如果出现No appenders could be found for logger或者logback.xml ignored之类提示,就要考虑是不是依赖冲突了。
3. 使用配置文件打印SQL日志和结果
3.1 先确认持久层框架把日志写到了哪个Logger
很多人配置日志级别后看不到SQL,第一个原因就是Logger名称写错了。MyBatis在打印SQL时,日志名并不是固定的org.apache.ibatis,而是Mapper接口的全限定名。比如你的Mapper是com.example.project.mapper.UserMapper,那就要设置logging.level.com.example.project.mapper.UserMapper: debug;但更省事的做法是直接设置包名com.example.project.mapper: debug,整个包下所有Mapper都会生效。
如果项目里既有单表CURD又有XML里写的复杂SQL,它们的Logger都指向同一个Mapper接口全限定名,所以包名设置能覆盖全部。而对于MyBatis-Plus,情况又稍微不同,它内部会额外使用com.baomidou.mybatisplus.core.override等Logger打印一些缓存和动态SQL信息,主SQL仍然通过Mapper接口名输出。
可以用一个快速验证法:先临时把logging.level设置成debug,然后执行任意一条CRUD操作,控制台如果仍然没有日志,再把logging.level.org.mybatis: debug加上,基本就能定位是框架自身的问题还是业务配置的问题。这里的核心思路是“由外到内”,先看框架底层日志,再看业务包日志。
3.2 MyBatis日志实现的选择:StdOutImpl、Slf4jImpl、NoLoggingImpl
配置文件方案里,还有一个常见的隐藏开关是MyBatis的log-impl。它决定MyBatis把日志交给谁处理。在application.yml里加这一段:
yaml复制mybatis:
configuration:
log-impl: org.apache.ibatis.logging.slf4j.Slf4jImpl
这里有几个可选值:
org.apache.ibatis.logging.stdout.StdOutImpl:直接输出到标准控制台,格式固定为==> Preparing、==> Parameters,调试临时用非常直观,但不会走Logback的Appender,也无法输出到指定文件。org.apache.ibatis.logging.slf4j.Slf4jImpl:通过SLF4J输出到统一日志框架,推荐在正式项目里使用。org.apache.ibatis.logging.nologging.NoLoggingImpl:彻底关闭MyBatis的SQL日志,误设置后看起来像是日志配置完全失败,其实是被这个开关关了。
我自己在实际项目里的经验是,开发阶段为了追求直观,优先用StdOutImpl;一旦需要把SQL单独写进文件,或者要和业务日志一起沉淀分析时,就切换到Slf4jImpl。因为StdOutImpl绕过Logback,很多团队会发现console能看到SQL但文件里没有,就是这个原因。
还有一个容易被忽略的细节:在Spring Boot 3.x下,如果你是手动配置的DataSource而不是用自动装配,MyBatis的log-impl可能不生效。这时需要检查是否有自定义的数据源配置覆盖了MyBatis的Configuration。如果发现不生效,把log-impl移到mybatis.configuration和mybatis-plus.configuration两处,避免整合包之间互相覆盖。
3.3 打印SQL参数与结果集的正确姿势
当debug级别开启后,你会在控制台看到类似这样的输出:
code复制==> Preparing: select id, user_name, phone from sys_user where id = ?
==> Parameters: 1001(Long)
<== Columns: ID, USER_NAME, PHONE
<== Row: 1001, zhangsan, 13800001111
<== Total: 1
其中Preparing是预编译SQL,Parameters是参数值,Columns和Row是查询结果的元数据和具体行内容,Total是返回行数。看到这个完整链条,你才算是真正“看到结果”了。
不过要注意,这套完整输出是有条件的。MyBatis的日志实现里,ResultSetHandler在输出Row内容时,会根据查询列数、字段类型等决定是否全部输出。如果遇到大字段(比如TEXT、BLOB),它可能只输出部分或直接跳过。真正常见的结果集日志看不到,是因为你没有打开足够低的日志级别。我在3.5.x版本里测试,只有debug级别就能看到Columns和Row,但在某些2.x版本里可能需要trace级别。所以如果你设置了debug仍然看不到行内容,可以临时把包级别调到trace试试。
这里有几个实操建议:
- 开发联调阶段使用
StdOutImpl加debug,看完整输出最省事。 - 结果集字段很多时,
Row日志会非常长,尽量在单行查询场景下使用。 - 不要在并发请求高峰期全量打开结果集日志,否则控制台会被刷爆,定位问题反而更困难。
4. 使用Logback定制SQL日志输出
4.1 为什么有了配置文件还要写logback-spring.xml
只靠application.yml,你能控制的只有日志级别,但无法做到“把SQL单独存到一个文件”。在大项目里,业务日志和SQL日志混在一起,排查问题时来回翻非常痛苦。再加上格式化需求、按天滚动、异步写入、脱敏处理,这些都必须靠Logback配置来实现。
就拿“按天滚动”来说,数据库每天产生的SQL日志可能有几百兆,如果不及时滚动清理,磁盘迟早满。而Logback的RollingFileAppender天然支持按天切分文件和保留天数,这些能力在application.yml里是没法直接做的。
另一个更实际的场景是:团队里分工明确,后端只关心业务日志,DBA只关心慢SQL日志。如果能把SQL单独写到sql.log,DBA直接拿这个文件做分析,效率会高很多。所以自定义logback-spring.xml不是炫技,而是工程化的需要。
4.2 一个可直接使用的logback-spring.xml模板
这里给出一份我常用的配置,注释都写在里面了,复制后改一下包名即可使用:
xml复制<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<!-- 从Spring配置里读取应用名和日志路径,支持外部覆盖 -->
<springProperty scope="context" name="appName" source="spring.application.name" defaultValue="demo-app"/>
<property name="LOG_HOME" value="${LOG_HOME:-./logs}"/>
<!-- 控制台输出 -->
<appender name="CONSOLE" 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>
</appender>
<!-- SQL日志独立文件,按天滚动,保留30天 -->
<appender name="SQL_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${LOG_HOME}/sql.log</file>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>${LOG_HOME}/sql.%d{yyyy-MM-dd}.log</fileNamePattern>
<maxHistory>30</maxHistory>
</rollingPolicy>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%thread] %logger{40} - %msg%n</pattern>
<charset>UTF-8</charset>
</encoder>
</appender>
<!-- 专门接管Mapper包的SQL日志,避免重复打印 -->
<logger name="com.example.project.mapper" level="DEBUG" additivity="false">
<appender-ref ref="CONSOLE"/>
<appender-ref ref="SQL_FILE"/>
</logger>
<!-- root配置保持INFO,不影响其他模块 -->
<root level="INFO">
<appender-ref ref="CONSOLE"/>
</root>
</configuration>
这份配置的核心思路是:先定义两个Appender,一个给控制台,一个给SQL文件;然后把com.example.project.mapper这个Logger的级别设为DEBUG,并且additivity="false",意味着这条日志不会继续传递给root,也就不会在业务日志文件里重复出现。
additivity是个关键属性,我在早期配置时就没设,结果SQL日志同时出现在控制台、业务文件、SQL文件三个地方,排查时总觉得是重复输出。设置成false后,SQL日志只走自己指定的Appender,干净很多。
4.3 过滤SQL日志格式与内容的小技巧
在实际使用中,你会发现默认的Pattern还会把Java类名、线程号等都打出来,这些信息有时候是噪音。我通常会在SQL文件的Pattern里只保留时间、级别和消息内容,例如:
code复制%d{HH:mm:ss.SSS} %-5level %msg%n
如果SQL是XML里写的大型动态语句,打印出来会带有换行符,一眼看上去很乱。可以用%replace(%msg){'\n', ' '}把换行替换成空格,如下:
xml复制<pattern>%d{HH:mm:ss.SSS} %-5level %replace(%msg){'\n', ' '}%n</pattern>
这个技巧在排查动态SQL时特别有用,所有WHERE条件会拼接成一行,方便阅读。注意,%replace是Logback 1.1.8以后才有的,Spring Boot内置版本都满足,不需要额外处理。
另外,如果项目里用了MyBatis-Plus,它的SQL日志Logger名可能是com.baomidou.mybatisplus.extension.parsers等。想统一收集,可以在Logback里再加一个Logger,或者直接把MyBatis-Plus的包也纳入SQL_FILE。我一般更倾向于只保留Mapper业务包,避免MyBatis-Plus的一些缓存初始化日志混入SQL文件。
4.4 多环境配置与动态调整
生产环境和开发环境对SQL日志的需求完全相反。开发环境必须全量打印,生产环境最好默认不打印。借助logback-spring.xml里的springProfile标签,可以写两套配置:
xml复制<springProfile name="dev">
<logger name="com.example.project.mapper" level="DEBUG" additivity="false">
<appender-ref ref="CONSOLE"/>
<appender-ref ref="SQL_FILE"/>
</logger>
</springProfile>
<springProfile name="prod">
<logger name="com.example.project.mapper" level="INFO" additivity="false">
<appender-ref ref="SQL_FILE"/>
</logger>
</springProfile>
这样做的效果是:dev环境控制台和文件都能看到完整SQL;prod环境SQL日志被限制在INFO级别,MyBatis的debug级SQL语句不会输出,只有项目中主动通过log.info打印的SQL摘要才会进入文件。当生产环境真需要排查时,通过启动命令临时覆盖级别即可,不用改代码:
bash复制java -jar app.jar --logging.level.com.example.project.mapper=debug
这种动态调整方式比改代码重启快得多,特别适合线上应急。不过要注意,线上临时开debug后记得及时关掉,否则日志量可能在几小时内把磁盘占满。我踩过一次坑,一个订单查询接口高峰期QPS约500,开了debug后单日日志超过10GB,差点把服务器磁盘写满。
5. 进阶玩法:用p6spy打印可执行SQL与完整结果
5.1 配置文件方案的边界在哪里
看到这里,你可能已经发现配置文件方案的局限:MyBatis打印的是预编译SQL和参数分开的形式,要拼成可直接执行的SQL还得自己操作;结果集内容又受日志级别和驱动版本影响,不一定能完整输出。更关键的是,MyBatis的SQL日志发生在业务代码调用Executor之后,你能看到的是最终SQL,但无法统一统计所有数据库操作的耗时,更没法做慢SQL告警。
这时候就需要把日志采集点下移到JDBC层,p6spy就是干这个的。它通过JDBC驱动代理,在真正的数据库驱动执行前后拦截SQL,拿到完整的语句、参数、耗时、结果集元数据。好处是无论你底层用MyBatis、JPA还是原生JDBC,都能统一魔法般打印出完整SQL,业务代码完全无感。
当然代价是引入一个额外的代理驱动。生产环境是否要长期挂着p6spy,取决于团队容忍度和磁盘成本。我的经验是,预发环境可以一直开着,生产环境平时关掉,只有慢SQL告警时临时打开,配合独立的日志文件分析一次。
5.2 p6spy依赖和配置步骤
先说依赖,用官方starter最省事:
xml复制<dependency>
<groupId>com.github.gavlyukovskiy</groupId>
<artifactId>p6spy-spring-boot-starter</artifactId>
<version>1.9.0</version>
</dependency>
然后修改数据源连接串和驱动:
yaml复制spring:
datasource:
url: jdbc:p6spy:mysql://localhost:3306/demo_db?useUnicode=true&characterEncoding=utf8
driver-class-name: com.p6spy.engine.spy.P6SpyDriver
如果不想改连接串,也可以保持原driver,在配置里加上p6spy的Spring Boot自动配置属性,但总体上改url是最直观的方法。启动后如果看到p6spy相关的初始化日志,说明代理已经生效。
接下来在src/main/resources下新增spy.properties:
properties复制modulelist=com.p6spy.engine.spy.P6SpyFactory,com.p6spy.engine.logging.P6LogFactory,com.p6spy.engine.outage.P6OutageFactory
appender=com.p6spy.engine.spy.appender.Slf4JLogger
logMessageFormat=com.p6spy.engine.spy.appender.CustomLineFormat
customLogMessageFormat=%(currentTime) | took %(executionTime) ms | %(category) | connection %(connectionId) | SQL: %(sql) | params: %(parameters)
excludecategories=info,debug,commit,rollback
deregisterdrivers=true
这里简单解释一下关键项。appender选择Slf4JLogger,p6spy的日志会交给SLF4J,最终统一由Logback处理。customLogMessageFormat定义输出模板,其中%(executionTime)是执行耗时,%(sql)是完整SQL,%(parameters)是参数。excludecategories排除了无意义的类别,比如事务的commit、rollback和内部debug信息。
配置完成后重启项目,任意执行一条查询,日志会变成类似下面这样:
code复制2024-05-20 11:24:33.562 INFO 12345 --- [http-nio-8080-exec-1] com.p6spy.engine.spy.P6SpyDriver : 2024-05-20 11:24:33 | took 12 ms | statement | connection 10 | SQL: select id, user_name, phone from sys_user where id = 1001 | params: []
这条日志最大的意义是SQL参数已经内联到语句里,复制出来就能直接在数据库客户端执行,排查结果集是否符合预期时特别方便。
5.3 怎么让p6spy打印结果集和行数
p6spy默认不会把每行ResultSet的内容都打出来,它主要打印执行耗时和SQL。如果你想看查询结果,需要把spy.properties里的excludecategories中移除result类别,同时确保appender输出模板里带上%(result)字段。
例如:
properties复制excludecategories=info,debug,commit,rollback
customLogMessageFormat=%(currentTime) | took %(executionTime) ms | %(category) | rows %(result) | SQL: %(sql) | params: %(parameters)
这样p6spy在select语句执行后会把返回行数和结果集概要带到日志里。但据我实测,%(result)对常见JDBC驱动能输出行数,对某些老驱动可能会输出[ResultSet@...]的引用,可读性一般。如果你必须看每一行字段内容,建议使用自定义MyBatis拦截器,而不是硬抠p6spy的输出格式。
另外要强调,p6spy的result类别如果全量输出,日志量会非常夸张。我在一个列表查询接口上开了result输出,一次查询返回500行,日志瞬间增加了上百KB,控制台都卡顿。所以生产环境千万不能开result。
5.4 自己写MyBatis拦截器打印完整SQL和结果集
如果项目里不想引入额外依赖,或者需要完全可控的输出格式,可以在MyBatis的Executor层写一个拦截器。它体积不大,但能解决参数和结果集打印的痛点。
下面是一个简化版示例,实现了查询和更新方法的耗时与SQL打印:
java复制@Intercepts({
@Signature(type = Executor.class, method = "query",
args = {MappedStatement.class, Object.class, RowBounds.class, ResultHandler.class}),
@Signature(type = Executor.class, method = "update",
args = {MappedStatement.class, Object.class})
})
public class SqlLogInterceptor implements Interceptor {
private static final Logger log = LoggerFactory.getLogger(SqlLogInterceptor.class);
@Override
public Object intercept(Invocation invocation) throws Throwable {
MappedStatement ms = (MappedStatement) invocation.getArgs()[0];
Object parameter = invocation.getArgs()[1];
BoundSql boundSql = ms.getBoundSql(parameter);
String sql = getPrintableSql(boundSql);
long start = System.currentTimeMillis();
Object result = invocation.proceed();
long cost = System.currentTimeMillis() - start;
log.info("cost={}ms | sql={}", cost, sql);
return result;
}
private String getPrintableSql(BoundSql boundSql) {
return boundSql.getSql().replaceAll("\\s+", " ");
}
}
还没完,如果要打印完整参数,还需要解析boundSql.getParameterObject()和additionalParameters。手写这个解析逻辑比较繁琐,我一般借助MyBatis的MetaObject来遍历对象属性,或者直接用JSON序列化工具打印参数。
结果集打印可以在这个拦截器里对result做一次大小判断,如果返回的是List且长度小于50,再逐行输出;大于50就只打印总数,避免日志刷屏。这个“行数阈值”是我强烈推荐加上的,因为真实业务里没人想看全量500行结果,大家只关心数量和是否为空。
5.5 慢SQL阈值监控与告警
慢SQL是另一个高频需求。p6spy里自带outage模块,当SQL执行时间超过阈值时,会单独打印一条告警日志。对应配置:
properties复制outagedetection=true
outagedetectioninterval=2000
outagedetectioninterval单位是毫秒,这里配置的是超过2秒判定为慢SQL。同时配合logMessageFormat模板里的%(executionTime),alert日志会明确指出哪条SQL超过了阈值。
如果是自定义拦截器,只需要在耗时计算后加一个判断:
java复制if (cost > 2000) {
log.warn("slow sql cost={}ms | sql={}", cost, sql);
}
我通常会把慢SQL日志级别定为WARN,这样在Logback里可以单独建一个WARN_FILE,只收集WARN及以上日志,DBA每天看一眼就能掌握全局慢SQL情况。这个组合比单纯开debug打印SQL高级很多,也更容易在团队里落地。
6. 常见问题排查与避坑实录
6.1 明明配置了debug,SQL日志就是不出现
这是出现频率最高的问题。我在多个项目里排查过,原因基本逃不出以下清单:
- Logger名称写错。确认Mapper接口实际包名,特别是多模块项目里容易把
com.xxx.app.mapper写成com.xxx.mapper。 - 日志级别被Logback覆盖。自定义
logback-spring.xml里的root或某个logger可能把包级别压回INFO,必须确保logger的level设置正确。 - MyBatis的
log-impl被设置成NoLoggingImpl。检查所有配置文件、注解,甚至启动参数。 - Spring Boot多环境配置导致
logging.level被prod环境覆盖。确认当前激活的profiles是哪个。 - 自定义数据源没有走MyBatis的自动配置,导致SqlSessionFactory里的Configuration没有读取
application.yml中的log-impl。
排查顺序建议:先看启动日志里有没有加载logback-spring.xml,确认配置文件生效;再用logging.level.org.apache.ibatis: debug试一次,如果这个能打出SQL而业务包名不行,就是Logger名称问题;最后查看数据库连接池是否被自定义类接管。
这里给一个粗暴但有效的兜底方法:临时在application.yml里把root级别调成debug,虽然日志会爆炸,但能快速确认SQL日志本身是否能产生。确认之后再缩回到包级别,缩小排查范围。
6.2 SQL打印出来了,但参数全是?,看不到具体值
严格来说,MyBatis的日志里Parameters行就是参数值,只是它不会自动拼进SQL字符串。比如:
code复制==> Preparing: select * from user where id = ? and name = ?
==> Parameters: 1001(Long), zhangsan(String)
你应该看Parameters那一行,而不是在SQL行后面找参数。很多开发者习惯把两行当成一个断句,没有意识到参数已经单独打出来了。如果连Parameters都没有,多半是日志级别只到了debug但MyBatis版本较老,需要调到trace。
想看到真正内联的完整SQL,最省事的方式就是引入p6spy。如果你不引p6spy,也可以自己写一个简单的SQL参数替换工具,把?按顺序替换成参数值,但要注意字符串类型加引号、日期类型格式化,否则拼接后还是不能执行。这个工具我写过一次,后来换到p6spy就删掉了,因为驱动代理方案能拿到真实参数类型,比自己解析安全得多。
6.3 结果集日志刷屏,日志文件几小时爆掉
结果集打印是把双刃剑。全量打印Row信息会让你看清数据,但遇到列表接口、报表接口,一次查询几千行,日志体量会非常可怕。我见过一个同事为了排查数据问题,把SQL日志级别开到trace跑了半天,下午服务器磁盘就满了。
处理方式有三个:
- 开发环境可以保留结果集日志,但联调和生产环境一定要关掉。
- 用自定义拦截器限制结果集打印行数,超过阈值只打印
rows=500,不打印内容。 - p6spy不要开
result类别,只保留SQL和执行耗时。
第三条是我在长期使用中总结出来的比较平衡的方案:结果集用本地测试时单独开,其他环境保持关闭。如果真需要线上确认某条数据,用p6spy打印的完整SQL复制到数据库客户端手动执行一次也行,不见得非要在日志里看。
6.4 生产环境日志包含敏感数据怎么办
SQL参数里经常出现手机号、身份证号、用户真实姓名。这些数据一旦进入日志文件,后续被运维或第三方看到,就构成数据安全风险。尤其是生产环境,日志文件可能被采集系统同步到日志平台,敏感信息等于被复制了多份。
我建议遵循几个基本原则:
- 生产环境默认不打印SQL参数,使用
info级别只输出摘要或执行耗时。 - 如果必须打印,p6spy的
customLogMessageFormat里去掉%(parameters)字段,只保留SQL语句,或者对参数做脱敏后再输出。 - 自定义Interceptor日志中,对某些关键词(手机号、身份证)做正则替换。
脱敏可以自己写一个简单的工具类,比如判断参数是手机号就用前三位后四位打码,是身份证就用前六后四打码。不要觉得这些细节无所谓,真到了数据合规审查时,日志里的敏感字段就是实打实的漏洞。
6.5 日志打印带来的性能开销如何控制
每条SQL执行时都输出日志,确实会有性能损耗,尤其是在高频接口上。Logback本身有异步Appender机制,可以把写磁盘的操作放到单独线程,减少对业务线程的阻塞:
xml复制<appender name="ASYNC_SQL_FILE" class="ch.qos.logback.classic.AsyncAppender">
<appender-ref ref="SQL_FILE"/>
<queueSize>1024</queueSize>
<neverBlock>true</neverBlock>
</appender>
queueSize是队列容量,neverBlock=true表示队列满时丢弃日志而不是阻塞业务线程,避免日志成为性能瓶颈。但异步意味着可能有少量日志丢失,不适合对日志完整性有硬性要求的场景。
我的实际经验是,开发环境不需要异步,直接同步输出方便实时看;生产和预发环境如果长期开SQL日志,一定要用异步Appender,并且把日志级别控制在INFO或WARN,不要开debug。
6.6 常见问题速查表
| 症状 | 可能原因 | 快速解决 |
|---|---|---|
| 配置debug后无SQL输出 | Logger名称错误 / log-impl为NoLogging | 打印org.apache.ibatis的debug,确认框架层有日志 |
| 只看到SQL,没有参数 | 日志级别不够低 / MyBatis版本差异 | 包级别改为trace,或p6spy内联参数 |
| 结果集内容看不到 | MyBatis未开启trace / 使用StdOutImpl | 临时开trace,调用完成后恢复 |
| 日志重复输出 | additivity未设false | logger上增加additivity="false" |
| 文件日志爆炸 | 结果集日志打开 / 生产环境未关闭debug | 关闭result输出,限制日志级别 |
| 线上临时排查慢SQL | 没有执行耗时统计 | 使用p6spy outagedetection或自定义拦截器打WARN |
写在最后
我个人在实际项目里最常用的组合是:开发环境用Logback把SQL日志独立输出到控制台和sql.log,MyBatis的log-impl设为Slf4jImpl;联调环境切到p6spy,查看完整可执行SQL和执行耗时;生产环境默认不打印SQL日志,仅在排查慢SQL时通过启动参数临时打开logging.level,同时用自定义拦截器把超过2秒的WARN级SQL单独落盘。这组配置让我在多个项目里少走了很多弯路,也从来没有遇到过“日志刷爆磁盘”的尴尬。如果你也打算把SQL日志做得更精细,建议从最小配置开始,先解决“看不见”的问题,再逐步增加格式化、脱敏和慢SQL告警,别一上来就上重型方案。
