背景
最近，我们在升级kubelet时，发现部分宿主机上docker出现hang死的现象，发现过程详见：docker-hang-死阻塞-kubelet-初始化流程。
现在，我们聚焦在docker上，分析docker hang死问题发生时的现象、形成的原因、问题定位的方法，以及对应的解决办法。本文详细记录了整个过程。
docker hang死
我们对docker hang死并不陌生，因为已经发生了好多起。其发生时的现象也多种多样。以往针对docker 1.13.1版本的排查都发现了一些线索，但是并没有定位到根因，最终绝大多数也是通过重启docker解决。而这一次发生在docker 18.06.3版本的docker hang死行为，经过我们4人小分队接近一周的望闻问切，终于确定了其病因。注意，docker hang死的原因远不止一种，因此本排查方法与结果并不具有普适性。
在开始问题排查之前，我们先整理目前掌握的知识：
- 特定容器异常，无法响应docker inspect操作
除此之外的信息，我们则一无所知。
当我们排查一个未知的问题时，一般的做法是先找一个切入点，然后顺藤摸瓜，逐步缩小问题排查的圈定范围，并最终在细枝末节上定位问题的所在。而本问题中，docker显然是我们唯一的切入点。
链路跟踪
首先，我们希望对docker运行的全局状况有一个大致的了解，熟悉go语言开发的用户自然能联想到调试神器pprof。我们借助pprof描绘出了docker当时运行的蓝图：
1 | goroutine profile: total 722373 |
注意，这是一份精简后的docker协程栈信息。从上面的蓝图，我们可以总结出如下结论：
- 有 717594 个协程被阻塞在docker inspect
- 有 4175 个协程被阻塞在docker stats
- 有 1 个协程被阻塞在获取 docker exec的任务ID
- 有 1 个协程被阻塞在docker exec的执行过程
从上面的结论，我们基本了解了异常容器hang死的原因：在于该容器执行docker exec (4)后未返回，进而导致获取docker exec的任务ID (3)阻塞，由于(3)获取了容器锁，进而导致了docker inspect (1)与docker stats (2)卡死。所以病因并非是docker inspect，而是docker exec。
要想继续往下挖掘，我们现在有必要补充一下背景知识。kubelet启动容器或者在容器内执行命令的完整调用路径如下：
1 | +--------------------------------------------------------------+ |
dockerd与containerd可以当做两层nginx代理，containerd-shim是容器的监护人，而runc则是容器启动与命令执行的真正工具人。runc干的事情也非常简单：按照用户指定的配置创建NS，或者进入特定NS，然后执行用户命令。说白了，创建容器就是新建NS，然后在该NS内执行用户指定的命令。
按照上面介绍的背景知识，我们继续往下探索containerd。幸运的是，借助pprof，我们也可以描绘出containerd此时的运行蓝图：
1 | goroutine profile: total 430 |
同样，我们仅保留了关键的协程信息，从上面的协程栈可以看出，containerd阻塞在接收exec返回结果处，附上关键代码佐证：
1 | func (c *Client) dispatch(ctx context.Context, req *Request, resp *Response) error { |
containerd将请求传递至containerd-shim之后，一直在等待containerd-shim的返回。
正常情况下，如果我们能够按照调用链路逐个分析每个组件的协程调用栈信息，我们能够很快的定位问题所在。不幸的是，由于线上docker没有开启debug模式，我们无法收集containerd-shim的pprof信息，并且runc也没有开启pprof。因此单纯依赖协程调用链路定位问题这条路被堵死了。
截至目前，我们已经收集了部分关键信息，同时也将问题排查范围更进一步地缩小在containerd-shim与runc之间。接下来我们换一种思路继续排查。
进程排查
当组件的运行状态无法继续获取时，我们转换一下思维，获取容器的运行状态，也即异常容器此时的进程状态。
既然docker ps执行正常，而docker inspect hang死，首先我们定位异常容器，命令如下：
1 | docker ps | grep -v NAME | awk '{print $1}' | while read cid; do echo $cid; docker inspect -f {{.State.Pid}} $cid; done |
拿到异常容器的ID之后，我们就能扫描与该容器相关的所有进程：
1 | UID PID PPID C STIME TTY TIME CMD |
核心进程列表如上，简单备注下：
- 6655：containerd进程
- 11646：异常容器的containerd-shim进程
- 11680：异常容器的容器启动进程。在容器内查看，因PID NS的隔离，该进程ID是1
- 15581：在异常容器内执行用户命令的进程，此时还未进入容器内部
- 15638：在异常容器内执行用户命令时，进入容器NS的进程
这里再补充一个背景知识：当我们启动容器时，首先会创建runc init进程，创建并进入新的容器NS；而当我们在容器内执行命令时，首先也会创建runc init进程，进入容器的NS。只有在进入容器的隔离NS之后，才会执行用户指定的命令。
面对上面的进程列表，我们无法直观地分辨问题究竟由哪个进程引起。因此，我们还需要了解进程当前所处的状态。借助strace，我们逐一展示进程的活动状态：
1 | // 11646 (container-shim) |
从关联进程的活动状态，我们可以得出如下结论：
- runc exec在等待从6号FD读取数据
- runc init在等待从2号FD写入数据
这些FD究竟对应的是什么文件呢？我们借助lsof可以查看：
1 | // 11638 (runc init) |
有心人结合strace与lsof的结果，已经能够自己得出结论。
runc init往2号FD内写数据时阻塞，2号FD对应的类型是pipe类型。而linux pipe有一个默认的数据大小，当写入的数据超过该大小时，同时读端并未读取数据，写端就会被阻塞。
小结一下：containerd-shim启动runc exec去容器内执行用户命令，而runc exec启动runc init进入容器时，由于往2号FD写数据超过限制大小而被阻塞。当最底层的runc init被阻塞时，造成了调用链路上所有进程都被阻塞：
1 | runc init → runc exec → containerd-shim exec → containerd exec → dockerd exec |
问题定位至此，我们已经了解了docker hang死的原因。但是，现在我们还有如下问题并未解决：
- 为什么runc init会往2号FD (对应go语言的os.Stderr) 中写入超过linux pipe大小限制的数据？
- 为什么runc init出现问题只发生在特定容器？
如果常态下runc init就需要往os.Stdout或者os.Stderr中写入很多数据，那么所有容器的创建都应该有问题。所以，我们可以确定是该异常容器出现了什么未知原因，导致runc init非预期往os.Stderr写入了大量数据。而此时runc init往os.Stderr中写入的数据就很有可能揭示非预期的异常。
所以，我们需要获取runc init当前正在写入的数据。由于runc init的2号FD是个匿名pipe，我们无法使用常规文件读取的方式获取pipe内的数据。这里感谢鹤哥趟坑，找到了一种读取匿名pipe内容的方法：
1 | # cat /proc/15638/fd/2 |
额，runc init因资源不足创建线程失败？？？这种输出显然不是runc的输出，而是go runtime非预期的输出内容。那么资源不足，究竟是什么资源类型资源不足呢？我们在结合 /var/log/message 日志分析：
1 | Jun 17 03:18:17 host-xx kernel: runc:[2:INIT] invoked oom-killer: gfp_mask=0xd0, order=0, oom_score_adj=997 |
/var/log/message 记录了该容器在大约1个月前大量的OOM日志信息，该时间与异常的runc init进程启动时间基本匹配。
小结runc init阻塞的原因：在一个非常关键的时间节点，runc init由于内存资源不足，创建线程失败，触发go runtime的非预期输出，进而造成runc init阻塞在写pipe操作。
定位至此，问题的全貌已经基本描述清楚。但是我们还有一个疑问，既然runc init在往pipe中写数据，难道没有其它进程来读取pipe中的内容吗？
大家还记得上面lsof执行的结果吗？有心人一定发现了该pipe的读端是谁了，对，就是containerd-shim，对应的pipe的inode编号为1070361747。那么，为什么containerd-shim没有来读pipe里面的内容呢？我们结合代码来分析：
1 | func (e *execProcess) start(ctx context.Context) (err error) { |
额，containerd-shim的设计是，等待runc init执行完成之后，再来读取pipe中的内容。但是此时的runc init由于非预期的写入数据量比较大，被阻塞在了写pipe操作处。。。完美的死锁。
终于，本次docker hang死问题的核心脉络都已理清。接下来我们再来聊聊解决方案。
解决方案
当了解了docker hang死的成因之后，我们可以针对性的提出如下解决办法。
最直观的办法
既然docker exec可能会引起docker hang死，那么我们禁用系统中所有的docker exec操作即可。最典型的是kubelet的probe，当前我们默认给所有Pod添加了ReadinessProbe，并且是以exec的形式进入容器内执行命令。我们调整kubelet的探测行为，修改为tcp或者http probe即可。
这里组件虽然改动不大，但是涉及业务容器的改造成本太大了，如何迁移存量集群是个大问题。
最根本的办法
既然当前containerd-shim读pipe需要等待runc exec执行完毕，如果我们将读pipe的操作提前至runc exec命令执行之前，理论上也可以避免死锁。
同样。这种方案的升级成本太高了，升级containerd-shim时需要重启存量的所有容器，这个方案基本不可能通过评审。
最简单的办法
既然runc init阻塞在写pipe，我们主动读取pipe内的内容，也能让runc init顺利退出。
在将本解决方案自动化的过程中，如何能够识别如docker hang死是由于写pipe导致的，是一个小小的挑战。但是相对于以上两种解决方案，我认为还是值得一试，毕竟其影响微乎其微。
后续
其实我们在读pipe的时候还引起了一个另外的问题，详见：一次读-pipe-引发的血案。
另外，docker hang死的原因远非这一种，本次排查的结果也并非适用于所有场景。希望各位看官能够根据自己的现场排查问题。
本次docker hang死的排查之旅已然告终。
本次排查由四人小分队 @飞哥 @鹤哥 @博哥 @我 一起排查长达数天的结论，欢迎大家一键三连，以表支持。
以上排查如果有误，也欢迎指正。
