概述

記錄一個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被誰幹掉了？

概述