ARTICLE DETAIL

资讯详情

深耕网站建设与运营推广的一线实战洞察。

MyBatis Plus SQL 日志打印从入门到生产实践:logback、traceId 与 ES 检索

MyBatis Plus SQL 日志打印从入门到生产实践:logback、traceId 与 ES 检索 实际调试过 MyBatis Plus 项目的同学大概率都有过这个经历SQL 一报错控制台满屏异常你盯着那堆堆栈猜参数到底是哪个。搜索「mybatis plus 打印 sql 日志」出来的结果一大半是同一招——往 application.yml 里塞一行log-impl: StdOutImpl。粘完确实能看到 SQL 了但用一阵你就会发现这行配置把 SQL 日志直接拍到了 System.out 上你的日志文件里没有日志采集平台里也没有。这还算轻的更麻烦的是线上出了问题你翻半天找不到 SQL 在哪更别说把一次请求的多条 SQL 串起来了。这篇文章我想把「MyBatis Plus 打印 SQL 日志」这件事从头到尾说透。既讲清楚开发环境怎么快速看到 SQL也讲清楚生产环境怎么让 SQL 日志进入统一日志体系、配上 traceId、最终能在 Elasticsearch 里按一条 traceId 把这次请求涉及的 SQL 全部捞出来。不管你是刚接触 Spring Boot MyBatis-Plus 的新人还是已经在生产环境被日志折腾过几次的 Java 开发应该都能从这里拿到能直接抄的配置和代码。1. 先搞清楚SQL 日志打印这件事到底卡在哪1.1 一条 log-impl 配置能解决什么又掩盖了什么很多开发第一次接触 MyBatis 的 SQL 日志都是从log-impl: org.apache.ibatis.logging.stdout.StdOutImpl这行配置开始的。它的原理非常直白MyBatis 内部定义了一个Log接口StdOutImpl就是这个接口的一个实现把所有日志内容通过System.out直接打到控制台。对本地调试来说这是最省事的路径不需要理解日志框架也不需要调整任何级别SQL 一执行完就往屏幕上一顿输出。但问题也恰恰出在直接这两个字上。Spring Boot 项目默认的日志通道是 SLF4J Logback日志要经过 logger、appender、encoder 这一整套流水线最后才会落到文件、滚动、或者被采集走。StdOutImpl相当于绕过了这条流水线把 SQL 日志单独拎出来贴在了大门口。你可以理解为别人寄信都走邮政系统有运单号、有投递记录StdOutImpl是直接把信贴在了电线杆上路过的人能看到但要归档、要追踪、要统一检索就完全办不到了。这也解释了为什么很多人在开发环境配了StdOutImpl觉得挺好一到测试环境、生产环境就开始抓瞎配置了logging.file或者接了 ELK 之后SQL 日志依然只出现在应用进程的控制台输出里日志文件里根本没有这一份。所以我的第一个建议是StdOutImpl只适合单机临时调试一旦你开始考虑日志的采集、留存、检索就必须把 SQL 日志放回日志框架的正规通道里。1.2 SQL 日志的价值远不止看一眼参数有人觉得 SQL 日志就是个调试工具代码写对了就关了没必要搞那么复杂。但如果你经历过一次线上缓慢查询的排查或者一次需要向 DBA 解释你这个接口为什么查了 20 次数据库的争执就会明白 SQL 日志在排查链路中的价值有多大。在开发期SQL 日志帮助你看清 MyBatis 最终拼接出来的 SQL 长什么样、参数绑定对不对尤其是遇到动态 SQL 拼接问题的时候这一条日志能省下半个小时的猜谜时间。在联调期和线上排查期一次前端点击会触发一个接口一个接口又会触发多条 SQL这些 SQL 散落在整个应用的日志流里如果没有 traceId 把它们串起来你要靠时间戳和上下文去人肉匹配效率极低。再往后走一层SQL 日志还能用来做慢 SQL 统计、热点查询分析甚至做简单的报表——哪些表被查得最频繁、哪些 SQL 的执行耗时在持续增长这些都是可以从 SQL 日志里挖掘出来的信息。所以我的观点很明确SQL 日志不是能打出来就行而是要让它成为整个可观测体系的一部分。好用的 SQL 日志应当具备三个特征一是能跟着统一的日志框架走二是能带着请求上下文traceId、userId 这类信息三是能方便地被采集和检索。后面所有方案都是围绕这三点展开的。1.3 打印 SQL 日志必须遵守的几条原则在进入具体配置之前先说几条我自己踩过坑之后总结出来的原则后面所有操作都不会违背这几条。第一分环境控制。开发环境可以把 SQL 日志的级别放到最低、输出最详细的内容甚至直接用StdOutImpl都无所谓只要能提高调试效率。但生产环境一定要克制SQL 日志的量往往比业务日志大一个数量级全量输出会让磁盘和采集链路压力很大所以生产环境要么把日志级别调高要么只打印慢 SQL要么做采样。第二SQL 日志必须和业务日志走同一条通道。有些项目图省事单独给 MyBatis 配了一个文件输出导致排查问题的时候要同时盯两个文件。更高效率的方式是让 SQL 日志和其他日志一起进 logback统一格式、统一滚动策略、统一采集这样在日志平台里按 traceId 一搜业务日志和 SQL 日志是混在一条时间线里的前后顺序一目了然。第三上下文信息要比 SQL 本身更重要。单独一行 SQL 日志的价值有限但如果这一行日志上带着哪次请求、哪个用户、哪个接口、耗时多少它的价值就完全不一样了。这也是我后面会花一整章讲 traceId 的原因——没有这个 IDSQL 日志就是一堆孤立的信息碎片。2. MyBatis Plus 打印 SQL 的三种主流方案按场景对号入座2.1 开发期救急log-impl 直接输出到控制台先看最经典也最简单的一种在 application.yml 里这样配置mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.stdout.StdOutImpl配置完之后启动项目只要执行了 SQL控制台就会出现类似这样的输出 Preparing: SELECT id,name,age FROM user WHERE id ? Parameters: 1(Long) Columns: id, name, age Row: 1, 张三, 20 Total: 1这个方案的优点是零成本、零理解门槛几秒钟就能看到 SQL特别适合刚接触 MyBatis Plus、只是想确认一条 SQL 拼得对不对的场景。我到现在都保留着一个习惯本地起服务做功能测试的时候如果只关心 SQL 是否正确我就会暂时打开这一个配置测完立刻关掉。这个方案的局限也很明显。第一它不受 logback 的级别控制不管你把 root 级别调到 INFO 还是 WARN它照样往控制台打。第二它不进日志文件即使 Spring Boot 配置了logging.file.nameStdOutImpl的输出也未必会被写入文件因为它是直接操作System.out和 logback 的 appender 完全是两条路。第三它无法带有 traceId 这类 MDC 信息因为 MDC 是日志框架的概念System.out.println根本不知道 MDC 是什么。所以这个方案我只推荐在本地开发环境使用一旦要部署到测试环境以上就换第二种方案。2.2 生产推荐用日志框架的级别控制接管 SQL 日志第二种方案是让 MyBatis 的日志输出走 SLF4J然后由 logback 统一控制。绝大多数 Spring Boot 项目不需要额外操作因为 MyBatis 启动时会在 classpath 里探测可用的日志框架顺序是 SLF4J 优先只要你的项目里有 logback-classicSpring Boot 默认就有MyBatis 就会自动使用Slf4jImpl根本不需要配log-impl。此时打印 SQL 的关键就是把你 mapper 接口所在的包在日志框架里的级别调到 TRACE。以 Spring Boot 的 application.yml 为例logging: level: com.example.demo.mapper: trace这里有个易踩的坑很多人在这里配置的是 debug结果只看得到Preparing看不到Parameters就以为配置没生效。实际上 Preparing:这一行 SQL 主体是 DEBUG 级别 Parameters:参数绑定信息是 TRACE 级别。MyBatis 在源码里就是这么设计的SQL 主干用logger.debug输出参数绑定用logger.trace输出。所以你想看到完整的、带参数的 SQL就得把 mapper 包的日志级别设成 trace而不是 debug。这种方式的好处是 SQL 日志彻底纳入了 logback 的体系你可以让它和业务日志一起滚动、一起采集也可以给 mapper 单独培一个 logger单独设置输出路径、输出格式。配合 MDC 里的 traceId日志一行行打出来之后就带上了请求上下文。这是三种方案里我个人最推荐的生产环境做法代码零侵入只动配置。2.3 进阶玩法自定义拦截器定制 SQL 输出如果觉得第二种方式还不够灵活——比如你想统一为所有 SQL 日志加个固定前缀、想统计单条 SQL 的执行耗时、想对超过 500ms 的慢 SQL 单独告警或者想对参数里的敏感信息做脱敏这时候就可以用 MyBatis 的拦截器机制自己接管 SQL 日志输出。拦截器的思路是在 MyBatis 执行 SQL 的核心方法上做切面。最常见的做法是拦截StatementHandler的prepare方法拿到BoundSql里的原始 SQL 和参数然后再配合System.currentTimeMillis()统计执行耗时。下面是一段可以直接用于参考的简化代码Intercepts({ Signature(type StatementHandler.class, method prepare, args {Connection.class, Integer.class}) }) public class CustomSqlLogInterceptor implements Interceptor { private static final Logger log LoggerFactory.getLogger(SQL_LOG); Override public Object intercept(Invocation invocation) throws Throwable { StatementHandler statementHandler (StatementHandler) invocation.getTarget(); MetaObject metaObject SystemMetaObject.forObject(statementHandler); BoundSql boundSql (BoundSql) metaObject.getValue(delegate.boundSql); String sql boundSql.getSql().replaceAll(\\s, ); long start System.currentTimeMillis(); try { return invocation.proceed(); } finally { long cost System.currentTimeMillis() - start; log.info(slow_sql{}, cost{}ms, sql, cost); } } Override public Object plugin(Object target) { return Plugin.wrap(target, this); } }然后在配置类里把这个拦截器注册进 MyBatisConfiguration public class MybatisPlusConfig { Bean public MybatisPlusInterceptor mybatisPlusInterceptor() { MybatisPlusInterceptor interceptor new MybatisPlusInterceptor(); interceptor.addInnerInterceptor(new PaginationInnerInterceptor(DbType.MYSQL)); return interceptor; } Bean public CustomSqlLogInterceptor customSqlLogInterceptor() { return new CustomSqlLogInterceptor(); } }注意一点MyBatis Plus 的MybatisPlusInterceptor是一个内部的InnerInterceptor链路和普通的org.apache.ibatis.plugin.Interceptor并不冲突。你完全可以同时注册两者一个负责分页这类增强逻辑一个负责 SQL 日志。自定义拦截器的优势是日志格式完全由你掌控比如你可以只打印执行耗时超过阈值的 SQL可以统计 prepare 阶段的耗时也可以把参数里的手机号、身份证号做脱敏处理。代价就是代码量多一点而且动态 SQL 的解析、参数列表的展开都需要你自行处理适合对 SQL 日志有细化诉求、且有一定 MyBatis 源码基础的同学。2.4 三种方案对比方案配置/改造成本是否受日志框架级别控制是否支持 traceId 与采集推荐场景StdOutImpl极低一行配置否直接 System.out否绕开日志体系本地快速调试日志框架级别控制低只改 yml是完全受 logback 控制是可进文件、可采集开发/测试/生产环境通用自定义拦截器中高需要写代码自定义可自行决定是而且格式更自由需要慢 SQL、脱敏、定制日志结构我的建议比较直接除非你只是临时看一眼 SQL否则不要碰StdOutImpl。默认首选第二种方案先让 SQL 日志进 logback、带上项目统一的格式和 traceId。等后续出现了「慢 SQL 统计」「敏感参数脱敏」这类硬需求再在第二种方案的基础上叠加第三种拦截器二者并不冲突。3. 生产级落地让 SQL 日志在 Elasticsearch 里按 traceId 可查3.1 项目基础环境与依赖准备如果你只是想本地看一眼 SQL到上一章就结束了。但如果你和我一样希望 SQL 日志最终能被采集到 Elasticsearch并在 Kibana 里通过一条 traceId 查出一个请求涉及的所有 SQL那就得把前面讲的东西串成一个完整链路。下面我会从一个典型的 Spring Boot MyBatis-Plus 项目出发演示从日志配置到 ES 检索的完整过程。我本地的验证环境是这样一套组合Spring Boot 2.7.x、MyBatis-Plus 3.5.3、Logback 1.2.xSpring Boot 自带、logstash-logback-encoder 7.4用于 JSON 日志输出。如果你用的是 Spring Boot 3.xlogstash-logback-encoder 的版本要换成 8.x其余思路完全一样。核心依赖如下dependency groupIdcom.baomidou/groupId artifactIdmybatis-plus-boot-starter/artifactId version3.5.3/version /dependency dependency groupIdnet.logstash.logback/groupId artifactIdlogstash-logback-encoder/artifactId version7.4/version /dependency之所以引入 logstash-logback-encoder是因为它的LogstashEncoder可以直接把日志输出成 JSON 格式而且能自动把 MDC 里的所有字段带出来。后面我们要在 Kibana 里按traceId搜索靠的就是它。3.2 第一步让 SQL 日志进入 logback 的“正规军”先做第一步——把 SQL 日志从控制台拉回 logback 体系里。具体操作分两步第一确保你的 application.yml 里没有配置log-impl: StdOutImpl让 MyBatis 走默认的 SLF4J 自动探测第二在配置里把 mapper 接口所在包的日志级别调成 TRACElogging: level: com.example.demo.mapper: trace注意这里一定是 trace原因我在 2.2 里说过了参数绑定信息Parameters的日志级别是 TRACE。如果你只设 DEBUG就会看到 SQL 主体但看不到参数列表排查问题的时候少了一半有效信息。这一步做完启动项目、执行一条 SQL你会在控制台看到类似下面的日志而且它们已经带上了 logback 的格式2025-01-15 14:22:10.123 TRACE 12345 --- [nio-8080-exec-1] c.e.demo.mapper.UserMapper.selectById : Preparing: SELECT id,name,age FROM user WHERE id? 2025-01-15 14:22:10.126 TRACE 12345 --- [nio-8080-exec-1] c.e.demo.mapper.UserMapper.selectById : Parameters: 1(Long)到这一步SQL 日志和业务日志就已经在同一个 logger 体系里了你可以继续往下配置 logback 的 RollingFileAppender让日志按天滚动落盘。下面是一份可以直接参考的 logback-spring.xml 片段我在其中把 traceId 的占位符%X{traceId}加到了输出模式里同时还区分了 console 和文件 appenderconfiguration appender nameCONSOLE classch.qos.logback.core.ConsoleAppender encoder pattern%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%X{traceId}] %logger{50} - %msg%n/pattern /encoder /appender appender nameFILE classch.qos.logback.core.rolling.RollingFileAppender filelogs/application.log/file rollingPolicy classch.qos.logback.core.rolling.TimeBasedRollingPolicy fileNamePatternlogs/application.%d{yyyy-MM-dd}.log/fileNamePattern maxHistory30/maxHistory /rollingPolicy encoder pattern%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%X{traceId}] %logger{50} - %msg%n/pattern /encoder /appender logger namecom.example.demo.mapper levelTRACE/ root levelINFO appender-ref refCONSOLE/ appender-ref refFILE/ /root /configuration这里我用%X{traceId}从 MDC 里取 traceId如果当前线程的 MDC 里没有 traceId这一项就会显示为空。所以下一步的关键就是给每个请求都种上一个 traceId。3.3 第二步用 traceId 把一次请求的所有日志串起来traceId 在 Java 领域通常通过 SLF4J 的 MDCMapped Diagnostic Context来实现。你可以把 MDC 理解成当前线程自带的一个小储物柜往里放一个键值对logback 格式化日志的时候就能通过%X{key}取出来。一个请求进了应用我们在入口处生成一个 traceId 放进 MDC那么在这个线程里发生的所有日志都会带上这个 ID包括后面 MyBatis 输出的 SQL 日志。下面我给出一个最标准的做法实现 Spring MVC 的HandlerInterceptor在每个 HTTP 请求进入时生成 traceId请求结束后再清理掉。public class TraceIdInterceptor implements HandlerInterceptor { private static final String TRACE_ID traceId; Override public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) { String traceId request.getHeader(X-Trace-Id); if (traceId null || traceId.isEmpty()) { traceId UUID.randomUUID().toString().replace(-, ); } MDC.put(TRACE_ID, traceId); response.setHeader(X-Trace-Id, traceId); return true; } Override public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) { MDC.remove(TRACE_ID); } }然后注册进 Spring MVCConfiguration public class WebConfig implements WebMvcConfigurer { Override public void addInterceptors(InterceptorRegistry registry) { registry.addInterceptor(new TraceIdInterceptor()).addPathPatterns(/**); } }这套逻辑里有一个细节值得注意afterCompletion里一定要MDC.remove而不是MDC.clear。因为 Tomcat 的线程是复用的一个线程处理完请求后会被放回线程池如果不清掉 traceId下个请求复用这个线程时就可能把上一个请求的 traceId 带到下一条日志里造成串号排查问题的时候会非常难受。另外如果你的接口里用了线程池、异步任务或者通过 MQ 消费消息MDC 并不会自动传递到子线程。因为 MDC 是绑定在线程上的子线程是另起炉灶。一个比较实用的方案是用TaskDecorator在任务提交时把主线程的 MDC 拷贝到子线程Bean public ThreadPoolTaskExecutor taskExecutor() { ThreadPoolTaskExecutor executor new ThreadPoolTaskExecutor(); executor.setCorePoolSize(4); executor.setMaxPoolSize(8); executor.setQueueCapacity(100); executor.setTaskDecorator(runnable - { MapString, String contextMap MDC.getCopyOfContextMap(); return () - { try { MDC.setContextMap(contextMap); runnable.run(); } finally { MDC.clear(); } }; }); return executor; }同理如果服务之间用 RestTemplate 或 Feign 互相调用也要在发送请求时把 traceId 通过 Header 传下去下游才能继续接力。这一步做到位你就能在日志文件里看到每一行日志都挂着一个 traceIdSQL 日志也不例外。3.4 第三步JSON 化日志并采集进 Elasticsearch日志文件里有了 traceId 之后下一步就是把日志变成 JSON 格式让 Elasticsearch 能够按字段解析和查询。这一步我推荐直接用 logstash-logback-encoder 的LogstashEncoder把上一节 logback-spring.xml 里的 encoder 做一个小改动appender nameFILE classch.qos.logback.core.rolling.RollingFileAppender filelogs/application.log/file rollingPolicy classch.qos.logback.core.rolling.TimeBasedRollingPolicy fileNamePatternlogs/application.%d{yyyy-MM-dd}.log/fileNamePattern maxHistory30/maxHistory /rollingPolicy encoder classnet.logstash.logback.encoder.LogstashEncoder/ /appender这样日志文件里每行就是一个 JSON 对象诸如timestamp、level、logger_name、message、traceId、thread_name等字段会被自动打出来。注意traceId之所以能出现在 JSON 里是因为LogstashEncoder默认会把 MDC 的所有键值对一起输出。这也是为什么我前面强调一定要往 MDC 里放 traceId。接下来就是采集链路。比较常见的做法是应用服务器上装 Filebeat读取日志文件把 JSON 原样发到 Logstash 或直接发到 Elasticsearch。在 Elasticsearch 里每一行日志就是一个 documenttraceId是一个独立的 keyword 字段。为了确保traceId能被按精确值搜索建议在索引模板里把traceId映射为 keyword。如果用的是 Filebeat Logstash 的标准采集链路通常不需要额外处理traceId会被自动识别为普通字段。链路搭好之后在 Kibana 的 Discover 页面里搜索traceId: 6aa2526590ad07346b76e2b8d8d80384你就能看到这次请求从进入到返回的全部日志包括 MyBatis 的 SQL 日志。举个例子你好奇某个接口到底执行了几条 SQL、每条耗时多少用 traceId 一查SQL 日志会按照时间顺序排在那里前面是准备 SQL、绑定参数后面是查询结果行数和总耗时排查性能和数据问题的时候这种体验比在服务器上翻日志文件舒服太多。3.5 这一步做完你会得到什么样的效果我把这套链路在本地完整搭过一遍实际效果是这样的普通访问一次用户查询接口日志文件里会依次出现一行业务日志然后跟着 MyBatis 输出的 Preparing、 Parameters、 Total等 SQL 日志而且每一行都带着同一个 traceId。把这份 JSON 日志喂给 Elasticsearch 之后在 Kibana 中输入 traceId从 HTTP 入口到数据库返回整条链路的日志都清晰可见。像热词里提到的那种长字符串 traceId在 Kibana 里直接一搜就能定位到对应的 SQL 日志网上很多人说的根据 traceId 查 SQL本质就是我上面实现的这套机制。这套机制对常规 Web 应用、微服务场景都适用。唯一的差别在于微服务场景下 traceId 还需要通过 Feign 或 RestTemplate 的拦截器往下游传递下游继续往 MDC 里放同一个 traceId最终整条调用链上的服务日志都能在 ES 里用同一个 traceId 串联。这一层设计得越早后面排查线上问题就越省力。4. 常见问题与排查技巧实录4.1 配置了 log-impl 却没有任何 SQL 输出按照网上的配置写了log-impl: StdOutImpl结果 SQL 还是不打印这种情况在真实项目里经常发生。我见到过的原因九成是下面三个。第一个原因Logger 名称对应的包路径写错了。比如你的 mapper 接口实际在com.company.module.user.mapper却在配置里写成了com.company.module.mapper级别没对上自然不打印。排查方法很简单启动日志里看 MyBatis 扫描到了哪些 mapper或者直接看 sqlSessionFactory 的 mapper 注册日志确认包名后重新配置。第二个原因log-impl配置被覆盖了。有些项目在SqlSessionFactory的 Bean 里显式调用了configuration.setLogImpl(NoLoggingImpl.class)或者通过自定义 MybatisConfiguration 类强制指定了日志实现这样 yml 里的配置就不再生效。排查时可以先全局搜一下代码里有没有setLogImpl。第三个原因是日志框架级别覆盖。比如 root 级别是 WARN而 mapper 包的日志级别没有单独配置那么 SQL 日志和业务日志都会被压掉。这时候在logging.level里显式把 mapper 包调高到 trace 即可。4.2 只看到 Preparing看不到 Parameters这个问题我在前面已经反复强调过是 MyBatis 日志设计中一个特别容易让人误解的地方。很多人配置了 DEBUG 级别看到 Preparing:正常输出就以为日志没问题结果参数列表 Parameters:一直不出现第一反应是 MyBatis Plus 版本 bug或者是参数解析失败。原因很简单Preparing是 DEBUG 级别Parameters是 TRACE 级别。如果日志级别只开到 DEBUGTRACE 内容会被过滤掉。想要完整看到 SQL 主体和参数信息必须把 mapper 包对应的日志级别设置为 TRACElogging: level: com.example.demo.mapper: trace如果你用的是自定义拦截器输出 SQL 日志也要注意不要只取BoundSql.getSql()而要把 ParameterMappings 和参数值拼出来。很多人在拦截器里只打印 SQL 不打印参数排查的时候还是得靠猜。4.3 traceId 打印出来是 null尤其异步线程里日志里[%X{traceId}]一直是 null最常见的原因是拦截器没注册成功或者 MDC 写入发生在日志输出之后。建议先单独写一个 Controller直接打印一行带MDC.get(traceId)的日志验证拦截器是否生效。另一个非常普遍的场景是异步线程。你用的是Async注解或者在CompletableFuture、线程池里执行了代码那么新线程的 MDC 是空的SQL 日志如果在子线程里执行traceId 自然就是 null。解决办法就是我 3.3 里给的TaskDecorator或者在异步方法入口手动把主线程的 traceId 塞进去。要切记MDC 里的值不会自动被子线程继承这是很多线程池MDC 方案失效的根源。还有一个小坑容易忽略MDC.remove和MDC.clear的区别。在请求结束时不清理 traceIdTomcat 线程复用后会出现 traceId 串号表现为日志里同一个 ID 突然出现很多无关请求的日志。正确的做法是按 key 清理只 remove 掉自己放的 traceId。4.4 SQL 日志量太大生产环境该怎么控制这个问题几乎每个做到生产环境的人都会遇到。一个业务系统每秒上千次请求全量 SQL 日志意味着每秒上千条带参数的日志磁盘消耗和采集链路压力都很大。我自己的经验是分三层做控制。第一层日志级别。生产环境把 root 级别设为 INFO只对需要排查的 mapper 包临时开 DEBUG 或 TRACE排查完立刻恢复。不要在生产永久开着 TRACE。第二层只打慢 SQL。借助自定义拦截器只有执行耗时超过设定阈值比如 300ms才输出 SQL 日志。这种方式对性能问题定位特别有效日常日志量能压缩到原来的十分之一以下。第三层采样。如果确实需要统计 SQL 执行概况可以对 SQL 日志做按比例采样比如每 10 次请求只输出 1 次用日志框架的采样过滤器实现或者自己在拦截器里加一个随机数判断。4.5 问题排查速查表现象可能原因解决方案配置后 SQL 完全不打印log-impl 覆盖、包名级别不匹配、root 级别过高确认 mapper 包路径与日志级别全局搜 setLogImpl只看到 Preparing看不到 Parameters日志级别是 DEBUG参数是 TRACE将 mapper 包日志级别改为 tracetraceId 为 null拦截器未注册、MDC 写入顺序问题验证拦截器生效确认请求入口先写 MDC异步线程 SQL 日志 traceId 为空MDC 不会自动传到子线程使用 TaskDecorator 或手动传递 MDCSQL 日志不落文件使用了 StdOutImpl去掉 log-impl让日志走 logbackJSON 日志里没有 traceId 字段LogstashEncoder 未输出 MDC 字段或 MDC 值为空检查 encoder 版本确认 MDC 已写入5. 几个容易被忽略的生产细节5.1 SQL 日志脱敏SQL 日志一旦进了统一日志平台就不再是你一个人能看到的东西运维、DBA、数据分析同事都可能接触到。如果你的业务涉及手机号、身份证号、邮箱这类敏感字段SQL 参数里直接带着明文日志平台就变成了一个数据泄露的口子。我建议在方案二的基础上配合自定义拦截器做参数脱敏对常见的敏感字段做正则替换或者对特定位置的参数做掩码处理。5.2 分环境配置文件的组织方式Spring Boot 支持多环境配置文件SQL 日志的级别配置不要一股脑写在 application.yml 里。我的习惯是application-dev.yml 里放开 mapper 包到 DEBUG 或 TRACE方便开发期调试application-test.yml 里开到 DEBUG配合测试环境的日志平台做问题排查application-prod.yml 里只保留 INFO需要排查时通过运维临时改日志级别排查完恢复。这样既保证了开发效率也守住了生产环境的日志量底线。5.3 别忘了观察 SQL 执行耗时很多人的 SQL 日志停留在打印 SQL这个层面但 MyBatis 的BaseJdbcLogger本身还会输出 Total: 3这样的结果行数。结合执行耗时一起看排查慢 SQL 的体验会好很多。如果希望每条 SQL 都带上耗时可以像我 2.3 那样写一个轻量拦截器在proceed()前后取时间差。注意这个时间差包含的是从 MyBatis 发起请求到拿到结果集的过程不包含网络传输到浏览器的时间但它足够反映 SQL 本身的执行性能。最后再分享一个我自己调试时的小技巧如果你只是临时想确认一条 SQL 到底执行的什么又不想改任何配置文件可以直接在测试代码里给对应 mapper 加一个 debug 断点然后在日志输出面板里看 MyBatis 的 SQL 输出。或者更简单先看log-impl当前是什么再决定要不要临时切换。这套 SQL 日志链路我前前后后踩过不少坑尤其是 PARAMETERS 级别和 MDC 串号这两个问题每次都花了不少时间才定位。希望这篇文章能帮你把这些坑提前填平让 SQL 日志真正成为你排查问题的左膀右臂。
返回列表