

记一次内存泄漏的解决
source link: https://my.oschina.net/u/3872630/blog/4815222
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.

内存泄漏
内存泄漏(Memory Leak)是指程序中已动态分配的堆内存由于某种原因程序未释放或无法释放,造成系统内存的浪费,导致程序运行速度减慢甚至内存溢出,系统崩溃等严重后果。在Go语言服务中,内存泄漏的大多数原因是goroutine泄露。
问题发现
在巡检过程中忽然发现某个服务模块服务的内存疯涨,刚刚部署时候很小,过了两个月左右达到了惊人的200倍左右,继续增长下去的结果就是内存溢出导致该服务的pod重启(该服务使用k8s的deploy部署)。需要排查一下泄露问题出在哪里,于是在本地自己模拟了一套逻辑相似的环境(自测用的,模拟了一个简单场景)。
pprof工具
pprof 是一个强大的性能分析工具,可以捕捉到多维度的运行状态的数据,便于排查程序的堆栈信息,goroutine分布等。
排查过程
1、程序中添加pprof工具
首先在程序添加监听端口,如下:

然后导入pprof包:

2、启动程序
访问本地端口6060(主要关注goroutine数量)

3、使用goTest发起请求
这里模拟了20个并发量,一次请求。

4、使用pprof查看样本数据
可以看到在请求结束之后,goroutine数量依然存在,并没有被回收。

猜测原因:大量goroutine滞留导致栈空间没有被释放(影响较小),goroutine没有被释放,goroutine指向的heap一系列对象没有被回收掉,heap越用越多,持续申请内存造成内存持续异常增长,也就是内存泄漏。
点击goroutine查看详细信息:

可以看到有四种类型的goroutine栈居高不下,grpc的出现率很高,猜测是在发起请求时创建的grpc连接没有释放掉。
gRpc的源码不必追溯,也没有完整的调用栈信息,作为一个rpc库,已经封装了关闭请求流的方法。应该关注引用的它库的位置,看看是否在应用层有暴露出来的关闭流的方法。
选择从该处向上追溯,首先定位到该处的源码:

每次的请求在该处都会阻塞住,是否需要在该处上游有一个释放信号,将该context构造的goroutine树释放掉。
一路向上追溯源码(不详述),看到一个在应用层结构体实现了close方法,点到close方法,可以看到该方法可以释放连接与缓存。于是在应用层找到合适的位置调用了close方法。
再次发起模拟请求,查看pprof工具:

可以看到协程数量恢复如初,业务正常没受影响,初步猜测是该处的原因。接下来各种业务验证不详述...
5、并发测试进程memory
继续单元测试。
创建20个协程,每个协程100个请求,中间休眠一秒(为了防止速度太快脚本无法记录)。

监控脚本一览:
#!/bin/bash
read -p "输入进程的id:" processId
while [ 1 ]
do
#每隔五秒读一次进程内存,看结束之后内存情况
ProcessMem=`cat /proc/$processId/status |grep VmRSS|awk '{print $2,$3}'`
DateTime=` date "+%H:%M:%S"`
echo $DateTime "| 进程内存:"$ProcessMem >> noclose-process-mem.txt
sleep 5s
done
6、测试结果
不关闭流:

内存情况(脚本统计):16M -> 822M,相当大
贴出来一部分脚本统计数据:
09:33:11 | 进程内存:16580 kB
09:33:16 | 进程内存:16580 kB
09:33:21 | 进程内存:16580 kB
09:33:26 | 进程内存:16580 kB
09:33:31 | 进程内存:16580 kB #发起请求,内存开始暴涨
09:33:36 | 进程内存:44324 kB
09:33:41 | 进程内存:74400 kB
09:33:46 | 进程内存:98708 kB
09:33:51 | 进程内存:122612 kB
09:33:56 | 进程内存:147912 kB
.....
10:05:57 | 进程内存:822224 kB #请求结束慢慢恢复稳定
10:06:12 | 进程内存:822488 kB
10:06:17 | 进程内存:822488 kB
......
10:06:47 | 进程内存:822488 kB
10:06:52 | 进程内存:822488 kB
10:06:57 | 进程内存:822488 kB#之后内存并没有缩小
查看一下goroutine:

关闭流:

内存统计:16M -> 44M(优化了80%左右,请求时间也缩短)
每次请求关闭流:
09:25:44 | 进程内存:16496 kB#初始内存----往下表示发起请求,内存开始增长
09:25:49 | 进程内存:35948 kB
09:25:54 | 进程内存:41320 kB
09:25:59 | 进程内存:41776 kB
......
09:29:24 | 进程内存:43976 kB#逐渐趋于稳定
09:29:29 | 进程内存:43976 kB
09:29:34 | 进程内存:43976 kB
09:29:39 | 进程内存:44180 kB#已经稳定在44M
09:29:44 | 进程内存:44180 kB
7、再次定位
定位到问题,虽然上述方法可以解决内存泄露的问题,但是并没有选择这种方式,因为和最初的设计模式相悖,最初针对这块设计模式是单例模式。
之后又是抓耳挠腮的读代码,调试,终于发现问题所在.......
查看一波自己写的该部分代码:
/*源代码不能泄露,这是本地自己编写的代码,大概逻辑类似*/
func GetClient(userName string) *Client{
//先在缓存读,读不到就new,存map
key := userName
//从map中获取,该map是sync.map,并发安全
value, ok := Map.Load(key)
if ok{
fmt.Println("读syncmap")
return value.(*Client)
}
client := newClient(userName)
Map.Store(key,client)
return client
}
发现客户端作为单例对象,不是线程安全的,没有并发控制机制,当初始遇到并发请求时候,就会创建大量的客户端,请求结束无法释放,导致程序中大量无感的客户端占用内存。
最终解决方法:既然不是线程安全,加个锁。
/*本地模拟的代码*/
func GetClient(userName string) *Client{
//加锁保证线程安全
lock.Lock()
defer lock.UnLock()
key := userName
value, ok := Map.Load(key)
if ok{
fmt.Println("读syncmap")
return value.(*Client)
}
client := newClient(userName)
Map.Store(key,client)
return client
}
果断修改调试.....
等待一天后......
goroutine数虽然有所减少还是让人抓狂,陷入自我怀疑
猜测问题是不是出在map里面,开始一波针对性的检查。
终于又发现问题:
首先,map在清理的时候没有释放掉里面的连接(在第一种方案时候就定位到了)。
map清理的定期时间是可配的,读取配置文件出错没有异常处理,使用了默认值(默认值很小)。
完成问题定位,最终修改完成,调试,内存虽然有增长,但是要优化了很多。
问题解决
这次问题的解决并不是一帆风顺,这个泄露问题是好多点综合作用的结果,期间还有很多繁琐的点,要复现某个泄露的点真的很让人头大,pprof显示的所有泄露的点调用栈都在引用的库源码里,和网上的定位文章一点不一样,算是在摸索着前进。最终主要的优化方式就是上述两种方式。选择了后者,最初设计是不能乱改的嘛,不过正因为这次问题出现,对Golang有了更深层的了解。
也得到一点经验教训:
一定要在测试机上仔细检查,业务验证同时要关注服务的内存与CPU。
goroutine泄露的点主要发生在channel的阻塞上。
对于Golang错误处理留个心眼,万一在没有察觉的地方出错了呢?
后台回复“加群”,带你进入高手如云交流群
推荐阅读:
10大高性能开发利器
喜欢,就给我一个“在看”

10T 技术资源大放送!包括但不限于:云计算、虚拟化、微服务、大数据、网络、Linux、Docker、Kubernetes、Python、Go、C/C++、Shell、PPT 等。在公众号内回复「1024」,即可免费获取!!
本文分享自微信公众号 - Linux云计算网络(cloud_dev)。
如有侵权,请联系 [email protected] 删除。
本文参与“OSC源创计划”,欢迎正在阅读的你也加入,一起分享。
Recommend
-
51
问题 背景 通过线上收集的日志分析,存在部分OOM的日志,故通过leakcanary进行内存泄漏追踪。 引用链日志 在开发的过程中,leakcanary报出了内存泄漏,详细的日志如下: 并且全局有其他Activity也存在相同引用链的内存泄漏,日志如下: 使用MAT进行分析,引用链也...
-
85
本文作者 作者:黄俊彬 链接: https://www.jianshu.com/p/c8e691a69086
-
65
由来 前些日子小组内安排值班,轮流看顾我们的服务,主要做一些报警邮件处理、Bug 排查、运营 issue 处理的事。工作日还好,无论干什么都要上班的,若是轮到周末,那这一天算是毁了。 不知道是公司网络广了就这样还是...
-
39
文章封面:成都宽窄巷子 importnew.com/29591.html 在一个凄凉的午夜 一定是网络的...
-
25
Java小能手21小时前故障案发缘起 网关上线一周以来,运行一直稳定,从未出现CPU飙高的情况。发生故障的当天,CPU开始缓慢上升,但是上升的过程并不是...
-
10
记一次 Go 服务内存泄漏问题调查 xinchen · 大约11小时之前 · 48 次点击 · 预计阅读时间 2 分钟 · 不到1分钟之前 开始浏览 ...
-
19
什么是内存泄漏: 程序向系统申请内存,使用完不需要之后 , 不释放内存还给系统回收,造成申请的内存被浪费 . 发现系统中内存使用量随着时间的流逝,消耗的越来越多,例如下图所示:
-
13
1. 讲故事 前天那位 his 老哥又来找我了,上次因为
-
6
1. 讲故事 上周四有位朋友加wx咨询他的程序内存存在一定程度的泄漏,并且无法被GC回收,最终机器内存耗尽,很尴尬。 沟通下来,这位朋友能力还是很不错的,也已经做了初步的dump分析,发现了托管堆上有 10w+ 的 byte[] 数组,并占...
-
11
1. 讲故事 七月底的时候有位朋友在wx上找到我,说他的程序内存占用8G,托管才占用1.5G,询问剩下的内存哪里去了?截图如下: 从求助内容看,这位朋友真的太客气了,动不动就谈钱,真伤感情,如果有朋友一直关注我的分享,应该知道我一直都是免...
About Joyk
Aggregate valuable and interesting links.
Joyk means Joy of geeK