记一次 OOM (Out of Memory)的调查
现象
我的 Openshift 3.11
集群近一段时间节点总是莫名其妙就挂掉了,并且是卡到整个节点系统 hung 住,没有完全死掉的节点的控制台有大量的 Out of memory: Kill
日志打印出来
但是最奇怪的是,挂掉的节点在 ESXi
中活动内存占用并不高,但是 CPU
直接满载
开始调查
仔细回忆了一下,近期在集群上部署了一套 CSI
(Container Storage Interface) 插件,基本上有了一个排查的大方向,应该是插件的内存泄漏了,但还是要找到实锤
首先在没死透的节点上挣扎一下看看能不能通过 top
命令看到信息,但是内核已经彻底 hung 死,尝试登陆的 bash
都被 kill
了
没有办法,只能重启一台机器看看 OOM Killer
的日志吧
OOM Killer 日志
我的 Openshift 3.11
集群的宿主机是 CentOS 7
,所以 OOM Killer
的日志会被存储在 /var/log/messages
中,如果机器重启过的话,过往的日志会被存储在 /var/log/messages-{restart_date}
中,如 /var/log/messages-20201223
重启完机器,直接 less /var/log/messages-$(date +%Y%m%d)
,输入命令 /Out of memory
回车,找到第一个引起 OOM
的程序
1 | Dec 15 13:47:22 master-01 kernel: Out of memory: Kill process 66909 (livenessprobe) score 1687 or sacrifice child |
确实是 CSI driver
的一部分,这是一个用于探测 CSI driver
提供的 GRPC
存活工具,由 kubernetes-csi
特别兴趣小组提供
按 n
继续搜索下一个,连续搜索了多个之后都是由这个 livenessprobe
引起的 OOM Kill
,那基本上问题就在这里了
通过图表验证
想起 Openshift
在部署的时候,一同部署了一个 Prometheus + Grafana
的监控套件
找到 livenessprobe
所在的 Pod
果然,短短的一个小时不到,已经吃了不下 200M
内存,而且这个内存占用曲线是一直递增的,基本可以断定是内存泄漏了
代码验证
代码仓库: https://github.com/kubernetes-csi/livenessprobe
因为用的是 spec 0.3
版本的 CSI
,所以,这里用的是 release-0.4
分支的代码
在 cmd/main.go
里有这样一个方法
1 | func getCSIConnection() (connection.CSIConnection, error) { |
connection.NewConnection
是创建一条 GRPC
连接,这个方法被 chekcHealth
方法调用(汗,还有错别字)
1 | func chekcHealth(w http.ResponseWriter, req *http.Request) { |
而这个方法又被注册到了 /healthz
路由上,也就是说,kubelet
的健康检查每请求一次这个健康检查接口,就会开启一条新的 GRPC
连接,而在检查完毕之后并没有让这个 GRPC
连接成为单例亦或是直接关闭这条连接
而 GRPC
的链接如果不关闭的话,其中持有的 io.Reader
以及 io.Writer
实例对象就得不到释放,内存就得不到释放,从而随着健康检查的请求数量越来越多,最终导致 OOM
破案
案子破了,是由于 livenessprobe
的没有关闭持有的 GRPC
连接,并且错误的在 /healthz
健康检查路由中不断去创建新的连接导致了最终的 OOM
仔细阅读了一下代码,实际上在 pkg/connection.go
中已经实现了一个对象用于持有 GRPC
的连接,只是在 getCSIConnection()
方法中返回的并不是单例的 CSIConnection
对象,而是每次都去创建新的连接
这个 BUG 已经在 Master 分支上被修复了,但是因为 Openshift 3.11
是基于 Kubernetes 1.11
的所以只能使用 CSI spec v0.3
,所以才碰上这个 BUG
反思
GRPC
的 ClientConn
最好是单例的,如果想要重新连接,也要记得关闭连接,和 http
标准库中的 ResponseBody
同理,如果不关将无法释放持有的 io