记一次 P0 bug 修复

[312ybj]

问题影响

今天早上 10:50 左右，系统页面突然不能访问，我们是 sass 系统，很多租户爆出了同样的错误。问题影响到了租户的使用。

排查流程

表现

时间

2021-09-15 10:50 am

问题表象

1. 多个租户素材列表页不显示内容

1. sentry 发出大量错误日志

都是同一个项目 general

排查方法

由于从报错日志中无法定位业务代码，所以采用相关度排查。

1. 确认最近的修改

早上 10:50 左右开始， 从此时间开始推导该时间前后

1. 上线的项目

昨晚是有一个项目上线，但是目前没有发现影响

1. 改过的配置

没有直接影响

1. 报错日志

无法定位问题

1. 数据量是否有较大变化

新租户 t247 上线了 80w 新素材，可能会对系统产生压力。

以上无法直接或间接得出结果

1. 判断代码&项目问题

general 模块报错， 但是从报错日志，无法确认是代码逻辑问题导致的错误。

一开始想找运维重启 general 项目，但是运维告知项目已经自动重启 6 次，重启无法解决问题。

1. 查看容器节点

正如运维所说 general 项目在不断的重启， 重启是因为节点的健康检查机制， 连续 5 次 3s 内健康检查请求得不到反馈，容器自动重启。 但是重启后最大请求时间还是居高不下。后来运维关闭健康检查机制。 奇怪的是关闭健康检查机制之后，系统莫名的正常了。但是没有找到正确答案，还是不能放松警惕。此时时间是 11:25 am 左右。

1. 关注 grafana

发现请求最大时长可以达到一分半，这个就绝对不正常了。怪不得容器不停重启，肯定是因为请求堵塞了，所以健康检查接口无法得到结果。

1. 定位请求慢原因（慢 SQL ）

当时项目 CPU 正常，内存正常，垃圾回收正常。 于是将问题归纳到数据库上，联系运维拉取慢日志。慢日志拉下来了。

慢日志还挺多

在茫茫日志中，有一个熟悉的数字 t247， 而且不止出现一次。这个 SQL 执行了 49s 。

当然一个 49s 的慢 SQL 不至于把系统整瘫。

1. 找人问最近上线事宜

在第一步中，我们找到最近上线的负责人， 因为他们上线时增加了 80w 数据，而慢 SQL 与数据量也有很大关系。仔细一聊，我们发现了一个要命的问题：前端有个页面，某个接口在会每隔 10s 请求一次 general，而且这个接口很慢。于是我打开了 grafana， 一遍复现这个请求，一遍观察请求速度。不出所料，的确很慢。 随后安排了这个逻辑修复。

为什么健康检查关闭就好了？

由后续的检测可以得知：慢 SQL 是拖垮 general 项目的原因。如果 genenral 项目能恢复，那么原因就是慢 SQL 任务执行完毕了。

在观察慢 SQL 日志时，我发现关闭健康检查的同时（ 11:25 am ），关于 t247 租户的慢 SQL 锐减。这基本上就能确定慢 SQL 的锅了。

总结

首先遇到较难问题不要慌，积极应对。多个人多份力量，一起分析。

可以按照上面的排查方法一步一步来。

1. 查看各个指标监控

• sentry 项目检测
• k8s 重启次数
• Grafana 性能指标
• 数据库 CPU&内存指标
• 慢 SQL 检测

1. 确认最近的修改

2. 代码与项目状态排查

3. 针对代码或者项目进行分析

4. 拉通第一步中人员进行一起分析

基本上通过这几步问题大致能够定位问题所在，剩下 20%的工作量就是修复 bug 了

[liprais]

如果是我的话我第一步就是确认数据库没问题

[shuimugan]

运维干的活只有重启和拉日志？那还不如直接上公有云的 serverless 架构，连运维都省了...

“联系运维拉取慢日志。慢日志拉下来了”
其实完全可以定时（比如 5min ）采集慢日志，收集起来，也就是为什么云厂商总有一个面板给你去看慢日志。

“仔细一聊，我们发现了一个要命的问题：前端有个页面，某个接口在会每隔 10s 请求一次 general，而且这个接口很慢”
如果你的网关日志采集了，并且做了阈值告警，这也可以感知出来，这也是为什么云厂商的日志服务里，可以根据查询结果配置告警。

“general 模块报错， 但是从报错日志，无法确认是代码逻辑问题导致的错误”

如果 CMDB 之类的信息化建设得好的话，每个项目都有哪些接口，每个接口背后调用了什么资源（比如数据库实例，用的 DB，查的表），每个项目在部署的时候怎么对应容器 Pod 等信息都能知道的话...
针对文中的 case，从网关日志中捕获到时间长的接口，就可以检索出接口背后在什么容器，负载如何，接口对应的库表当前有什么慢查询，当前版本和上一个版本差异的提交有哪些...各个维度的内容 load 出来一份报告，问题就找得差不多了。
这时候自动出一个审批单，是否紧急屏蔽这个接口的访问，熔断也好了。

当然，这些都很理想，在中华田园敏捷开发的模式下很难搞起来，不然你这个问题在上线前测试流程加一道压测就不会存在了。

[adspe]

不如好好检讨一下为什么前端会有这个轮询的接口，完全是自己作出来的

[zjj19950716]

80w 是什么概念

[neptuno]

这 sql 看上去是挺慢的，select id from (select b1.id,(select.....))

[312ybj]

@shuimugan 大佬一针见血， 佩服佩服

[qionnian]

请教一下，第一张图叫什么来着