看不懂一屏 SQL 日志在干什么？让每条日志都变成可点击的源码坐标

MyBatis 的 SQL 日志告诉你"执行了什么查询"，但不告诉你"哪个业务步骤触发的"。一个接口跑出十五条 SQL，你扫完只知道数据库很忙，不知道该看哪行代码——这篇文章解决这个问题。

你让 AI 写了段代码，但你心里没底

周一早上，你让 AI 帮你写完了"创建订单"这个功能。你把需求描述给它，它生成了 Controller、Service、Mapper——类名规范、注释齐全、测试全绿，跑起来一点毛病没有。

但你心里清楚：你并不真正了解这段代码。没有文档，注释是 AI 自己写的，可不可信你也没底。你想搞清楚这个接口到底做了哪些事，于是打开了 SQL 日志。

屏幕上是这样的：

==>  Preparing: insert into orders (id, user_id, amount, status) values (?, ?, ?, ?)
==> Parameters: 1001(Long), 123(Long), 99.50(BigDecimal), 0(Integer)
<==    Updates: 1
==>  Preparing: insert into order_items (order_id, product_id, qty, price) values (?, ?, ?, ?)
==> Parameters: 1001(Long), 456(Long), 2(Integer), 49.75(BigDecimal)
<==    Updates: 1
==>  Preparing: insert into order_items (order_id, product_id, qty, price) values (?, ?, ?, ?)
==> Parameters: 1001(Long), 789(Long), 1(Integer), 49.75(BigDecimal)
<==    Updates: 1
==>  Preparing: update stock set quantity = quantity - ? where product_id = ?
==> Parameters: 2(Integer), 456(Long)
<==    Updates: 1
==>  Preparing: update stock set quantity = quantity - ? where product_id = ?
==> Parameters: 1(Integer), 789(Long)
<==    Updates: 1
==>  Preparing: update coupon set status = ? where id = ? and user_id = ?
==> Parameters: 2(Integer), 88(Long), 123(Long)
<==    Updates: 1
==>  Preparing: insert into payments (order_id, amount, channel, status) values (?, ?, ?, ?)
==> Parameters: 1001(Long), 99.50(BigDecimal), 1(Integer), 0(Integer)
<==    Updates: 1

七条 SQL，二十一行日志。你看到 ? 和参数分属两行，得在脑子里逐个替换：第一条是插订单，第二三条是插明细，第四五条是扣库存，第六条……status = 2 是什么意思？核销优惠券？还是作废？

你靠全局搜索反推调用链。从 Controller 找到 Service，Service 里调了 OrderMapper、StockMapper、CouponMapper、PaymentMapper……一层一层跟，花二十分钟才理清"原来这个接口做了五件事：建订单、插明细、扣库存、核销券、建支付记录"。

中途你试着去问 AI——毕竟代码是它写的。现在的 AI 会续会话、能检索仓库，你问"这条 update coupon 是哪段逻辑触发的"，它能翻到代码，给你一个有出处、像模像样的回答。可你依然没法直接信——它告诉你的是代码里写的是什么，不是这段代码实际跑起来是什么样：参数传了什么值、SQL 按什么顺序执行、和前面扣库存是不是同一个事务。这些它没见过，它不在运行时现场。你分不清它是真看到了，还是在顺着你的问法补全一个合理的故事。

你缺的不是 SQL 内容，你缺的是"每条 SQL 对应哪行代码"。

如果日志是这样的呢？

DEBUG [(OrderService.java:86)]  OrderMapper.insert           12ms => insert into orders (id,user_id,amount,status) values (1001,123,99.50,0)
DEBUG [(OrderService.java:92)]  OrderItemMapper.insert       12ms => insert into order_items (order_id,product_id,qty,price) values (1001,456,2,49.75)
DEBUG [(OrderService.java:92)]  OrderItemMapper.insert       12ms => insert into order_items (order_id,product_id,qty,price) values (1001,789,1,49.75)
DEBUG [(OrderService.java:98)]  StockMapper.deduct           12ms => update stock set quantity=quantity-2 where product_id=456
DEBUG [(OrderService.java:98)]  StockMapper.deduct           12ms => update stock set quantity=quantity-1 where product_id=789
DEBUG [(OrderService.java:105)] CouponMapper.use             12ms => update coupon set status=2 where id=88 and user_id=123
DEBUG [(PaymentService.java:67)] PaymentMapper.insert        12ms => insert into payments (order_id,amount,channel,status) values (1001,99.50,1,0)

七行，一眼看完。每条 SQL 自带源码坐标，参数已经拼好。你扫一遍就知道执行顺序：先建订单（OrderService.java:86），再插两条明细（:92），扣两次库存（:98），核销优惠券（:105），最后建支付记录（PaymentService.java:67）。

对哪一步有疑问，点坐标直接进源码。你不再需要 AI 的解释——日志自己告诉你，每一条 SQL 是从哪一行代码里出来的。这就是 DlzCaller 做的事。

这份日志还有第二个读者——AI。现在开发的东西基本都是给 AI 用的：代码是 AI 写的、排查也常由 AI 帮忙，日志的第一个读者往往就是 AI。你把它原样丢给一个能读仓库的 agent，坐标同样是它的入口：看到 (OrderService.java:86)，它直接去读那一行，不用先在全仓库里猜"这条 SQL 在哪"。但人读一样好用——你扫一眼就有执行顺序，不用等 AI 转述、再回头核一遍。对人，它解决"读不熟代码"这个真痛点；对 AI，它省掉最费劲的定位步骤。一个坐标，两个读者，各取所需。

---

日志是索引，代码是真相

在讲实现之前，先说清楚 DlzCaller 的设计理念，因为它决定了工具的定位和边界。

SQL 能告诉你"动了什么数据"——update coupon set status=2 where id=88 and user_id=123，用户 123 的 88 号券状态被改成了 2。但 status=2 到底是核销、作废还是冻结？为什么在这个时机改？失败了怎么补偿？这些只有代码知道。

所以 DlzCaller 不试图把业务语义塞进日志——它做不到，也不该做。它做的是把日志变成源码的索引：一行日志 = 一个可点击的坐标。你在日志里扫一遍执行顺序，对哪一步有疑问，点进去看真相。

日志不是代码的替代品，是代码的入口。被消灭的是"全局搜索 + 反推调用链"的二十分钟，不是"阅读代码"本身。

各维度信息的分工：

信息	回答什么	来源
SQL 语句	动了哪张表、什么操作	MyBatis
参数值	针对哪条数据	MyBatis
Mapper 方法	走的哪个数据访问方法	MyBatis
caller 坐标	代码在哪里触发	DlzCaller
traceId / 业务 ID	属于哪次请求	业务埋点
源码	为什么这么做、怎么补偿	代码本身

caller 坐标是日志和源码之间的 join key——它不替代任何一列，但缺了它，日志和代码就对不上。而这个 join key 对人和 AI 都是同一把：人点进去看，AI 读进去跳，指向的都是同一个真相。

---

MyBatis 原生日志的三个问题

上面那个场景的痛苦，根源在于 MyBatis 原生日志格式的设计缺陷。

问题一：三行碎片化。 一条 SQL 至少输出三行——Preparing、Parameters、结果统计（查询为 Total，增删改为 Updates）。十五条 SQL 就是四十五行，一屏只能看到五六条，上下文断裂。

问题二：参数和 SQL 分离。 select * from orders where user_id = ? and status = ? 搭配 Parameters: 123(Long), PAID(String)——你得在脑子里把两个 ? 替换成实际值。参数一多就容易搞错位置，复杂查询根本没法一眼读懂。

问题三：没有调用方。 这是最致命的。你看到一条 update coupon set status = 2，知道在改优惠券状态，但不知道是哪个业务方法触发的。是下单核销？还是定时任务批量过期？没有调用方信息，SQL 日志和源码之间断了一座桥。

这三个问题叠加，在一个接口触发十几条 SQL 的复杂场景下被无限放大——SQL 日志本身携带大量业务信息（查什么、改什么、条件是什么），但原生格式把它碎片化了，你无法直接阅读。

有人会说，那业务代码自己多打点日志不就行了？问题是"在哪打""打多细""谁来维护"这三件事，团队协作下从来没有标准答案。现在你也许想：代码是 AI 写的，让 AI 打日志不就行了？确实可以——但只在"生成那一刻"有效。你现在调试的这段代码，是上周、上个会话、上个人让 AI 生成的；就算你回到那个会话让它补上日志，这些日志也只出现在下一次运行里，救不了手上这次故障。何况给代码打日志的 AI 和写出这段代码的是同一个理解——它没理解对的逻辑，日志也不会打在对的地方。手动打日志这个方案的缺陷不在"人会不会漏"，在它只在生成时有效，而调试发生在代码写好之后的每一次。

---

已有方案与差异

Java 生态中并不缺乏相关尝试。P6Spy、log4jdbc、datasource-proxy 可以格式化 SQL 日志；Logback 和 Log4j2 自带 caller 信息输出（%class、%method、%line）；APM Agent 能关联方法、SQL 和 Span。

但日志框架自带的 caller 信息，报告的是日志语句本身所在的物理位置。这对业务代码自己打的日志很有效——你在 OrderService.createOrder() 里写一行 log.info(...)，%caller 就准确指向这一行。但对基础设施日志无效：MyBatis 打印 SQL 的那行 log.debug(...) 写在 MyBatis 内部的日志类里，不在你的业务代码里，%caller 只会告诉你"这行日志是 MyBatis 第几行打的"。P6Spy、HttpClient 内部日志也是同样的结构性问题——日志语句的物理位置和你想知道的"业务调用方"根本不是一回事。

要让原生 %caller 有业务价值，唯一办法是业务代码在每个调用点手动加一行日志，把日志语句"搬"到业务代码里——每个调用点都要记得加，团队协作下很容易漏，这个办法能用，但无法规模化。

DlzCaller 解决的是这个结构性错位：日志语句留在基础设施内部不动（MyBatis 拦截器、HttpClient 封装类），但在打印日志前先遍历一次调用栈，跳过配置好的基础设施包，找到第一个业务帧写入 MDC。效果上和"逐处手动打日志"一样，但业务方不需要碰任何代码，也不会漏——只要基础设施的日志点被这套机制包住，所有经过它的调用都自动带上业务 caller，不依赖某个开发者记不记得加。

---

MyBatis 插件：最有价值的场景

SQL 是 DlzCaller 最有价值的场景，因为 SQL 日志携带的业务信息密度最高——表名、字段名、条件值，每一条都在描述业务操作。而 MyBatis 插件是接入成本最低的，不需要改任何业务代码。

引入依赖

<dependency>
    <groupId>top.dlzio</groupId>
    <artifactId>dlz-caller-mybatis</artifactId>
    <version>6.7.4</version>
</dependency>

Spring Boot / MyBatis-Plus 配置

@Configuration
public class DlzMybatisConfig {

    @Bean
    @ConfigurationProperties(prefix = "dlz.caller.mybatis.sql-log")
    public DlzSqlLogProperties dlzSqlLogProperties() {
        return new DlzSqlLogProperties();
    }

    @Bean
    public DlzMybatisSqlLogInterceptor dlzMybatisSqlLogInterceptor(DlzSqlLogProperties properties) {
        return new DlzMybatisSqlLogInterceptor(properties);
    }
}

application.yml：

dlz:
  caller:
    mybatis:
      sql-log:
        enabled: true
        show-caller: true
        show-mapper: true
        inject-caller-mdc: true
        ignore-caller-packages:
          - com.example.persistence
          - com.example.infrastructure

开启 DEBUG 日志：<logger name="dlz-sql" level="DEBUG"/>。原生 MyBatis 接法相同：在 mybatis-config.xml 的 <plugins> 中注册 DlzMybatisSqlLogInterceptor，<property> 配置项与上方 YAML 完全对应——注意插件要放在分页、租户等 SQL 重写插件之后。

插件自身已内置排除 org.apache.ibatis、org.mybatis、org.springframework 和 com.baomidou（MyBatis-Plus），这些不用手动配置；ignore-caller-packages 只需要填业务自己的持久层包。

DlzCaller 是新增日志，不会自动关闭 MyBatis 原生输出。如果之前开启了 Mapper 包的 DEBUG 日志，建议调整为 INFO 或以上，避免同一条 SQL 输出两份。

效果对比

改造前（MyBatis 原生日志，三行）：

==>  Preparing: select id, name, status from orders where user_id = ? and status = ?
==> Parameters: 123(Long), PAID(String)
<==      Total: 1

改造后（DlzCaller，一行）：

DEBUG (OrderService.java:120) OrderMapper.findByUserAndStatus 12ms => select id, name, status from orders where user_id=123 and status='PAID'

一行包含五个维度：源码坐标、Mapper 方法名、耗时、拼接好的完整 SQL、日志级别。你不用在脑子里替换参数，不用全局搜索去找调用方——坐标直接给你，点进去就是源码（在 IntelliJ IDEA / Eclipse 控制台里，Ctrl/Cmd + 点击坐标即可直接跳转）。

12ms 是从调用到结果映射完成的应用侧总耗时，包含 JDBC、网络 IO、数据库执行、结果集映射，不等于数据库服务端纯执行时间。适合做应用侧慢调用筛查，但定位根因仍需结合数据库慢日志、执行计划和锁等待分析。

关于拼接 SQL 的准确性

拼接后的 SQL 用于日志阅读和排查，不保证与 JDBC 驱动最终提交给数据库的执行文本完全一致。null 参数的渲染方式、日期时区类型的格式化、byte[] / BLOB 等二进制类型、自定义 TypeHandler 的转换结果、SQL 字符串本身包含 ? 字符、批处理参数的顺序等，都可能导致差异。因此拼接 SQL 适合用于理解业务意图和快速筛查，不建议直接复制后作为审计依据或精确复现的依据。

---

通用场景：HttpClient / Redis / MQ

SQL 之外，HttpClient 和 Redis 的日志也面临同样的问题：日志只有技术信息，没有源码入口。

ERROR [(OrderService.java:86)] HttpClientUtil - HTTP POST /payments failed, read timeout

看到 (OrderService.java:86)，在 IDE 控制台里这是一个可点击的链接，点过去就是源码那一行。你不用全局搜 /payments 找调用点，坐标直接给你。

接入方式很简单——在公共组件的最外层方法加一行 try-with-resources：

public class HttpClientUtil {
    public HttpResult post(String url, Map<String, Object> params) {
        try (MdcContext ignored = DlzCaller.caller(0)) {
            log.info("HTTP POST {}", url);
            return httpClient.execute(buildRequest(url, params));
        }
    }
}

只加了三行。所有调用这个方法的业务代码，日志里都会自动显示源码坐标。业务代码不需要任何改动。

---

核心机制：MDC + 栈帧过滤

原理很简单：Java 的调用栈里本来就有完整信息。DlzCaller 遍历 StackTraceElement[]，跳过配置过的公共组件包，第一个不在忽略列表里的栈帧就是业务调用方；再把 (FileName.java:lineNumber) 写入 SLF4J 的 MDC，日志 pattern 里加一个 %X{dlz-caller} 就自动输出。

┌─────────────────────────────────────────────────────────┐
│  1. 公共组件入口打开 caller scope                        │
│     try (MdcContext ctx = DlzCaller.caller(0)) {        │
│         log.info("...");  ← 日志打在这里                │
│     }                                                    │
│                                                          │
│  2. 遍历当前线程的 StackTraceElement[]                   │
│     跳过配置过的"公共组件包"（http/redis/rpc/proxy）     │
│     第一个不在忽略列表里的栈帧 → 就是业务调用方           │
│                                                          │
│  3. 把 "FileName.java:line" 写入 MDC                     │
│     日志 pattern 里加 %X{dlz-caller} → 自动输出          │
└─────────────────────────────────────────────────────────┘

两个关键设计：

• 包前缀过滤，而不是固定栈深度。 代理层数会变——今天加个 RetryProxy，明天加个 CircuitBreakerProxy，固定层级就全错了。包前缀匹配不管有多少层包装，只要前缀匹配就跳过。java、jdk、sun、org.springframework、CGLIB 代理类和 Lambda 代理类已默认排除，一般只需在启动时添加业务自己的公共组件包：

DlzCaller.getProperties().addIgnoreCallerPackage(
    "com.example.http",
    "com.example.redis",
    "com.example.rpc",
    "com.example.mq"
);

• 输出格式 (FileName.java:lineNumber)。 这是 Java 堆栈中源码位置的常见格式，IDE 控制台能识别并生成可点击超链接。不写全限定类名——类名加行号通常已足够定位，短格式让日志更紧凑，和 Logback 用 %logger{36} 压缩包名是同一个道理。

不过这里有一个取舍值得说清楚：人是短名的受益者，AI 是长名的受益者。 OrderService.java 对人一眼就懂；但对 AI——尤其大仓库里存在同名文件时——全限定名 com.example.order.OrderService#createOrder:86 能让它一次定位，不用先 Glob 猜是哪一个。后续版本会加一个配置项，支持像 Logback 的 %logger{36} 那样调整坐标的详细程度：默认输出短格式，切一个开关就输出全限定名，方便把日志直接喂给 AI 做定位。一个字段，两个读者，各取所需。

核心模块唯一依赖 slf4j，体积约 100KB。低侵入是设计理念，不是妥协：MyBatis 场景零代码接入，通用场景在公共组件入口接入一次，调用方业务代码完全无感知。

---

常见问题

多层代理 / AOP 会定位错吗？ 包过滤不依赖固定栈深度，因此对多层代理更稳定。但过滤规则配置不完整时，仍可能定位到 Facade、代理层或框架层。比如调用链是 OrderService.createOrder() → PaymentFacade.pay() → RetryProxy.invoke() → … → HttpClientUtil.post()，只忽略 com.example.retry、com.example.rpc、com.example.http 时，定位到的是 PaymentFacade.pay()——这可能是你期望的，也可能不是，取决于项目分层和忽略包配置。

异步线程池 / CompletableFuture 没有 caller 怎么办？ 这是 SLF4J MDC 的通用限制，不是 DlzCaller 独有的问题。MDC 基于 ThreadLocal，线程切换时不会自动传播。TaskDecorator / getCopyOfContextMap 可以把已捕获的 caller 带到异步线程，但无法恢复任务提交点的调用栈——异步线程内重新解析栈拿到的是线程池栈，不是提交方。大多数项目已有 MDC 传播方案（用于 traceId 透传），可以直接复用来传播已捕获的 caller。

性能开销有多大？ 相对于 HTTP、Redis、SQL 这种毫秒级 IO 操作，单次栈解析通常不是主要成本。实际开销可能主要来自 SQL 参数格式化和字符串拼接，而非栈帧遍历本身。建议只在公共组件入口使用 caller()，不要在高频循环内调用，并确保日志级别关闭时跳过栈解析和 SQL 拼接。

生产环境可以开吗？ 核心逻辑在多个生产环境验证稳定，try-with-resources 能保证同步作用域内及时恢复 MDC。但完整 SQL 参数输出会引入敏感数据泄露风险——手机号、身份证号、密码、银行卡等一旦进入日志平台和长期存储，就有明显安全合规风险。且 MyBatis 插件拿到的是 JDBC 层面的参数值列表，不包含字段名，目前无法按字段名精准脱敏。建议仅在开发和测试环境开启；生产如需排障，临时开启并在排查后关闭，必要时在采集层做正则脱敏。

另外注意，(FileName.java:lineNumber) 依赖行号表：代码升级后行号会变化，日志必须与对应版本源码匹配；混淆或未保留行号表时可能得到 Unknown Source。

---

与链路追踪的关系

DlzCaller 和链路追踪（SkyWalking / Zipkin）解决的是不同层面的问题。链路追踪擅长跨服务、跨进程关联，回答"一个请求经过了哪些服务"；DlzCaller 更轻量，回答"这条 SQL 该点进哪行代码看"，不需要部署任何基础设施。两者不冲突，很多团队同时用——traceId 贯穿调用链，dlz-caller 标注每一步的代码来源。

---

写在最后

这个工具的代码量不大，核心逻辑几百行。但它解决的问题，是每个 Java 后端工程师每天都在经历的"小摩擦"。

你让 AI 写了一段业务代码，打开 SQL 日志想理解它到底干了什么，面对一屏碎片化的 ? 和参数，无从下手。你只能靠全局搜索反推调用链，花二十分钟才拼出"哪条 SQL 对应哪行代码"。

DlzCaller 把这个过程压缩到几秒——日志直接给你每条 SQL 的源码坐标，参数已经拼好，一行一条。扫一遍看执行顺序，对哪步有疑问，点坐标进源码看真相。

日志是索引，代码是真相。这份索引人和 AI 都能读：人扫执行顺序，AI 直接跳代码，指向的都是同一个真相。原理简单，做了，就好用。

---

源码地址： github.com/dingkui/dlz-kit · gitee.com/dlzio/dlz-kit

完整文档： DLZ Caller 3 分钟启用指南

如果你觉得有用，去 GitHub 或 Gitee 点个 Star，让更多人看到。

---