Dockerd資源泄露系列 - 內(nèi)存&FD泄露 - 1

背景

線上部分宿主機(jī)dockerd占用內(nèi)存過(guò)大，有的甚至超過(guò)100G，而整個(gè)宿主上的容器使用的內(nèi)存還不如dockerd一個(gè)進(jìn)程使用的多，現(xiàn)在的處理辦法是故障自愈，檢測(cè)到dockerd使用內(nèi)存超過(guò)10G后會(huì)設(shè)置live-restore，然后重啟dockerd，而不影響正常運(yùn)行的容器，但是重啟后還一直存在內(nèi)存泄露的問(wèn)題。可以總結(jié)為兩類內(nèi)存泄露情況：沒(méi)有設(shè)置live-restore: true的和設(shè)置了live-restore: true且重啟過(guò)dockerd的，這里是針對(duì)后者的排查，因?yàn)榫€上默認(rèn)dockerd沒(méi)有開(kāi)啟debug模式，要想排查前者的問(wèn)題，就需要重啟docker，又因?yàn)闆](méi)有配置live-restore: true，就會(huì)影響到正在運(yùn)行的容器。

dockerd日志

tail -f /var/log/messages | grep dockerd，結(jié)果如下圖，存在內(nèi)存泄露的dockerd的日志都有如下的日志記錄，且看時(shí)間規(guī)律是相同sandbox的記錄每秒打印一遍

從源碼中搜索日志內(nèi)容，對(duì)應(yīng)下面的源碼分析-2里的內(nèi)容。

查看dockerd啟動(dòng)時(shí)的日志，如下

步驟

步驟比較長(zhǎng)，尤其是源碼那部分，不關(guān)注源碼的可以直接跳過(guò)源碼，直接看代碼的解釋

pprof分析

1. 開(kāi)啟dockerd的debug模式，即編輯/etc/docker/daemon.json，加上debug: true的配置并重啟dockerd，方便利用pprof來(lái)定位內(nèi)存泄露對(duì)應(yīng)的代碼位置。

2. 執(zhí)行g(shù)o tool pprof http://ip:port/debug/pprof/heap，輸入top命令查看內(nèi)存分配情況，如下圖  

   

   可以看到占用內(nèi)存較多的函數(shù)調(diào)用，但是并不是很直觀，可以繼續(xù)輸入web命令，會(huì)生成svg圖片并通過(guò)畫(huà)圖軟件或?yàn)g覽器打開(kāi)，這樣就可以清楚地看到整個(gè)調(diào)用流程及各函數(shù)占用內(nèi)存大小，可以發(fā)現(xiàn)是外部某程序調(diào)用了docker的api，最終調(diào)用SubscribeTopic，此函數(shù)里面存在內(nèi)存泄露。

源碼分析

明確了發(fā)生泄露的源碼位置，接下來(lái)就是去看下源碼的具體邏輯，下面貼出部分docker源碼(tag v1.13.1)，省略部分不影響結(jié)果的代碼

 // 位置github.com/docker/docker/pkg/pubsub/publisher.go // SubscribeTopic adds a new subscriber that filters messages sent by a topic. func (p *Publisher) SubscribeTopic(topic topicFunc) chan interface{} {    ch := make(chan interface{}, p.buffer)    p.m.Lock()    p.subscribers[ch] = topic    p.m.Unlock()    return ch }

這段代碼很短，每次先new一個(gè)新的chan，然后把chan加入到字典中。可以看到如果發(fā)生內(nèi)存泄漏，那八成就是這句p.subscribers[ch] = topic，也就是說(shuō)會(huì)一直往map里添加新元素而得不到刪除。為了驗(yàn)證，繼續(xù)向上找此函數(shù)的調(diào)用方，沿著調(diào)用堆棧（svg圖片里顯示了具體的調(diào)用堆棧）往上找，如下

// Subscribe adds a new subscriber to the publisher returning the channel. func (p *Publisher) Subscribe() chan interface{} {    // 這里調(diào)用SubscribeTopic    return p.SubscribeTopic(nil) }   // collect registers the container with the collector and adds it to // the event loop for collection on the specified interval returning // a channel for the subscriber to receive on. func (s *statsCollector) collect(c *container.Container) chan interface{} {    s.m.Lock()    defer s.m.Unlock()    publisher, exists := s.publishers[c]    if !exists {       publisher = pubsub.NewPublisher(100*time.Millisecond, 1024)       s.publishers[c] = publisher    }    // 這里調(diào)用Subscribe    return publisher.Subscribe() }   func (daemon *Daemon) subscribeToContainerStats(c *container.Container) chan interface{} {    return daemon.statsCollector.collect(c) }   // ContainerStats writes information about the container to the stream // given in the config object. func (daemon *Daemon) ContainerStats(ctx context.Context, prefixOrName string, config *backend.ContainerStatsConfig) error {    ...      // subscribe    updates := daemon.subscribeToContainerStats(container)    // unsubscribe    defer daemon.unsubscribeToContainerStats(container, updates)     noStreamFirstFrame := true    for {       select {       case v, ok := <-updates:          if !ok {             return nil          }           ...           if !config.Stream && noStreamFirstFrame {             // prime the cpu stats so they aren't 0 in the final output             noStreamFirstFrame = false             continue          }           if err := enc.Encode(statsJSON); err != nil {             return err          }           if !config.Stream {             return nil          }       case <-ctx.Done():          return nil      }    } } 

可以看到最終在ContainerStats中調(diào)用了subscribe并在此函數(shù)退出后調(diào)用defer里的unsubscribe。直接看代碼可能看不懂，先介紹下docker stats的api，此api用來(lái)獲取容器資源使用詳情，包括cpu，memory，network等信息，支持兩種方式，流和非流的方式，流是利用http的chunked屬性實(shí)現(xiàn)的，非流的方式是直接返回。

chan的產(chǎn)生

每次調(diào)用docker stats {container} 或者 docker stats的api的時(shí)候，都會(huì)進(jìn)入到ContainerStats函數(shù)，這里使用了一個(gè)chan來(lái)達(dá)到異步的效果，即并不是每次調(diào)用stats都去實(shí)時(shí)的統(tǒng)計(jì)相關(guān)數(shù)據(jù)，而是有個(gè)后臺(tái)goroutine在定時(shí)的stats（下面會(huì)介紹），并把數(shù)據(jù)推送到chan，每次調(diào)用api時(shí)只是去chan中獲取數(shù)據(jù)而已，此chan對(duì)應(yīng)的就是上面for select中的updates，即daemon.subscribeToContainerStats(container)的返回結(jié)果，也就是最終SubscribeTopic里new的chan。

chan的消亡

在ContainerStats函數(shù)結(jié)束后會(huì)調(diào)用unsubscribeToContainerStats，這里會(huì)關(guān)閉創(chuàng)建出來(lái)的chan并從map中刪除，釋放內(nèi)存。

知道了chan的產(chǎn)生和消亡，可以排除以stream形式調(diào)用api導(dǎo)致的，因?yàn)檫@種方式不會(huì)一直調(diào)用api，也就不會(huì)導(dǎo)致chan一直新建。那就只剩下一種形式，即外部有程序定時(shí)的以非stream的形式調(diào)用docker stats的api。但是上面也看到了函數(shù)結(jié)束后會(huì)在defer里釋放掉申請(qǐng)的chan，為什么還會(huì)導(dǎo)致內(nèi)存泄露呢？稍微注意一下就可以看到釋放chan的函數(shù)是在defer里調(diào)用的，而且函數(shù)里還有個(gè)for循環(huán)，所以很可能是因?yàn)楹瘮?shù)的for循環(huán)一直沒(méi)有退出，導(dǎo)致defer一直得不到執(zhí)行，chan也就一直釋放不了，而且外部還定時(shí)的調(diào)用api，會(huì)導(dǎo)致一直會(huì)有新的chan的創(chuàng)建且舊的chan加入緩存后無(wú)法被刪除，最終導(dǎo)致占用的內(nèi)存越來(lái)越大。那就看下for循環(huán)內(nèi)的代碼，可以看到只有一個(gè)select，兩個(gè)case，分別對(duì)應(yīng)從updates chan中讀數(shù)據(jù)和從ctx.Done()中讀數(shù)據(jù)，后者是外部程序取消此次api調(diào)用后會(huì)得到執(zhí)行的，即結(jié)束此次調(diào)用，前者是從updates chan中讀stats數(shù)據(jù)，所以如果想要函數(shù)不退出，那么兩個(gè)case都無(wú)法滿足即可，即外部程序沒(méi)有主動(dòng)cancel request且updates chan中始終沒(méi)有數(shù)據(jù)，先不管外部程序，因?yàn)橐膊恢劳獠砍绦蚴钦l(shuí)，代碼怎么寫的，但是可以肯定的是外部程序在調(diào)用docker api時(shí)的處理有問(wèn)題，沒(méi)有設(shè)置超時(shí)或者超時(shí)了也沒(méi)有去cancel request。重點(diǎn)關(guān)注下為什么updates chan中一直沒(méi)有數(shù)據(jù)，那就要看下寫數(shù)據(jù)相關(guān)代碼，如下

func (s *statsCollector) run() {    type publishersPair struct {       container *container.Container       publisher *pubsub.Publisher    }    // we cannot determine the capacity here.    // it will grow enough in first iteration    var pairs []publishersPair     // s.interval是1s，硬編碼的    for range time.Tick(s.interval) {       // it does not make sense in the first iteration,       // but saves allocations in further iterations       pairs = pairs[:0]        s.m.Lock()       for container, publisher := range s.publishers {          // copy pointers here to release the lock ASAP          pairs = append(pairs, publishersPair{container, publisher})      }       s.m.Unlock()       if len(pairs) == 0 {          continue      }        systemUsage, err := s.getSystemCPUUsage()       if err != nil {          logrus.Errorf("collecting system cpu usage: %v", err)          continue      }        for _, pair := range pairs {          stats, err := s.supervisor.GetContainerStats(pair.container)          if err != nil {             if _, ok := err.(errNotRunning); !ok {                logrus.Errorf("collecting stats for %s: %v", pair.container.ID, err)            }             continue          }          // FIXME: move to containerd on Linux (not Windows)          stats.CPUStats.SystemUsage = systemUsage          // 往chan里推送數(shù)據(jù)          pair.publisher.Publish(*stats)      }    } } 

可以看到函數(shù)內(nèi)有個(gè)定時(shí)器，每1秒執(zhí)行一次，每次執(zhí)行都遍歷一遍所有注冊(cè)了的container的publisher，再遍歷獲取對(duì)應(yīng)container的stats，這里是實(shí)時(shí)的去計(jì)算的，如果獲取過(guò)程中出錯(cuò)，且不是notRunning的錯(cuò)誤，則會(huì)打一條日志，collecting stats for {containerID}: {err}，然后跳過(guò)往chan里推送數(shù)據(jù)的邏輯。這里日志正好和從宿主上看到的日志內(nèi)容匹配，且時(shí)間間隔也相同。

接著看GetContainerStats函數(shù)代碼，為什么會(huì)出錯(cuò)，如下

 // GetContainerStats collects all the stats published by a container func (daemon *Daemon) GetContainerStats(container *container.Container) (*types.StatsJSON, error) {    stats, err := daemon.stats(container)    if err != nil {       return nil, err    }     // We already have the network stats on Windows directly from HCS.    if !container.Config.NetworkDisabled && runtime.GOOS != "windows" {       if stats.Networks, err = daemon.getNetworkStats(container); err != nil {          return nil, err      }    }     return stats, nil }

從日志里可以看到sandbox字樣，和網(wǎng)絡(luò)有關(guān)，直接看getNetworkStats

func (daemon *Daemon) getNetworkStats(c *container.Container) (map[string]types.NetworkStats, error) {    ...     sb, err := daemon.netController.SandboxByID(sandboxID)    if err != nil {       return nil, err    }     ... }   func (c *controller) SandboxByID(id string) (Sandbox, error) {    if id == "" {       return nil, ErrInvalidID(id)    }    c.Lock()    s, ok := c.sandboxes[id]    c.Unlock()    if !ok {       return nil, types.NotFoundErrorf("sandbox %s not found", id)    }    return s, nil } 

可以看到在根據(jù)id從字典中取sandbox時(shí)如果沒(méi)有取到，則會(huì)報(bào)sandbox not found的error，和日志里的報(bào)錯(cuò)匹配。也就匹配上了dockerd啟動(dòng)時(shí)的報(bào)錯(cuò)，即failed to create osl sandbox while trying to restore sandbox bc51d3e: failed to create a netlink handle: failed to set into network namespace 214 while creating netlink socket: invalid argument。那這個(gè)錯(cuò)是從哪里報(bào)出來(lái)的呢？

繼續(xù)看restore sandbox failed的錯(cuò)誤，代碼位置如下

func executeInNetns(newNs, curNs netns.NsHandle) (func(), error) {    ...    if newNs.IsOpen() {       runtime.LockOSThread()       unlockThd = runtime.UnlockOSThread       if !curNs.IsOpen() {          if curNs, err = netns.Get(); err != nil {             restore()             return nil, fmt.Errorf("could not get current namespace while creating netlink socket: %v", err)          }          closeNs = curNs.Close      }       if err := netns.Set(newNs); err != nil {          restore()          return nil, fmt.Errorf("failed to set into network namespace %d while creating netlink socket: %v", newNs, err)      }       moveBack = netns.Set    }    return restore, nil }   // Set sets the current network namespace to the namespace represented // by NsHandle. func Set(ns NsHandle) (err error) {    return Setns(ns, CLONE_NEWNET) }   // Setns sets namespace using syscall. Note that this should be a method // in syscall but it has not been added. func Setns(ns NsHandle, nstype int) (err error) {    _, _, e1 := syscall.Syscall(SYS_SETNS, uintptr(ns), uintptr(nstype), 0)    if e1 != 0 {       err = e1    }    return }

可以看到最終是在調(diào)用系統(tǒng)調(diào)用進(jìn)入netns時(shí)出錯(cuò)了，但是去宿主上操作，實(shí)際是可以執(zhí)行ip netns exec命令的，這個(gè)錯(cuò)在網(wǎng)上搜也可以搜到，如https://github.com/moby/moby/issues/33656，但是經(jīng)過(guò)去宿主上查看并沒(méi)有ds_agent進(jìn)程，也可能是有其他病病毒掃描類的軟件導(dǎo)致的，但是可能性不大。后續(xù)把netns操作的相關(guān)代碼單獨(dú)拿出來(lái)搞了個(gè)demo，到宿主上執(zhí)行仍然會(huì)報(bào)此錯(cuò)誤，后經(jīng)孔飛兄測(cè)試，發(fā)現(xiàn)只要把docker參數(shù)MountFlags=slave去掉，demo就能運(yùn)行成功，dockerd啟動(dòng)就不會(huì)再報(bào)這個(gè)錯(cuò)，但是同時(shí)又發(fā)現(xiàn)了其他問(wèn)題，相關(guān)問(wèn)題簡(jiǎn)體見(jiàn)如下issue

https://blog.frognew.com/2018/02/k8s-unable-delete-pod-docker-device-busy.html

https://github.com/moby/moby/issues/35873

https://access.redhat.com/solutions/2991041

其中又涉及到多個(gè)其他issue，涉及docker版本和linux版本的問(wèn)題，從上面為issue里看這種問(wèn)題暫時(shí)是無(wú)解的，無(wú)論怎么設(shè)置MountFlags，只要與live-restore一起使用就會(huì)存在問(wèn)題，后面會(huì)單獨(dú)有一篇來(lái)分析不同版本的docker，MountFlags和live-restore一起使用時(shí)應(yīng)該如何設(shè)置。就目前線上配置看，除了內(nèi)存泄露，還沒(méi)有反饋其他問(wèn)題，所以可以先找出來(lái)api調(diào)用方，規(guī)范api調(diào)用，及時(shí)關(guān)閉超時(shí)連接也是可以避免內(nèi)存泄露的。而且辛虧現(xiàn)在用的物理網(wǎng)路，否則還可能出現(xiàn)把同一個(gè)ip分配給多個(gè)容器的bug。之前出現(xiàn)過(guò)的netns泄露的問(wèn)題可能也與此有關(guān)。

誰(shuí)是調(diào)用方

經(jīng)過(guò)上面的排查，已經(jīng)可以明確問(wèn)題的原因，對(duì)應(yīng)的代碼邏輯。雖然還無(wú)法從根本上解決，但是找到調(diào)用方，規(guī)范調(diào)用規(guī)則也是可以避免這個(gè)問(wèn)題的，如何找到調(diào)用方呢，一般找api調(diào)用方，只需要netstat找對(duì)用端口就好了，會(huì)顯示出來(lái)調(diào)用方的IP和Port，但是這里并不是通過(guò)ip:port形式訪問(wèn)的，而是直接通過(guò)docker.sock訪問(wèn)，因?yàn)榫€上docker并沒(méi)有開(kāi)啟tcp訪問(wèn)。其實(shí)這里也可以驗(yàn)證一下，因?yàn)槊棵胝{(diào)用一次api，創(chuàng)建一個(gè)新的鏈接，一定會(huì)導(dǎo)致fd泄露的，可以直接到進(jìn)入/proc/{dockerd's pid}/fd，看里面文件個(gè)數(shù)，確實(shí)是在一直增加的，而且增長(zhǎng)速度與宿主上的容器數(shù)有關(guān)，這也是一個(gè)潛在的風(fēng)險(xiǎn)點(diǎn)。

剩下的問(wèn)題就是尋找unix socket的peer，目前我們已經(jīng)一端是docker，只需要找到另一端就可以了，步驟如下

1. ss -a --unix -p | grep docker，輸出如下

   左邊紅框是dockerd開(kāi)的一個(gè)socket，右邊的框是調(diào)用者開(kāi)的socket

2. 在右邊的紅框里隨意挑一個(gè)，執(zhí)行ss -a --unix -p | awk '$6==-219386905' ，輸出如下     u_str  ESTAB      0      0            * -219386905            *      -219569454                 users:(("agent",pid=1962370,fd=55416))     可以看到另一端是agent

結(jié)束了嗎

調(diào)用方是誰(shuí)也查清楚了，按照上面的分析，只要設(shè)置了live-restore: true且設(shè)置完執(zhí)行過(guò)重啟的dockerd都存在內(nèi)存泄露的情況，通過(guò)一個(gè)腳本批量執(zhí)行了一下，結(jié)果卻發(fā)現(xiàn)例外，此時(shí)心中又是萬(wàn)馬奔騰啊，難道之前的分析是錯(cuò)的？

登錄到?jīng)]問(wèn)題的機(jī)器上，查看dockerd的日志，failed to create osl candbox的日志有，但是每秒一次的collecting stats的日志卻沒(méi)有。上面分析過(guò)，只有當(dāng)前存在未關(guān)閉的連接時(shí)，每秒一次的遍歷才能發(fā)現(xiàn)有需要執(zhí)行的stats，才會(huì)打印collecting stats的日志。可以通過(guò)執(zhí)行docker stats命令驗(yàn)證，執(zhí)行之后再去看dockerd的日志就會(huì)發(fā)現(xiàn)出現(xiàn)collecting stats的日志。也正因?yàn)闆](méi)有未關(guān)閉的連接，所以不會(huì)出現(xiàn)內(nèi)存和unix socket泄露，經(jīng)過(guò)查看調(diào)用方即agent的版本，發(fā)現(xiàn)是1.18.1

至此，已找到問(wèn)題，1.18.1版本的agent還沒(méi)有問(wèn)題，1.20.0版本有問(wèn)題。順便去看了一眼agent的代碼，當(dāng)時(shí)master分支的相關(guān)代碼如下

//拿到容器stats func getContainerStats(containerID string) (threadNum int, err error) {         if dockerClient == nil {                dlog.Error("dockerClient is nil!!!")                return        }       // 萬(wàn)惡之源，context.Background()         resp, err := dockerClient.ContainerStats(context.Background(), containerID, false)         if err != nil {                dlog.Error(err)                return        }          var stats DockerStats         err = json.NewDecoder(resp.Body).Decode(&stats)         if err != nil {                return        }          threadNum = stats.PidsStats.Current         return }   func UpdateContainerStat() {         fp := "/home/odin/container-host"         if !file.IsExist(fp) {                return        }         dlog.Info("UpdateContainerStat start...")          go CleanContainerInspectMap()          var err error         ContainerType, err = file.ToString(fp)         if err != nil {                dlog.Error("read file err:", err, fp)                return        }          GetMajorMinor()          dockerClient, err = dockerclient.NewEnvClient()         if err != nil {                dlog.Error(err)        }      // 10s         t1 := time.NewTicker(time.Duration(common.DEFAULT_INTERVAL[common.TYPE_DOCKER]) * time.Second)         for {                updateContainerStat()                <-t1.C        } } 

終于驗(yàn)證了問(wèn)題的所在，客戶端沒(méi)有超時(shí)設(shè)置，服務(wù)端也沒(méi)有，10s獲取一次所有容器的stats信息，假如有20個(gè)容器，就會(huì)導(dǎo)致一天創(chuàng)建172800個(gè)chan（內(nèi)存泄露）和172800 * 2個(gè)socket（fd泄露，dockerd和agent各占一半）

總結(jié)

根本原因：服務(wù)端（dockerd）在設(shè)計(jì)API時(shí)未設(shè)置超時(shí)，客戶端在調(diào)用API時(shí)也為設(shè)置超時(shí)

docker使用下來(lái)給人的感覺(jué)就是存在太多的問(wèn)題了，后面還會(huì)有多篇有關(guān)docker資源泄露、容器刪除不掉等各式各樣的問(wèn)題，敬請(qǐng)期待。

 點(diǎn)擊屏末 | 閱讀原文 | 即刻學(xué)習(xí)