概述
记录一个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相关系统服务,发现systemd-journad服务在systemd升级后被自动重启。
Google一下,果然发现了类似问题:https://github.com/moby/moby/issues/19728
问题原因
systemd由于要收集服务的标准输出和标准错误日志,会对标准输出和标准错误做重定向。当journald服务重启后,标准输出的socket连接被终止,如果服务再有标准输出时,系统会返回给服务SIGPIPE信号。systemd建议服务忽略这个信号保证可用性,但是Golang在1.5版本以前没有做正确处理。发生问题的Docker版本是1.8,是用Golang 1.5版本编译的,这就导致Docker服务接收到SIGPIPE信号后被kill。
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%以上的问题是变更引起的,发现问题后首先要考虑是否有过变更?能否回滚?
-
解决问题的方案要尽量根治,长期来看升级版本是更好的方案;
-
开源组件尽量使用比较新的稳定版,太旧的版本坑多踩不完。