背景
最近线上有个服务内存异常增长, 默认服务启动实存应该是25M左右, 但是这个服务运行了一段时间实存达到了32G的量级, 并且还在缓慢增长, QA重启之后内存就恢复到了初始水准, 需要我们定位一下内存异常的问题进行解决
过程
整吧那就, pprof整起来, 在main 函数增加三行代码
import _ "net/http/pprof" func main() { go func() { _ = http.ListenAndServe("0.0.0.0:6060", nil) }() }
点进源码就看见它会注册5个接口, 用来查看维度数据
代码部署上去之后用top命令可以看到服务占用实存确实是在缓慢增加, 想单看这个服务的top可以用 top -p pid 指定进程id查看
里面 VIRT 是虚存, 即程序申请的内存; RES就是实存了, 即当前程序已经占用的内存
等服务跑一会就可以进网址http://127.0.0.1:6060/debug/pprof上查看服务占用情况了
也可以在命令行里面进行交互, 因为要查内存问题, 所以就直接看堆占用
go tool pprof http://127.0.0.1:6060/debug/pprof/heap
用top命令可以查看占用前十的函数
(pprof) top Showing nodes accounting for 4109.08kB, 100% of 4109.08kB total Showing top 10 nodes out of 91 flat flat% sum% cum cum% 1028kB 25.02% 25.02% 1028kB 25.02% bufio.NewReaderSize (inline) 518.02kB 12.61% 37.62% 518.02kB 12.61% go.uber.org/zap/buffer.(*Buffer).AppendByte 514.38kB 12.52% 50.14% 514.38kB 12.52% encoding/json.typeFields 512.44kB 12.47% 62.61% 512.44kB 12.47% encoding/pem.Decode 512.19kB 12.46% 75.08% 512.19kB 12.46% runtime.malg 512.05kB 12.46% 87.54% 512.05kB 12.46% regexp.newOnePassMachine 512.01kB 12.46% 100% 512.01kB 12.46% github.com/jinzhu/gorm.(*Scope).getModelStruct 0 0% 100% 1028kB 25.02% bufio.NewReader 0 0% 100% 512.44kB 12.47% crypto/tls.(*Conn).Handshake 0 0% 100% 512.44kB 12.47% crypto/tls.(*Conn).clientHandshake
可以看到还都比较正常, 没有异常占用的函数; 这样的话就再看一眼网页版的堆占用情况
http://127.0.0.1:6060/debug/pprof/heap?debug=1
可以看到有很多关于 GetTransactionLevelList 这个方法的占用, 在项目里找到这个方法就很容易就定位到了一行异常代码
context.Set(_r, "key", val)
查看一下源代码
发现这是 gorilla 里面对当前请求存储特定键值的一个包, 关键是代码调用只有插入(Set)没有删除(Clear), 导致底层 data 和datat 一直在储存所有请求的数据及时间戳;
这就是这个服务内存异常的原因, 坑的是发现竟然连Get方法都没有调用, 相当于只存不用…emmm由于这块代码是已经离职的同事写的, 检查没用就直接干掉了, 顺便把所有的服务都自查了一下, 相对应的方法都清理了一遍;
改完代码重新部署服务, 果然内存稳定在了初始水准, 问题解决;
结束
这次问题解决是比较顺利的, pprof还有很多好用的可视化界面(需要安装 graphviz) 以及火焰图(需要安装原生pprof工具)供调用分析, 有兴趣的可以看下面两篇博客去实验玩一玩
