做后端这几年我几乎每次排查接口慢、数据查不对的问题第一反应都是先看 MyBatis 到底执行了什么 SQL。但早期我的项目里一没配日志、二没加拦截器控制台干干净净翻到数据库端去查慢查询日志又费劲一条条对上接口里的方法更痛苦。后来我专门花时间整理了一套方案把“Mybatis 控制台打印 SQL 执行信息执行方法、执行 SQL、执行时间”这件事彻底落地现在排查问题的效率高了不少。这篇文章不是讲怎么配一个现成插件而是把整个实现思路、完整代码、接入方式、坑位排查一次性讲透适合做 Java 后端并且正在用 MyBatis 或 MyBatis-Plus 的朋友。不管你是想把 SQL 打出来调试还是想定位慢 SQL这套方案都能直接抄作业。1. 先说清楚要解决什么以及为什么不直接用现成方案1.1 痛点拆解打印 SQL 不只是“看到 SQL”很多人一开始觉得打印 SQL 就是把 SQL 字符串输出到控制台其实真正要解决的是三个问题。第一个问题是可读性。默认的 MyBatis 日志只打印预编译语句和参数形如SELECT * FROM user WHERE name ? AND age ?后面跟着独立的 Parameters 列表。小项目还能忍稍微复杂一点的 SQL 里十几个占位符眼睛看一遍根本对不上哪个值对应哪个条件。第二个问题是归属。数据库慢查询日志能告诉你 SQL 本身慢但不会告诉你这条 SQL 是哪台机器、哪个线程、哪个 Mapper 方法发出来的。接口慢了想定位到代码层中间要绕不少圈子。第三个问题是时间。MySQL 的 slow log 有 threshold 阈值默认 10 秒你这个接口慢是慢在 800 毫秒还是 3 秒日志根本不打。上面这几个信息凑不齐排查效率就上不去。所以这套方案要输出的信息至少包含执行方法的全限定名也就是 Mapper 接口 方法名、完整可执行的 SQL占位符已经被替换成真实参数值、SQL 执行耗时。有这三样绝大多数问题都能一眼定位。1.2 为什么现成方案不够用市面上不是没有现成的“打印 SQL”手段我挨个试过各有各的局限整理成表格大家看得更清楚。方案能打印不足配置 log-impl 为 StdOutImplSQL 预编译语句、参数列表耗时不准、方法归属不直观、无法格式化输出MyBatis-Plus 旧版 PerformanceInterceptorSQL、耗时已废弃不能打印方法名参数替换也不完整p6spy 代理数据源SQL、耗时需要额外引入依赖和配置数据源拦截的是 JDBC 层拿不到 Mapper 方法名Druid StatFilterSQL、执行次数、慢 SQL面向连接池维度控制台输出依赖监控页面不适合日常看日志上面对比下来会发现其实最能贴合需求的还是自己写一个 MyBatis 拦截器。它天然能拿到 MappedStatement、BoundSql、ParameterHandler 这些内部对象方法名、SQL、耗时都能打印得规规矩矩而且对业务代码零侵入。这也是我这套方案的最终选择。1.3 为什么选自定义拦截器拦截 Executor 而不是别的对象MyBatis 的执行链路大致是Mapper 接口代理 - SqlSession - Executor - StatementHandler - ParameterHandler / ResultSetHandler。打印 SQL 执行信息最合适的位置就是 Executor。拦截 Executor 的好处是它是整个执行的入口query 和 update 都从这里过而且参数对象在里面可以拿到。拦截 StatementHandler 虽然也能拿 SQL但很多场景下拿不到上游方法名MappedStatement 在 Executor 层更顺你还要额外处理新增语句和存储过程的差异。拦截 ParameterHandler 则只适合看参数不适合做整体耗时统计。还有一点要注意不要在业务代码里写日志去记耗时那是最后的手段。用拦截器做所有 Mapper 方法自动生效不需要每写一个方法记一次。2. 前置知识MyBatis 执行链路与拦截器机制2.1 Executor 和 MappedStatement 的关系Executor 是 MyBatis 执行 SQL 的核心接口我们最关心它两个方法query和update。MyBatis 每次执行一条 SQL都会构建一个 MappedStatement里面保存着这条 SQL 对应的 Mapper 方法全限定名也就是 namespace id比如com.example.mapper.UserMapper.selectById、SqlSource、结果映射等。拿到 MappedStatement 之后再通过getBoundSql(param)拿到 BoundSql这里面就有我们要的原始 SQL 字符串和参数映射信息。原始 SQL 是带占位符?的做完参数替换之后就是我们最终要打印的可执行 SQL。2.2 拦截器签名query 和 update 的方法重载写自定义拦截器必须用Intercepts注解声明要拦截的方法签名这一步最容易出错。MyBatis 3.5.x 中 Executor 的query方法有多个重载我们需要拦截的是最常用的一组Intercepts({ Signature(type Executor.class, method update, args {MappedStatement.class, Object.class}), Signature(type Executor.class, method query, args {MappedStatement.class, Object.class, RowBounds.class, ResultHandler.class}) })有个细节在新版 MyBatis3.5.x 之后里Executor 还多了一个带 CacheKey 和 BoundSql 参数的 query 重载如果你在特殊场景下触发了二级缓存命中查询可能还是走旧签名。实际项目中绝大多数方法调用走的是上面这个签名所以先这样配置就够用。如果想覆盖更全可以再补一个带{MappedStatement.class, Object.class, RowBounds.class, ResultHandler.class, CacheKey.class, BoundSql.class}的签名但代码里要做类型判断防止重复打印。2.3 核心可获取信息汇总在拦截器里我们能拿到的关键信息有这几类MappedStatement.getId()完整的方法名例如com.example.mapper.UserMapper.selectByCondition。boundSql.getSql()预编译的原始 SQL带?占位符。parameterHandler.getParameterObject()参数对象可能是 null、简单类型、Map、POJO也可能是集合。boundSql.getParameterMappings()参数映射列表保存了每个占位符对应的属性名、jdbcType 等信息。executor.getTransaction()里的连接信息可以截取出当前数据库连接用来排查连接池是否复用。这些信息足够我们做一次完整、可读的输出。3. 核心实现拦截器完整代码与逐行拆解3.1 拦截器骨架与 Intercepts 配置先给出完整代码骨架后面逐个拆解注意点。Component Intercepts({ Signature(type Executor.class, method update, args {MappedStatement.class, Object.class}), Signature(type Executor.class, method query, args {MappedStatement.class, Object.class, RowBounds.class, ResultHandler.class}) }) public class SqlExecutionInterceptor implements Interceptor { private static final Logger log LoggerFactory.getLogger(SqlExecutionInterceptor.class); Override public Object intercept(Invocation invocation) throws Throwable { long startTime System.nanoTime(); // 用于在异常/正常路径之后打印 String methodInfo ; String sql ; int rowCount 0; boolean success true; String errorMsg ; try { Object target invocation.getTarget(); MappedStatement mappedStatement null; if (target instanceof Executor) { Object[] args invocation.getArgs(); mappedStatement (MappedStatement) args[0]; Object parameter args.length 1 ? args[1] : null; BoundSql boundSql mappedStatement.getBoundSql(parameter); methodInfo mappedStatement.getId(); sql buildExecutableSql(boundSql, parameter); Object result invocation.proceed(); if (result instanceof List) { rowCount ((List?) result).size(); } else if (result instanceof Integer) { rowCount (Integer) result; } return result; } return invocation.proceed(); } catch (Throwable e) { success false; errorMsg e.getMessage(); throw e; } finally { long elapsed (System.nanoTime() - startTime) / 1_000_000; printLog(methodInfo, sql, elapsed, rowCount, success, errorMsg); } } Override public Object plugin(Object target) { return Plugin.wrap(target, this); } Override public void setProperties(Properties properties) { // 可以读取自定义配置比如慢 SQL 阈值 } }这里有一个容易被忽略的点invocation.proceed()之后的返回值query 方法返回的是 Listupdate 方法返回的是 Integer分别记录行数。如果一个方法执行失败我们也要把 SQL 打出来这样能结合异常信息快速定位所以统一放在 finally 里处理不要在处理完正常情况后直接 return 中断。3.2 参数解析把占位符替换成真实值这是整个拦截器最核心也最容易写错的部分。MyBatis 的 BoundSql 里保存了 parameterMappings我们按顺序遍历这个列表再把每个占位符?替换成对应的参数值即可不需要自己去分析#{}这种表达式。下面是我实测稳定的实现private String buildExecutableSql(BoundSql boundSql, Object parameter) throws Exception { String sql boundSql.getSql(); if (parameter null) { return handleParamSet(sql, null, null); } ListParameterMapping mappings boundSql.getParameterMappings(); // 如果没有任何参数映射说明 SQL 无占位符直接返回 if (mappings null || mappings.isEmpty()) { return handleParamSet(sql, null, null); } // 用 MetaObject 解析复杂对象属性兼容 MyBatis 的参数对象结构 Configuration configuration boundSql.getConfiguration(); MetaObject metaObject configuration.newMetaObject(parameter); int idx 0; // 这里不能用 String.replace 或 String.format要从左往右找占位符逐个替换 for (ParameterMapping parameterMapping : mappings) { String propertyName parameterMapping.getProperty(); Object value; if (metaObject.hasGetter(propertyName)) { value metaObject.getValue(propertyName); } else if (parameter instanceof Map ((Map?, ?) parameter).containsKey(propertyName)) { value ((Map?, ?) parameter).get(propertyName); } else { // 简单类型String、Integer、Long 等直接使用参数本身 value parameter; } sql replacePlaceholder(sql, value, idx); idx; } return sql; }这里有个小坑循环里第 idx 个占位符替换完后SQL 里剩余问号的位置会变化所以必须找一个替换对应的占位符。上面代码的replacePlaceholder我推荐用字符数组按顺序扫找到第 idx1 个?再做替换。如果只写sql.replaceFirst(\\?, ...)遇到 SQL 文本里其他问号会出错比如存储过程调用、字符串常量里的问号。replacePlaceholder的核心逻辑是这样private String replacePlaceholder(String sql, Object value, int targetIndex) { int count 0; int pos 0; int start -1; while ((start sql.indexOf(?, pos)) ! -1) { if (count targetIndex) { String formattedValue formatValue(value); return sql.substring(0, start) formattedValue sql.substring(start 1); } count; pos start 1; } return sql; }formatValue负责把值转成 SQL 里可以直接执行的字符串private String formatValue(Object value) { if (value null) { return NULL; } if (value instanceof Number) { return value.toString(); } if (value instanceof Boolean) { return value.toString(); } if (value instanceof java.util.Date) { // 这里按自己项目需要的格式输出只要在 SQL 里能用单引号包起来 return new SimpleDateFormat(yyyy-MM-dd HH:mm:ss).format(value) ; } if (value instanceof String) { // 字符串里如果有单引号SQL 中用两个单引号转义 String v (String) value; return v.replace(, ) ; } // 枚举、其他类型统一走 toString return String.valueOf(value) ; }我个人建议字符串和日期都加单引号这样打印出来的 SQL 放到数据库客户端里直接能跑不用再手动补引号。3.3 关于 foreach 和集合参数的注意点很多时候 SQL 里是IN (?)参数是 ListMyBatis 会在解析 SQL 时把IN (?)展开为IN (?, ?, ?)同时 parameterMappings 也会相应地生成多条记录。上面“按顺序找问号”的逻辑天然能处理这种情况。也就是说你 diffs 不需要关心 foreach 展开只用 ParameterMapping 列表逐条替换占位符就行。但有一个边界情况如果参数本身是 List/数组直接传给 Mapper 方法比如selectByIds(ListInteger ids)metaObject 里不一定有collection这个属性名但 MyBatis 内部映射时用的是collection或list。为了兼容我在上面代码里判断metaObject.hasGetter(propertyName)不通过时会看parameter instanceof Map或直接退回成参数本身。实战中这个方法能解决 99% 的解析问题剩下 1% 是层层嵌套的 Param 对象需要用反射递归解析属性建议遇到再补。3.4 耗时统计与输出格式设计耗时统计我用System.nanoTime()单位换算成毫秒打印。如果系统对高精度时间要求高也可以用 Spring 的StopWatch但对这种场景没什么必要nanoTime 已经足够。打印格式我是这么设计的清爽、信息完整、同事看到也能快速懂 MyBatis SQL 执行信息 方法: com.example.mapper.UserMapper.selectByCondition SQL : SELECT * FROM user WHERE name 张三 AND age 18 AND status 1 耗时: 3 ms 结果: 返回 2 行 printLog方法里把上面这些字段用日志打印。默认走 info 级别如果设置了慢 SQL 阈值超过阈值改成 warn 级别单独提示这样日志系统里 grep 起来非常方便。4. 落地实操接入项目与配置4.1 MyBatis / MyBatis-Plus 整合时注册插件如果你用的是 Spring Boot MyBatis Starter 或者 MyBatis-Plus注册插件最省事的方式是直接定义一个配置类Configuration public class MyBatisConfig { Bean public SqlExecutionInterceptor sqlExecutionInterceptor() { return new SqlExecutionInterceptor(); } Bean public ConfigurationCustomizer configurationCustomizer(SqlExecutionInterceptor sqlExecutionInterceptor) { return configuration - { configuration.addInterceptor(sqlExecutionInterceptor); }; } }如果用的是传统 XML 方式配置 MyBatis需要在 mybatis-config.xml 里加plugins plugin interceptorcom.example.interceptor.SqlExecutionInterceptor property namemaxSqlLength value1000/ /plugin /plugins千万别写死两个注册入口否则 SQL 会被打印两次。Spring Boot 场景下Component加Bean同时存在是最容易踩的重复注册问题。4.2 配置项设计慢 SQL 阈值、打印开关、字段截断这是一个成熟方案该有的样子。我自己在项目里会给拦截器加三个可配置项enable总开关生产环境如果需要临时看 SQL不用改代码重启改配置热刷新即可。slowSqlThresholdMs慢 SQL 阈值比如 500ms超过就 warn 打印。maxSqlLength最大 SQL 长度超过会截断。避免大字段 IN 列表或批量插入把控制台刷爆。在setProperties里读取存放在拦截器成员变量里Override public void setProperties(Properties properties) { if (properties null) { return; } this.enable Boolean.parseBoolean(properties.getProperty(enable, true)); this.slowSqlThresholdMs Long.parseLong(properties.getProperty(slowSqlThresholdMs, 500)); this.maxSqlLength Integer.parseInt(properties.getProperty(maxSqlLength, 1500)); }拦截器最外层加判断if (!enable) return invocation.proceed();这样开关关闭时只多一个 boolean 判断性能损耗可以忽略。4.3 日志框架适配输出到控制台与文件分离拦截器内部不要用System.out.println要统一用 SLF4J。这样你完全可以在生产环境把它打到独立的日志文件本地开发则输出到控制台切换全靠 logback/log4j2 配置。我实际项目里的 logback 配置大概是logger namecom.example.interceptor.SqlExecutionInterceptor levelINFO appender-ref refCONSOLE/ appender-ref refSQL_FILE/ /loggerSQL_FILE 这个 appender 单独滚定到 sql 日志目录滚动策略按天保存最近 30 天。这样做的好处是就算线上出了事故也能从日志文件里翻出当时执行的完整 SQL配合接口入参回放问题非常好用。尤其排查那种偶发性的慢 SQL这种独立日志能救大命。4.4 实测效果打印出来的一行示例我在一个模拟订单查询里跑了真实测试控制台打印效果 MyBatis SQL 执行信息 方法: com.example.mapper.OrderMapper.selectOrderDetailById SQL : SELECT id, order_no, user_id, amount, status, create_time FROM t_order WHERE id 10086 AND status 1 耗时: 2 ms 结果: 返回 1 行 这个输出在本地排查“某条数据查出来和预期不一致”的问题时特别直观。比如你想确认status 1到底有没有生效直接看打印的 SQL一眼就明白。你不需要像以前那样去猜测 MyBatis 组装的 SQL 是什么数据库里做的所有转化和优化现在都明明白白摆在你面前。5. 常见问题与坑位速查5.1 高频问题汇总表问题现象原因分析解决方案拦截器没生效控制台没有任何输出插件未注册或注册了但打印的 logger 级别被过滤检查 MyBatis 配置中是否有 plugin/Interceptor 节点检查 logback 日志级别SQL 被打印两次同一个拦截器实例被同时用 XML 和注解注册或 Spring 容器里有两个实例检查全局配置只保留一种注册方式参数替换后 SQL 无法执行字符串参数没有加单引号日期格式不对统一在formatValue里处理引号和日期格式打印出来的时间明显偏大第一次连接数据库耗时被算进 SQL 耗时连接池预热未处理观察多次执行后的平均值或者忽略第一次执行批量插入的 SQL 太长日志刷屏批量 SQL 展开后可能上万字符配置 maxSqlLength 截断打印或者批处理场景单独关闭完整 SQL 打印存储过程等复杂 SQL 打印异常存储过程里有自定义分隔符、多个问号拦截器仅做简单日志不做 SQL 格式化这类场景建议单独用 JDBC 日志排查5.2 底层细节连接池、事务、批处理的隐藏影响这部分是我踩坑踩出来的经验建议收藏。首先如果你用 Druid 或 HikariCP 连接池并且执行的是同一事务里的多条 SQL它们共享同一个数据库连接第一次连接必须经历建连过程耗时可能到几十毫秒甚至上百毫秒。这时候你看打印出来的耗时是“整体方法耗时”不是“纯 SQL 执行耗时”容易产生误判。为了减少误解我一般会在耗时后面加一个“含连接获取”备注同时提醒排查慢 SQL 时多看几次循环执行的平均值。其次事务里的多条 SQL 因为连接复用后面的 SQL 相对更快。如果你想比较两个 SQL 谁更慢尽量都放在独立事务或非事务环境里跑否则结果没有可比性。第三批处理场景比如ExecutorType.BATCH批量插入MyBatis 的 update 方法在 flush 之前可能不真正执行 SQL导致单条耗时打印出来的时间异常小。这种情况建议在打印里看到result instanceof Integer时也顺带打印累计批次大小或者干脆对批处理场景不打印单条耗时而是打印一次 flush 的整体耗时。性能开销方面拦截器默认每次执行都会做字符串替换和日志拼接。对绝大多数业务系统来说这个开销是微乎其微的百万级 QPS 系统另说。如果你们是超高频系统建议在生产环境关掉完整 SQL 打印只保留慢 SQL 阈值告警能显著减少日志 I/O 负担。实际测下来一个中等规模服务打印完整 SQL 只会增加 1% 以内的耗时吞吐量影响可以忽略日志文件增长倒是明显需要考虑磁盘空间。6. 进阶扩展让打印工具变成排查利器6.1 慢 SQL 告警与统计只打印已经满足日常需求但我觉得还能更进一步。既然有了耗时数据可以在printLog里做一次慢 SQL 计数把超过阈值的 SQL 累计到一个本地队列定时上报到监控平台。这样即使半夜没有人在看控制台系统也能自动帮你记录最需要关注的 SQL。我实现过一种简单玩法用ConcurrentHashMapString, SlowSqlStatkey 是 MappedStatement 的 idvalue 统计次数、最大耗时、平均耗时。每 5 分钟打一条汇总日志格式大概是慢SQL统计: 方法OrderMapper.selectOrderDetailById 次数12 最大耗时2300ms 平均耗时876ms这种汇总日志特别适合汇报性能优化成果。你把优化前后的平均耗时放在一起对比数字直接说话。6.2 配合定位 N1 查询问题N1 问题是 MyBatis 关联查询里最隐蔽的性能杀手。表面上你调用了一个查询实际上 MyBatis 内部可能会循环发出 N 条额外 SQL。控制台平时只打一条 SQL 看不出来但加上我们的拦截器后执行一个方法时连续打印多条 SQLN1 一下就暴露了。我遇到过这样一个案例某接口查询一批订单返回结果是 100 条但控制台连续打印了 101 条 SQL第一条查订单主表后面 100 条逐条查订单明细。普通日志根本不会把这些 SQL 关联起来看但用我们这套打印输出一眼就能看出来是循环查询导致的问题。配合 6.1 的统计机制还能直接算出这批 SQL 的总耗时给优化方案提供数据支撑。6.3 SQL 脱敏与合规打印 SQL 方便归方便但要注意隐私安全。如果表里有手机号、身份证号这类敏感字段直接拼参数打印出来会有合规风险。我建议在formatValue里做一层脱敏比如手机号只保留前 3 后 4 位其他字符用*代替。生产环境必须开启脱敏本地开发环境可以看原始值。脱敏实现也不复杂在formatValue里对特定 key 或特定类型的字符串做判断比如属性名包含 phone、mobile、idcard 之类的字段直接替换if (propertyName.contains(phone) || propertyName.contains(mobile)) { return maskMobile(value.toString()) ; }注意 setProperties 里也可以配置脱敏开关默认环境变量决定这样日志文件和监控平台里不会出现敏感信息既有追溯能力又符合数据安全要求。结尾一点个人经验这套拦截器方案我已经在多个项目里用了一年多从最开始只打印 SQL到后来加上慢 SQL 统计、脱敏、批量占位符替换这些能力都是被实际问题一步一步逼出来的。中间踩过最大的坑就是参数解析早期图省事直接拿parameter.toString()塞到 SQL 里结果碰到 Param 和 POJO 混用、foreach 展开、枚举类型打印出来完全不是能直接执行的 SQL给排查帮了倒忙。后来老老实实按 ParameterMapping 顺序替换占位符这个问题才彻底根治。如果你也想在自己项目里落地这套方案我的建议是先别追求一次做完所有功能第一步只要能让控制台看到“方法 SQL 耗时”三要素就已经比大多数项目强了。用一段时间后再根据实际排查需要逐步加上慢 SQL 告警、脱敏、独立日志这些能力。这中间还有个小技巧打印出来一段 SQL 后不妨把它直接丢进数据库客户端跑一遍对比一下执行计划你会发现自己对业务系统的 SQL 认识又深了一层。