​

 概述

记录一个 Docker 服务被异常终止问题的排查流程。

排查过程

1. 在问题发生前……

在服务器盲测时发现了一个问题，有服务器重启后 ssh 服务没有正常启动导致服务器无法登录，排查发现是由于 systemd 版本太低存在 Bug，sshd 服务在 network 服务启动完成之前就开始启动，导致无法绑定内网 IP，sshd 服务启动失败。为了修复这一问题，SA 同学操作升级了一批主机的 systemd 版本。

2. Docker 挂掉了！

有同学反馈，有一批服务器上的 Docker 服务在凌晨 2 点左右的时候挂掉了，感觉问题很严重，SA 赶紧介入排查。2 点这个时间看起来比较特殊，是不是有啥定时任务？这类问题排查顺序：看系统 messages、看用户操作日志、看 crontab 执行日志。果然发现了一个定时任务：

0 2 * * * root python /home/xxx/logrotate.py  > /dev/null

Emmmmmm…… 看起来是个日志轮转脚本，打开脚本看一看，里头有这么一行:

/bin/docker exec nginx001 cat /var/run/nginx.pid | xargs /bin/docker exec nginx001 /bin/kill -USR1

意思就是日志轮转完后让 nginx 重新打开日志文件。那么执行 docker exec 以后，docker 就挂掉啦？匪夷所思。

3. 是 systemd 的锅？

排查看起来陷入了瓶颈，执行 docker exec 就会导致 docker 被 kill，怎么想都不合理。另外问题为何突然出现？最近有什么变更？联系业务同学反馈说程序没有变化，2 点的定时任务脚本也是 2018 年部署的了。突然想到前一天，有同学升级了 systemd 版本，莫非跟这个有关？

systemd 是啥？是 Linux 中系统和服务管理工具，CentOS 从 7 版本开始，默认使用 systemd 管理系统和服务。

查看 systemd 相关系统服务，发现 systemd-journad 服务在 systemd 升级后被自动重启。Google 一下，果然发现了类似问题：https://github.com/moby/moby/issues/19728

journald 是啥？是 systemd 中的日志管理服务，用于管理系统和应用日志。

问题原因

systemd 由于要收集服务的标准输出和标准错误日志，会对标准输出和标准错误做重定向。当 journald 服务重启后，标准输出的 socket 连接被终止，如果服务再有标准输出时，系统会返回给服务 SIGPIPE 信号。systemd 建议服务忽略这个信号保证可用性，但是 Golang 在 1.5 版本以前没有做正确处理。发生问题的 Docker 版本是 1.8，是用 Golang 1.5 版本编译的，这就导致 Docker 服务接收到 SIGPIPE 信号后被 kill。

SIGPIPE 信号是干啥的？当服务器 close 一个连接时，若 client 端接着发数据。根据 TCP 协议的规定，会收到一个 RST 响应，client 再往这个服务器发送数据时，系统会发出一个 SIGPIPE 信号给进程，告诉进程这个连接已经断开了，不要再写了。

Golang 在 1.6 之前的处理逻辑：收到连续 10 次 EPIPE/SIGPIPE 信号后，程序退出（不知道为啥这么搞……）。

func epipecheck(file *File, e error) {	if e == syscall.EPIPE {		if atomic.AddInt32(&file.nepipe, 1) >= 10 {			sigpipe()		}	} else {		atomic.StoreInt32(&file.nepipe, 0)	}}

1.6 以后的处理逻辑：当 broken pipe 的 fd 是 1 或 2（stdout 和 stderr）时，抛出异常；fd 非 1 或 2 时不做处理。

func epipecheck(file *File, e error) {	if e == syscall.EPIPE && (file.fd == 1 || file.fd == 2) {		sigpipe()	}}...func sigpipe() {	if sigsend(_SIGPIPE) {		return	}	setsig(_SIGPIPE, _SIG_DFL, false)	raise(_SIGPIPE)}

总结

再来总结一下故障的整个流程：

1. systemd 版本升级，引起了 systemd-journad 服务自动重启；

2. journald 服务重启后，原来 docker 进程标准输出与 journald 服务之间的 socket 被断开；

3. 执行 docker exec 命令后，docker 服务产生标准输出，由于原来的 socket 连接已断开，系统返回给 docker 进程一个 SIGPIPE 信号；

4. docker 收到 SIGPIPE 信号，把自己停了。

看来不是 systemd 的锅，而是 Golang 的 :)

4. 复现问题

复现流程：

• 在一台测试机上安装 docker-engine 1.8 版本

• 重启 systemd-journald 服务: systemctl restart systemd-journald

• 执行一个有标准输出的 docker 命令，如: docker ps

• 观察发现，Docker 被 kill 啦。

5. 如何修复？

有几种方案：

• 升级 docker 版本，到 Golang 版本>1.6，对应 docker 版本 1.10 以上（实际采用这种方案，升级到当前最新的 20.10.6）；

• docker 启动时增加参数：--log-driver=journald，让 docker 直接输出到 journald（非 stdout），绕过这个问题。

总结

• 90%以上的问题是变更引起的，发现问题后首先要考虑是否有过变更？能否回滚？

• 解决问题的方案要尽量根治，长期来看升级版本是更好的方案；

• 开源组件尽量使用比较新的稳定版，太旧的版本坑多踩不完。

参考文章

• https://github.com/moby/moby/issues/19728
  

• https://bugzilla.redhat.com/show_bug.cgi?id=1300076
  

• https://bugs.freedesktop.org/show_bug.cgi?id=84923
  

• https://go-review.googlesource.com/c/go/+/18151/
  

​