记一次 OOM （Out of Memory）的调查

发表于 2020-12-23 更新于 2021-06-12 分类于 Kubernetes

现象

我的 Openshift 3.11 集群近一段时间节点总是莫名其妙就挂掉了，并且是卡到整个节点系统 hung 住，没有完全死掉的节点的控制台有大量的 Out of memory: Kill 日志打印出来

oom

但是最奇怪的是，挂掉的节点在 ESXi 中活动内存占用并不高，但是 CPU 直接满载

cpu-full

开始调查

仔细回忆了一下，近期在集群上部署了一套 CSI (Container Storage Interface) 插件，基本上有了一个排查的大方向，应该是插件的内存泄漏了，但还是要找到实锤

首先在没死透的节点上挣扎一下看看能不能通过 top 命令看到信息，但是内核已经彻底 hung 死，尝试登陆的 bash 都被 kill 了

dead-vm

没有办法，只能重启一台机器看看 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

pod-metrics-dashboard

果然，短短的一个小时不到，已经吃了不下 200M 内存，而且这个内存占用曲线是一直递增的，基本可以断定是内存泄漏了

代码验证

代码仓库： https://github.com/kubernetes-csi/livenessprobe

因为用的是 spec 0.3 版本的 CSI，所以，这里用的是 release-0.4 分支的代码

在 cmd/main.go 里有这样一个方法

func getCSIConnection() (connection.CSIConnection, error) {
	// Connect to CSI.
	glog.Infof("Attempting to open a gRPC connection with: %s", *csiAddress)
	csiConn, err := connection.NewConnection(*csiAddress, *connectionTimeout)
	if err != nil {
		return nil, err
	}
	return csiConn, nil
}

connection.NewConnection 是创建一条 GRPC 连接，这个方法被 chekcHealth 方法调用（汗，还有错别字）

func chekcHealth(w http.ResponseWriter, req *http.Request) {

	glog.Infof("Request: %s from: %s\n", req.URL.Path, req.RemoteAddr)
	csiConn, err := getCSIConnection()
...

而这个方法又被注册到了 /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 对象