一次排查 Go 程序协程泄露的记录

sunls24 于 2021-05-21 发布

发现内存泄漏

由于在电脑上运行 DBaaS 时较卡顿,通过查看任务管理器发现,在 DBaaS 运行过程中,内存占用不断增加,并且 CPU 占用率一直维持在 20% 左右(事件监听导致)。

通过 kubectl top 查看服务器上的 DBaaS 容器占用内存已接近 2G,初步确定可能是 协程泄露 导致,出现了应该释放而没有被释放的协程,导致系统协程数量一直上升。

使用 pprof 性能分析工具

首先需要在 main 包中引入 pprof

import _ "net/http/pprof"

然后在 main 函数中开启一个 http 服务,http.pprof 会注册一些路由到 http.DefaultServeMux 默认路由中

go func() {
    _ = http.ListenAndServe("0.0.0.0:8080", nil)
}()

使用浏览器打开 http://localhost:8080/debug/pprof/,如下图:

Snipaste_2021-05-21_14-25-48

主要关注 goroutine 这行, 前面的数字 498,表示当前正在运行的协程数量。

点击 goroutein 的链接可查看当前正在运行协程的详细信息,如下图:

Snipaste_2021-05-21_14-26-56

可以看到 writeLoop 方法开启了 256 个协程,readLoop 方法开启了 254 个协程,大部分的协程都由这两个方法产生,并且可以看到这两个方法都在 net/http 包下的 transport 文件中。

分析协程泄露的原因

排查显式的协程泄露

通过观察 debug/pprof 中的信息发现协程的数量会每隔五秒增加四个,规律增长,于是推测协程泄露发生在每隔 5s 执行一次的定时任务中。有以下两个任务是每隔 5s 执行:

metricsPods := "@every 5s"
_, err = cc.AddFunc(metricsPods, cs.AsyncMetricsPods)
utils.LoggerError(err)

asyncCommonInfo := "@every 5s"
_, err = cc.AddFunc(asyncCommonInfo, cs.AsyncCommonInfo)
utils.LoggerError(err)

一个是采集性能数据,另一个是同步集群信息,不过通过排查相关代码并未发现问题。

排查隐式的协程泄露

在 pprof 的性能数据中还有一个很重要的信息,就是协程的启动信息

goroutine profile: total 530 // 总的协程数量
256 @ 0x62ec9a 0x63fc68 0x9a54de 0x664a41
#	0x9a54dd	net/http.(*persistConn).writeLoop+0xfd	D:/Go/go1.16.windows-amd64/src/net/http/transport.go:2382

...

第二行的 256 表示由 net/http.(*persistConn).writeLoop 方法启动的协程数量,后面是此方法所在的文件以及行号,由此可看出协程泄露主要发生在这里。

通过对此方法的追踪和分析,发现调用它的方法主要是 net/http.(*Client).Do,于是全局搜索 http.Client 的引用,最终把问题锁定在采集性能数据的一段代码中:

func (cs *commonService) AsyncMetricsPods() {
    ...
    tr := &http.Transport{
        TLSClientConfig: &tls.Config{
            RootCAs:      pool,
            Certificates: []tls.Certificate{cliCrt},
        },
    }
    client := &http.Client{Transport: tr}
    response, err := client.Do(request)
    ...
}

此处主要是建立一个 TLS 长连接,主要问题是每次采集的时候都会创建一个 Client,并且未配置最大连接数和连接空闲时间,就会导致连接越来越多而且不会被回收。

代码改造

首先采集数据不用每次都创建一个 Client,可以在系统初始化时创建一个并复用,其次需要对连接进行一些配置:最大连接数,空闲连接数,连接超时和空闲连接时间。代码如下:

func (cs *commonService) setClientTR() {
	if cs.Config == nil || cs.clientTR != nil {
		return
	}
	pool := x509.NewCertPool()
	pool.AppendCertsFromPEM(cs.Config.CAData)
	cliCrt, err := tls.X509KeyPair(cs.Config.CertData, cs.Config.KeyData)
	if err != nil {
		return
	}
	dialer := &net.Dialer{
		Timeout:   10 * time.Second,
		KeepAlive: time.Minute,
	}
	tr := &http.Transport{
		DialContext:     dialer.DialContext,
		IdleConnTimeout: time.Minute,
		MaxIdleConns:    60,
		MaxConnsPerHost: 20,
		TLSClientConfig: &tls.Config{
			RootCAs:      pool,
			Certificates: []tls.Certificate{cliCrt},
		},
	}
	cs.clientTR = &http.Client{Transport: tr, Timeout: 10 * time.Second}
}
func (cs *commonService) AsyncMetricsPods() {
    ...
    response, err := cs.clientTR.Do(request)
    ...
}

系统初始化时调用 setClientTR 创建 Client,采集数据时直接复用。

最终结果

Snipaste_2021-05-21_14-59-03

如图所示,协程的数量稳定在 26 个,内存占用也稳定在 20MB 左右:

Snipaste_2021-05-21_15-26-28