上周排查一个生产数据变更问题翻遍整个日志平台都没找到是谁动了那条用户记录。后来才发现服务里的 MyBatis Plus 虽然配置了日志输出但 SQL 全打在控制台 stdout日志采集器根本收不到。这其实是很多项目的通病只解决了“本地能看”没解决“线上能查”。这篇文章我打算把这件事讲透Spring Boot MyBatis Plus 项目里如何让 SQL 日志不仅能在控制台看到还能带上 traceId 进入 Elasticsearch按请求维度搜索到一次业务操作执行过哪些 SQL。内容包括 MyBatis 日志适配器的底层逻辑、logback / Filebeat / Logstash 的配置踩坑、生产环境全量打印 SQL 的成本控制以及 Kibana 里常用的排查模板。适合正在搭日志平台、或者每天被“这条 SQL 到底谁执行的”折磨的同学参考。1. 为什么你配了 mybatis-plus.configuration.log-impl 却还是看不到 SQL1.1 MyBatis 内部其实是靠一套 Log 适配器打日志很多人以为 MyBatis Plus 打印 SQL 是个“开关”问题打开就完事。实际上 MyBatis 定义了一套自己的Log接口运行时选择一个实现类再通过这个实现输出日志。常见的实现有StdOutImpl直接通过System.out.println输出到控制台Slf4jImpl把日志委托给 SLF4J再由 logback / log4j2 输出Log4j2Impl委托给 Log4j2NoLoggingImpl什么都不打。mybatis-plus.configuration.log-impl这个配置项本质就是指定 MyBatis 全局应该使用哪个 Log 实现类。如果你不显式配置MyBatis 的LogFactory会按照 classpath 里的日志框架自动适配。在 Spring Boot 项目中通常已经有 SLF4J所以自动选中的大概率是Slf4jImpl。关键来了如果自动选中Slf4jImpl那么 SQL 日志走的是业务日志框架受日志框架的 level 控制但如果有人手动把它改成了StdOutImpl日志就直接进了标准输出再也不受 logback 管了。这也是很多人“明明开了日志却采集不到”的第一个原因。1.2 打印 SQL 的两条路径一条通向控制台一条通向日志平台我把常见的配置方式整理成了一个表格你可以直接对照自己项目属于哪种配置方式是否走日志框架能否被 Filebeat 采集进 ELK适用场景log-impl: StdOutImpl否直接 stdout一般不作为日志采集源本地临时调试log-impl: Slf4jImpl 设置 mapper 包为 debug是能生产/测试推荐只设置logging.level.xxx.mapper: debug不配 log-impl是能但依赖自动适配不够稳定项目迁移时的过渡方案P6Spy 代理数据源是能需要打印真实 SQL 和执行耗时最稳妥的组合是Slf4jImpl logging.level 指定 mapper 接口所在的包为 debug。配置示例mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.slf4j.Slf4jImpl logging: level: com.example.demo.mapper: debug这里有个容易踩坑的知识点MyBatis 打印 SQL 用的 logger 名称不是 Mapper XML 的文件路径而是 Mapper 接口的全限定名。什么意思你的接口如果是com.example.demo.mapper.UserMapper那日志级别就必须配在com.example.demo.mapper这个包上配置成 XML 目录是没用的。输出效果大概是这样 Preparing: SELECT id,name,age FROM user WHERE id? Parameters: 1(Long) Columns: id, name, age Row: 1, test, 18 Total: 1注意Preparing和Parameters是分开的两行第一条是预编译 SQL第二条是参数列表。排查问题时需要把两行拼起来看才能还原真正执行的语句。1.3 配完不生效的排查链路我见过太多“明明配置了就是不打 SQL”的情况按下面顺序排查基本能定位多数据源 / 自定义 SqlSessionFactorylog-impl配置只对自动装配的 SqlSessionFactory 生效。如果你自己 new 过MybatisSqlSessionFactoryBean或者用了多数据源框架全局配置可能被绕过。需要在每个 SqlSessionFactory 创建时单独设置configuration.setLogImpl(Slf4jImpl.class)。logback 里写死了 logger 级别有些项目的logback-spring.xml里已经写了logger namecom.example.demo.mapper levelinfo/这时候 application.yml 里配debug是不生效的因为文件配置优先级更高。包名写错logger 名是 Mapper 接口全限定名不是 XML 路径。很多人把包名配成resources/mapper下的目录结构自然打不出来。查询走了缓存MyBatis Plus 默认开启一级缓存如果两次查询在同一个 SqlSession 里且参数一样第二次可能直接命中缓存不会真正执行 SQL所以你看不到第二条 SQL。这通常不算配置问题而是你的测试方式有问题。依赖包版本不对Spring Boot 3 项目还在用mybatis-plus-boot-starter的话自动配置可能没生效。Spring Boot 3 需要单独引入mybatis-plus-spring-boot3-starter。2. 从控制台到 ElasticsearchSQL 日志必须先走日志框架2.1 为什么 StdOutImpl 到不了 Elasticsearch很多小型项目的日志链路是应用写文件 → Filebeat 采集 → Logstash 处理 → Elasticsearch。Filebeat 监听的是日志文件路径而StdOutImpl的输出目标是标准输出两者在默认情况下根本不会相遇。有些同学的部署方式是容器化应用日志打到 stdout然后用容器日志采集器收集。这种方式也不是不行但 SQL 日志会和所有业务日志、框架启动日志混在一起没法按照“每条日志来自哪个 mapper 接口”做结构化处理查询效率很低。更关键的是stdout 日志通常没有业务上下文字段想按 traceId 搜一条请求跑了哪些 SQL基本做不到。2.2 logback 里把 SQL 单独落盘既然要让 SQL 日志进 ELK就得让它走日志框架。我的做法是在 logback-spring.xml 里单独给 mapper 包指定一个 appender这样 SQL 日志会和业务日志分文件便于采集端单独配置 index。appender nameSQL_FILE classch.qos.logback.core.rolling.RollingFileAppender filelogs/sql.log/file rollingPolicy classch.qos.logback.core.rolling.TimeBasedRollingPolicy fileNamePatternlogs/sql.%d{yyyy-MM-dd}.log/fileNamePattern maxHistory30/maxHistory /rollingPolicy encoder pattern%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] [%X{traceId:-}] %-5level %logger{50} - %msg%n/pattern /encoder /appender logger namecom.example.demo.mapper levelDEBUG additivityfalse appender-ref refSQL_FILE/ appender-ref refCONSOLE/ /logger这个配置有几个细节值得注意additivityfalse是为了防止 SQL 日志同时打到根 logger导致重复输出。如果你希望 SQL 日志也汇总到主业务日志里可以不加这个开关根据实际情况取舍。%X{traceId:-}就是读取 MDC 里的 traceId 字段没有值时输出-。单独文件的好处是 Filebeat 只需要监听一个路径索引和数据量也更好控制。2.3 traceId 是怎么进入每一条 SQL 日志的这里需要理解一个简单但重要的概念MDCMapped Diagnostic Context。它是 SLF4J 提供的一个线程上下文 Maplogback 在打印日志时会自动读取 MDC 里的值填充 pattern 中的%X{traceId}。只要在请求入口处把 traceId 放进 MDC那么同一个线程里所有日志都会带上它包括 MyBatis 打印的 SQL 日志。这就是“按 traceId 关联 SQL 日志”的底层原理。实现方式也不复杂一个 OncePerRequestFilter 就够了Component public class TraceIdFilter extends OncePerRequestFilter { Override protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain chain) throws ServletException, IOException { String traceId request.getHeader(X-Trace-Id); if (traceId null || traceId.isBlank()) { traceId UUID.randomUUID().toString().replace(-, ); } MDC.put(traceId, traceId); response.setHeader(X-Trace-Id, traceId); try { chain.doFilter(request, response); } finally { MDC.remove(traceId); } } }有些团队在用 Spring Cloud Sleuth 或 Micrometer Tracing它们会自动往 MDC 里塞 traceId 和 spanId这时候你就不需要自研 Filter 了。但要注意不同版本写入 MDC 的 key 略有不同有的是traceId有的是trace_idlogback pattern 要对上。2.4 日志采集Filebeat 到 Logstash 再到 ES如果你还在用普通文本日志Filebeat 也可以采但每次查询都要全文检索 message 字段效率会差一些。我更推荐让 logback 直接输出 JSON 格式日志一行一条 JSON采集端解析后 traceId、logger、level 自动变成独立字段Kibana 里查询体验完全不一样。logback 里需要引入依赖dependency groupIdnet.logstash.logback/groupId artifactIdlogstash-logback-encoder/artifactId version7.4/version /dependency然后定义 JSON appenderappender nameSQL_JSON classch.qos.logback.core.rolling.RollingFileAppender filelogs/sql.log/file rollingPolicy classch.qos.logback.core.rolling.TimeBasedRollingPolicy fileNamePatternlogs/sql.%d{yyyy-MM-dd}.log/fileNamePattern maxHistory30/maxHistory /rollingPolicy encoder classnet.logstash.logback.encoder.LogstashEncoder includeMdctrue/includeMdc customFields{app_name:demo}/customFields /encoder /appenderFilebeat 端添加 ndjson 解析器日志进来后直接按 JSON 字段拆分filebeat.inputs: - type: filestream enabled: true paths: - /logs/sql.log fields: app_name: demo fields_under_root: true parsers: - ndjson: target: Logstash 配置可以很简单收到日志后直接发往 Elasticsearchinput { beats { port 5044 } } output { elasticsearch { hosts [http://elasticsearch:9200] index app-sql-log-%{yyyy.MM.dd} } }到这一步“SQL 日志进 Elasticsearch”的通路就打通了。剩下的问题就是怎么让日志里有 traceId以及怎么按 traceId 查询。3. 按 traceId 关联一次请求的所有 SQLFilter logback pattern 实操3.1 一个可复现的最小项目我直接给一个最简单的 Spring Boot MyBatis Plus 项目骨架。Spring Boot 2.x 用mybatis-plus-boot-starterSpring Boot 3.x 用mybatis-plus-spring-boot3-starter版本选 3.5.x 就行。dependency groupIdcom.baomidou/groupId artifactIdmybatis-plus-boot-starter/artifactId version3.5.5/version /dependency配置文件spring: datasource: url: jdbc:mysql://localhost:3306/demo?useSSLfalsecharacterEncodingutf8 username: root password: root mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.slf4j.Slf4jImpl logging: level: com.example.demo.mapper: debugService 里写一段典型的业务逻辑Service public class UserService { private final UserMapper userMapper; public UserService(UserMapper userMapper) { this.userMapper userMapper; } Transactional public User changeUserName(Long id, String name) { User user userMapper.selectById(id); user.setName(name); userMapper.updateById(user); return userMapper.selectById(id); } }这里有一个很典型的现象第一次selectById和第三次selectById的参数相同如果一级缓存命中了第三次可能不会打印 SQL。这恰恰说明日志不出现不等于没执行也可能是缓存机制在起作用。本地验证时建议换成不同 id 的查询方便观察多条 SQL 同时带 traceId 的效果。3.2 请求入口 Filter 与 logback pattern 组合前面给过TraceIdFilter的代码再配合 logback patternpattern%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] [%X{traceId:-}] %-5level %logger{50} - %msg%n/pattern实际输出会是这样2024-11-20 15:30:22.123 [http-nio-8080-exec-1] [6aa2526590ad07346b76e2b8d8d80384] DEBUG c.e.demo.mapper.UserMapper - Preparing: SELECT id,name FROM user WHERE id? 2024-11-20 15:30:22.126 [http-nio-8080-exec-1] [6aa2526590ad07346b76e2b8d8d80384] DEBUG c.e.demo.mapper.UserMapper - Parameters: 1(Long)注意看每一条 SQL 日志都带上了同一个 traceId。这就是按请求维度追踪 SQL 的基础。3.3 在 Elasticsearch 里把这条链路捞出来日志进入 ES 之后你可以直接在 Kibana Discover 里搜索traceId:6aa2526590ad07346b76e2b8d8d80384如果日志是 JSON 格式且 Filebeat 正确解析了字段你会看到这个请求相关的所有日志从 Controller 入口日志到 Service 日志再到 SQL 日志按时间排成一条完整的执行链。如果你只想看 SQL 日志加上 logger 过滤traceId:6aa2526590ad07346b76e2b8d8d80384 AND logger_name:com.example.demo.mapper.UserMapper如果用的是普通文本日志没有解析出 logger_name 字段也可以用全文搜索替代。但说实话字段化之后查询效率和使用体验都远超全文检索这也是我一直强调 JSON 日志格式的原因。4. 生产环境才可能遇到的坑多数据源、拦截器改写、性能损耗4.1 多数据源和自定义 SqlSessionFactoryMyBatis Plus 的配置项通过自动装配绑定到默认的 SqlSessionFactory 上。如果项目引入了dynamic-datasource-spring-boot-starter这类多数据源组件或者自己创建了多个SqlSessionFactory那么全局log-impl很可能只对某个数据源生效其他数据源的相关 SQL 依然打不出来。这时候需要手动给每个SqlSessionFactory设置配置MybatisConfiguration configuration new MybatisConfiguration(); configuration.setLogImpl(org.apache.ibatis.logging.slf4j.Slf4jImpl.class);不同多数据源框架的配置入口略有不同但核心逻辑是一样的让每个 SqlSessionFactory 持有同一份带log-impl的 MybatisConfiguration 对象。4.2 拦截器改写 SQL 后打印出来的是最终执行的 SQL 吗MyBatis 标准日志在 Executor 执行时打印的是当时的 BoundSql。如果项目里有分页插件它会在 Executor 层改写 SQL并重新生成新的 BoundSql所以最终打印的 SQL 通常是带有分页 SQL 的版本比如LIMIT 1。这条链路本身问题不大。真正的坑在于自定义拦截器改写了 StatementHandler 层的 SQL 字符串而日志打印发生在更早的位置导致你看到的 SQL 和数据库实际执行的 SQL 不一致。如果你需要确认数据库真正收到的 SQL 是什么就要用 P6Spy 这类 DataSource 层代理工具。P6Spy 的接入方式和 MyBatis Plus 标准日志不同它不是配置一下就完事spring: datasource: url: jdbc:p6spy:mysql://localhost:3306/demo driver-class-name: com.p6spy.engine.spy.P6SpyDriverP6Spy 会输出完整 SQL参数已经拼进去和执行耗时排错时很直观。但它会在连接层增加一层包装高并发场景下会有额外开销生产环境建议只在排查期间临时打开并且和 MyBatis Plus 自己的日志二选一不要同时开否则会看到重复日志。4.3 全量打印 SQL 的成本到底怎么算如果你觉得“不就是多打几行日志吗”那建议算一笔账。假设单机 QPS 是 1000平均每个请求执行 2 条 SQL每秒会产生 2000 条 SQL 日志。每条日志几十到几百字节一天下来就是几千万甚至上亿条ES 索引和磁盘压力会非常大。日志量一大采集、存储、查询都会变慢最后反而影响定位问题的速度。我的建议是默认不打印 SQL排查问题时临时通过配置中心把logging.level.com.example.demo.mapper改成debug如果确实需要长期保留 SQL 日志使用异步 appender避免日志 I/O 阻塞业务线程ES 索引保留周期别太长SQL 日志一般留 3 到 7 天够用分环境管理日常开发、测试环境可以全量打印生产环境谨慎开启。4.4 SQL 日志脱敏与权限SQL 参数里经常出现手机号、身份证、地址这类敏感信息日志一旦进到 ELK就相当于把部分用户数据放到了日志平台。如果你的日志平台权限不够严格很容易成为数据泄露的入口。保守做法是在应用层对参数做脱敏处理后再写入日志或者在 logback 层面做自定义过滤。更实际的做法是控制 ES 索引的访问权限只有 DBA 和核心开发人员能看这些 SQL 日志。权限控制的优先级其实比脱敏更高因为日志一旦落地你再怎么处理也不如别让不该看的人看到。5. 在 Kibana 里按 traceId 查 SQL 日志的排查模板5.1 按 traceId 找回一次请求的完整 SQL 链实际操作中用户报问题后我们从网关或业务日志里能拿到一个 traceId比如traceId:6aa2526590ad07346b76e2b8d8d80384在 Kibana Discover 搜索框输入traceId:6aa2526590ad07346b76e2b8d8d80384点击时间范围按时间正序排列能看到这个请求从入口到结束的所有日志。我通常先看有没有异常堆栈再看 SQL 日志的先后顺序基本能还原一次操作到底改了哪些表。如果发现某个 update 操作不在预期逻辑里直接把该 SQL 和代码里的 mapper 方法对应上问题通常就浮出水面了。5.2 高频慢 SQL 的聚合分析按单个 traceId 查询适合处理单点问题但如果是“最近接口平均响应变慢”这类全局问题需要换一种排查方式。如果接入了 P6Spy 或自定义插件日志里会有耗时字段就可以在 Kibana Lens 里做聚合按 SQL 语句分组看每个 SQL 的 P95 耗时和调用次数。没有耗时信息也没关系可以直接看数据库慢查询日志再回到 ELK 里按 traceId 反查对应请求。这种方法比在代码里一个个加埋点高效得多尤其是老项目没有指标系统的时候日志聚合往往是最快的手段。5.3 把排查模板固化下来Kibana 支持保存 Discover 搜索条件。我建议团队里把“按 traceId 查全链路日志”和“按 SQL 关键字查慢 SQL”这两个搜索保存为公共 Saved Search其他同事拿到 traceId 直接打开就能查。更好的方式是配合告警系统。当某个接口超时或数据异常时把 traceId 放到通知消息里比如企业微信推送订单查询超时traceId:6aa2526590ad07346b76e2b8d8d80384同事点开日志平台就能直接检索不用再经历“先翻机器、再找日志、再对应时间点”的漫长链路。这算是我个人在团队协作里觉得收益最大的一个改进。最后聊聊我个人的选择。如果只是本地开发直接用 StdOutImpl 就够了但只要涉及线上排查我一律用 Slf4jImpl MDC traceId Filebeat Elasticsearch 这套组合日志格式用 JSONKibana 里做成按 traceId 查询的 Saved Search。这样每次有人报数据问题我第一句话就是“把 traceId 发我”而不是“去机器上翻日志”。一个实用小技巧在 TraceIdFilter 里顺手把请求 URI 和耗时也放进 MDC日志里就能直接看到这个请求处理了多久能省掉不少在业务代码里手动打点的事。