前一阵有客户docker18.06.3集群中呈现Pod卡在terminating状态的问题,通过排查发现是containerd和dockerd之间事件流阻塞,导致后续事件得不到解决造成的。
定位问题的过程极其艰巨,其中不乏大量工具的应用和大量的源码浏览。本文将梳理排查此问题的过程,并总结残缺的dockerd和contaienrd之间事件传递流程,一步一步找到问题产生的起因,特写本文记录分享,心愿大家在有相似问题产生时,可能迅速定位、解决。
对于本文中提到的问题,在docker19中曾经失去解决,但docker18无奈间接降级到docker19,因而本文在结尾参考docker19给出了一种简略的解决方案。
删除不掉Pod
置信大家在解决现网问题时,常常会遇到Pod卡在terminating不动的状况,产生这种状况的起因有很多,比方《Pod Terminating起因追踪系列之一》中提到的containerd没有正确处理错误信息,当然更常见的比方umount失败、dockerd卡死等等。
遇到此类问题时,通常通过kubelet或dockerd日志、容器和Pod状态、堆栈信息等伎俩来排查问题。本问题也不例外,首先登录到Pod所在节点,应用以下两条指令查看容器状态:
#查看容器状态,看到容器状态为updocker ps | grep <container-id>#查看task状态,显示task的状态为STOPPEDdocker-container-ctr --namespace moby --address var/run/docker/containerd/docker-containerd.sock task ls | grep <container-id>
能够看到在dockerd中容器状态为up,但在containerd中task状态为STOPPED,两者信息产生了不统一,也就是说因为某种原因containerd中的状态信息没有同步到dockerd中,为了探索为什么两者状态产生了不统一,首先须要理解从dockerd到containerd的整体调用链:
当启动dockerd时,会通过NewClient办法创立一个client,该client保护一条到containerd的gRPC连贯,同时起一个协程processEventStream订阅(subscribe)来自containerd的task事件,当某个容器的状态发生变化产生了事件,containerd会返回事件到client的eventQ队列中,并通过ProcessEvent办法进行解决,processEventStream协程在除优雅退出以外永远不会退出(但在有些状况下还是会退出,在后续会推出一篇文章,恰好是这种状况,敬请期待~)。
当容器过程退出时,containerd会通过上述gRPC连贯返回一个exit的task事件给client,client接管到来自containerd的exit事件之后由ProcessEvent调用DeleteTask接口删除对应task,至此实现了一个容器的删除。
因为containerd始终处于STOPPED状态,因而通过下面的调用链猜想会不会是task exit事件因为某种原因而阻塞掉了?产生的后果就是在containerd侧因为发送了exit事件而进入STOPPED状态,但因为没有调用DeleteTask接口,因而本task还存在。
模仿task exit事件
通过发送task exit事件给一个卡住的Pod,来模仿容器完结的状况:
/tasks/exit {"container_id":"23bd0b1118238852e9dec069f8a89c80e212c3d039ba030cfd33eb751fdac5a7","id":"23bd0b1118238852e9dec069f8a89c80e212c3d039ba030cfd33eb751fdac5a7","pid":17415,"exit_status":127,"exited_at":"2020-07-17T12:38:01.970418Z"}
咱们能够手动将上述事件publish到containerd中,然而须要留神的一点的是,在publish之前须要将上述内容进行一下编码(参考containerd/cmd/containerd-shim/main_unix.go Publish办法)。失去的后果如下图,能够看到事件胜利的被publish,也被dockerd捕捉到,但容器的状态依然没有变动。
#将file文件中的事件发送到containerddocker-containerd --address var/run/docker/containerd/docker-containerd.sock publish --namespace moby --topic /tasks/exit < ~/file
当咱们查看docker堆栈日志(向dockerd过程发送SIGUSR1信号),发现有大量的Goroutine卡在append办法,每次publish新的exit事件都会减少一个append办法的堆栈信息:
通过查看append办法的源码发现,append办法负责将收到的containerd事件放入eventQ,并执行回调函数,对收到的不同类型事件进行解决:
func (q *queue) append(id string, f func()) { q.Lock() defer q.Unlock() if q.fns == nil { q.fns = make(map[string]chan struct{}) } done := make(chan struct{}) fn, ok := q.fns[id] q.fns[id] = done go func() { if ok { <-fn } f() close(done) q.Lock() if q.fns[id] == done { delete(q.fns, id) } q.Unlock() }()}
形参中的id为container的id,因而对于同一个container它的事件是串行解决的,只有前一个事件处理完结才会解决下一个事件,且没有超时机制。
因而只有eventQ中有一个事件产生了阻塞,那么在它前面所有的事件都会被阻塞住。这也就解释了为什么每次publish新的对于同一个container的exit事件,都会在堆栈中减少一条append的堆栈信息,因为它们都被之前的一个事件阻塞住了。
深刻源码定位问题起因
为了找到阻塞的起因,咱们找到阻塞的第一个exit事件append的堆栈信息再具体的看一下:
通过堆栈能够发现代码卡在了docker/daemon/monitor.go文件的123行(省略了不重要的代码):
func (daemon *Daemon) ProcessEvent(id string, e libcontainerd.EventType, ei libcontainerd.EventInfo) error { ...... case libcontainerd.EventExit: ...... if execConfig := c.ExecCommands.Get(ei.ProcessID); execConfig != nil { ......123行 execConfig.StreamConfig.Wait() if err := execConfig.CloseStreams(); err != nil { logrus.Errorf("failed to cleanup exec %s streams: %s", c.ID, err) } ...... } else { ...... } ...... return nil}
能够看到收到的事件为exit事件,并在第123行streamConfig在期待一个wg,这里的streamconfig为一个内存队列,负责收集来自containerd的输入返回给客户端,具体是如何解决io的在前面会细讲,这里先顺藤摸瓜查一下wg在什么时候add的:
func (c *Config) CopyToPipe(iop *cio.DirectIO) { copyFunc := func(w io.Writer, r io.ReadCloser) { c.Add(1) go func() { if _, err := pools.Copy(w, r); err != nil { logrus.Errorf("stream copy error: %v", err) } r.Close() c.Done() }() } if iop.Stdout != nil { copyFunc(c.Stdout(), iop.Stdout) } if iop.Stderr != nil { copyFunc(c.Stderr(), iop.Stderr) } .....}
CopyToPipe是用来将containerd返回的输入copy到streamconfig的办法,能够看到当来自containerd的io流不为空,则会对wg add1,并开启协程进行copy,copy完结后才会done,因而一旦阻塞在copy,则对exit事件的解决会始终期待copy完结。咱们再回到docker堆栈中进行查找,发现的确有一个IO wait,并阻塞在polls.Copy函数上:
至此造成dockerd和containerd状态不统一的起因曾经找到了!咱们来梳理一下。
首先通过查看dockerd和containerd状态,发现两者状态不统一。因为containerd处于STOPPED状态因而判断在containerd发送task exit事件时可能产生阻塞,因而咱们结构了task exit事件并publish到containerd,并查看docker堆栈发现有大量阻塞在append的堆栈信息,证实了咱们的猜测。
最初咱们通过剖析代码和堆栈信息,最终定位在ProcessEvent因为pools.Copy的阻塞,也会被阻塞,直到copy完结,而事件又是串行解决的,因而只有有一个事件处理被阻塞,那么前面所有的事件都会被阻塞,最终体现出的景象就是dockerd和containerd状态不统一。
找出罪魁祸首
咱们曾经晓得了阻塞的起因,然而到底是什么操作阻塞了事件的解决?其实很简略,此exit事件是由exec退出产生的,咱们通过查看堆栈信息,发现在堆栈有为数不多的ContainerExecStart办法,阐明有exec正在执行,揣测是客户行为:
ContainerExecStart办法中第二个参数为exec的id值,因而能够应用gdb查找对应地址内容,查看其参数中的execId和terminating Pod中的容器的exexId(docker inspect能够查看execId,每个exec操作对应一个execId)是否统一,后果发现execId雷同!因而能够判定是因为exec退出,产生的exit事件阻塞了ProcessEvent的解决逻辑,通过浏览源码总结出exec的解决逻辑:
那么为什么exec的exit会导致Write阻塞呢?咱们须要梳理一下exec的io解决流程看看到底Write到了哪里。下图为io流的处理过程:
首先在exec开始时会将socket的输入流attach到一个内存队列,并启动了⼀个goroutine用来把内存队列中的内容输入到socket中,除了内存队列外还有一个FIFO队列,通过CopyToPipe开启协程copy到内存队列。FIFO队列用来接管containerd-shim的输入,之后由内存队列写入socket,以response的形式返回给客户端。但咱们的问题还没有解决,还是不分明为什么Write会阻塞住。不过能够通过gdb来定位到Write函数关上的fd,查看一下socket的状态:
n, err := syscall.Write(fd.Sysfd, p[nn:max])type FD struct { // Lock sysfd and serialize access to Read and Write methods. fdmu fdMutex // System file descriptor. Immutable until Close. Sysfd int ......}
Write为零碎调用,其参数中第一位即关上的fd号,但须要留神,Sysfd并非FD构造体的第一个参数,因而须要加上偏移量16字节(fdMutex占16字节)
发现该fd为一个socket连贯,应用ss查看一下socket的另一端是谁:
发现该fd为来自kubelet的一个socket连贯,且没有被敞开,因而能够判断Write阻塞的起因正是客户端exec退出当前,该socket没有失常的敞开,使Write一直地向socket中写数据,直到写满阻塞造成的。
通过询问客户是否应用过exec,发现客户本人写了一个客户端并通过kubelet exec来拜访Pod,与上述排查后果相符,因而反馈客户能够排查下客户端代码,是否正确敞开了exec的socket连贯。
修复与反思
其实docker的这个事件处理逻辑设计并不优雅,客户端的行为不应该影响到服务端的解决,更不应该造成服务端的阻塞,因而本打算提交pr修复此问题,发现在docker19中曾经修复了此问题,而docker18的集群无奈间接降级到docker19,因为docker会长久化数据到硬盘上,而docker19不反对docker18的长久化数据。
尽管不能间接降级到docker19,不过咱们能够参考docker19的实现,在docker19中通过增加事件处理超时的逻辑防止事件始终阻塞,在docker18中同样能够增加一个超时的逻辑!
对exit事件增加超时解决:
#/docker/daemon/monitor.goctx, cancel := context.WithTimeout(context.Background(), 2*time.Second)execConfig.StreamConfig.WaitWithTimeout(ctx)cancel()
#/docker/container/stream/streams.gofunc (c *Config) WaitWithTimeout(ctx context.Context) { done := make(chan struct{}, 1) go func() { c.Wait() close(done) }() select { case <-done: case <-ctx.Done(): if c.dio != nil { c.dio.Cancel() c.dio.Wait() c.dio.Close() } }}
这里增加了一个2s超时工夫,超时则优雅敞开来自containerd的事件流。
至此一个辣手的Pod terminating问题曾经解决,后续也将推出小版本修复此问题,尽管修复起来比较简单,但问题剖析的过程却无比艰苦,心愿本篇文章可能对大家今后的问题定位关上思路,谢谢观看~
【腾讯云原生】云说新品、云研新术、云游新活、云赏资讯,扫码关注同名公众号,及时获取更多干货!!