正式服slave1节点cpu爆满宕机复盘

正式服slave1节点cpu爆满宕机复盘

Scroll Down

0、导:

▲ k8s集群

▲ 阿里云ECS、监控报警

▲ cpu报警后,经理简单排查后重启了服务器

▲ 收到报警短信时间:2021-8-30 19:23

▲ 报警持续时间 4 分钟

▲ 收到报警恢复短信时间:2021-8-30 19:38

▲ 经理告知我:排查之后发现有异常磁盘读写,猜测日志落盘问题,让我复盘排查

出问题第一时间应恢复服务正常运行,其次才是落盘当时状态以便时候复查复盘

问题发生时我未第一时间响应,经理便亲自动手保障了服务正常运行

下面记录一下我排查的过程:

1、翻看系统message、journal日志

使用journalctl --since="2021-08-30 19:00:00"查看系统日志,发现系统日志缺失了时间段 19:16:00 - 19:35:00的日志记录,应该是cpu等系统资源爆满阻塞导致日志数据没有落盘(补上缺失日志图)

journalctl --since="2021-08-30 19:00:00"

image.png

顺着时间段往后查找日志,发现 K8S 有一个 业务Pod 因为 OOM 原因被杀死,其内存使用量远超其它服务

image.png

16305644181.jpg

再往下翻,从日志记录可以看出19:37机器下发了重启指令,这里应该是领导控制台手动重启了ECS
image.png

为保证排查完整性,又去手动翻看了一边messages日志,查看后发现和journal日志一摸一样

经上述排查,可定位到一个疑似嫌疑犯的服务Pod,但是并不能完全确定它就是导致宿主机资源爆满的罪魁祸首,同时也不能确定犯罪嫌疑服务是否只有它一个。还需继续往下排查

2、查看Pod状态

我们从第1步的找到了一个疑似嫌疑犯的业务 Pod 名称,接下来在集群的Master节点上查看该业务Pod状态

kubectl get pod -A -owide| grep managerpkg
production   managerpkg-deployment-5ddc4687b8-2ttxr                    1/1     Running   0          19d 	k8s-node-06
production   managerpkg-deployment-5ddc4687b8-btd8r                    1/1     Running   0          19d	k8s-node-02
production   managerpkg-deployment-5ddc4687b8-m2n89                    1/1     Running   0          18h	k8s-node-01

从输出可以看到该Pod有三个副本,并且其中两个已存在19d,但是有一个特殊的Pod运行时间18h,从我当前时间往前推18h,巧了,刚好就是事故发生的那个时间段,这也恰恰印证了上边的OOM日志记录

随后查看该Pod的详细信息

kubectl describe pod -n production manager-deployment-5ddc4687b8-m2n89

image.png

通过 describe pod 发现了两个关键信息,其一如上图所示,该Pod的Start Time 为 Mon, 30 Aug 2021 19:22:54 ,这个时间是不是感觉特别可疑?没错,文章开头有提到收到报警短信的时间是 2021-8-30 19:23(持续时间4分钟),该Pod的启动时间早于收到报警短信的时间且在报警的沉默周期内。其二该Pod的Controller Deployment并未做资源限制。也就是说是有可能因为managerpkg吃掉系统资源而导致系统资源不足而崩溃的,而且而且,恰巧这个服务是没有做资源限制的

3、查看监控数据

根据以上信息,已经注意到了managerpkg服务,根据上文使用的get pod -owide可以看到managerpkg服务Pod都被调度到了k8s-node-06k8s-node-02k8s-node-01节点上,查看对应节点在故障发生时的监控数据(因为故障发生时我没响应到,经理简单排查说有异常磁盘读写,所以这里我主要看的是磁盘读写的BPS和IOPS监控数据

监控数据看了managerpkg服务所在的node和其它的node,在故障发生时段的监控数据对比,managerpkg服务pod所在的node节点磁盘读写bps果然都小高峰了

1630567058.jpg

image.png

image.png

排查到这里,基本上已经能确定造成此次故障的原因,不说唯一,最起码之一就是managerpkg服务

4、破案

随后去询问了该服务的研发,他说该服务确实会使用cpu资源去计算数据,特别是数据比较庞大的时候,但是并不涉及到磁盘读写,基本破案

和研发一同反馈到了领导,领导叫了两位研发分别修改优化自身代码

后来不知道领导问了谁,回馈我们说,因为计算量大,有一定等待时间,然后有位同事计算数据时疯狂点击,导致连续发送多条数据请求,不仅占用了cpu资源,更消耗了大量内存资源,也因为没有做资源限制,最终导致了node节点的资源爆满(这也就离谱,然后前端后端都得优化一下)

5、优化

研发在测试服优化修改代码(优化计算逻辑、加入缓存处理、单线程计算改多线程)(我知道的有修改每个线程获取数据条数、以及将数据存入Redis等操作),我帮忙修改k8s的资源限制,并查看该服务计算数据时需要的cpu天花板是多少,我俩疯狂测试实际计算时间和资源消耗

前端也优化了相应显示

我也优化了监控报警和集群相关资源限制

6、故障重现

过了一天,我添加的磁盘iops读和bps读报触发了(后询问是测试同事在正式服测试老版本服务),刚巧我在,直接动手开始排查。

找到对应节点,有先前经验,加上优化之后的代码还没上线正式服。所以我第一反应就是排查之前那个业务pod,kubectl get pod -owide | grep managerpkg,果不其然,该节点上还真有那个业务pod,这并不足以支持确定报警来源。

因为是磁盘读 IOPS、BPS 监控报,所以我用了iotop命令查找造成io读过高的程序,一找一个准,如下图:

image.png

实话说,我的操作系统、组成原理学的也就那样,基于个人不扎实的基础知识、过往经验和博客参考,以及与研发的沟通,我猜测问题出现原因是,多用户同时请求计算数据,业务pod开启了多个计算任务,cpu资源上去的同时,多线程直接导致了内存也开始飙升,因业务pod做了资源限制(第一次故障之后直接限制了资源使用量),当内存达到一定瓶颈,虚拟内存不够用了,于是从开始疯狂读宿主机磁盘了,导致宿主机磁盘bps 和iops都报警了起来,加至用户未收到计算结果疯狂点击,最终导致了pod oom的崩溃

查看内存监控(内存确实也有一点飙升),IO高确实也是因为进程大量使用Swap交换页所导致!

image.png

image.png

7、总结:

根据以上过程总结,判断当时正式服故障原因就是业务pod没做资源限制,计算量大,同时疯狂吃宿主机cpu,而当计算数据的请求达到一定数量时,Pod会用硬盘空间当虚拟内存,如果空间不足,就会虚拟内存不足,到达一定峰值时,疯狂读写磁盘,导致磁盘IOPS、BPS飙升

该程序优化前,计算数据会使用大量cpu资源,多条计算数据的请求会消耗大量内存以及读写宿主机硬盘

参考:
https://www.cnblogs.com/zhanglianghhh/archive/2020/02/04/12262009.html

https://www.liuhaolin.com/note/331.html

http://www.toxingwang.com/linux-unix/linux-admin/2984.html