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

5次阅读

共计 8446 个字符,预计需要花费 22 分钟才能阅读完成。

前一段时间发现有一些 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。

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

正文完
 0