概述

记录一个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)
}

总结

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

  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%以上的问题是变更引起的,发现问题后首先要考虑是否有过变更?能否回滚?

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

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

参考文章:

06-24 11:52