关于腾讯云:Pod-Terminating原因追踪系列之一containerd中被漏掉的runc错误信息

前一段时间发现有一些containerd集群呈现了Pod卡在Terminating的问题,通过一系列的排查发现是containerd对底层异样解决的问题。最初尽管通过一个短小的PR修复了这个bug,然而找到bug的过程和对问题的反思还是值得和大家分享的。

本文中会借由排查bug的过程来剖析kubelet删除Pod的调用链,这样不仅仅能够理解containerd的bug,还能够借此理解更多Pod删除不掉的起因。在文章的最初会对问题进行反思,来探讨OCI呈现的问题。

一个删除不掉的Pod

可能大家都会遇到这种问题,就是集群中有那么几个Pod无论如何也删除不掉,看起来和下图一样。当然可有很多可能导致Pod卡在Terminating的起因,比方mount目录被占用、dockerd卡死了或镜像中有“i”属性的文件。因为节点上简单的组件(docker、containerd、cri、runc)和过长的调用链,导致很难霎时定位呈现问题的地位。所以个别遇到此类问题都会通过日志、Pod的信息和容器的状态来逐渐放大排查范畴。

当然首先看下集群的信息,发现没有应用docker而间接用的cri和containerd。间接应用containerd照比应用docker会有更短的调用链和更强的鲁棒性,照比应用docker应该更稳固才对(比方经常出现的docker和containerd数据不统一的问题在这里就不会呈现)。接下来当然是查看kubelet日志,如下(只保留了外围局部),从这条日志中能够发现貌似是kubelet调用cri接口,最终调用runc去删除容器时报错导致删除失败。

$ journalctl -u kubelet
Feb 01 11:37:27 VM_74_45_centos kubelet[687]: E0201 11:37:27.241794     687 pod_workers.go:190] Error syncing pod 18c3d965-38cc-11ea-9c1d-6e3e7be2a462 ("advertise-api-bql7q_prod(18c3d965-38cc-11ea-9c1d-6e3e7be2a462)"), skipping: error killing pod: [failed to "KillContainer" for "memcache" with KillContainerError: "rpc error: code = Unknown desc = failed to kill container \"55d04f7c957e81fcf487b0dd71a4e50fe138165303cf6e96053751fd6770172c\": unknown error after kill: runc did not terminate sucessfully: container \"55d04f7c957e81fcf487b0dd71a4e50fe138165303cf6e96053751fd6770172c\" does not exist\n: unknown"

接下来咱们打算剖析下容器以后的状态,简略介绍下,containerd中用container来示意容器、用task来示意容器的运行状态,创立一个容器相当于创立container,而把容器运行起来相当于创立一个task并把task状态置为Running。当然停掉容器就相当于把task的状态设置为Stopped。通过ctr命令看下containerd中container和task的状态,容器55d04f对应的container和task都还在、task状态是STOPPED。接下来查看containerd日志,咱们节选了一小部分,发现了如下景象,第一条日志是stop容器55d04f时做umount失败,接下来都是kill容器55d04f时发现container不存在。

error="failed to handle container TaskExit event: failed to stop container: failed rootfs umount: failed to unmount target /run/containerd/io.containerd.runtime.v1.linux/k8s.io/55d04f.../rootfs: device or resource busy: unknown"
error="failed to handle container TaskExit event: failed to stop container: unknown error after kill: runc did not terminate sucessfully: container "55d04f..." does not exist"
error="failed to handle container TaskExit event: failed to stop container: unknown error after kill: runc did not terminate sucessfully: container "55d04f..." does not exist"
error="failed to handle container TaskExit event: failed to stop container: unknown error after kill: runc did not terminate sucessfully: container "55d04f..." does not exist"

当然失去这些信息直觉会认为排查方向是:

  • 为何rootfs会被占用,只有找进去是谁在占用rootfs就能够解决问题了
  • 既然umount报错,咱们是否能够应用lazy umount
  • 反正之后containerd还会重试,再起初的重试中是否能够正确删除容器

第一个选项间接被排除了,看起来占用rootfs的过程并不是长期存在,等发现问题登录到节点上排查时过程曾经不在了。如果不是常驻过程问题就变得麻烦了,可能是某个周期执行的监控组件,也可能是用户的某个日志收集容器某次收集工夫较长在rootfs上多停留了一会。

处于懈怠的本能,咱们先尝试下第二个计划。刚刚咱们说过容器在containerd中被定义为containertask,查看容器信息时发现task并没有被删掉,于是咱们间接在containerd的代码中找到了umount容器rootfs的代码,如下(为了浏览体验,曾经简化):

func (p *Init) delete(ctx context.Context) error {
    err := p.runtime.Delete(ctx, p.id, nil)
  // ...
    if err2 := mount.UnmountAll(p.Rootfs, 0); err2 != nil {
        log.G(ctx).WithError(err2).Warn("failed to cleanup rootfs mount")
        if err == nil {
            err = errors.Wrap(err2, "failed rootfs umount")
        }
    }
    return err
}
func unmount(target string, flags int) error {
    for i := 0; i < 50; i++ {
        if err := unix.Unmount(target, flags); err != nil {
            switch err {
            case unix.EBUSY:
                time.Sleep(50 * time.Millisecond)
                continue
            default:
                return err
            }
        }
        return nil
    }
    return errors.Wrapf(unix.EBUSY, "failed to unmount target %s", target)
}

containerd创立容器时会创立一个containerd-shim过程来治理创立进去的容器,本来containerd对容器过程的操作就转化成了containerd对shim的RPC调用;而调用runc来操作容器的工作天然就会交给shim来做,这样最大的益处就是能够不便的实现live-restore能力,也就是即便containerd重启也不会影响到容器过程。

下面代码中的 delete函数就是由containerd-shim调用的,函数中次要工作有两个:调用runc delete删掉容器、调用umount卸载掉容器的rootfs。containerd日志中第一次device busy导致的umount失败就是在这里产生的。当然在umount函数中还是有个短暂的重试的,看来社区还是思考到了偶然可能会呈现rootfs被占用的状况(狐疑是容器过程还没来的急被回收,但在某些场景下,可能这个重试的工夫还有点短)。

这里要留神unmount的flags是0,查看docker代码,发现docker在umount时加了MNT_DETACH。在简略地批改了shim的代码后,在节点上测试,果然增加了MNT_DETACH当前就不会呈现device busy了。于是自信的向社区提了PR,后果失去的回复却是:

What typically happens in cases like this is you there is a mount marked as private that gets copied into a new mount namespace.
A new mount namespace is created for every container, for systemd services that have MountPropagation or PrivateTmp defined, and these types of things.
When those namespaces are created they get a copy of the root namespace, anything that has a private mount cannot be unmounted until all the namespaces are shut down.
Mounts get marked private depending on the propagation defined on their root mount or if explicitly set…. so for example if you have /var/foo mounted and /var is mounted with mount private propagation, /var/foo will inherit the private propagation.

In this case MNT_DETACH only detaches the mount and hides very real problems. Even if you remove the mountpoint the data will not be freed until (possibly?) a reboot or all other namespaces with copies of that mount in them are shut down.

大略意思就是如果你用了MNT_DETACH,会有一些真正的问题被藏起来。(这里有待测试,我感觉社区里这个人回复的思路有问题)。

看起来咱们只能排查下为什么重试时还会失败了,节点上执行删除Pod的流程还是比拟长的,很难简略通过几个举例间接阐明问题,所以接下来剖析下kubelet从cri到OCI删除容器的流程。

kubelet如何删除Pod中的容器

对于kubelet的剖析就要从赫赫有名的SyncPod开始剖析了,在SyncPod开始时会计算podContainerChanges,接下来整个流程都是依据podContainerChanges的状况来执行对容器的操作。咱们假如change就是KillPod,而kubelet执行KillPod会先通过创立多个goroutine并发执行StopContainers,等到所有Containers都删除胜利后再删除Pod的Sandbox。具体调用流程如下:

图中用红色标记的StopContainer其实就是最终调用了cri接口(container runtime interface),比方以下是两个和删除容器相干的两个cri接口,Kubernetes要求每种容器运行时都要实现cri接口。docker通过docker-shim实现了cri接口;而container通过cri插件实现了cri接口,两者并没区别。比方运行时是containerd时,对cri的调用就会通过containerd-shim最终在容器上产生影响。

// StopContainer stops a running container with a grace period (i.e., timeout).
// This call is idempotent, and must not return an error if the container has
// already been stopped.
// TODO: what must the runtime do after the grace period is reached?
StopContainer(context.Context, *StopContainerRequest) (*StopContainerResponse, error)
// RemoveContainer removes the container. If the container is running, the
// container must be forcibly removed.
// This call is idempotent, and must not return an error if the container has
// already been removed.
RemoveContainer(context.Context, *RemoveContainerRequest) (*RemoveContainerResponse, error)

当申请到了cri后,剩下的工作就都交给了containerd和containerd-cri。cri以插件的形式运行在containerd中,实质和containerd是同一个过程,因而能够通过containerd提供的client间接通过函数调用containerd提供的service。失常状况下整个调用链如下图所示。

另外,cri插件中存在一个eventloop专门解决从containerd中获取的event。比方当容器删除后,会收到TaskExit事件,这是cri会做清理工作;比方当容器oom时,会收到OOMKill事件,cri除了清理还会更新Reason。接下来咱们理解下整个删除流程

  1. 当kubelet调用cri的StopContainer接口后,cri会调用containerd的task.Kill接口(这里的task就是containerd中用来示意容器运行状态的模块),containerd收到申请后会调用containerd-shim的kill接口,而containerd-shim会通过命令行工具runc来kill掉容器过程。runc尽管不是守护过程,然而也有局部数据会被长久化到文件系统中,执行runc kill后,不只会给容器过程发送信号,同时还会批改runc的长久化数据。另外,当容器过程被干掉后,会被父过程shim回收掉。
  2. shim胜利干掉容器后,会给cri发送TaskExit的事件。当cri收到事件后会调用containerd的task.Delete接口,这个接口会先通过shim清理runc保留的容器长久化数据和容器运行时所用的rootfs。当两者都被清理后,shim留着也没用了,这时罗唆间接发信号kill掉shim,并清理掉containerd保留的task信息。这时containerd中和容器状态相干的信息就都隐没了,当然containerd中的container还完整无缺。
  3. 哪怕代码中不存在bug,这么长的调用链也可能会遇到零碎问题。eventLoop调用task.Delete如果返回谬误会把以后的event放到一个backoff队列,等过一段时间拿进去重试。这样就保障哪怕以后对一个容器的操作失败了,过段时间还能够重试。

回到之前的问题上,可能有些聪慧的同学通过下面的流程图和剖析之前的日志就能够猜到答案了。没猜到也没关系,当初和大家一起剖析下。还记的过后containerd的日志分成两局部么,首先是执行umount报错device busy,之后重复呈现unknown error after kill: runc did not terminate sucessfully: container "55d04f..." does not exist"。这两局部和咱们下面说的“delete task时清理rootfs,如果失败了会隔段时间进行重试”这个表述很靠近。咱们再把调用的流程图画的更细点,这下应该就能够在图中找到答案了。

当容器被kill掉之后还一切正常,cri收到了容器退出的信号,调用containerd的task.Delete()时,能够留神到,这里多了个withKill选项(下面的流程中其实也有,只不过被省略掉了)。增加这个选项会在调用shim的Delete接口之前再次调用Kill,这样能够避免Delete了正在运行的容器,算是“乐观”的决定。

第一次task Delete的流程中,所有运行的都很顺畅,runc kill掉一个曾经挂掉的容器也没什么问题。直到umount容器的rootfs,发现rootfs被占用了,而且在umount的50次重试中占用rootfs的过程并没有退出,shim只好通过containerd向cri返回一个谬误。cri会在之后的一段时间里从新尝试解决刚刚的这个event。

在接下来重试 task Delete中,会和第一次执行一样,都会在delete之前执行kill。但因为第一次runc delete胜利的删除了runc所长久化的容器信息,重试时执行runc kill会报错container does not exist。不巧的是shim和containerd并没有特地解决这个错误信息,而是间接返回给了cri。这就导致了cri删除容器会失败,并且再也无奈umount容器的rootfs了。cri中的容器无奈被删掉,天然发动删除流程的syncPod也会呈现问题,这样最终就导致了Pod卡在了Terminating。

最终修复与反思

当然这里的修复也很简略,只须要在调用runc kill后增加非凡判断就能够了,具体修复的pr见https://github.com/containerd/containerd/pull/4214,目前曾经合并到骨干,并且回溯到1.2的版本中了。很多时候发现问题远比修复问题要简单的多,尽管最终修复bug的代码很简略,然而整个为了发现bug,咱们用了好几天工夫来剖析梳理整个流程。简略看下错误处理的代码,这里的error就是调用runc呈现谬误的返回后果。

if strings.Contains(err.Error(), "os: process already finished") ||
        strings.Contains(err.Error(), "container not running") ||        
        strings.Contains(strings.ToLower(err.Error()), "no such process") ||
        err == unix.ESRCH {
        return errors.Wrapf(errdefs.ErrNotFound, "process already finished")
    } else if strings.Contains(err.Error(), "does not exist") {
    // we add code here !
        return errors.Wrapf(errdefs.ErrNotFound, "no such container")
    }
    return errors.Wrapf(err, "unknown error after kill")
}

不言而喻这坨代码存在问题:

containerd-shim本来目标就是反对各种OCI工具,然而却把runc的错误处理信息写死在调用OCI的门路上,这样最终可能导致shim只能为runc服务,而不好适配其余的OCI。比方欠缺containerd测试时就会发现这坨代码对crun并不work(crun是用纯c语言实现的OCI工具)。不可能在containerd中适配每一种OCI工具,所以问题还是呈现在制订OCI标准时没思考到错误处理的状况,同样咱们也和OCI社区提了issue。

【腾讯云原生】云说新品、云研新术、云游新活、云赏资讯,扫码关注同名公众号,及时获取更多干货!!

评论

发表回复

您的邮箱地址不会被公开。 必填项已用 * 标注

这个站点使用 Akismet 来减少垃圾评论。了解你的评论数据如何被处理