Administrator
发布于 2020-11-23 / 3741 阅读
61

一次生产事故复盘:一个慢 SQL 拖垮整个链路

十一月二十三号:一条 SQL 拖垮了五个服务

那天上午 10:07,监控大屏开始变红。从商品服务开始,10 分钟内波及五个服务,最后整个交易链路不可用,持续 23 分钟。这篇把整个过程复盘一遍,包括我们当时做错的判断。

时间线

时间事件
10:07商品服务接口 TP99 从 45ms 涨到 3.2 秒
10:09订单服务调用商品服务超时,下单接口 TP99 涨到 8 秒
10:11购物车、优惠券服务开始告警(都依赖商品服务)
10:13网关活跃连接数 7800(平时 200),大量 502
10:15我们做了第一个处置:重启商品服务(错误决策
10:18重启后 30 秒内短暂恢复,然后再次恶化
10:22定位到慢 SQL,DBA 杀掉会话
10:26商品服务恢复,链路开始自愈
10:30全部指标恢复正常

起点:一条没有索引的查询

起因是 DBA 在 10:05 执行了一个数据修复脚本,里面有这么一条:

-- 修复一批商品的类目,运营手工整理的 ID 列表
UPDATE t_item
SET category_id = 108
WHERE supplier_code IN ('SUP00123', 'SUP00456', ...);   -- 一共 812 个值

supplier_code 字段上没有索引。表 380 万行。这条 UPDATE 要全表扫描,并且对所有扫描到的行加行锁(RR 隔离级别下还会加间隙锁)。

实际的锁等待情况:

mysql> SELECT * FROM sys.innodb_lock_waits LIMIT 5;
+-------------------+-------------------+-----------------+------------------+
| waiting_pid       | waiting_query     | blocking_pid    | blocking_query   |
+-------------------+-------------------+-----------------+------------------+
|              1203 | UPDATE t_item ... |            1188 | UPDATE t_item SE |
|              1207 | UPDATE t_item ... |            1188 | UPDATE t_item SE |
|              1211 | SELECT ... FOR UP |            1188 | UPDATE t_item SE |
|              1412 | UPDATE t_item ... |            1188 | UPDATE t_item SE |
+-------------------+-------------------+-----------------+------------------+

1188 是那个修复脚本的连接,后面排了 40 多个等待锁的会话。商品服务的正常业务 UPDATE(改库存、改状态)全部卡在锁等待上,每个等待 50 秒超时(innodb_lock_wait_timeout)。

雪崩是怎么传播的

这是复盘里最值得写的一部分。一条 SQL 慢了,为什么会导致五个服务全挂?

第一层:数据库连接池被占满

商品服务的 HikariCP 配置是 maximumPoolSize: 20。锁等待让每个查询都要 50 秒才返回,20 个连接瞬间被占满。第 21 个请求来的时候:

java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available,
request timed out after 30000ms
	at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:696)
	at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:197)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128)
	at com.xxx.service.ItemService.getDetail(ItemService.java:88)

获取连接超时是 30 秒。也就是说,商品服务的每个接口都要等 30 秒才返回失败。

第二层:Tomcat 线程池跟着耗尽

商品服务的 200 个 Tomcat 线程,全部阻塞在"等数据库连接"或者"等下游 SQL"上。

$ curl http://localhost:8080/actuator/metrics/tomcat.threads.busy
{"name":"tomcat.threads.busy","measurements":[{"statistic":"VALUE","value":198.0}]}

198/200。商品服务彻底失去响应能力。

第三层:上游同步调用被拖死

订单服务调商品服务用的是 OpenFeign,同步阻塞,超时配置 3 秒:

@FeignClient(name = "item-service", configuration = FeignConfig.class)
public interface ItemClient {
    @GetMapping("/api/item/{id}")
    Result<ItemVO> getById(@PathVariable("id") Long id);
}
feign:
  client:
    config:
      default:
        connectTimeout: 2000
        readTimeout: 3000      # 3 秒超时

3 秒超时,看起来是保护。但订单服务自己的 Tomcat 线程数是 200,QPS 是 400。一个新请求进来占一个线程,3 秒后才释放,那么订单服务的处理能力就是 200 线程 ÷ 3 秒 = 66 QPS,远低于 400 的入口流量。

结果:订单服务的 Tomcat 线程也被占满,连"不依赖商品服务"的接口(比如查订单详情)都开始超时。

第四层:重试放大流量

我们当时配了 Ribbon 的重试(Spring Cloud Hoxton):

ribbon:
  MaxAutoRetries: 1              # 同一实例重试 1 次
  MaxAutoRetriesNextServer: 2    # 换实例重试 2 次
  OkToRetryOnAllOperations: true

这意味着一次失败的请求最多会发 (1 + 1) × (1 + 2) = 6 次。商品服务已经在垂死挣扎,重试又给它加了 3~6 倍的流量。这是典型的重试风暴

10:10 的时候商品服务的入口 QPS 是 8400,而它的真实业务流量只有 1200。多出来的 7200 全是重试。

第五层:网关连接耗尽

Spring Cloud Gateway 用的是 Netty(异步非阻塞),理论上不该被拖垮。但它的 worker 线程在处理时如果调用了阻塞的下游(我们的鉴权过滤器里有同步的 Redis 调用),也会被拖住。

$ curl http://gateway:8080/actuator/metrics/reactor.netty.connection.provider.total.connections
{"measurements":[{"statistic":"VALUE","value":7821.0}]}

连接数 7821,最终网关也开始返回 502。

我们做错的两件事

错误一:第一时间重启了服务

10:15 我们判断"商品服务卡死了",就把它重启了。这是当时能做的最坏的选择,原因有两个:

  • 重启丢失了所有现场。jstack、连接池状态、慢查询的现场全没了,白白浪费了宝贵的排查时间。
  • 重启之后的"冷启动"让情况更糟。服务刚起来时本地缓存是空的,所有请求直击数据库,而数据库正被那条慢 SQL 锁着。10:18 的监控显示,重启后 30 秒内商品服务 QPS 短暂恢复到 800,然后连接池瞬间再次打满,比重启前更彻底。

正确做法应该是:先摘流量(或者在网关层限流),保住一台机器做现场分析。我们后来定的规范是,出现这类故障,先保留一台实例不重启,把它的 jstack 和 jstat 抓下来。

错误二:核心链路没配熔断

这是根子上最该反思的一点。我们当时的架构里,只配了限流,没有配熔断。限流防的是"流量超过我的能力",熔断防的是"依赖变慢时我别被拖死"。这两个是不同的东西。

如果当时商品服务的调用有熔断,链路会在 3 秒内断开,订单服务不会被拖满线程,故障范围就局限在商品服务自己。

正确的定位路径

事后复盘,如果重来一次,最快定位到那条慢 SQL 的方式是:

-- 1. 看当前正在执行且超过 2 秒的会话
SELECT id, user, host, db, command, time, state, LEFT(info, 120) AS sql_text
FROM information_schema.processlist
WHERE command != 'Sleep'
  AND time > 2
ORDER BY time DESC
LIMIT 20;

+------+---------+-----------------+------+---------+------+-----------+----------------------------------+
| id   | user    | host            | db   | command | time | state     | sql_text                         |
+------+---------+-----------------+------+---------+------+-----------+----------------------------------+
| 1188 | appuser | 10.20.3.11:5213 | shop | Query   |  642 | updating  | UPDATE t_item SET category_id ... |
| 1203 | appuser | 10.20.1.24:4182 | shop | Query   |  318 | updating  | UPDATE t_item SET stock = ...    |
| 1207 | appuser | 10.20.1.25:5193 | shop | Query   |  297 | updating  | UPDATE t_item SET stock = ...    |
+------+---------+-----------------+------+---------+------+-----------+----------------------------------+

第一条已经执行了 642 秒,后面全是等锁的。看到这个,答案就已经出来了。

-- 2. 杀掉它
KILL 1188;

MySQL 8.0 也可以用 sys.innodb_lock_waits 这个视图,它把锁等待的上下游关系理得很清楚(前面贴过)。

改造措施

故障之后我们做了五件事,按优先级排序。

一、DDL / DML 变更必须走审核

这条 SQL 是 DBA 手工执行的,没有走审核流程。我们上线了 Archery(一个开源的 SQL 审核平台),规则包括:

  • WHERE 条件里的字段必须有索引(用 EXPLAIN 检查 type 不能是 ALL)。
  • 单条 UPDATE/DELETE 影响行数超过 1 万,必须拆分。
  • 大批量操作必须在业务低峰期执行,且要分批 + 加 sleep。

顺便说下,那条修复脚本本身也应该改成分批:

-- 不要一次更新 812 个值,按主键分批,每批 500 行
UPDATE t_item SET category_id = 108
WHERE id IN (SELECT id FROM (SELECT id FROM t_item WHERE supplier_code IN (...) LIMIT 500) t);
-- 每批之间 sleep 0.5 秒,给从库和业务留出喘息时间

二、接入 Sentinel 做熔断降级

这是我们之前最大的缺失。用 Sentinel 1.8,给所有跨服务调用配熔断规则。

@Configuration
public class SentinelConfig {

    @PostConstruct
    public void init() {
        List<DegradeRule> rules = new ArrayList<>();

        // 商品服务调用:慢调用比例熔断
        DegradeRule itemRule = new DegradeRule("GET:http://item-service/api/item/{id}")
                .setGrade(RuleConstant.DEGRADE_GRADE_RT)
                .setCount(500)                    // RT 阈值 500ms
                .setSlowRatioThreshold(0.5)       // 慢调用比例超过 50%
                .setMinRequestAmount(20)          // 最少 20 个请求才开始统计
                .setStatIntervalMs(10000)         // 统计窗口 10 秒
                .setTimeWindow(30);               // 熔断 30 秒
        rules.add(itemRule);

        // 异常比例熔断
        DegradeRule stockRule = new DegradeRule("POST:http://item-service/api/stock/deduct")
                .setGrade(RuleConstant.DEGRADE_GRADE_EXCEPTION_RATIO)
                .setCount(0.6)                    // 异常比例 60%
                .setMinRequestAmount(10)
                .setStatIntervalMs(10000)
                .setTimeWindow(60);
        rules.add(stockRule);

        DegradeRuleManager.loadRules(rules);
    }
}

配合 @SentinelResource 和降级方法:

@SentinelResource(
        value = "getItemById",
        blockHandler = "getItemBlockHandler",
        fallback = "getItemFallback")
public ItemVO getItemById(Long id) {
    return itemClient.getById(id).getData();
}

/** 熔断/限流时走这里 */
public ItemVO getItemBlockHandler(Long id, BlockException e) {
    log.warn("商品服务被熔断, id={}", id);
    return ItemVO.degraded(id);          // 返回一个兜底对象,标记"信息暂不可用"
}

/** 业务异常时走这里 */
public ItemVO getItemFallback(Long id, Throwable t) {
    // 先查本地缓存,再不行返回兜底
    ItemVO cached = localCache.get(id);
    return cached != null ? cached : ItemVO.degraded(id);
}

配好之后的效果用故障演练验证过:人为把商品服务的响应延迟到 5 秒,10 秒内订单服务的熔断生效,之后 30 秒内所有对商品服务的调用直接走降级方法,不发请求。订单服务的 Tomcat 线程占用从 198 降到 41。

三、关掉 Ribbon 的重试,或者大幅收敛

原来的 MaxAutoRetriesNextServer: 2OkToRetryOnAllOperations: true 是危险组合。OkToRetryOnAllOperations: true 意味着非幂等的 POST 请求也会重试,可能造成重复下单。

ribbon:
  MaxAutoRetries: 0                  # 不重试同一实例
  MaxAutoRetriesNextServer: 1        # 最多换 1 个实例
  OkToRetryOnAllOperations: false    # 只对 GET 重试,POST 不重试
  retryableStatusCodes: 502,503      # 只对网关错误重试,不对超时重试

更激进一点的做法是干脆关掉重试,让 Sentinel 的熔断来兜底。我们最后是只对 GET 请求保留 1 次换实例重试,写操作一律不重试。

四、数据库连接池和 Tomcat 线程池的参数对齐

之前这两个是各配各的,没有考虑过它们的联动关系。现在的规则是:

spring:
  datasource:
    hikari:
      maximum-pool-size: 20          # 20 个连接
      connection-timeout: 3000       # 从 30 秒降到 3 秒
  server:
    tomcat:
      max-threads: 200
      max-connections: 8192

connection-timeout 从 30 秒改成 3 秒是个关键改动。原来的逻辑是"多等等,说不定能拿到连接",但实际上等 30 秒拿不到,请求早就超时了,白占线程。改成 3 秒之后,拿不到连接立刻失败,线程马上释放,服务的吞吐量反而上去了。

另一个原则:Tomcat 线程数不应该远大于数据库连接池大小。200 个线程抢 20 个连接,意味着 180 个线程在空等。我们现在按 max-threads ≈ connection-pool-size × 4 来配(考虑到只有部分请求需要查库)。

五、给核心接口加线程池隔离

这个是借鉴舱壁模式。即使熔断生效了,商品服务内部的慢 SQL 还是会把自己的线程占满。给读写操作分配独立的连接池:

spring:
  datasource:
    write:
      jdbc-url: jdbc:mysql://master:3306/shop
      hikari:
        maximum-pool-size: 12
        connection-timeout: 3000
    read:
      jdbc-url: jdbc:mysql://slave:3306/shop
      hikari:
        maximum-pool-size: 20
        connection-timeout: 3000

写操作(下单、扣库存)有自己独立的 12 个连接,即使读操作全部卡住,下单依然可用。

改造后的故障演练

一个月后我们做了一次演练:人工在商品库上执行一个全表锁的 UPDATE,持续 5 分钟。

指标事故时演练时
商品服务 TP993.2 秒1.2 秒(快速失败)
订单服务 TP998 秒520ms(熔断后走降级)
下单成功率0%94%
影响服务数5 个1 个(只有商品服务)
恢复时间23 分钟自动,无需人工

下单成功率 94% 而不是 100%,是因为商品信息拿不到的时候,部分校验做不了,只能拒绝。这个是我们能接受的——保住核心可用,比全挂强得多。

小结

  1. 雪崩的传播链条是:慢 SQL → 连接池满 → Tomcat 线程满 → 上游同步调用超时 → 上游线程满 → 重试放大 → 网关连接耗尽。每一层都会把故障放大。
  2. 限流和熔断是两件事。限流防流量过载,熔断防依赖拖死。这次事故暴露的就是"有 Sentinel 但只配了限流,没配熔断"。
  3. 故障第一时间不要重启服务,会丢失现场。先摘流量,留一台机器抓 jstack 和 processlist。
  4. 重试是双刃剑。OkToRetryOnAllOperations: true 会让非幂等请求也重试,既放大流量又可能造成重复数据。写操作一律不重试。
  5. 超时时间要收敛,别"多等一会"。connection-timeout 30 秒比 3 秒更害人——等不到还白占线程。快速失败 + 熔断降级,比死等健康得多。

参考