了解Docker EOF问题排查

一、前言

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

二、问题

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

三、环境

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

组件 版本

k8s 1.14.x

四、排查

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

I0507 03:43:28.310630  57003 prober.go:112] Readiness probe for "adsfadofadfabdfhaodsfa(d1aab5f0- 

ae8f-11eb-a151-080027049c65):c0" failed (failure): OCI runtime exec failed: exec failed: EOF: unknown 

I0507 07:08:49.834093  57003 prober.go:112] Readiness probe for "adsfadofadfabdfhaodsfa(a89a158e- 

ae8f-11eb-a151-080027049c65):c0" failed (failure): OCI runtime exec failed: exec failed: unexpected EOF: unknown 

I0507 10:06:58.307881  57003 prober.go:112] Readiness probe for "adsfadofadfabdfhaodsfa(d1aab5f0- 

ae8f-11eb-a151-080027049c65):c0" failed (failure): OCI runtime exec failed: exec failed: EOF: unknown 

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

 

time="2021-05-06T16:51:40.009989451+08:00" level=error msg="stream copy error: reading from a closed fifo" 

time="2021-05-06T16:51:40.010054596+08:00" level=error msg="stream copy error: reading from a closed fifo" 

time="2021-05-06T16:51:40.170676532+08:00" level=error msg="Error running exec 8e34e8b910694abe95a467b2936b37635fdabd2f7b7c464d 

fef952fa5732aa4e in container: OCI runtime exec failed: exec failed: EOF: unknown" 

虽然从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。

func (*NativeExecHandler) ExecInContainer(client libdocker.Interface, container *dockertypes.ContainerJSON, cmd []string, stdin io.Reader, stdout, stderr io.WriteCloser, tty bool, resize <-chan remotecommand.TerminalSize, timeout time.Duration) error { 

   execObj, err := client.CreateExec(container.ID, createOpts) 

    

   startOpts := dockertypes.ExecStartCheck{Detach: false, Tty: tty} 

   streamOpts := libdocker.StreamOptions{ 

      InputStream:  stdin, 

      OutputStream: stdout, 

      ErrorStream:  stderr, 

      RawTerminal:  tty, 

      ExecStarted:  execStarted, 

   } 

   err = client.StartExec(execObj.ID, startOpts, streamOpts) 

   if err != nil { 

      return err 

   } 

 

    ticker := time.NewTicker(2 * time.Second) 

    defer ticker.Stop() 

    count := 0 

    for { 

       inspect, err2 := client.InspectExec(execObj.ID) 

       if err2 != nil { 

          return err2 

       } 

       if !inspect.Running { 

          if inspect.ExitCode != 0 { 

             err = &dockerExitError{inspect} 

          } 

          break 

       } 

     

       count++ 

       if count == 5 { 

          klog.Errorf("Exec session %s in container %s terminated but process still running!", execObj.ID, container.ID) 

          break 

       } 

     

       <-ticker.C 

    } 

 

   return err 

} 

ExecInContainer 做了以下几件事：

鸿蒙官方战略合作共建——HarmonyOS技术社区

调用 CreateExec 创建 ExecID

调用 StartExec 执行 exec，并通过 holdHijackedConnection 来重定向输入输出。将 inputStream 写入到 connection，并将 response stream 重定向到 stdout，stderr。

调用 InspectExec 获取本次 exec 的运行状态和 exitcode

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