聊聊Docker EOF问题排查

本文转载自微信公众号「运维开发故事」，作者运维开发故事。转载本文请联系运维开发故事公众号。

一、前言

问题排查过程，源码部分均由我的开发同事排查和记录;在征得其同意后，由我发表在此。

二、问题

某天接到客户反馈，pod的事件中出现大量的 warning event: Readiness probe failed: OCI runtime execfailed: exec failed: EOF: unknown。但不影响客户访问该服务。

三、环境

特别说明：客户在负责运行业务的k8s节点上坚持开启了cpu-manager

组件 | 版本 |
---|---|---
k8s | 1.14.x |

四、排查

1、接到客户反馈后，检查该pod所在节点的kubelet日志，如下：

probe的错误类型为failure，对应代码如下：图片2、再查看docker日志，如下：

虽然从Docker日志中显示是 stream copy error，但实际上是底层的 runc 返回了 EOF，导致返回了 error。3、因为日志中显示probe 类型为 Failure，因此 e.CombinedOutPut() 的 err != nil，并且 ExitStatus 不为 0，data的值为 OCI runtime exec failed: exec failed: unexpected EOF: unknown，最终会调用到RunInContainer 方法

ExecSync 是通过 GRPC 调用了 dockershim 的 ExecSync

dockershim 最终调用到 ExecInContainer 方法，并且该方法的返回了 exitcode 不为 0 的 error。

ExecInContainer 做了以下几件事：

那么日志中打印的报错就是 response stream 传递过来的字符流。也就是说，dockerd 的 response 中包含了错误值。

此时去 docker 代码中查找原因，ExecStart 会调用到 dockerd 的以下代码：

根据上面 docker 的日志，err 的错误信息为：OCI runtime exec failed: exec failed: EOF:unknown。也就是说 ContainerExecStart 返回了错误。ContainerExecStart 会调用到containerd.Exec，也就是 dockerd 和 containerd 之间进行通信

这里 new 了一个 FIFOSet，而 reading from a closed fifo 仅出现在 fifo 被 close掉时，仍然在读取的情况。即 f.Close() 发生在 f.Read() 前面。在外层可以看到

p.Start 调用到下面的代码，通过 GRPC 和 containerd 通信。

这个 GRPC 调用会到达 containerd 以下的代码：

Exec 的代码如下：

因此是 runc 在运行后输出了 exec failed: EOF: unknown 这个错误。

将 runc 指令循环执行，可少量复现。经过排查，发现 runc exec 在运行期间会读取 container 的 state.json，并使用 jsondecode 时出现异常。

此时联想到开启 kubelet cpu-manager 后，会 update container，也就是更新这个 state.json 文件。导致 runc读到了部分 cpu-manager 更新的内容。从而导致 json decode 失败。此时排查 runc EOF 和 kubelet cpu-manager update container(默认每 10s 更新一次) 的时间，发现时间点刚好吻合，验证猜想。

查看 runc 是否有修复，发现了这个 pr: https://github.com/opencontainers/runc/pull/2467。修复思路是将 saveState 变成原子操作，这样就不会出现读取 state.json 时，读到部分写入的内容，导致 unexpected EOF (或EOF)的问题

五、解决

关闭cpu-manager

升级runc