问题影响
今天早上 10:50 左右，系统页面突然不能访问，我们是 sass 系统，很多租户爆出了同样的错误。问题影响到了租户的使用。
排查流程
表现
时间
2021-09-15 10:50 am
问题表象
- 多个租户素材列表页不显示内容
- sentry 发出大量错误日志
都是同一个项目 general
排查方法
由于从报错日志中无法定位业务代码，所以采用相关度排查。
-
确认最近的修改
早上 10:50 左右开始， 从此时间开始推导该时间前后
- 上线的项目
昨晚是有一个项目上线，但是目前没有发现影响
- 改过的配置
没有直接影响
- 报错日志
无法定位问题
- 数据量是否有较大变化
新租户 t247 上线了 80w 新素材，可能会对系统产生压力。
以上无法直接或间接得出结果
-
判断代码&项目问题
general 模块报错， 但是从报错日志，无法确认是代码逻辑问题导致的错误。
一开始想找运维重启 general 项目，但是运维告知项目已经自动重启 6 次，重启无法解决问题。
- 查看容器节点
正如运维所说 general 项目在不断的重启， 重启是因为节点的健康检查机制， 连续 5 次 3s 内健康检查请求得不到反馈，容器自动重启。 但是重启后最大请求时间还是居高不下。后来运维关闭健康检查机制。 奇怪的是关闭健康检查机制之后，系统莫名的正常了。但是没有找到正确答案，还是不能放松警惕。此时时间是 11:25 am 左右。
- 关注 grafana
发现请求最大时长可以达到一分半，这个就绝对不正常了。怪不得容器不停重启，肯定是因为请求堵塞了，所以健康检查接口无法得到结果。
-
定位请求慢原因（慢 SQL ）
当时项目 CPU 正常，内存正常，垃圾回收正常。 于是将问题归纳到数据库上，联系运维拉取慢日志。慢日志拉下来了。
慢日志还挺多
在茫茫日志中，有一个熟悉的数字 t247， 而且不止出现一次。这个 SQL 执行了 49s 。
当然一个 49s 的慢 SQL 不至于把系统整瘫。
-
找人问最近上线事宜
在第一步中，我们找到最近上线的负责人， 因为他们上线时增加了 80w 数据，而慢 SQL 与数据量也有很大关系。仔细一聊，我们发现了一个要命的问题：前端有个页面，某个接口在会每隔 10s 请求一次 general，而且这个接口很慢。于是我打开了 grafana， 一遍复现这个请求，一遍观察请求速度。不出所料，的确很慢。 随后安排了这个逻辑修复。
为什么健康检查关闭就好了？
由后续的检测可以得知：慢 SQL 是拖垮 general 项目的原因。如果 genenral 项目能恢复，那么原因就是慢 SQL 任务执行完毕了。
在观察慢 SQL 日志时，我发现关闭健康检查的同时（ 11:25 am ），关于 t247 租户的慢 SQL 锐减。这基本上就能确定慢 SQL 的锅了。
总结
首先遇到较难问题不要慌，积极应对。多个人多份力量，一起分析。
可以按照上面的排查方法一步一步来。
- 查看各个指标监控
- sentry 项目检测
- k8s 重启次数
- Grafana 性能指标
- 数据库 CPU&内存指标
- 慢 SQL 检测
-
确认最近的修改
-
代码与项目状态排查
-
针对代码或者项目进行分析
-
拉通第一步中人员进行一起分析
基本上通过这几步问题大致能够定位问题所在，剩下 20%的工作量就是修复 bug 了
2
Select Language