记一次 Go 协程泄漏的排查过程
涛叔昨天例行查看服务监控,发现协程数量异常增加(超过10倍)。经过一翻努力查到了源头,并顺利上线修复(效果见题图)。对于协程,一千个程序员有一千种用法。了解这次泄漏的细节意义并不大。但从发现到修复的整个过程还是有一些参考价值的,所以记录一下,分享给大家。
首先想到的是最近有什么发版。结果发现我们是在10月28号有过发版,但问题是从30号开始的。对比了新上线的业务代码,没有发现可能导致泄漏的用法。这条线索就断了。
订正:事后复盘发现这有步是有问题的。28号上线了 PV 功能,而 PV信息需要通过 grpc 接口查询。到30号运营在线上配置了PV信息,触发了这个问题。
既然新代码没有可疑的地方,那就只能排查老代码了。不管是线程还是协程,并发编程的本质非常复杂。越复杂越容易出问题,所以我一直要求工友避免直接在业务代码起协程。要查询使用协程的地方,只需要搜索关键词"\bgo "
,用的地方非常少,多数都是业务框架在用,基本不可能有泄漏问题。这条线索也只能打住了。
有同学提出使用重启大法,看重启之后能不能恢复。 重启大法一般应急使用,并不解决根本问题,但在关键时刻有奇效。如果线上炸的飞起而又没有头绪可以先试一下。但是重启会破坏问题现场,所以最好留一个实例用于问题的后续排查。正好当天有新代码上线,就通过发版实现了重启效果。重启后协程数量很快恢复到高位。重启更加证明这是代码的BUG。
好了,三板斧用完了,问题很没解决,开始烦躁了。
就在这时,SLB 不时传来告警,说是用户阅读历史接口偶现 5xx 报错。整个人都有点不对劲了。之前阅读历史报错都是源于厂内一个叫泰山的组件,查了一下错误日志,泰山居然很稳。心态更是要炸了。
既然查不到协程泄漏的源头,那能不能查一下现在线上协程都在做什么事情呢?Go 语言内置了丰富的诊断工具,大家可以参考这篇文章(我是通过谷歌关键词 golang trace goroutine create 找到的 )
https://golang.org/doc/diagnostics.htmlgolang.org
读罢我就想通过 pprof 查一下 goroutine 的使用情况。要想使用 pprof 需要在你的程序里导入net/http/pprof
,一翻代码,线上版本居然已经导入了这个包,果然优秀是一种习惯
到线上找一台实例执行下面的命令
go tool pprof $ip:$port/debug/pprof/goroutine
pprof 会启动一个交互式的界面,输入top
得到如下结果:
top
1267 99.29% 99.29% 1267 99.29% runtime.gopark
...
0 0% 99.29% 1190 93.26% golang.org/x/net/http2.(*ClientConn).readLoop
0 0% 99.29% 1190 93.26% golang.org/x/net/http2.(*Framer).ReadFrame
0 0% 99.29% 1190 93.26% golang.org/x/net/http2.(*clientConnReadLoop).run
0 0% 99.29% 1190 93.26% golang.org/x/net/http2.readFrameHeader
...
显然,golang.org/x/net/http2
是罪魁祸首。 于是立马想到主站一直在强推 grpc ,很多业务都不再提供 http 接口。无奈之下,我写了一个简单的 grpc 客户端,在这里用到了 http 包的 http2 功能。应该是这里用错了。好了上代码:
func NewGrpcClient(timeout time.Duration) GrpcClient {
return &myClient{
: &http.Client{
cli: &http2.Transport{
Transport: true,
AllowHTTP: func(network, addr string, cfg *tls.Config) (net.Conn, error) {
DialTLSreturn net.Dial(network, addr)
},
},
: timeout,
Timeout},
}
}
不知道哪位同学能一眼看出问题所在。反正我是没看出来。
我首先怀疑 http.Client 可能没有复用 tcp 连接,进而导致泄露。赶紧谷歌关键词 golang http reuse connection 。网上的资料教说只要读完响应内容关闭 response 就可以复用连接。我看了一下代码,也都是这样写的,没毛病:
func (c *myClient) DoUnary(ctx context.Context, api string, req, resp proto.Message) (h2resp *http.Response, err error) {
...
, err = c.Do(ctx, h2req)
h2resp...
defer h2resp.Body.Close()
...
}
无奈之下,只能逐篇阅读了。最后,我读到了这篇回答:
Transport
is the struct that holds connections for re-use; see https://godoc.org/net/http#Transport (“By default, Transport caches connections for future re-use.”) So if you create a new Transport for each request, it will create new connections each time. In this case the solution is to share the one Transport instance between clients.
破案了!前面说的NewGrpcClient
每次创建的 http.Client 的时候都会创建新的 Transport 对像,所以无法复用连接池。 办法也很简单,直接上代码:
var plainTextH2Transport = &http2.Transport{
: true,
AllowHTTP: func(network, addr string, cfg *tls.Config) (net.Conn, error) {
DialTLSreturn net.Dial(network, addr)
},
}
func NewGrpcClient(timeout time.Duration) GrpcClient {
return &myClient{
: &http.Client{
cli: plainTextH2Transport,
Transport: timeout,
Timeout},
}
}
简单在线下验证功能之后直接就线上灰度了。灰度实例放量后测了一下协程数,一下降到了100以内。全量发布,问题解决。
这里还有一个小插曲。我厂的监控平台居然无法采集灰度实例的 prometheus 指标。我是跑到实例上使用 curl + grep 人肉查确认协程数指标的。所以大家一定不要拘泥于现有的平台和工具,没有条件就创造条件。
最后再回过来说一下那个 SLB 报警的问题。报警的是阅读历史接口,这个接口所依赖的泰山用的就是 grpc 协议!一切都串起来了。协程问题修复后 SLB 也再也没报阅读历史接口5xx。
所以说,从现象到本质是很遥远的距离。根据报警和监控来排查问题是不太容易的。那怎么办呢?
只能在前置工作下工夫。
- 如果我在使用 http.Client 他细看一下它的文档和 Transport 字段的用法,这个问题就很容易避免。
- 如果我在上线之前对
NewGrpcClient
做一下并发测试,也很容易发现这个问题,但定位的难度就会比提前看文档高了不少。 - 如果在线上没做监控,那只能收到 SLB 告警,根本不会知道有协程泄漏,问题也就无从查起。
- 如果不太懂英语,不愿意用谷歌,那基本也很难找到网上优秀的内容。
- 如果不能熟练在纯字符界面下工作,也很难使用 go 的诊断工具(我们的平台有要视化的诊断工具,同样因为有 BUG 而没法使用。服务端尽量要摆脱对图形界面的依赖。)
- 如果对 http2 没有基础的了解,也就很难联想到 http 连接复用跟协程泄漏的关系。
所以说,线上问题一定要坚持预防为主、防治结合的思路。Keep It Simple, Stupid!
最后给大家留个问题。为什么没有复用 http2 连接会导致协程泄漏呢