go (*persistConn).writeLoop 导致goroutine泄漏

十一长假，由于服务好几天没有发布上线，监控显示goroutine的数量一直在持续增长，初步判断是goroutine泄漏。
使用 go pprof 排查后发现泄漏的 goroutine 信息

1201 @ 0x438dfa 0x43411a 0x433797 0x4f76ab 0x4f772d 0x4f858d 0x58922f 0x59bb4a 0x6a3006 0x53d36e 0x53d4ba 0x6a3ac5 0x4666e1
#   0x433796    internal/poll.runtime_pollWait+0x56 /home/go/src/runtime/netpoll.go:173
#   0x4f76aa    internal/poll.(*pollDesc).wait+0x9a /home/go/src/internal/poll/fd_poll_runtime.go:85
#   0x4f772c    internal/poll.(*pollDesc).waitRead+0x3c /home/go/src/internal/poll/fd_poll_runtime.go:90
#   0x4f858c    internal/poll.(*FD).Read+0x17c      /home/go/src/internal/poll/fd_unix.go:157
#   0x58922e    net.(*netFD).Read+0x4e          /home/go/src/net/fd_unix.go:202
#   0x59bb49    net.(*conn).Read+0x69           /home/go/src/net/net.go:176
#   0x6a3005    net/http.(*persistConn).Read+0x135  /home/go/src/net/http/transport.go:1453
#   0x53d36d    bufio.(*Reader).fill+0x11d      /home/go/src/bufio/bufio.go:100
#   0x53d4b9    bufio.(*Reader).Peek+0x39       /home/go/src/bufio/bufio.go:132
#   0x6a3ac4    net/http.(*persistConn).readLoop+0x184  /home/go/src/net/http/transport.go:1601

1201 @ 0x438dfa 0x448b10 0x6a508b 0x4666e1
#   0x6a508a    net/http.(*persistConn).writeLoop+0x14a /home/go/src/net/http/transport.go:1822

发现有大量的 net/http.(*persistConn).writeLoop
百度谷歌一下，发现了可能造成泄漏的原因：没有主动关闭http.Response.Body，官方文档也写的很清楚

// The client must close the response body when finished with it:

resp, err := http.Get("http://example.com/")
if err != nil {
    // handle error
}
defer resp.Body.Close()
body, err := ioutil.ReadAll(resp.Body)
// ...

但对代码排查一番过后，发现所有网络请求的地方，都调用了 defer resp.Body.Close()。
原文地址

继续排查，使用 netstat -antl 查看连接占用情况，发现请求某个ip，有大量的 ESTABLISHED，找出其中一个

tcp        0      0 10.10.1.2:18555           10.10.10.11:80          ESTABLISHED

查看对应端口18555的使用情况
lsof -i:18555

COMMAND     PID    USER   FD   TYPE     DEVICE      SIZE/OFF NODE   NAME
xxxxx      16218   user  3119u IPv4     42480944        0t0  TCP 10.10.1.2:18555->10.10.10.11:http (ESTABLISHED)

根据 FD=3119，找到对应的文件
ls -l /proc/16218/fd/3119

lrwx------ 1 user user 64 10月 10 13:02 /proc/16218/fd/3119 -> socket:[42480944]

看了下当前时间，已经下午5点多了，连接存在了 4个多小时，那就说明，连接一直都没有断掉。
再排查每个http调用的地方，发现有个调用每次请求都是短链接，但是使用了连接池(Transport)的配置，而且没有指定连接空闲断开时间(Transport.IdleConnTimeout)，也没有禁用长连接(设置 Transport.DisableKeepAlives = true)，导致连接变成了长连接，对方服务端不主动断开的话，连接会一直存在。

client := &http.Client{
    Transport: &http.Transport{
        DialContext: (&net.Dialer{
            Timeout: 5 * time.Second,
        }).DialContext,
    },
    Timeout: 5 * time.Second,
}

最后，将配置修改，大功告成

client := &http.Client{
    Transport: &http.Transport{
        DialContext: (&net.Dialer{
            Timeout: 5 * time.Second,
        }).DialContext,
        DisableKeepAlives: true,
    },
    Timeout: 5 * time.Second,
}

参照：
https://sanyuesha.com/2019/09/10/go-http-request-goroutine-leak/
https://github.com/docker/distribution/issues/473

最后编辑于：2020.10.29 00:40:54