44

字节跳动踩坑记:Goroutine 泄漏

 3 years ago
source link: https://mp.weixin.qq.com/s/5q5eIMDHz35ycTBTkB33JQ
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.

zYVvqiy.jpg!mobile

- 1 -

那是一个月以前,一个令人愉快的周五晚上,我在收工前扫了一眼监控看板,看到了点不太好的迹象:

IJbyauy.png!mobile

稍微解释一下,图中骚动的绿线表示 Goroutine 的数量,密集的红色竖线表示发布了新版的时间点。

因为26和27号下午照常发车,所以 Goroutine 的数量下降了;而28号 值班同学偷懒 没有需要发布的commit,于是 Goroutine 数量一路上涨,眼看就要冲破方框。

我心想: 这走势要是我买的510500该多好啊 糟了,这铁定是 Goroutine 泄漏了,那我还收不收工了?

经过一番思考,头脑里的勤奋小人打败了懒惰小人,指挥我把问题抛给了当天值班的 H 同学,然后愉快地去健身房了。

毕竟 Goroutine 泄漏排查起来应该不会很困难,按套路用 pprof dump 两份采样数据、然后用 --base 比较一下,就该结案了吧。

- 2 -

然后 H 同学用 pprof 确实看到了泄漏的 2498 个 goroutine:

fINvAvF.jpg!mobile

(不是我没截全,是真的只有一行stack)

但问题是这些 goroutine 的 stack 过于简单了 —— 这 http.(*persisteConn).writeLoop 是个什么鬼,没有 stack 真是瞎了。

Mri2yuQ.jpg!mobile

只好先用笨办法筛一下,往前找发现问题的时间点,然后看看当时上线了什么奇怪的东西。

7vEbe2Y.png!mobile

(点击可放大)

从上图可以看到,把时间拉长了以后,问题出现的时间点应该是8月22号前后 ,接着翻了翻前几天的 commit,果然什么也没发现,并没有哪些 commit 用 go 关键词新建 goroutine 。

yqeyYn.jpg!mobile

- 3 -

虽说套路不得人心,那实在没办法,也还是得硬着头皮查; 还好重启大法给了我们充足的支撑和信念。

在第二周的周二,尝试了各种可能以后,我们终于想到,说不定是上周开启的那个实验导致的呢?

负责该实验的 G 同学用前面发现的 stack 作为关键字,在 Google 上看到了别人遇到的 case  —— 我们竟然一直没用上 STFW 大法。

YBRVZjV.jpg!mobile

对应到我们的代码,是因为该实验相关逻辑需要发起一个 http 请求,于是有一段代码长这样:

client := &http.Client{}
_, err = client.Do(req)
if err != nil {
...
}

问题就在这里 —— 你能想到么,这里 client.Do 会返回一个 http.Response ,而 Response.Body 这个 "io.ReadCloser" 是需要主动关闭的。

Y73QRzi.jpg!mobile

- 4 -

当然文档里倒是写得很清楚:

The http Client and Transport guarantee that Body is always non-nil, even on responses without a body or responses with a zero-length body. It is the caller's responsibility to close Body.

但为啥会出现 goroutine 泄漏呢? 还是得从源码下手。

前面我们用 pprof 看到,goroutine 的 stack 在 http.(*persisteConn).writeLoop,这个方法位于 src/net/http/transport.go ,而它的调用方只有一处:

func (t *Transport) dialConn(...) (...) {
...
go pconn.readLoop()
go pconn.writeLoop()
return pconn, nil
}

也就是说,虽然我们没有主动用 go 启动新的 goroutine,但是在 http 库里,建立一个新的连接时会自动创建两个 goroutine ,一个用于读,一个用于写。

而 writeLoop 在做什么呢?以下是一个简化的版本:

func (pc *persistConn) writeLoop() {
defer close(pc.writeLoopDone)
for {
select {
case wr := <-pc.writech:
err := wr.req.Request.write(...)
... // 一些错误处理
if err != nil {
pc.close(err)
return
}
case <-pc.closech:
return
}
}
}

也就是说,要么遇到错误,要么 "closech" 这个 channel 返回,writeLoop 才会结束 —— "closech" 正是需要我们主动调用 Response.Body.Close() 后才会被 close 掉;而当 channel 被关闭后,读取该 channel 的地方会立即返回。

于是前面踩坑的代码被改成这样:

client := &http.Client{}
resp, err = client.Do(req)
if err != nil {
...
}
defer resp.Body.Close()

填坑完毕。

- 5 -

总结起来,整个过程中实际上踩了好几个坑:

  • 没有主动关闭 http.Response.Body ,导致 goroutine 泄漏;

  • 没有 RTFM,导致踩坑;

  • 忘了 STFW,导致问题的解决耗时较长;

  • 监控指标没有及时调整,导致没有及时报警。

推荐阅读

福利

我为大家整理了一份从入门到进阶的Go学习资料礼包(下图只是部分),同时还包含学习建议:入门看什么,进阶看什么。

eeMVJrQ.png!mobile

关注公众号 「polarisxu」,回复  ebook  获取;还可以回复「 进群 」,和数万 Gopher 交流学习。

NzmEvyb.jpg!mobile


About Joyk


Aggregate valuable and interesting links.
Joyk means Joy of geeK