概述

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

排查过程

1. 在问题发生前……

在服务器盲测时发现了一个问题，有服务器重启后ssh服务没有正常启动致使服务器没法登陆，排查发现是因为systemd版本过低存在Bug，sshd服务在network服务启动完成以前就开始启动，致使没法绑定内网IP，sshd服务启动失败。
为了修复这一问题，SA同窗操做升级了一批主机的systemd版本。nginx

2. Docker挂掉了！

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

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

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

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

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

3. 是systemd的锅？

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

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

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

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)
}

总结

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

systemd版本升级，引发了systemd-journad服务自动重启；
journald服务重启后，原来docker进程标准输出与journald服务之间的socket被断开；
执行docker exec命令后，docker服务产生标准输出，因为原来的socket链接已断开，系统返回给docker进程一个SIGPIPE信号；
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%以上的问题是变动引发的，发现问题后首先要考虑是否有过变动？可否回滚？
解决问题的方案要尽可能根治，长期来看升级版本是更好的方案；
开源组件尽可能使用比较新的稳定版，太旧的版本坑多踩不完。

Docker被谁干掉了？

概述