记一次golang代码内存泄露分析

1.背景

工作中，无意中发现vm系统日志里近期出现过OOM，且系统主动kill了某一进程（称为进程A）。 重新部署A的二进制文件，执行top命令观察到进程A疯狂吃内存，内存占比肉眼可见的飙升。 查看代码逻辑，大致为：for循环启动多个goroutine，每个goroutine各自从prometheus或者es库里查询指定index的内容，然后push到远程tsdb中，每间隔一段时间进入下一次循环。

2.现象查询

1. 引入pprof工具分析内存泄露原因

_ import "net/http/pprof"

//在main函数里添加监听内容，端口视占用情况改动
go http.ListenAndServe(":8099", nil)
           

1. 本地重新执行代码，访问http://127.0.0.1:8099/debug/pprof， 代码执行不到半分钟，50w+的groutine数量，而且一直在增加。

   

2. 准备点击进去查看具体groutine内容时，mac已经卡到“不能自已”，只能关闭进程，不过为查询内存泄露指明了大致方向。

3.问题分析

内存无法收回的原因基本确认为：groutine没有及时退出，groutine数量堆积过多。

第一反应是：查询es或者push到远程tsdb过程中出现io wait，程序hang住在某一个接口调用过程中。 注释其他代码，只留一个goroutine, 查看groutine内部每一个接口调用的超时时间，均正常，并不是因为接口调用导致groutine无法退出。于是，查看全局变量中用于sleep的时间值大于查询es时间间隔，理论上进入下一个循环的时候，当前的groutine应该全部自动退出才对。

从pprof中看出，groutine数量一直在疯狂增加， 既然接口调用没有卡住，程序可以正常退出，原因可能是for循环出了问题，便在for循环内部打印日志，查看goroutine内是否按照设定的时间间隔启动groutine和打印日志。

结果发现循环的速度远远超出预期，查看sleep内参数，发现少了单位，使用了默认值。

修改后代码为：

重新验证，goroutine数量符合预期，内存占用也比较小且长时间没有明显增加。

4.查看源码

sleep函数参数为time.Duration类型， Durarion的源码注释里明确默认单位是纳秒。所以设置interval为300时，实际上为300ns，和300s之间差距10的9次方，导致goroutine数量疯狂增加，内存被大量占用且持续增加。

总结

错误比较低级，实现的时候想当然以毫秒为单位。逻辑能力有待提高，需要更客观冷静的去对待每一个函数的实现和内置方法的使用。