dockerd 造成 too many open files
一臺(tái)運(yùn)行時(shí)長約5天的機(jī)器扔亥，被發(fā)現(xiàn) docker 無法使用,且其他操作報(bào)錯(cuò) too many open files寸莫。
docker version: 19.03
排查
- docker client 報(bào)錯(cuò)
Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running? - lsof 查看蛮放，沒有輸出... 為文件描述符過多。數(shù)分鐘后有輸出其中包含大量 “/var/run/docker.dock” 推測為 docker 客戶端使用不當(dāng)造成愿卸。一般為連接使用后未關(guān)閉埠啃。
-
lsof /var/run/docker.sock查看該文件FD持有者發(fā)現(xiàn)為 dockerd ,遂進(jìn)入dockerd查找問題瑟由。 - 查看 dockerd 日志济竹，日志顯示是由于連接不上 docker-libnetwork plugin痕檬，發(fā)現(xiàn)該插件服務(wù)處于停止?fàn)顟B(tài)，理論上將其啟動(dòng)即可送浊，但治標(biāo)不治本梦谜，到底為什么這種情況會(huì)導(dǎo)致如此多的FD占用。
# journalctl -xe -u docker.service -f
5月 06 10:57:23 node-2-76 dockerd[5082]: time="2020-05-06T10:57:23.395950238+08:00" level=error msg="1484f4ee9031a4e560c55ed4fdbc68689a668209f4b18b92350e3830969026ec cleanup: failed to delete container from containerd: no such container"
5月 06 10:57:24 node-2-76 dockerd[5082]: time="2020-05-06T10:57:24.387829239+08:00" level=warning msg="Unable to locate plugin: calico-ipam, retrying in 2s"
5月 06 10:57:26 node-2-76 dockerd[5082]: time="2020-05-06T10:57:26.388193568+08:00" level=warning msg="Unable to locate plugin: calico-ipam, retrying in 4s"
5月 06 10:57:30 node-2-76 dockerd[5082]: time="2020-05-06T10:57:30.388593845+08:00" level=warning msg="Unable to locate plugin: calico-ipam, retrying in 8s"
- 繼續(xù)查看 dockerd trace袭景，docker 開啟了 pprof 端點(diǎn)唁桩。
curl --unix-socket /var/run/docker.sock "http://./debug/pprof/goroutine?debug=2" > docker.trace
發(fā)現(xiàn)其中有許多goroutine處于 semacquire 狀態(tài)，該狀態(tài)是在等待鎖浴讯，且有時(shí)長最大高達(dá) 8355 分鐘的。
goroutine 2195141 [semacquire, 5306 minutes]:
sync.runtime_SemacquireMutex(0xc0004aa704, 0xc00c3cd700)
/usr/local/go/src/runtime/sema.go:71 +0x3f
sync.(*Mutex).Lock(0xc0004aa700)
/usr/local/go/src/sync/mutex.go:134 +0x10b
github.com/docker/docker/daemon.(*Daemon).ContainerStart.func1(0x0, 0x0)
/root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/daemon/start.go:29 +0x45
-
查看源碼
github.com/docker/docker/daemon/start.go:29確實(shí)在等鎖蔼啦，如果是在等鎖榆纽。則是由于有地方長期未釋放鎖。注意查找使用 container.Lock() 的地方捏肢。// https://github.com/moby/moby/blob/19.03/daemon/start.go#L29 28 validateState := func() error { 29 container.Lock() 30 defer container.Unlock() -
鑒于上述發(fā)現(xiàn)的 network plugin 不可用基礎(chǔ)上奈籽，一番尋找后發(fā)現(xiàn)：
//https://github.com/moby/moby/blob/master/daemon/container_operations.go#L1065 1061 func (daemon *Daemon) ConnectToNetwork(container *container.Container, idOrName string, endpointConfig *networktypes.EndpointSettings) error { 1062 if endpointConfig == nil { 1063 endpointConfig = &networktypes.EndpointSettings{} 1064 } 1065 container.Lock() 1066 defer container.Unlock() -
該部分執(zhí)行了所有關(guān)于 docker網(wǎng)絡(luò)相關(guān)的操作，最終追蹤到這里鸵赫，該處會(huì)不同的嘗試調(diào)用相關(guān)插件衣屏，直到插件可用，才會(huì)繼續(xù)執(zhí)行辩棒。
// https://github.com/moby/moby/blob/master/pkg/plugins/plugins.go#L208 func loadWithRetry(name string, retry bool) (*Plugin, error) { ... 208 for { pl, err := registry.Plugin(name) if err != nil { if !retry { return nil, err } timeOff := backoff(retries) if abort(start, timeOff) { return nil, err } retries++ 220 logrus.Warnf("Unable to locate plugin: %s, retrying in %v", name, timeOff) time.Sleep(timeOff) continue } ... 241 return pl, err } } 似乎已經(jīng)知道了狼忱，在 network-plugin 不可用的狀態(tài)下膨疏，所有依賴plugin的操作均會(huì)阻塞。我們繼續(xù)使用
docker start [container]驗(yàn)證它钻弄，果然佃却，使用了 network plugin 的容器無法啟動(dòng)，也無法被刪除窘俺。查看 FD
lsof /var/run/docker.sock | wc -l會(huì)發(fā)現(xiàn)饲帅，每次 docker start 并 ctrl-c 后，F(xiàn)D 計(jì)數(shù)會(huì) +1 瘤泪。因 start 操作發(fā)送給 dockerd 后dockerd會(huì)阻塞該請(qǐng)求直到插件可用灶泵。在程序中，docker start 基于 context timeout对途，如果超時(shí)赦邻，則取消start 請(qǐng)求，等待數(shù)秒后在此start掀宋，如此深纲，在很長一段時(shí)間后FD逐漸超標(biāo)。直至達(dá)到限制劲妙。
解決方案
- 改變 calico-libnetwork-plugin 重啟方式
- 改變調(diào)用 docker client 方式湃鹊，不實(shí)用超時(shí)context，一個(gè)請(qǐng)求阻塞直到 dockerd 返回镣奋。
