性能优化手记:灰度发布 排查全过程
起因
上周给订单详情服务发了个新版本,改动不大,就是在接口返回里加了个用户标签的展示,照例先灰度 5% 的流量,观察半小时没问题再全量。结果发上去还不到十分钟,告警群就响了,P99 从平时 80ms 左右直接飙到 500 多毫秒,灰度实例上尤其明显。
第一反应肯定是回滚,但转念一想,才 5% 的流量,影响可控,不如先按住别动,趁这个机会把原因查清楚,不然回头全量的时候还得再踩一遍。
先看监控,圈定范围
打开 Grafana,把灰度实例和线上老实例的曲线叠在一起看,CPU 差不多,内存也差不多,GC 频率没有明显变化,QPS 按流量比例算也正常。唯独两处不对劲:
- 灰度实例 P99 高得离谱,但平均响应没什么变化,说明被拖慢的只是少数请求;
- 灰度实例连的那台 MySQL 从库,QPS 比平时高了一截。
到这里基本可以断定是灰度版本带进来的问题,而且大概率出在某个新加的查询上——个别请求慢、整体不慢,这种特征一般就是少数流量走到了一条很慢的路径上。中间还绕了个弯,先去怀疑是新加的 Redis 调用超时,翻了半天访问日志,Redis 这边耗时都是毫秒级,排除。
翻慢查询日志,逮到那条 SQL
然后就去翻了慢查询日志,果然,多了条之前从没见过的 SQL:
SELECT * FROM user_tag WHERE user_id = 12345 AND scene = 'detail';
单条执行时间 400ms 往上。EXPLAIN 一看,type 是 ALL,全表扫描,rows 那一列预估要扫两千多万行,看到这个数字基本就不用再猜了。
对着代码一查就明白了:这次要查的 user_tag 其实是张老表,一直有个离线任务在往里同步数据,两千万多行就是这么攒出来的。之前没有任何线上接口读过它,所以谁也不知道它压根没索引,建表语句当年是从别的项目抄的,只留了个自增主键。这次接口第一次开始读它,直接就是全表扫。
验证一下,别冤枉了它
虽然证据已经比较充分了,还是走了个流程:预发环境部署灰度分支,用线上采样下来的真实流量回放一遍,P99 一样飙;然后给测试库的 user_tag 加索引,同样的请求再回放,耗时直接掉到 2ms 以内。实锤了。
ALTER TABLE user_tag
ADD INDEX idx_uid_scene (user_id, scene);
修复与放量
加索引、发版、把灰度比例调回去,流程本身没什么好说的,两个细节值得记一下:
- 两千多万行的表直接加索引是有风险的。我们这边 MySQL 是 8.0,加二级索引默认走
INPLACE,不锁写,但会吃 IO,所以挑了个凌晨低峰执行,实测跑了两分多钟,主从延迟有个小尖峰,无伤大雅。如果是 5.7 或者更老的版本,记得先确认ALGORITHM=INPLACE能不能走,不行就得用 pt-osc 这类工具,没准儿你们 DBA 平台上已经有现成的入口; - 顺手立了条规矩:以后新表相关的 SQL 变更上工单,必须附一张
EXPLAIN的执行计划截图,别再靠肉眼盯代码猜。
改完重新灰度,观察了半小时,P99 稳定在 85ms 左右,和线上老版本基本持平,第二天才放的全量。目前跑了一个多星期,没再出过幺蛾子。
几点记录
- 灰度这次是救命了,5% 的流量把影响面控制得死死的,不然那张表全表扫描,估计就不只是 P99 飙 500ms 这么简单了;
- “平均响应没变、P99 飙了”这个特征很好用,可以直接往“少数请求走了慢路径”这个方向查,省掉很多绕路的时间;
- 从库 QPS 那个指标是这次破案的关键,当时要是只盯着应用自身的 CPU 和 GC 看,没准儿还在 JVM 里绕圈呢;
- 最后就是建表别偷懒,索引该加就加,尤其是从别的项目抄建表语句的时候,抄完记得
SHOW INDEX看一眼,这玩意儿真不能省。
评论
还没有评论。
发表评论
提交后评论将经过自动审核,审核通过后公开展示。