MyBatis Plus SQL日志接入ELK：实现按traceId追踪请求执行链

上周排查一个生产数据变更问题，翻遍整个日志平台都没找到是谁动了那条用户记录。后来才发现，服务里的 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 却还是看不到 SQL

1.1 MyBatis 内部其实是靠一套 Log 适配器打日志

很多人以为 MyBatis Plus 打印 SQL 是个“开关”问题，打开就完事。实际上 MyBatis 定义了一套自己的Log接口，运行时选择一个实现类，再通过这个实现输出日志。常见的实现有：

• StdOutImpl：直接通过System.out.println输出到控制台；
• Slf4jImpl：把日志委托给 SLF4J，再由 logback / log4j2 输出；
• Log4j2Impl：委托给 Log4j2；
• NoLoggingImpl：什么都不打。

mybatis-plus.configuration.log-impl这个配置项，本质就是指定 MyBatis 全局应该使用哪个 Log 实现类。如果你不显式配置，MyBatis 的LogFactory会按照 classpath 里的日志框架自动适配。在 Spring Boot 项目中通常已经有 SLF4J，所以自动选中的大概率是Slf4jImpl。

关键来了：如果自动选中Slf4jImpl，那么 SQL 日志走的是业务日志框架，受日志框架的 level 控制；但如果有人手动把它改成了StdOutImpl，日志就直接进了标准输出，再也不受 logback 管了。这也是很多人“明明开了日志，却采集不到”的第一个原因。

1.2 打印 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”的情况，按下面顺序排查，基本能定位：

• 多数据源 / 自定义 SqlSessionFactory：log-impl配置只对自动装配的 SqlSessionFactory 生效。如果你自己 new 过MybatisSqlSessionFactoryBean，或者用了多数据源框架，全局配置可能被绕过。需要在每个 SqlSessionFactory 创建时单独设置configuration.setLogImpl(Slf4jImpl.class)。
• logback 里写死了 logger 级别：有些项目的logback-spring.xml里已经写了<logger name="com.example.demo.mapper" level="info"/>，这时候 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. 从控制台到 Elasticsearch：SQL 日志必须先走日志框架

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 name="SQL_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"> <file>logs/sql.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <fileNamePattern>logs/sql.%d{yyyy-MM-dd}.log</fileNamePattern> <maxHistory>30</maxHistory> </rollingPolicy> <encoder> <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] [%X{traceId:-}] %-5level %logger{50} - %msg%n</pattern> </encoder> </appender> <logger name="com.example.demo.mapper" level="DEBUG" additivity="false"> <appender-ref ref="SQL_FILE"/> <appender-ref ref="CONSOLE"/> </logger>

这个配置有几个细节值得注意：

• additivity="false"是为了防止 SQL 日志同时打到根 logger，导致重复输出。如果你希望 SQL 日志也汇总到主业务日志里，可以不加这个开关，根据实际情况取舍。
• %X{traceId:-}就是读取 MDC 里的 traceId 字段，没有值时输出-。
• 单独文件的好处是 Filebeat 只需要监听一个路径，索引和数据量也更好控制。

2.3 traceId 是怎么进入每一条 SQL 日志的

这里需要理解一个简单但重要的概念：MDC（Mapped Diagnostic Context）。它是 SLF4J 提供的一个线程上下文 Map，logback 在打印日志时会自动读取 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_id，logback pattern 要对上。

2.4 日志采集：Filebeat 到 Logstash 再到 ES

如果你还在用普通文本日志，Filebeat 也可以采，但每次查询都要全文检索 message 字段，效率会差一些。我更推荐让 logback 直接输出 JSON 格式日志，一行一条 JSON，采集端解析后 traceId、logger、level 自动变成独立字段，Kibana 里查询体验完全不一样。

logback 里需要引入依赖：

<dependency> <groupId>net.logstash.logback</groupId> <artifactId>logstash-logback-encoder</artifactId> <version>7.4</version> </dependency>

然后定义 JSON appender：

<appender name="SQL_JSON" class="ch.qos.logback.core.rolling.RollingFileAppender"> <file>logs/sql.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <fileNamePattern>logs/sql.%d{yyyy-MM-dd}.log</fileNamePattern> <maxHistory>30</maxHistory> </rollingPolicy> <encoder class="net.logstash.logback.encoder.LogstashEncoder"> <includeMdc>true</includeMdc> <customFields>{"app_name":"demo"}</customFields> </encoder> </appender>

Filebeat 端添加 ndjson 解析器，日志进来后直接按 JSON 字段拆分：

filebeat.inputs: - type: filestream enabled: true paths: - /logs/sql.log fields: app_name: demo fields_under_root: true parsers: - ndjson: target: ""

Logstash 配置可以很简单，收到日志后直接发往 Elasticsearch：

input { beats { port => 5044 } } output { elasticsearch { hosts => ["http://elasticsearch:9200"] index => "app-sql-log-%{+yyyy.MM.dd}" } }

到这一步，“SQL 日志进 Elasticsearch”的通路就打通了。剩下的问题就是怎么让日志里有 traceId，以及怎么按 traceId 查询。

3. 按 traceId 关联一次请求的所有 SQL：Filter + logback pattern 实操

3.1 一个可复现的最小项目

我直接给一个最简单的 Spring Boot + MyBatis Plus 项目骨架。Spring Boot 2.x 用mybatis-plus-boot-starter，Spring Boot 3.x 用mybatis-plus-spring-boot3-starter，版本选 3.5.x 就行。

<dependency> <groupId>com.baomidou</groupId> <artifactId>mybatis-plus-boot-starter</artifactId> <version>3.5.5</version> </dependency>

配置文件：

spring: datasource: url: jdbc:mysql://localhost:3306/demo?useSSL=false&characterEncoding=utf8 username: root password: root mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.slf4j.Slf4jImpl logging: level: com.example.demo.mapper: debug

Service 里写一段典型的业务逻辑：

@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 pattern：

<pattern>%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 多数据源和自定义 SqlSessionFactory

MyBatis 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.P6SpyDriver

P6Spy 会输出完整 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 这套组合，日志格式用 JSON，Kibana 里做成按 traceId 查询的 Saved Search。这样每次有人报数据问题，我第一句话就是“把 traceId 发我”，而不是“去机器上翻日志”。

一个实用小技巧：在 TraceIdFilter 里顺手把请求 URI 和耗时也放进 MDC，日志里就能直接看到这个请求处理了多久，能省掉不少在业务代码里手动打点的事。