慢查询测试难复现?用插桩技术把SQL和业务场景串起来定位
2026/9/24 23:13:42 网站建设 项目流程

1. 先聊清楚:测试里的慢查询为什么难搞

我做了几年的服务端测试和性能调优,有一个场景几乎每次版本迭代都会遇到:接口响应时间突然从 80ms 飙到 800ms,线上监控一查发现是数据库慢查询,但这个问题在测试环境里死活复现不出来。等到上线后用户开始投诉,DBA 那边调出慢查询日志,才发现是一条走了全表扫描的 SQL,只在特定数据量、特定索引失效的情况下才会变慢。

这个问题的本质在于:慢查询不是一个“有或无”的问题,而是一个“触发条件”的问题。触发条件可能包括数据量级、缓存命中率、并发压力、参数嗅探、索引选择,甚至是一次不恰当的统计信息更新。测试环境里数据量小、并发低、缓存新鲜,很多慢查询根本不会冒头。

想解决这个问题,不能只靠“多写几条 SQL 然后 explain”,而是得有一套能主动捕获慢查询、并把它和具体业务场景、具体代码调用链关联起来的机制。插桩技术就是用来干这个的。

插桩这个词听起来有点底层,好像只有做 APM、做编译器的人才会碰。但放到测试场景里,它的思路非常简单:在你关心的关键路径上,主动埋下探针,采集执行数据,把这些数据汇总起来形成报表,用于定位问题。用在慢查询测试上,就是两件事:第一,找到哪条 SQL 慢;第二,搞清楚这条 SQL 是在哪个接口、哪个业务操作、哪个数据量条件下变慢的。

这套思路适合谁?适合所有被“测试环境一切正常,上线就出问题”折磨过的测试工程师、后端开发、性能测试同学。不需要你有多深的字节码功底,也不需要动线上代码,只要你手头有一个可运行的测试环境,再配合一点简单的埋点手段,就能把慢查询问题从“靠运气复现”变成“靠机制发现”。

2. 核心思路拆解:给程序装探头,把慢查询“看”清楚

2.1 插桩技术的基本原理:它到底在做什么

插桩的本质是在程序运行路径中插入一段额外的观测代码,就像在一条管道上装流量计。这段观测代码本身不影响业务逻辑,只是记录“经过这里时的状态”:耗时多少、入参是什么、走了哪条分支、调用了什么下游。

放到慢查询测试里,我们需要观测的点有三个:

  • SQL 执行入口:也就是 DAO 层或者 ORM 框架执行 SQL 的地方
  • 业务方法入口:也就是 Service 层或 Controller 层处理请求的地方
  • 数据访问上下文:也就是当前请求携带的用户、场景、参数、数据量等信息

如果你手动在代码里加日志,这当然也是一种插桩,但问题是太折腾,而且容易漏。更推荐的做法是用现成的中间件或框架能力来做,比如 Java 里的 MyBatis Interceptor、Spring AOP,MySQL 自带的慢查询日志,或者像 SkyWalking 这类 APM 工具里内置的 SQL 采集能力。它们本质上都是“插桩”,只是位置和粒度不同。

2.2 为什么不能只靠数据库慢查询日志

很多团队的第一反应是:打开 MySQL 的 slow_query_log 不就行了吗?确实,这能拿到最直接的 SQL 文本和执行耗时,但光有它远远不够。

我举个例子。假设慢查询日志里记录了这样一条:

SELECT * FROM order_detail WHERE user_id = 12345 AND status = 1 ORDER BY create_time DESC LIMIT 20;

执行耗时 2.3 秒。你看到这条 SQL,能立刻说出是哪个页面、哪个操作导致的吗?大概率不能。你还需要去代码里全局搜这条 SQL,然后反查是哪个 Mapper 方法、哪个 Service 在调用,再结合调用栈去推断业务场景。如果这个 Mapper 方法被十几个接口复用了,你就得一个个排除。

慢查询日志只回答了“哪条 SQL 慢”,但没回答“在什么业务场景下慢”。而后一个问题恰恰是测试同学复现问题、定位根因最需要的信息。所以,慢查询日志是底座,但光有底座不够,必须往上叠加应用层的插桩数据,把 SQL、接口、参数、场景串联起来。

2.3 统计口径的设计:比工具更重要的思路

工具选型是后话,思路里的核心其实是统计口径。你准备拿什么指标来判断“慢”?多长时间算慢?这个口径设计不好,后面全白搭。

先说结论,我的建议是至少从两个维度看:

  • 绝对阈值:单条 SQL 执行时间超过某个值(比如 500ms),直接判为慢
  • 相对基线:同一条 SQL 在正常情况下的平均耗时是 30ms,某次测试里变成 300ms,虽然绝对值没过阈值,但已经涨了 10 倍,这种也必须抓

只做绝对阈值会漏掉那些“本来很快、突然劣化”的 SQL;只做相对基线会有很多误报,因为测试环境的数据量抖动本来就会带来波动。两个维度一起看,才能既抓得住大问题,也不放过小劣化。

这套思路想清楚了,你再去选工具、写脚本,都会顺手很多。因为你不是在盲目收集数据,而是带着明确的观测目标去做插桩。

3. 实操落地:从零到一搭一套慢查询插桩方案

3.1 我的推荐组合:MySQL 慢查询日志 + 应用层 AOP + 数据汇聚

下面这套方案不是唯一解,但很适合测试团队快速落地,我用的也是这套组合:

  • 第一层:开启 MySQL 慢查询日志,设置一个相对敏感的阈值(测试环境可以设 200ms)
  • 第二层:在应用代码里用 AOP 拦截 Service 层方法,记录业务方法耗时;用 MyBatis Interceptor 或 Hibernate 拦截 SQL 执行,记录 SQL 耗时
  • 第三层:把两层日志通过 traceId 关联起来,汇聚成一张“接口-方法-SQL”的明细表

这三层分别回答不同的问题:MySQL 慢查询日志回答“数据库视角哪条 SQL 慢”,应用层插桩回答“业务视角哪个操作慢”,traceId 关联回答“慢 SQL 是由哪个请求触发的”。

3.2 第一步:开启慢查询日志,并解决“日志轮转”问题

MySQL 侧的操作不复杂,但要小心几个坑。先看基础配置:

-- 查看当前配置 SHOW VARIABLES LIKE 'slow_query_log%'; SHOW VARIABLES LIKE 'long_query_time'; SHOW VARIABLES LIKE 'log_queries_not_using_indexes'; -- 动态开启(重启失效) SET GLOBAL slow_query_log = ON; SET GLOBAL long_query_time = 0.2; SET GLOBAL log_queries_not_using_indexes = ON;

long_query_time的单位是秒,测试环境我建议设成 0.2,也就是 200ms,这样能捕捉到大多数潜在问题。线上一般设 1 秒,但测试环境为了“多看问题”,阈值可以激进一点。

log_queries_not_using_indexes这个开关建议一并打开,它会把没走索引的查询也记录下来,即使执行时间没超过阈值。这个配置对测试特别有用,因为它能提前暴露索引失效的问题。

需要特别注意日志轮转。默认情况下 MySQL 会不断往同一个慢查询日志文件里写,时间长了文件会变得巨大,甚至影响磁盘空间。建议在测试服务器上用 logrotate 做日志切割:

# /etc/logrotate.d/mysql-slow /var/log/mysql/mysql-slow.log { daily rotate 7 compress missingok postrotate mysqladmin flush-logs endscript }

3.3 第二步:应用层埋点,把 SQL 和业务场景“绑”起来

只有数据库日志,你只能看到 SQL 文本和耗时。要想知道这条 SQL 来自哪个接口、哪个用户、哪次操作,就得在应用层做文章。

如果你的项目是 Java 技术栈,MyBatis 的 Interceptor 是最省事的埋点位置。下面是一个简化版的拦截器,它的作用是在 SQL 执行前后记录耗时,并捕获当前请求的 traceId:

@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 SqlCostInterceptor implements Interceptor { private static final ThreadLocal<String> TRACE_ID_HOLDER = new ThreadLocal<>(); public static void setTraceId(String traceId) { TRACE_ID_HOLDER.set(traceId); } @Override public Object intercept(Invocation invocation) throws Throwable { long start = System.currentTimeMillis(); try { return invocation.proceed(); } finally { long cost = System.currentTimeMillis() - start; MappedStatement ms = (MappedStatement) invocation.getArgs()[0]; String sqlId = ms.getId(); String traceId = TRACE_ID_HOLDER.get(); if (cost > 50) { System.out.println("[SLOW-SQL] traceId=" + traceId + ", sqlId=" + sqlId + ", cost=" + cost + "ms"); } TRACE_ID_HOLDER.remove(); } } @Override public Object plugin(Object target) { return Plugin.wrap(target, this); } }

然后在 Controller 入口处,通过拦截器或过滤器生成 traceId,并塞到 ThreadLocal 里:

@Component public class TraceIdFilter implements Filter { @Override public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException { String traceId = UUID.randomUUID().toString().replace("-", ""); SqlCostInterceptor.setTraceId(traceId); try { chain.doFilter(request, response); } finally { // 请求结束,清理 ThreadLocal,避免线程池复用导致串号 } } }

这样,每次请求都会生成一个唯一的 traceId,这个 traceId 会贯穿到 SQL 执行的埋点日志里。拿到一条慢 SQL 的日志后,用 traceId 去查应用日志,就能定位到完整的调用链。

这里有个非常关键的经验:一定要在 finally 里清理 ThreadLocal。如果服务用了线程池,线程是复用的,不清理的话下一个请求会读到上一个请求的 traceId,排查问题的时候会被带偏。

3.4 第三步:设定采集维度,把数据变成可分析报表

日志打出来了还不够,要把数据变成可分析的形式。我最常用的做法是:把埋点日志输出到独立的文件,然后用 Logstash 或者简单的 Python 脚本按分钟聚合,最终落到一个 test_report 表里,包含以下字段:

  • trace_id:请求唯一标识
  • interface_name:接口名/PATH
  • method_name:Service 方法名或 Mapper 方法 ID
  • sql_text:慢 SQL 文本
  • sql_cost_ms:SQL 执行耗时
  • request_time:请求时间
  • extra_params:可选的扩展字段,比如 userId、订单号等

这张表建好之后,你就可以用 SQL 做各种分析:哪个接口产生的慢 SQL 最多、哪条 SQL 平均耗时最高、哪个时间窗口慢查询最集中、SQL 耗时和接口耗时之间的差距有多大。这个过程其实就是把“零散的日志”变成“结构化的测试结论”。

我建表之后最常用的几条查询长这样:

-- 按接口维度统计慢 SQL 数量 SELECT interface_name, COUNT(*) AS slow_cnt, ROUND(AVG(sql_cost_ms), 2) AS avg_cost FROM slow_sql_report WHERE report_date = CURRENT_DATE GROUP BY interface_name ORDER BY slow_cnt DESC; -- 查询同一 traceId 下所有 SQL,还原一次请求的完整 SQL 执行序列 SELECT sql_text, sql_cost_ms, method_name FROM slow_sql_report WHERE trace_id = '某个具体的traceId' ORDER BY id;

到这里,一套能落地的慢查询插桩方案就成形了。从数据库层到应用层再到分析层,每一层都在回答不同的问题。

4. 我踩过的坑:这些细节不处理,方案等于白搭

4.1 坑一:慢查询日志“时有时无”,其实是阈值和采样问题

有段时间我发现测试环境的慢查询日志特别稀疏,明明接口已经明显变慢了,日志里却只有几条记录。排查之后发现是两个原因叠加:一是long_query_time设得偏大,二是测试环境的 SQL 大多走了缓存,真正打到磁盘的查询不多。

解决办法是把阈值调低并清理缓存。注意,MySQL 的查询缓存即使命中,也仍然会去解析 SQL,但执行时间会显著下降。为了让慢查询能稳定复现,建议在测试方案里加上“清缓存”前置步骤:

RESET QUERY CACHE;

或者干脆在测试环境关闭查询缓存,避免缓存命中掩盖真实的 SQL 性能问题。

4.2 坑二:traceId 在异步线程里丢失

一个典型的场景:接口在主线程里生成了 traceId,但某条 SQL 是在异步线程池里执行的(比如一个任务回调、一个 MQ 消费逻辑)。由于 ThreadLocal 是线程隔离的,异步线程根本读不到主线程塞进去的 traceId,导致慢 SQL 日志里 traceId 为空,无法关联业务场景。

我的处理方式是在提交异步任务时手动传递 traceId:

ExecutorService executor = new ThreadPoolExecutor(...); String traceId = SqlCostInterceptor.getTraceId(); executor.submit(() -> { SqlCostInterceptor.setTraceId(traceId); try { // 异步任务真实逻辑 } finally { SqlCostInterceptor.clear(); } });

类似的坑还出现在 Redis 回调、MQ 监听器、定时任务里。只要你发现日志里有 SQL 慢记录但 traceId 是空的,不用怀疑,基本都是这类问题。

4.3 坑三:埋点影响性能,导致测试数据失真

插桩本身是有开销的。MyBatis Interceptor 里的反射调用、日志输出、traceId 生成,都会增加额外耗时。如果埋点写得太重(比如每个 SQL 都打印完整参数、每个方法都记录堆栈),那最终的耗时数据里掺杂了太多插桩自身的时间,反而不准。

我的建议是分级采样:

  • 所有 SQL 都记录耗时,但只在耗时超过阈值时才输出详情
  • 接口层埋点只记方法名和耗时,不记参数体
  • 日志输出用异步方式,或者直接写到独立文件,避免和业务日志混在一起造成 IO 抢占

另外,埋点上线后做一个“空跑对比”:在没有慢查询的场景里跑一遍接口,看插桩带来的额外耗时大概是多少。如果额外耗时稳定在 10ms 以内,对测试结论的影响就很有限;如果超过 50ms,就要精简埋点逻辑了。

4.4 坑四:慢查询日志只记录执行结束后的结果,中间态丢失

MySQL 慢查询日志是在 SQL 执行完之后才记录的,它只能告诉你“这条 SQL 花了多久”,但没法告诉你“执行过程中走了哪个索引、扫描了多少行、临时表用了多少”。这些中间态对定位根因极其重要。

所以我在捕获到慢 SQL 之后,还有一步固定动作:把 SQL 文本拿去做 EXPLAIN ANALYZE。MySQL 8.0 以后支持 EXPLAIN ANALYZE,它会真实执行 SQL 并给出每一步的耗时和行数,比传统 EXPLAIN 准确得多:

EXPLAIN ANALYZE SELECT * FROM order_detail WHERE user_id = 12345 AND status = 1 ORDER BY create_time DESC LIMIT 20;

执行结果里能看到是不是全表扫描、 sort_buffer 用了多少、索引扫描行数和返回行数的比例。这一步能直接定位到“为什么慢”,是缺索引、索引失效、排序太重还是数据倾斜。

5. 一次完整的实战复盘:用这套思路定位一个真实慢查询

5.1 现象

某次版本测试中,我的测试脚本报告“订单列表接口”P95 响应时间从 180ms 涨到了 860ms,但功能表现完全正常,没有任何报错。按照之前的经验,先把慢查询日志调出来看,果然发现一条 SQL 多次出现在慢查询列表里:

SELECT * FROM order_info WHERE user_id = 12345 AND pay_status IN (1, 2) AND deleted = 0 ORDER BY id DESC LIMIT 20;

执行耗时在 1.2 秒到 2.1 秒之间跳动。但奇怪的是,这条 SQL 在之前的测试里从来没慢过,索引也是有的。

5.2 插桩数据怎么帮我缩小范围

靠数据库日志我只能看到这一条 SQL,但应用层埋点给了我额外信息:慢 SQL 集中出现在 user_id 尾号为奇数的那批账号上。结合 traceId 反查后发现,这些请求都来自同一个模拟用户批量下单的测试脚本,而这个脚本在下单前会构造大量 order_info 数据。

也就是说,这不是 SQL 本身写坏了,而是数据分布发生了变化。某些 user_id 下的订单数据量特别大,单用户的数据行数已经超过 50 万,LIMIT 20 的查询在这批数据上走索引也可能扫出大量行。

5.3 用 EXPLAIN ANALYZE 锁定根因

对这条 SQL 执行 EXPLAIN ANALYZE 之后,关键信息出来了:虽然走了 idx_user_id 索引,但由于需要回表过滤 pay_status、deleted,再加上排序,优化器计算出的成本反而更倾向于全表扫描。数据量小的账号没问题,是因为优化器认为走索引成本更低;数据量大的账号则触发了错误的选择。

根因找到了:复合索引idx_user_id (user_id)对单字段查询有效,但无法覆盖 WHERE 中的 pay_status 和 deleted 两个过滤条件,导致大量回表。

5.4 修复与验证

修复方式是建立覆盖索引:

ALTER TABLE order_info ADD INDEX idx_user_status_deleted (user_id, pay_status, deleted, id);

重新跑同一批测试脚本,慢 SQL 从列表里消失,P95 响应时间稳定回落到了 190ms 左右。

这个案例里,数据库慢查询日志提供了“线索”,应用层插桩提供了“场景”,EXPLAIN ANALYZE 提供了“实锤”。三个工具缺一不可,而这套流程只有在测试环境提前做好插桩埋点的情况下才能顺畅跑通。如果还是靠“上线后等用户投诉再排查”,整个定位周期可能从 1 小时拉长到 1 天。

6. 几个关键参数的设置建议,直接抄作业

很多同学看完上面的思路,最容易卡在参数设置上。这里整理一份我在测试环境里常用的配置,可以当作初始值,再根据具体场景微调。

参数项推荐值说明
long_query_time0.2(200ms)测试环境尽量灵敏,宁多勿漏
log_queries_not_using_indexesON捕获未走索引的查询
slow_query_log 文件轮转daily + 保留7天避免磁盘空间被日志占满
应用层 SQL 埋点输出阈值50ms低于该值的 SQL 不做详情输出
traceId 传递范围全链路线程池重点检查异步线程、MQ 消费
慢查询分析聚合粒度分钟级和测试脚本执行节奏对齐

补充一点:long_query_time是否要设置成 0,这个要看测试目的。如果是专门做慢查询压测,可以临时设为 0,捕获所有 SQL;如果是回归测试,设成 0.2 比较合理,不然日志量太大,反而淹没了真正需要关注的问题。

日志量大不是小事。log_queries_not_using_indexes开启后,只要有一条 SQL 没走索引,就会持续输出。如果应用里有定时任务,每 10 秒跑一次全表扫的统计 SQL,那慢查询日志会以肉眼可见的速度膨胀。所以日志轮转和阈值控制一定不能省。

7. 这套思路还能怎么扩展

慢查询插桩的思路不只是适用于 MySQL,本质上它是一个“可观测性”的测试方案。顺着这个思路往下走,至少还能扩展出三个方向。

第一个方向是扩大到其他数据源。Redis 慢日志、Elasticsearch 慢查询、MongoDB 慢查询、甚至第三方接口的耗时,都可以用同样的思路做埋点和关联。只需要把 traceId 继续往下游传递,把各个组件的耗时都聚到同一张表里。

第二个方向是和自动化测试框架结合。在自动化测试的断言阶段,不只校验接口返回结果,还额外校验“这个接口产生的慢 SQL 数量是否为 0”。一旦有新增慢 SQL,断言直接失败,把问题挡在发布之前。我是在测试脚本里把慢 SQL 结果作为性能断言的条件之一,这样每次跑回归测试都能自动做一次性能体检。

第三个方向是接入告警。测试环境不是只有你在跑,可能还有联调、演示、验收在共用。与其人肉盯日志,不如写一个定时任务,每 5 分钟扫描一次慢 SQL 明细表,发现新增记录就推到企业微信或钉钉群。这样不管是谁把环境搞慢了,都能第一时间发现。

对我来说,这套思路最大的价值不在于工具多花哨,而在于它让慢查询从“偶发的线上问题”变成了“测试流程里可控的一环”。以前是上线出问题再去查日志,现在是在测试阶段就把慢 SQL 揪出来,并且能直接告诉开发是哪条 SQL、哪个接口、什么场景下变慢的。省下来的排查时间,远比搭这套方案花的时间多。

最后再分享一个小技巧:如果你们团队暂时没有精力做应用层埋点,那至少先把 MySQL 慢查询日志开起来,然后写一个每周汇总脚本,把 Top 10 慢 SQL 发到群里。这一步不需要任何代码侵入,5 分钟就能搞定,但已经能帮助你发现相当一部分潜在风险。等你们觉得有必要深挖“哪个场景触发的慢查询”了,再补齐应用层的插桩,整体效果会立刻上一个台阶。

需要专业的网站建设服务?

联系我们获取免费的网站建设咨询和方案报价,让我们帮助您实现业务目标

立即咨询