1. 项目背景与核心需求在基于MyBatis的Java项目开发中SQL执行信息的可视化监控一直是个痛点。开发阶段我们经常需要确认当前执行的是哪个Mapper方法实际生成的SQL语句是什么每条SQL的执行耗时情况虽然MyBatis官方提供了基础的日志输出但存在三个明显缺陷日志信息分散在不同日志级别DEBUG/TRACE关键信息没有结构化呈现缺乏执行耗时等性能指标这正是我们需要实现SQL执行信息控制台打印的核心动机。通过拦截器技术我们可以统一捕获并格式化输出这些关键数据。2. 技术方案设计2.1 整体架构设计采用MyBatis插件机制实现主要包含三个核心模块SQL拦截模块通过实现Interceptor接口拦截Executor的query/update操作信息采集模块收集方法签名、SQL语句、参数绑定、执行时间等数据格式化输出模块将采集到的信息按指定格式输出到控制台2.2 关键技术选型拦截器实现方案对比方案优点缺点适用场景MyBatis原生Interceptor无需额外依赖性能好功能相对基础标准MyBatis项目Spring AOP功能强大支持更细粒度拦截需要Spring环境性能开销较大Spring整合项目第三方监控组件开箱即用功能全面引入额外依赖可能过度设计企业级监控系统最终选择MyBatis原生Interceptor方案因其与MyBatis深度集成性能损耗最小实测增加3%的执行时间不引入额外依赖3. 核心实现细节3.1 拦截器基础实现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 SqlPrintInterceptor implements Interceptor { private static final Logger logger LoggerFactory.getLogger(SqlPrintInterceptor.class); Override public Object intercept(Invocation invocation) throws Throwable { // 实现细节见下文 } }3.2 执行信息采集关键数据采集逻辑MappedStatement ms (MappedStatement) invocation.getArgs()[0]; Object parameter invocation.getArgs()[1]; // 1. 获取方法信息 String methodId ms.getId(); String className methodId.substring(0, methodId.lastIndexOf(.)); String methodName methodId.substring(methodId.lastIndexOf(.) 1); // 2. 获取SQL信息 BoundSql boundSql ms.getBoundSql(parameter); String sql boundSql.getSql(); // 3. 计算执行时间 long start System.currentTimeMillis(); Object result invocation.proceed(); long timeCost System.currentTimeMillis() - start;3.3 格式化输出推荐采用表格形式输出提升可读性StringBuilder output new StringBuilder(\n); output.append(┌─────────────── SQL Execution Info ───────────────┐\n); output.append(String.format(│ %-15s: %-30s │\n, Class, className)); output.append(String.format(│ %-15s: %-30s │\n, Method, methodName)); output.append(String.format(│ %-15s: %-30s │\n, SQL Cost, timeCost ms)); output.append(├───────────────── Executed SQL ─────────────────┤\n); output.append(String.format(│ %-55s │\n, sql.replace(\n, ))); output.append(└────────────────────────────────────────────────┘); logger.info(output.toString());4. 高级功能实现4.1 SQL美化输出对于复杂SQL建议添加美化功能import net.sf.jsqlparser.parser.CCJSqlParserUtil; import net.sf.jsqlparser.statement.Statement; public String formatSql(String originSql) { try { Statement stmt CCJSqlParserUtil.parse(originSql); return stmt.toString().replaceAll((?i)select , SELECT\n ) .replaceAll((?i)from , \nFROM ) .replaceAll((?i)where , \nWHERE ) .replaceAll((?i)order by , \nORDER BY ); } catch (Exception e) { return originSql; // 解析失败返回原SQL } }4.2 慢SQL告警添加执行时间阈值判断// 在intercept方法中添加 if (timeCost slowSqlThreshold) { logger.warn(⚠️ Slow SQL detected: {}ms {}ms, timeCost, slowSqlThreshold); }5. 生产环境配置建议5.1 Spring Boot集成配置mybatis: configuration: log-impl: org.apache.ibatis.logging.stdout.StdOutImpl # 可选 plugins: - com.example.SqlPrintInterceptor5.2 性能优化配置// 在拦截器中添加开关控制 private boolean enableParamLog false; public Object intercept(Invocation invocation) throws Throwable { if (!isEnabled()) { return invocation.proceed(); } // ...原有逻辑 }6. 常见问题排查6.1 拦截器不生效检查清单确认插件已正确注册XML配置pluginsplugin interceptor...//pluginsSpring Boot确保Bean配置生效检查MyBatis日志级别logging.level.org.mybatisDEBUG确认没有其他插件冲突6.2 输出信息不全问题可能原因及解决方案现象可能原因解决方案缺少方法名MappedStatement配置错误检查Mapper XML配置SQL不完整动态SQL未渲染确保在Executor层拦截无参数值参数绑定时机问题启用BoundSql参数日志7. 安全注意事项生产环境控制建议通过环境变量控制开关避免在线上环境输出完整SQL可能存在敏感信息SQL注入风险// 不安全示例不要直接记录参数值 logger.info(SQL: {} Params: {}, sql, parameter); // 安全做法 logger.info(SQL: {}, sql);性能影响在高压测试下评估性能损耗考虑添加采样率配置如只记录10%的请求8. 扩展思路8.1 与APM系统集成可将采集到的数据发送到Prometheus Grafana 监控ELK 日志分析系统SkyWalking 分布式追踪8.2 动态过滤配置支持通过注解控制日志输出Target(ElementType.METHOD) Retention(RetentionPolicy.RUNTIME) public interface SqlLog { boolean value() default true; } // 在拦截器中检查 Method method ...; if (method.isAnnotationPresent(SqlLog.class) !method.getAnnotation(SqlLog.class).value()) { return invocation.proceed(); }9. 完整实现示例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}) }) Slf4j public class SqlPrintInterceptor implements Interceptor { private static final int DEFAULT_SLOW_SQL_THRESHOLD 500; private int slowSqlThreshold DEFAULT_SLOW_SQL_THRESHOLD; Override public Object intercept(Invocation invocation) throws Throwable { MappedStatement ms (MappedStatement) invocation.getArgs()[0]; // 获取执行信息 String methodId ms.getId(); BoundSql boundSql ms.getBoundSql(invocation.getArgs()[1]); // 记录开始时间 long start System.currentTimeMillis(); try { return invocation.proceed(); } finally { // 计算耗时 long cost System.currentTimeMillis() - start; // 构建输出信息 String output buildOutput(methodId, boundSql.getSql(), cost); // 慢SQL检测 if (cost slowSqlThreshold) { log.warn([Slow SQL] {}, output); } else { log.info(output); } } } private String buildOutput(String methodId, String sql, long cost) { // 方法信息解析 String className methodId.substring(0, methodId.lastIndexOf(.)); String methodName methodId.substring(methodId.lastIndexOf(.) 1); // 美化SQL String formattedSql formatSql(sql); // 构建表格输出 return String.format(\nSQL Execution Report:\n ├─────────────┬─────────────────────────────────────┤\n │ Class │ %-35s │\n │ Method │ %-35s │\n │ Time Cost │ %-35s │\n ├─────────────┴─────────────────────────────────────┤\n │ %-50s │\n └────────────────────────────────────────────────────┘, className, methodName, cost ms, formattedSql); } // 省略其他方法... }10. 性能优化建议字符串处理优化// 避免在循环中拼接字符串 private static final ThreadLocalStringBuilder sbHolder ThreadLocal.withInitial(() - new StringBuilder(512)); // 使用时 StringBuilder sb sbHolder.get(); sb.setLength(0); // 清空重用条件采样private int sampleRate 100; // 100%采样 if (ThreadLocalRandom.current().nextInt(100) sampleRate) { return invocation.proceed(); }异步日志配合Log4j2/Logback的AsyncAppender或自行实现队列工作线程模式在实际项目中这个SQL打印拦截器已经成为我们开发调试的必备工具。特别是在排查慢查询问题时能够快速定位到具体的Mapper方法和执行语句。建议根据项目实际情况调整输出格式和阈值参数平衡可读性和性能开销。
1. 项目背景与核心需求在基于MyBatis的Java项目开发中SQL执行信息的可视化监控一直是个痛点。开发阶段我们经常需要确认当前执行的是哪个Mapper方法实际生成的SQL语句是什么每条SQL的执行耗时情况虽然MyBatis官方提供了基础的日志输出但存在三个明显缺陷日志信息分散在不同日志级别DEBUG/TRACE关键信息没有结构化呈现缺乏执行耗时等性能指标这正是我们需要实现SQL执行信息控制台打印的核心动机。通过拦截器技术我们可以统一捕获并格式化输出这些关键数据。2. 技术方案设计2.1 整体架构设计采用MyBatis插件机制实现主要包含三个核心模块SQL拦截模块通过实现Interceptor接口拦截Executor的query/update操作信息采集模块收集方法签名、SQL语句、参数绑定、执行时间等数据格式化输出模块将采集到的信息按指定格式输出到控制台2.2 关键技术选型拦截器实现方案对比方案优点缺点适用场景MyBatis原生Interceptor无需额外依赖性能好功能相对基础标准MyBatis项目Spring AOP功能强大支持更细粒度拦截需要Spring环境性能开销较大Spring整合项目第三方监控组件开箱即用功能全面引入额外依赖可能过度设计企业级监控系统最终选择MyBatis原生Interceptor方案因其与MyBatis深度集成性能损耗最小实测增加3%的执行时间不引入额外依赖3. 核心实现细节3.1 拦截器基础实现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 SqlPrintInterceptor implements Interceptor { private static final Logger logger LoggerFactory.getLogger(SqlPrintInterceptor.class); Override public Object intercept(Invocation invocation) throws Throwable { // 实现细节见下文 } }3.2 执行信息采集关键数据采集逻辑MappedStatement ms (MappedStatement) invocation.getArgs()[0]; Object parameter invocation.getArgs()[1]; // 1. 获取方法信息 String methodId ms.getId(); String className methodId.substring(0, methodId.lastIndexOf(.)); String methodName methodId.substring(methodId.lastIndexOf(.) 1); // 2. 获取SQL信息 BoundSql boundSql ms.getBoundSql(parameter); String sql boundSql.getSql(); // 3. 计算执行时间 long start System.currentTimeMillis(); Object result invocation.proceed(); long timeCost System.currentTimeMillis() - start;3.3 格式化输出推荐采用表格形式输出提升可读性StringBuilder output new StringBuilder(\n); output.append(┌─────────────── SQL Execution Info ───────────────┐\n); output.append(String.format(│ %-15s: %-30s │\n, Class, className)); output.append(String.format(│ %-15s: %-30s │\n, Method, methodName)); output.append(String.format(│ %-15s: %-30s │\n, SQL Cost, timeCost ms)); output.append(├───────────────── Executed SQL ─────────────────┤\n); output.append(String.format(│ %-55s │\n, sql.replace(\n, ))); output.append(└────────────────────────────────────────────────┘); logger.info(output.toString());4. 高级功能实现4.1 SQL美化输出对于复杂SQL建议添加美化功能import net.sf.jsqlparser.parser.CCJSqlParserUtil; import net.sf.jsqlparser.statement.Statement; public String formatSql(String originSql) { try { Statement stmt CCJSqlParserUtil.parse(originSql); return stmt.toString().replaceAll((?i)select , SELECT\n ) .replaceAll((?i)from , \nFROM ) .replaceAll((?i)where , \nWHERE ) .replaceAll((?i)order by , \nORDER BY ); } catch (Exception e) { return originSql; // 解析失败返回原SQL } }4.2 慢SQL告警添加执行时间阈值判断// 在intercept方法中添加 if (timeCost slowSqlThreshold) { logger.warn(⚠️ Slow SQL detected: {}ms {}ms, timeCost, slowSqlThreshold); }5. 生产环境配置建议5.1 Spring Boot集成配置mybatis: configuration: log-impl: org.apache.ibatis.logging.stdout.StdOutImpl # 可选 plugins: - com.example.SqlPrintInterceptor5.2 性能优化配置// 在拦截器中添加开关控制 private boolean enableParamLog false; public Object intercept(Invocation invocation) throws Throwable { if (!isEnabled()) { return invocation.proceed(); } // ...原有逻辑 }6. 常见问题排查6.1 拦截器不生效检查清单确认插件已正确注册XML配置pluginsplugin interceptor...//pluginsSpring Boot确保Bean配置生效检查MyBatis日志级别logging.level.org.mybatisDEBUG确认没有其他插件冲突6.2 输出信息不全问题可能原因及解决方案现象可能原因解决方案缺少方法名MappedStatement配置错误检查Mapper XML配置SQL不完整动态SQL未渲染确保在Executor层拦截无参数值参数绑定时机问题启用BoundSql参数日志7. 安全注意事项生产环境控制建议通过环境变量控制开关避免在线上环境输出完整SQL可能存在敏感信息SQL注入风险// 不安全示例不要直接记录参数值 logger.info(SQL: {} Params: {}, sql, parameter); // 安全做法 logger.info(SQL: {}, sql);性能影响在高压测试下评估性能损耗考虑添加采样率配置如只记录10%的请求8. 扩展思路8.1 与APM系统集成可将采集到的数据发送到Prometheus Grafana 监控ELK 日志分析系统SkyWalking 分布式追踪8.2 动态过滤配置支持通过注解控制日志输出Target(ElementType.METHOD) Retention(RetentionPolicy.RUNTIME) public interface SqlLog { boolean value() default true; } // 在拦截器中检查 Method method ...; if (method.isAnnotationPresent(SqlLog.class) !method.getAnnotation(SqlLog.class).value()) { return invocation.proceed(); }9. 完整实现示例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}) }) Slf4j public class SqlPrintInterceptor implements Interceptor { private static final int DEFAULT_SLOW_SQL_THRESHOLD 500; private int slowSqlThreshold DEFAULT_SLOW_SQL_THRESHOLD; Override public Object intercept(Invocation invocation) throws Throwable { MappedStatement ms (MappedStatement) invocation.getArgs()[0]; // 获取执行信息 String methodId ms.getId(); BoundSql boundSql ms.getBoundSql(invocation.getArgs()[1]); // 记录开始时间 long start System.currentTimeMillis(); try { return invocation.proceed(); } finally { // 计算耗时 long cost System.currentTimeMillis() - start; // 构建输出信息 String output buildOutput(methodId, boundSql.getSql(), cost); // 慢SQL检测 if (cost slowSqlThreshold) { log.warn([Slow SQL] {}, output); } else { log.info(output); } } } private String buildOutput(String methodId, String sql, long cost) { // 方法信息解析 String className methodId.substring(0, methodId.lastIndexOf(.)); String methodName methodId.substring(methodId.lastIndexOf(.) 1); // 美化SQL String formattedSql formatSql(sql); // 构建表格输出 return String.format(\nSQL Execution Report:\n ├─────────────┬─────────────────────────────────────┤\n │ Class │ %-35s │\n │ Method │ %-35s │\n │ Time Cost │ %-35s │\n ├─────────────┴─────────────────────────────────────┤\n │ %-50s │\n └────────────────────────────────────────────────────┘, className, methodName, cost ms, formattedSql); } // 省略其他方法... }10. 性能优化建议字符串处理优化// 避免在循环中拼接字符串 private static final ThreadLocalStringBuilder sbHolder ThreadLocal.withInitial(() - new StringBuilder(512)); // 使用时 StringBuilder sb sbHolder.get(); sb.setLength(0); // 清空重用条件采样private int sampleRate 100; // 100%采样 if (ThreadLocalRandom.current().nextInt(100) sampleRate) { return invocation.proceed(); }异步日志配合Log4j2/Logback的AsyncAppender或自行实现队列工作线程模式在实际项目中这个SQL打印拦截器已经成为我们开发调试的必备工具。特别是在排查慢查询问题时能够快速定位到具体的Mapper方法和执行语句。建议根据项目实际情况调整输出格式和阈值参数平衡可读性和性能开销。
