MyBatis拦截器实战：打印SQL执行方法、SQL与耗时排查慢查询

做后端这几年，我几乎每次排查接口慢、数据查不对的问题，第一反应都是先看 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”手段，我挨个试过，各有各的局限，整理成表格大家看得更清楚。

上面对比下来会发现，其实最能贴合需求的，还是自己写一个 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}) })

有个细节：在新版 MyBatis（3.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 方法返回的是 List，update 方法返回的是 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); } List<ParameterMapping> 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我推荐用字符数组按顺序扫，找到第 idx+1 个?再做替换。如果只写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 (?)，参数是 List，MyBatis 会在解析 SQL 时把IN (?)展开为IN (?, ?, ?)，同时 parameterMappings 也会相应地生成多条记录。上面“按顺序找问号”的逻辑天然能处理这种情况。也就是说，你 diffs 不需要关心 foreach 展开，只用 ParameterMapping 列表逐条替换占位符就行。

但有一个边界情况：如果参数本身是 List/数组，直接传给 Mapper 方法，比如selectByIds(List<Integer> 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 interceptor="com.example.interceptor.SqlExecutionInterceptor"> <property name="maxSqlLength" value="1000"/> </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 name="com.example.interceptor.SqlExecutionInterceptor" level="INFO"> <appender-ref ref="CONSOLE"/> <appender-ref ref="SQL_FILE"/> </logger>

SQL_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 高频问题汇总表

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。

我实现过一种简单玩法：用ConcurrentHashMap<String, SlowSqlStat>，key 是 MappedStatement 的 id，value 统计次数、最大耗时、平均耗时。每 5 分钟打一条汇总日志，格式大概是：

慢SQL统计: 方法=OrderMapper.selectOrderDetailById 次数=12 最大耗时=2300ms 平均耗时=876ms

这种汇总日志特别适合汇报性能优化成果。你把优化前后的平均耗时放在一起对比，数字直接说话。

6.2 配合定位 N+1 查询问题

N+1 问题是 MyBatis 关联查询里最隐蔽的性能杀手。表面上你调用了一个查询，实际上 MyBatis 内部可能会循环发出 N 条额外 SQL。控制台平时只打一条 SQL 看不出来，但加上我们的拦截器后，执行一个方法时连续打印多条 SQL，N+1 一下就暴露了。

我遇到过这样一个案例：某接口查询一批订单，返回结果是 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 认识又深了一层。