接口突然慢了 10 倍,我用这 5 个命令定位到一条 SQL 接口突然慢了 10 倍我用这 5 个命令定位到一条 SQL一个原本 200ms 的订单接口线上突然变成 2 秒偶尔还会直接超时。CPU 看起来不高内存也没有爆重启之后短暂恢复过一会儿又开始变慢。最后没有靠重启解决而是顺着线程、连接池和数据库定位到了一条没有索引的 SQL。一、事故现场下午业务高峰期监控连续报警订单查询接口 P99230ms - 2.6s Tomcat 活跃线程38 - 196 数据库连接池 active12 - 50 数据库连接池 pending0 - 87 接口超时率0.1% - 6.4%第一反应通常是看 CPU 和内存。结果服务器上的指标并不夸张CPU35% 堆内存58% Full GC没有明显增加 机器负载略有升高没有 CPU 打满也没有 OOM。但接口就是越来越慢。这类事故最麻烦的地方在于服务看起来还活着实际上处理请求的线程正在排队等待。如果这时候只重启应用连接池和线程池会暂时清空接口确实可能恢复。但真正的问题还在。流量一回来故障还会再次出现。下面按一次典型排查过程把整条链路走一遍。二、第一步用 top 判断是不是机器资源问题先登录故障机器top重点看这些指标%Cpu(s) load average RES 进程 CPU 排名如果 Java 进程 CPU 已经接近 100%优先排查死循环、频繁 GC、序列化、加密计算或者热点代码。如果 CPU 不高但接口仍然很慢不能得出“应用没问题”的结论。因为线程可能正在等待等待数据库返回 等待远程接口返回 等待 Redis 返回 等待获取数据库连接 等待获取锁等待中的线程不一定消耗很多 CPU。所以这次事故里top的作用不是直接找到根因而是先确定排查方向CPU 不高优先检查线程都在等什么。找到 Java 进程 PIDjps-l假设应用 PID 是18472。三、第二步用 top -Hp 找热点线程继续查看 Java 进程里的线程top-Hp18472如果存在持续占用 CPU 的线程记下线程 ID。假设线程 ID 是18531Java 线程栈中的线程编号是十六进制需要转换printf%x\n18531输出4863后面就可以在jstack中搜索nid0x4863不过这次没有发现某个线程持续吃满 CPU。反而发现大量线程 CPU 占用很低。这更加符合“线程阻塞等待”的特征。四、第三步连续抓三次 jstack不要只抓一次线程栈。单次线程栈只能看到一个瞬间容易把正常的短暂等待误判成故障。建议间隔 5 到 10 秒连续抓三次jstack-l18472/tmp/jstack-1.logsleep5jstack-l18472/tmp/jstack-2.logsleep5jstack-l18472/tmp/jstack-3.log如果环境里的jstack无法正常附加也可以使用jcmd18472Thread.print-l/tmp/thread.log检查线程状态分布grepjava.lang.Thread.State/tmp/jstack-1.log|sort|uniq-c这次看到大量请求线程处于java.lang.Thread.State: WAITING (parking)继续查看堆栈出现了大量类似内容http-nio-8080-exec-173 java.lang.Thread.State: WAITING (parking) at jdk.internal.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(...) at com.zaxxer.hikari.util.ConcurrentBag.borrow(...) at com.zaxxer.hikari.pool.HikariPool.getConnection(...) at com.zaxxer.hikari.HikariDataSource.getConnection(...)这段栈已经给出了非常明确的线索Tomcat 请求线程不是在执行慢代码而是在等待数据库连接。如果三份线程栈里同一批线程一直停留在HikariPool.getConnection()就不是瞬时抖动了。连接池大概率已经被占满。五、第四步检查数据库连接池应用使用的是 HikariCP可以直接查看监控指标hikaricp_connections_active hikaricp_connections_idle hikaricp_connections_pending hikaricp_connections_timeout_total事故发生时的数据是maximumPoolSize 50 active 50 idle 0 pending 87它表达的意思很直接50 个连接全部被占用 没有空闲连接 87 个请求正在排队等连接此时把连接池从 50 调到 100可能让接口短暂恢复。但这通常只是把问题往数据库推。如果某条 SQL 执行 3 秒50 个连接可以同时压 50 条慢 SQL 100 个连接可以同时压 100 条慢 SQL连接池变大之后数据库可能反而更快被拖垮。所以连接池占满只是现象还要继续查这些连接到底在执行什么六、第五步从数据库找出正在执行的 SQL先看当前数据库会话SHOWFULLPROCESSLIST;也可以通过performance_schema查询SELECTPROCESSLIST_ID,PROCESSLIST_USER,PROCESSLIST_HOST,PROCESSLIST_DB,PROCESSLIST_TIME,PROCESSLIST_STATE,PROCESSLIST_INFOFROMperformance_schema.threadsWHERETYPEFOREGROUNDANDPROCESSLIST_COMMANDSleepORDERBYPROCESSLIST_TIMEDESC;当时出现了大量相同 SQLSELECTid,order_no,user_id,status,amount,create_timeFROMt_orderWHEREuser_id10086ANDstatus1ORDERBYcreate_timeDESCLIMIT20;单看 SQL 并不复杂。但执行计划暴露了问题EXPLAINSELECTid,order_no,user_id,status,amount,create_timeFROMt_orderWHEREuser_id10086ANDstatus1ORDERBYcreate_timeDESCLIMIT20;结果中的关键信息type: ALL key: NULL rows: 2865341 Extra: Using where; Using filesort也就是说这条看起来普通的查询做了这些事扫描大量订单数据 按 user_id 和 status 过滤 再按 create_time 排序 最后只返回 20 条数据量小时它可能只执行几十毫秒。当订单表增长到几百万行高峰期再被并发调用执行时间就从几十毫秒涨到了几秒。慢 SQL 长时间占着数据库连接不释放最终形成完整的故障链路SQL 没有合适索引 ↓ 单次查询时间变长 ↓ 数据库连接长期被占用 ↓ 连接池 active 达到上限 ↓ Tomcat 线程等待连接 ↓ 请求排队接口 RT 飙升 ↓ 上游重试流量进一步放大这也解释了为什么 CPU 并不高接口却慢了 10 倍。七、真正的修复不是重启也不是扩大连接池根据查询条件和排序方式补充联合索引ALTERTABLEt_orderADDINDEXidx_user_status_create_time(user_id,status,create_time);再次检查执行计划type: ref key: idx_user_status_create_time rows: 32 Extra: Using index condition索引上线后接口逐步恢复SQL 平均耗时2.1s - 18ms 连接池 active50 - 9 连接池 pending87 - 0 接口 P992.6s - 240ms这里需要注意联合索引不能只看这一条 SQL 就直接在生产创建。还要评估表的数据量 现有索引是否重复 写入成本是否可接受 索引创建是否会影响线上业务 查询字段和排序方向 不同 user_id、status 的数据分布MySQL 8.0 可以先确认具体版本与 DDL 能力再选择合适的上线方式。数据量很大的表应该在业务低峰操作并准备监控和回退方案。八、为什么测试环境一直没发现因为测试环境通常不具备三个条件。1. 数据量不够测试表可能只有几千条数据。即使全表扫描执行也非常快。生产表有几百万甚至上亿条数据同一条 SQL 的成本完全不同。2. 并发量不够一条 SQL 执行 2 秒不一定立刻拖垮服务。但 50 条慢 SQL 同时执行就可能占满连接池。3. 数据分布不一样测试数据往往非常均匀。生产里可能存在大客户、热门用户和特殊状态单个条件就能命中几十万行。所以慢 SQL 排查不能只问在我本地执行快不快还要问在生产数据量、真实数据分布和高峰并发下它会占用多少资源九、线上接口变慢我一般按这个顺序查遇到接口 RT 突然升高可以先保存下面这份顺序。第一步确认影响范围单个接口还是全部接口 单台机器还是全部实例 持续变慢还是偶发尖刺 是否刚发布或变更配置第二步看机器资源top检查 CPU、负载、内存和 Java 进程。第三步看线程在做什么top-Hppidjstack-lpid连续抓三次区分 CPU 热点、锁等待、连接池等待和远程调用阻塞。第四步看资源池Tomcat 线程池 数据库连接池 业务线程池 HTTP 连接池 Redis 连接池第五步顺着等待点查下游慢 SQL 和执行计划 远程接口 RT Redis 慢查询 消息队列积压 磁盘和网络不要一看到接口慢就先改 JVM 参数也不要一看到连接池满就直接扩容。先找到线程在等待什么排查会快很多。十、总结这次事故最容易误导人的地方是CPU 不高 内存正常 重启后能恢复但真正的故障链路是一条 SQL 没有合适索引 - 查询越来越慢 - 数据库连接被占满 - 请求线程排队 - 接口整体超时所以线上接口变慢时先别急着重启。记住这条排查主线机器资源看方向线程栈看等待点连接池看拥堵数据库看根因。遇到线上问题也可以来找我一起看如果你正在处理这些问题Java 服务启动失败、接口超时、CPU 或内存异常 Spring Boot、MySQL、Redis、Nginx 安装与部署 Linux 环境配置、服务上线、日志和故障排查 线程池、连接池、慢 SQL、死锁等线上问题可以关注公众号云技纵横后台发送“排查”联系我。为了更快判断问题建议同时提供1. 出现了什么现象 2. 完整报错或脱敏日志 3. 系统、JDK 和中间件版本 4. 最近做过哪些发布或配置变更 5. 已经尝试过哪些处理方式简单问题、基础安装和初步排查我可以免费帮忙看一下涉及长期运维、生产环境操作或完整项目实施会先说明范围和风险再确认是否需要进一步处理。生产日志请先脱敏不要发送密码、Token、数据库账号、服务器私钥和用户隐私数据。下一篇继续复现线上频繁 Full GC堆内存明明还有空间为什么接口还是卡死