一次读 pipe 引发的血案

背景

背景详见：docker-hang-死排查之旅。总结成一句话：runc非预期写pipe造成一系列组件的阻塞，当我们读pipe以消除阻塞时，发生了一个非预期的现象——宿主上所有的容器都被重建了。

再详细分析问题原因之前，我们先简单回顾下linux pipe的基础知识。

linux pipe

linux pipe（也即管道），相信大家对它都不陌生，是一种典型的进程间通信机制。管道主要分为两类：命名管道与匿名管道。其区别在于：

命名管道：管道以文件形式存储在文件系统之上，系统中的任意两个进程都可以借助命名管道通信
匿名管道：管道不以文件形式存储在文件系统之上，仅存储在进程的文件描述符表中，只有具有血缘关系的进程直接才能借助管道通信，如父子进程、子子进程、祖孙进程等

管道可以被想象成一个固定大小的文件，分为读写两端，阻塞型管道读写有如下特点：

读端：当管道内无数据时，读操作阻塞，直到有数据写入，或者所有写段关闭
写段：当管道已被写满时，写操作阻塞，直到数据被读出

linux pipe默认大小为16内存页[ref.2]，也即65536字节。

这里我有一个小疑惑：写pipe超过65536字节才会被阻塞，我们在宿主上也验证了这个结论，但是docker-hang-死排查之旅写入5378字符时就已被阻塞。欢迎了解的小伙伴解惑。

血案发生

由于runc init非预期往pipe里写入大量数据而引起阻塞，我们消除阻塞的做法很简单，人为读取pipe中的内容。当我们读取完pipe中的内容时，原本一切都应该按照我们的预期发展：收集到runc init非预期写pipe的真正原因；异常容器恢复响应。确实，以上两点都如我们预期的发生了，然而，此时还发生了一个非预期的动作：宿主上所有容器都被重建了。

一个线上事故就此发生。原本其他线上容器运行正常，当我们解决docker hang死问题时，却引起了其他容器的一次重建，这显然是不可接受的。

问题定位

我们的第一嫌犯是docker，怀疑宿主docker服务发生了重启。当我们验证docker服务状态时，排除了docker的嫌疑，因为docker上一次重启时间是好多天前。

既然不是docker，那基本就是kubernetes了。kubernetes组件又分为master端与node端两大类。node端组件仅有kubelet，但是kubelet的嫌疑很小，因为它就是个打工仔，所有事情都是听从master的安排。而master端组件有三：控制器、调度器，与API服务。由于调度器包含驱逐功能，原本调度器嫌疑最大，但是因为我们线上关闭了驱逐功能，因此也基本不可能是调度器搞的鬼；而API服务则是被动的接收变更请求，也能排除嫌疑；那么嫌疑犯只剩下控制器了，控制器为什么要重建宿主上的所有容器呢？

以上是我们的猜测环节，为了验证猜测正确与否，我们必须收集证据。证据何在？基本就埋没在海量的组件日志中。天网恢恢疏而不漏，在控制器日志中，我们掌握了它犯罪的关键证据：

1	/var/log/kubernetes/kube-controller-manager.root.log.INFO.20200712-014245.35913:I0712 03:19:59.590703 35913 controller_utils.go:95] Starting deletion of pod default/kproxy-sf-69466-1

我们在0709发现宿主docker异常，而控制器在0712主动删除了宿主上的容器。证据在手，我们就开始审问控制器，它的交代入下：

// DeletePods will delete all pods from master running on given node,
// and return true if any pods were deleted, or were found pending
// deletion.
func DeletePods(kubeClient clientset.Interface, recorder record.EventRecorder, nodeName, nodeUID string, daemonStore extensionslisters.DaemonSetLister) (bool, error) {
	......
	for _, pod := range pods.Items {
		......
		glog.V(2).Infof("Starting deletion of pod %v/%v", pod.Namespace, pod.Name)
		if err := kubeClient.CoreV1().Pods(pod.Namespace).Delete(pod.Name, nil); err != nil {
			return false, err
		}
		remaining = true
	}
  ......
}

func (nc *Controller) doEvictionPass() {
	nc.evictorLock.Lock()
	defer nc.evictorLock.Unlock()
	for k := range nc.zonePodEvictor {
		// Function should return 'false' and a time after which it should be retried, or 'true' if it shouldn't (it succeeded).
		nc.zonePodEvictor[k].Try(func(value scheduler.TimedValue) (bool, time.Duration) {
			......
			remaining, err := nodeutil.DeletePods(nc.kubeClient, nc.recorder, value.Value, nodeUID, nc.daemonSetStore)
			......
		})
	}
}

// Run starts an asynchronous loop that monitors the status of cluster nodes.
func (nc *Controller) Run(stopCh <-chan struct{}) {
	  ......
		// Managing eviction of nodes:
		// When we delete pods off a node, if the node was not empty at the time we then
		// queue an eviction watcher. If we hit an error, retry deletion.
		go wait.Until(nc.doEvictionPass, scheduler.NodeEvictionPeriod, stopCh)
    ......
}

这个控制器就是node_lifecycle_controller，也即宿主生命周期控制器，该控制器定时 (每100ms) 驱逐宿主上的容器。这个控制器并非不分青红皂白就一通乱杀，不然线上早就乱套了，我们再来看看其判断条件：

// monitorNodeStatus verifies node status are constantly updated by kubelet, and if not,
// post "NodeReady==ConditionUnknown". It also evicts all pods if node is not ready or
// not reachable for a long period of time.
func (nc *Controller) monitorNodeStatus() error {
  ......
  if currentReadyCondition != nil {
			// Check eviction timeout against decisionTimestamp
			if observedReadyCondition.Status == v1.ConditionFalse {
					if decisionTimestamp.After(nc.nodeStatusMap[node.Name].readyTransitionTimestamp.Add(nc.podEvictionTimeout)) {
						if nc.evictPods(node) {
							glog.V(2).Infof("Node is NotReady. Adding Pods on Node %s to eviction queue: %v is later than %v + %v",
								node.Name,
								decisionTimestamp,
								nc.nodeStatusMap[node.Name].readyTransitionTimestamp,
								nc.podEvictionTimeout,
							)
						}
					}
			}
			if observedReadyCondition.Status == v1.ConditionUnknown {
					if decisionTimestamp.After(nc.nodeStatusMap[node.Name].probeTimestamp.Add(nc.podEvictionTimeout)) {
						if nc.evictPods(node) {
							glog.V(2).Infof("Node is unresponsive. Adding Pods on Node %s to eviction queues: %v is later than %v + %v",
								node.Name,
								decisionTimestamp,
								nc.nodeStatusMap[node.Name].readyTransitionTimestamp,
								nc.podEvictionTimeout-gracePeriod,
							)
						}
					}
			}
  }
  ......
}

func (nc *Controller) evictPods(node *v1.Node) bool {
	nc.evictorLock.Lock()
	defer nc.evictorLock.Unlock()
	return nc.zonePodEvictor[utilnode.GetZoneKey(node)].Add(node.Name, string(node.UID))
}

可见，控制器驱逐该宿主上的所有Pod的条件有二：

宿主的状态为NotReady或者Unknown
宿主状态保持非Ready超过指定时间阈值。该时间阈值由nc.podEvictionTimeout定义，默认为5分钟，我们的线上集群将其定制为2000分钟

在docker-hang-死阻塞-kubelet-初始化流程中，我们提到由于docker hang死，kubelet初始化流程被阻塞，宿主状态为NotReady，命中条件1；我们检查kubelet NotReady的起始时间为2020-07-10 17:58:59，与控制器删除Pod的时间间隔基本为2000分钟，命中条件2。

至此，本问题基本已盖棺定论：由于线上宿主状态非Ready持续时间太长，引起控制器驱逐宿主上所有容器导致。

思考

清楚了其原理之后，大家再来思考一个问题：当宿主状态非Ready时，无法处理控制器发出的驱逐容器的请求，当且仅当宿主状态变成Ready之后，才能开始处理。既然宿主已恢复，是否还有必要立即驱逐其上的所有容器？尤其是针对有状态服务，删除Pod之后，立马又在原宿主创建该Pod。我个人感觉非但没有必要，而且还存在一定风险。

针对控制器的驱逐策略，我们调大了线上的驱逐时间间隔，从原来的2000分钟，调整为3年。

背景

linux pipe

血案发生

问题定位

思考

Reference