问题影响
今天早上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了
近期评论