内存分析

golang pprof
当你的golang程序在运行过程中消耗了超出你理解的内存时,你就需要搞明白,到底是 程序中哪些代码导致了这些内存消耗。此时golang编译好的程序对你来说是个黑盒,该 如何搞清其中的内存使用呢?幸好golang已经内置了一些机制来帮助我们进行分析和追 踪。



此时,通常我们可以采用golang的pprof来帮助我们分析golang进程的内存使用。

pprof 实例
通常我们采用http api来将pprof信息暴露出来以供分析,我们可以采用net/http/pprof 这个package。下面是一个简单的示例:



// pprof 的init函数会将pprof里的一些handler注册到http.DefaultServeMux上
// 当不使用http.DefaultServeMux来提供http api时,可以查阅其init函数,自己注册handler
import _ “net/http/pprof”



go func() {
http.ListenAndServe(“0.0.0.0:8080”, nil)
}()
此时我们可以启动进程,然后访问http://localhost:8080/debug/pprof/可以看到一个简单的 页面,页面上显示: 注意: 以下的全部数据,包括go tool pprof 采集到的数据都依赖进程中的pprof采样率,默认512kb进行 一次采样,当我们认为数据不够细致时,可以调节采样率runtime.MemProfileRate,但是采样率越低,进 程运行速度越慢。



/debug/pprof/



profiles:
0 block
136840 goroutine
902 heap
0 mutex
40 threadcreate



full goroutine stack dump
上面简单暴露出了几个内置的Profile统计项。例如有136840个goroutine在运行,点击相关链接 可以看到详细信息。



当我们分析内存相关的问题时,可以点击heap项,进入http://127.0.0.1:8080/debug/pprof/heap?debug=1 可以查看具体的显示:



heap profile: 3190: 77516056 [54762: 612664248] @ heap/1048576
1: 29081600 [1: 29081600] @ 0x89368e 0x894cd9 0x8a5a9d 0x8a9b7c 0x8af578 0x8b4441 0x8b4c6d 0x8b8504 0x8b2bc3 0x45b1c1


0x89368d github.com/syndtr/goleveldb/leveldb/memdb.(*DB).Put+0x59d


0x894cd8 xxxxx/storage/internal/memtable.(*MemTable).Set+0x88


0x8a5a9c xxxxx/storage.(*snapshotter).AppendCommitLog+0x1cc


0x8a9b7b xxxxx/storage.(*store).Update+0x26b


0x8af577 xxxxx/config.(*config).Update+0xa7


0x8b4440 xxxxx/naming.(*naming).update+0x120


0x8b4c6c xxxxx/naming.(*naming).instanceTimeout+0x27c


0x8b8503 xxxxx/naming.(*naming).(xxxxx/naming.instanceTimeout)-fm+0x63



……



runtime.MemStats


Alloc = 2463648064


TotalAlloc = 31707239480


Sys = 4831318840


Lookups = 2690464


Mallocs = 274619648


Frees = 262711312


HeapAlloc = 2463648064


HeapSys = 3877830656


HeapIdle = 854990848


HeapInuse = 3022839808


HeapReleased = 0


HeapObjects = 11908336


Stack = 655949824 / 655949824


MSpan = 63329432 / 72040448


MCache = 38400 / 49152


BuckHashSys = 1706593


GCSys = 170819584


OtherSys = 52922583


NextGC = 3570699312


PauseNs = [1052815 217503 208124 233034 1146462 456882 1098525 530706 551702 419372 768322 596273 387826 455807 563621 587849 416204 599143 572823 488681 701731 656358 2476770 12141392 5827253 3508261 1715582 1295487 908563 788435 718700 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]


NumGC = 31


DebugGC = false


其中显示的内容会比较多,但是主体分为2个部分: 第一个部分打印为通过runtime.MemProfile()获取的runtime.MemProfileRecord记录。 其含义为:



heap profile: 3190(inused objects): 77516056(inused bytes) [54762(alloc objects): 612664248(alloc bytes)] @ heap/1048576(2*MemProfileRate)
1: 29081600 [1: 29081600] (前面4个数跟第一行的一样,此行以后是每次记录的,后面的地址是记录中的栈指针)@ 0x89368e 0x894cd9 0x8a5a9d 0x8a9b7c 0x8af578 0x8b4441 0x8b4c6d 0x8b8504 0x8b2bc3 0x45b1c1


0x89368d github.com/syndtr/goleveldb/leveldb/memdb.(*DB).Put+0x59d 栈信息


第二部分就比较好理解,打印的是通过runtime.ReadMemStats()读取的runtime.MemStats信息。 我们可以重点关注一下



Sys 进程从系统获得的内存空间,虚拟地址空间。
HeapAlloc 进程堆内存分配使用的空间,通常是用户new出来的堆对象,包含未被gc掉的。
HeapSys 进程从系统获得的堆内存,因为golang底层使用TCmalloc机制,会缓存一部分堆内存,虚拟地址空间。
PauseNs 记录每次gc暂停的时间(纳秒),最多记录256个最新记录。
NumGC 记录gc发生的次数。
相信,对pprof不了解的用户看了以上内容,很难获得更多的有用信息。因此我们需要引用更多工具来帮助 我们更加简单的解读pprof内容。



go tool
我们可以采用go tool pprof -inuse_space http://127.0.0.1:8080/debug/pprof/heap命令连接到进程中 查看正在使用的一些内存相关信息,此时我们得到一个可以交互的命令行。



我们可以看数据top10来查看正在使用的对象较多的10个函数入口。通常用来检测有没有不符合预期的内存 对象引用。



(pprof) top10
1355.47MB of 1436.26MB total (94.38%)
Dropped 371 nodes (cum <= 7.18MB)
Showing top 10 nodes out of 61 (cum >= 23.50MB)
flat flat% sum% cum cum%
512.96MB 35.71% 35.71% 512.96MB 35.71% net/http.newBufioWriterSize
503.93MB 35.09% 70.80% 503.93MB 35.09% net/http.newBufioReader
113.04MB 7.87% 78.67% 113.04MB 7.87% runtime.rawstringtmp
55.02MB 3.83% 82.50% 55.02MB 3.83% runtime.malg
45.01MB 3.13% 85.64% 45.01MB 3.13% xxxxx/storage.(Node).clone
26.50MB 1.85% 87.48% 52.50MB 3.66% context.WithCancel
25.50MB 1.78% 89.26% 83.58MB 5.82% runtime.systemstack
25.01MB 1.74% 91.00% 58.51MB 4.07% net/http.readRequest
25MB 1.74% 92.74% 29.03MB 2.02% runtime.mapassign
23.50MB 1.64% 94.38% 23.50MB 1.64% net/http.(
Server).newConn
然后我们在用go tool pprof -alloc_space http://127.0.0.1:8080/debug/pprof/heap命令链接程序来查看 内存对象分配的相关情况。然后输入top来查看累积分配内存较多的一些函数调用:



(pprof) top
523.38GB of 650.90GB total (80.41%)
Dropped 342 nodes (cum <= 3.25GB)
Showing top 10 nodes out of 106 (cum >= 28.02GB)
flat flat% sum% cum cum%
147.59GB 22.68% 22.68% 147.59GB 22.68% runtime.rawstringtmp
129.23GB 19.85% 42.53% 129.24GB 19.86% runtime.mapassign
48.23GB 7.41% 49.94% 48.23GB 7.41% bytes.makeSlice
46.25GB 7.11% 57.05% 71.06GB 10.92% encoding/json.Unmarshal
31.41GB 4.83% 61.87% 113.86GB 17.49% net/http.readRequest
30.55GB 4.69% 66.57% 171.20GB 26.30% net/http.(*conn).readRequest
22.95GB 3.53% 70.09% 22.95GB 3.53% net/url.parse
22.70GB 3.49% 73.58% 22.70GB 3.49% runtime.stringtoslicebyte
22.70GB 3.49% 77.07% 22.70GB 3.49% runtime.makemap
21.75GB 3.34% 80.41% 28.02GB 4.31% context.WithCancel
可以看出string-[]byte相互转换、分配map、bytes.makeSlice、encoding/json.Unmarshal等调用累积分配的内存较多。 此时我们就可以review代码,如何减少这些相关的调用,或者优化相关代码逻辑。



当我们不明确这些调用时是被哪些函数引起的时,我们可以输入top -cum来查找,-cum的意思就是,将函数调用关系 中的数据进行累积,比如A函数调用的B函数,则B函数中的内存分配量也会累积到A上面,这样就可以很容易的找出调用链。



(pprof) top20 -cum
322890.40MB of 666518.53MB total (48.44%)
Dropped 342 nodes (cum <= 3332.59MB)
Showing top 20 nodes out of 106 (cum >= 122316.23MB)
flat flat% sum% cum cum%
0 0% 0% 643525.16MB 96.55% runtime.goexit
2184.63MB 0.33% 0.33% 620745.26MB 93.13% net/http.(conn).serve
0 0% 0.33% 435300.50MB 65.31% xxxxx/api/server.(
HTTPServer).ServeHTTP
5865.22MB 0.88% 1.21% 435300.50MB 65.31% xxxxx/api/server/router.(httpRouter).ServeHTTP
0 0% 1.21% 433121.39MB 64.98% net/http.serverHandler.ServeHTTP
0 0% 1.21% 430456.29MB 64.58% xxxxx/api/server/filter.(
chain).Next
43.50MB 0.0065% 1.21% 429469.71MB 64.43% xxxxx/api/server/filter.TransURLTov1
0 0% 1.21% 346440.39MB 51.98% xxxxx/api/server/filter.Role30x
31283.56MB 4.69% 5.91% 175309.48MB 26.30% net/http.(conn).readRequest
0 0% 5.91% 153589.85MB 23.04% github.com/julienschmidt/httprouter.(
Router).ServeHTTP
0 0% 5.91% 153589.85MB 23.04% github.com/julienschmidt/httprouter.(Router).ServeHTTP-fm
0 0% 5.91% 153540.85MB 23.04% xxxxx/api/server/router.(
httpRouter).Register.func1
2MB 0.0003% 5.91% 153117.78MB 22.97% xxxxx/api/server/filter.Validate
151134.52MB 22.68% 28.58% 151135.02MB 22.68% runtime.rawstringtmp
0 0% 28.58% 150714.90MB 22.61% xxxxx/api/server/router/naming/v1.(serviceRouter).(git.intra.weibo.com/platform/vintage/api/server/router/naming/v1.service)-fm
0 0% 28.58% 150714.90MB 22.61% xxxxx/api/server/router/naming/v1.(
serviceRouter).service
0 0% 28.58% 141200.76MB 21.18% net/http.Redirect
132334.96MB 19.85% 48.44% 132342.95MB 19.86% runtime.mapassign
42MB 0.0063% 48.44% 125834.16MB 18.88% xxxxx/api/server/router/naming/v1.heartbeat
0 0% 48.44% 122316.23MB 18.35% xxxxxx/config.(*config).Lookup
如上所示,我们就很容易的查找到这些函数是被哪些函数调用的。



根据代码的调用关系,filter.TransURLTov1会调用filter.Role30x,但是他们之间的cum%差值有12.45%,因此 我们可以得知filter.TransURLTov1内部自己直接分配的内存量达到了整个进程分配内存总量的12.45%,这可是一个 值得大大优化的地方。



然后我们可以输入命令web,其会给我们的浏览器弹出一个.svg图片,其会把这些累积关系画成一个拓扑图,提供给 我们。或者直接执行go tool pprof -alloc_space -cum -svg http://127.0.0.1:8080/debug/pprof/heap > heap.svg来生 成heap.svg图片。



下面我们取一个图片中的一个片段进行分析:



golang-memory-pprof.png



每一个方块为pprof记录的一个函数调用栈,指向方块的箭头上的数字是记录的该栈累积分配的内存向,从方块指出的 箭头上的数字为该函数调用的其他函数累积分配的内存。他们之间的差值可以简单理解为本函数除调用其他函数外,自 身分配的。方块内部的数字也体现了这一点,其数字为:(自身分配的内存 of 该函数累积分配的内存)。



–inuse/alloc_space –inuse/alloc_objects区别
通常情况下:



用–inuse_space来分析程序常驻内存的占用情况;
用–alloc_objects来分析内存的临时分配情况,可以提高程序的运行速度。
go-torch
除了直接使用go tool pprof外,我们还可以使用更加直观了火焰图 。因此我们可以直接使用go-torch来生成golang程序的火焰图,该工具也直接 依赖pprof/go tool pprof等。该工具的相关安装请看该项目的介绍。该软件的 a4daa2b 以后版本才支持内存的profiling。



我们可以使用



go-torch -alloc_space http://127.0.0.1:8080/debug/pprof/heap –colors=mem
go-torch -inuse_space http://127.0.0.1:8080/debug/pprof/heap –colors=mem
注意:-alloc_space/-inuse_space参数与-u/-b等参数有冲突,使用了-alloc_space/-inuse_space后请将pprof的 资源直接追加在参数后面,而不要使用-u/-b参数去指定,这与go-torch的参数解析问题有关,看过其源码后既能明白。 同时还要注意,分析内存的URL一定是heap结尾的,因为默认路径是profile的,其用来分析cpu相关问题。



通过上面2个命令,我们就可以得到alloc_space/inuse_space含义的2个火焰图,例如 alloc_space.svg/inuse_space.svg。 我们可以使用浏览器观察这2张图,这张图,就像一个山脉的截面图,从下而上是每个函数的调用栈,因此山的高度跟函数 调用的深度正相关,而山的宽度跟使用/分配内存的数量成正比。我们只需要留意那些宽而平的山顶,这些部分通常是我们 需要优化的地方。



testing
当我们需要对go test中某些test/benchmark进行profiling时,我们可以使用类似的方法。例如我们可以先使用go test 内置的参数生成pprof数据,然后借助go tool pprof/go-torch来分析。



生成cpu、mem的pprof文件
go test -bench=BenchmarkStorageXXX -cpuprofile cpu.out -memprofile mem.out
此时会生成一个二进制文件和2个pprof数据文件,例如
storage.test cpu.out mem.out
然后使用go-torch来分析,二进制文件放前面
#分析cpu
go-torch storage.test cpu.out
#分析内存
go-torch –colors=mem -alloc_space storage.test mem.out
go-torch –colors=mem -inuse_space storage.test mem.out
优化建议
Debugging performance issues in Go programs 提供了一些常用的优化建议:



1 将多个小对象合并成一个大的对象
2 减少不必要的指针间接引用,多使用copy引用
例如使用bytes.Buffer代替*bytes.Buffer,因为使用指针时,会分配2个对象来完成引用。



3 局部变量逃逸时,将其聚合起来
这一点理论跟1相同,核心在于减少object的分配,减少gc的压力。 例如,以下代码



for k, v := range m {
k, v := k, v // copy for capturing by the goroutine
go func() {
// use k and v
}()
}
可以修改为:



for k, v := range m {
x := struct{ k, v string }{k, v} // copy for capturing by the goroutine
go func() {
// use x.k and x.v
}()
}
修改后,逃逸的对象变为了x,将k,v2个对象减少为1个对象。



4 []byte的预分配
当我们比较清楚的知道[]byte会到底使用多少字节,我们就可以采用一个数组来预分配这段内存。 例如:



type X struct {
buf []byte
bufArray [16]byte // Buf usually does not grow beyond 16 bytes.
}



func MakeX() *X {
x := &X{}
// Preinitialize buf with the backing array.
x.buf = x.bufArray[:0]
return x
}
5 尽可能使用字节数少的类型
当我们的一些const或者计数字段不需要太大的字节数时,我们通常可以将其声明为int8类型。



6 减少不必要的指针引用
当一个对象不包含任何指针(注意:strings,slices,maps 和chans包含隐含的指针),时,对gc的扫描影响很小。 比如,1GB byte 的slice事实上只包含有限的几个object,不会影响垃圾收集时间。 因此,我们可以尽可能的减少指针的引用。



7 使用sync.Pool来缓存常用的对象



Go 常见内存泄漏的情况
Go程序可能会在一些情况下造成内存泄漏。go101网站总结了各种内存泄漏的情况,我在这里简单罗列一下:



获取长字符串中的一段导致长字符串未释放
同样,获取长slice中的一段导致长slice未释放
在长slice新建slice导致泄漏
goroutine泄漏
time.Ticker未关闭导致泄漏
Finalizer导致泄漏
Deferring Function Call导致泄漏
内存回收分析
实际问题
写这篇文章的初衷是我在实现一个新项目的时候遇到一个问题。这个项目使用了一个缓存组件对请求的结果进行缓存,以提高请求的耗时。这个缓存组件对使用的最大内存进行了限制,比如缓存占用的最大内存为1GB。运行过程中可以对这个最大值进行调整,比如我们可以调整到100MB。在调整的过程中发现虽然最大内存从1GB调整到100MB之后,程序的RSS依然占用很大,一直是1GB+ ~ 2GB的内存,感觉内存并没有降下去。



可以看到缓存调小了它占用的内存确实降到几乎为0了:



但是释放的内存并没有返回给操作系统(HeapReleased)



当然经过相应的测试和调研之后,可以看到缓存的最大内存减少后占用内存和RSS也下降了:



仓促之间我只截取了很小一段时间的指标,实际观察很长时间也是这样。



测试程序
我在这个项目中实现了一个 LRU的cache, 这个cache基于内存管理,一旦使用的内存超过了MaxMemory,就会自动进行内存清理工作,将最不常用的缓存项删除,具体实现太长就不贴出来了,基本上就是map + container/list + sync.Mutex的实现,实现的接口如下:
type Cache interface {
AddValue(slot uint32, key string, value []byte)
GetAndValidate(key string, bizKey []byte) (value *CachedValue, ok bool)
SetMaxMemory(m int64)
Clear()
}
现在通过一个程序进行测试,分别测试测试前、增加一千万条数据、将最大内存从1G减少到1B、强制垃圾回收四个动作之后的内存的使用情况,代码如下:
➜ memoryleak git:(master) ✗ GODEBUG=gctrace=1 go run leak.go
gc 1 @0.027s 0%: 0.009+0.43+0.009 ms clock, 0.037+0.13/0.31/0.82+0.038 ms cpu, 4->4->0 MB, 5 MB goal, 4 P
gc 2 @0.048s 0%: 0.005+0.40+0.003 ms clock, 0.022+0.17/0.29/0.91+0.014 ms cpu, 4->4->0 MB, 5 MB goal, 4 P
……
gc 4 @0.063s 6%: 0.003+7.8+0.028 ms clock, 0.012+0.12/6.1/15+0.11 ms cpu, 23->24->22 MB, 24 MB goal, 4 P
gc 5 @0.121s 5%: 0.003+12+0.035 ms clock, 0.013+1.3/11/27+0.14 ms cpu, 42->43->40 MB, 44 MB goal, 4 P
🍀 before: inuse: 656 KB, idle: 63 MB, released: 0 B, heapsys: 63 MB, sys: 66 MB
gc 1 @0.007s 3%: 0.031+0.94+0.013 ms clock, 0.12+0.10/0.84/0.18+0.052 ms cpu, 4->4->4 MB, 5 MB goal, 4 P
gc 2 @0.013s 7%: 0.004+4.3+0.045 ms clock, 0.017+0.078/3.9/0.85+0.18 ms cpu, 7->8->8 MB, 8 MB goal, 4 P
……
gc 17 @22.855s 6%: 0.018+517+0.011 ms clock, 0.072+105/516/11+0.047 ms cpu, 2441->2644->1368 MB, 2553 MB goal, 4 P
🍀 added: inuse: 1 GB, idle: 942 MB, released: 0 B, heapsys: 2 GB, sys: 2 GB, current: 1023 MB
gc 18 @24.763s 6%: 0.015+87+0.009 ms clock, 0.063+6.0/83/13+0.038 ms cpu, 2568->2622->128 MB, 2737 MB goal, 4 P
gc 19 @25.295s 6%: 0.014+35+0.009 ms clock, 0.056+0.41/35/64+0.037 ms cpu, 247->263->90 MB, 257 MB goal, 4 P
gc 20 @25.397s 6%: 0.015+89+0.004 ms clock, 0.061+14/50/0.60+0.019 ms cpu, 173->194->95 MB, 181 MB goal, 4 P
gc 21 @25.551s 6%: 0.012+59+0.010 ms clock, 0.050+17/59/0.46+0.043 ms cpu, 175->207->105 MB, 191 MB goal, 4 P
🍀 after decreased: inuse: 156 MB, idle: 2 GB, released: 0 B, heapsys: 2 GB, sys: 2 GB, current: 0 B
gc 22 @25.651s 6%: 0.003+67+0.003 ms clock, 0.015+0/52/14+0.012 ms cpu, 156->156->74 MB, 211 MB goal, 4 P (forced)
scvg-1: 2740 MB released
scvg-1: inuse: 75, idle: 2740, sys: 2815, released: 2740, consumed: 75 (MB)
🍀 after gc: inuse: 75 MB, idle: 2 GB, released: 2 GB, heapsys: 2 GB, sys: 2 GB, current: 0 B
首先,我们复习一下Go垃圾回收的日志的意义,再进一步看各个阶段内存的变化。



以这一条为例:



1
gc 21 @25.551s 6%: 0.012+59+0.010 ms clock, 0.050+17/59/0.46+0.043 ms cpu, 175->207->105 MB, 191 MB goal, 4 P
gc 21: 21是垃圾回收的编号,逐步递增,可能会从1重新开始
@25.551s: 自程序开始经历了多少时间,这里是25秒多
6%: 自程序启动花在GC上的CPU时间百分比, CPU 6%花在了GC上
0.012+59+0.010 ms clock: GC各阶段的墙上时间(wall-clock),各阶段包括STW sweep termination、concurrent mark and scan、STW mark termination
0.050+17/59/0.46+0.043 ms cpu: 各阶段的CPU时间。各阶段同上,其中mark/scan阶段又分成了assist time、background GC time和idle GC time阶段
175->207->105 MB: GC开始时、GC结束的heap大小、存活(live)的heap大小
191 MB goal:下一次垃圾回收的目标值
4 P: 使用的处理器的数量
(forced): 强制垃圾回收, 程序中调用runtime.GC()或者类似操作
scvg-1: 2740 MB released: gctrace的值大于0时,如果垃圾回收将内存返回给操作系统时,会打印一条summary,包括下一条数据
通过对每一项的介绍,你应该了解了go gc日志的含义,接下来让我们看看我们的测试各阶段的内存占用情况,也就是标记🍀的日志:



1
2
3
4
🍀 before: inuse: 656 KB, idle: 63 MB, released: 0 B, heapsys: 63 MB, sys: 66 MB
🍀 added: inuse: 1 GB, idle: 942 MB, released: 0 B, heapsys: 2 GB, sys: 2 GB, current: 1023 MB
🍀 after decreased: inuse: 156 MB, idle: 2 GB, released: 0 B, heapsys: 2 GB, sys: 2 GB, current: 0 B
🍀 after gc: inuse: 75 MB, idle: 2 GB, released: 2 GB, heapsys: 2 GB, sys: 2 GB, current: 0 B
在程序刚启动时,内存占用很小, 真正inuse不到1MB。
我们增加了上万条数据,每条数据光数就1KB,如果加上key的大小,以及管理cache的一些数据结构的额外开销,占用就比较大了,粗略统计inuse的占用就达到了1GB以上,idle的span的字节数不到1GB,从操作系统获得了2GB的内存,没有内存返回。可以看到cache使用的内存粗算为1023MB。
我们将cache的最大内存设置为1B,这会触发cache对象的清理工作,因为最大内存很小,导致后续的增加缓存操作实际并不会缓存对象,可以看到缓存的实际大小为0B。可以看到inuse讲到了156MB,我们可以把它看作额外的一些开销,实际上开始添加的对象都被回收掉了。idle span的字节数达到了2GB,但是并没有内存返还给操作系统。这会导致操作系统认为这个程序占用内存达到2GB,linux服务器上有可能会导致OOM killer杀掉这个程序。
我们进行了一次强制垃圾回收(实际调用debug.FreeOSMemory(),它会进行一次强制垃圾回收),可以看到虽然idle span的值还是2GB+,但是实际其中的2GB+的大小返还给操作系统了,如果这个时候你能够通过top观察程序的内存使用的话,可以看到这个程序的RES占用很小了。
top命令中关于程序使用内存的项介绍:



%MEM:Memory usage (RES) 内存占用
使用的物理内存



VIRT:Virtual Image (kb) 虚拟镜像
总虚拟内存的使用数量



SWAP:Swapped size (kb)
非驻留但是存在于程序中的内存,虚拟内存减去物理内存



RES:Resident size (kb)
非swap的物理内存



SHR:Shared Mem size (kb)
程序使用的共享内存,可以被其它进程所共享



可以看到,当对象释放的时候,释放出来的内存并没有立即返还给操作系统,而在我们进行了一次强制垃圾回收后才返还。 Go语言把返还的过程叫做scavenging (拾荒)。这个拾荒的算法一直在演化,可以查看issue #16930,相关的优化提案可以参考:issue #30333。



原先的scavenging是每隔几分钟(5分钟)执行一次拾荒操作,保证程序使用的内存和RSS基本一致。后来在1.11、1.12的演化过程中,改成了”智能”的拾荒操作。目标是尽量避免全部返还给操作系统导致的很重的重获取的花销,但是这也带来了一个问题,那就是当前的拾荒设计对于偶尔一个尖峰,并不会将不用的大量内存返还给操作系统,也就是本文一开始我在项目中遇到的问题。这个问题在issue中也有讨论:



Thus, I propose the following heuristic, borrowed from #16930: retain C*max(heap goal, max(heap goal over the last N GCs))



What happens in an application that has a huge heap spike (say, an initial loading phase) and then the heap drops significantly? In particular, let’s say this is drastic enough that the runtime doesn’t even notice the drop until a 2 minute GC kicks in. At that scale, it could take a while for N GCs to pass, and we won’t reclaim the heap spike until they do.



This is something that came to my mind recently too. An alternative is to set a schedule to decrease the scavenge goal linearly, or according to a smoothstep function, which goes to zero over N GCs. If this schedule ever gets below C * the heap goal, we use that instead. We’ll get smoother cliffs in general and still make progress in the case you describe. Smoothstep is preferred here since we won’t over-fit to transient drops in heap size, but this also means we might be slower to react in the case you described. I prefer not to over-fit here because that carries a performance cost.



这是一个坑,不幸踩到了。我们这个项目的需求就是运维人员有时候可以将缓存使用的最大内存设置一个比较小的数,设置之后,go运行时不触发拾荒事件,就会导致内存被大量占用而不返还给操作系统。



目前我的修改是在cache的最大内存调小后执行一次debug.FreeOSMemory(),这样可以保证不用的一些内存返还给操作系统。当然执行这个操作也是有代价的:



Returning all free memory back to the underlying system at once is expensive, and can lead to latency spikes as it holds the heap lock through the whole process.
It’s an invasive solution: you need to modify your code to call it when you need it.
Reusing free chunks of memory becomes more expensive. On UNIX-y systems that means an extra page fault (which is surprisingly expensive on some systems).
Go 1.13中对拾荒的实现有进行了改进,而且Go 1.13也快发布了,发布之后我再做进一步的测试,尽量避免使用debug.FreeOSMemory()。



runtime.MemStats
通过runtime.MemStats可以实时的获取Go运行时的内存统计信息,这个数据结构包含很多的字段。字段虽然很多,但是由于文档还是不够详细,如果没有深入理解Go语言内部的实现方式和相关的概念的话,不容易理解这个数据结构具体的含义,只根据字面值去理解很容易误用, 比如HeapIdle并不是Go占用的还没有释放的内存空间,其中的HeapReleased其实已经返还给操作系统了。



我将各个字段的中文解释列在了这里,如果你要监控go运行时的内存,需要仔细阅读相关的字段的解释。
type MemStats struct {
// 已分配的对象的字节数.
//
// 和HeapAlloc相同.
Alloc uint64
// 分配的字节数累积之和.
//
// 所以对象释放的时候这个值不会减少.
TotalAlloc uint64
// 从操作系统获得的内存总数.
//
// Sys是下面的XXXSys字段的数值的和, 是为堆、栈、其它内部数据保留的虚拟内存空间.
// 注意虚拟内存空间和物理内存的区别.
Sys uint64
// 运行时地址查找的次数,主要用在运行时内部调试上.
Lookups uint64
// 堆对象分配的次数累积和.
// 活动对象的数量等于Mallocs - Frees.
Mallocs uint64
// 释放的对象数.
Frees uint64
// 分配的堆对象的字节数.
//
// 包括所有可访问的对象以及还未被垃圾回收的不可访问的对象.
// 所以这个值是变化的,分配对象时会增加,垃圾回收对象时会减少.
HeapAlloc uint64
// 从操作系统获得的堆内存大小.
//
// 虚拟内存空间为堆保留的大小,包括还没有被使用的.
// HeapSys 可被估算为堆已有的最大尺寸.
HeapSys uint64
// HeapIdle是idle(未被使用的) span中的字节数.
//
// Idle span是指没有任何对象的span,这些span 可以返还给操作系统,或者它们可以被重用,
// 或者它们可以用做栈内存.
//
// HeapIdle 减去 HeapReleased 的值可以当作”可以返回到操作系统但由运行时保留的内存量”.
// 以便在不向操作系统请求更多内存的情况下增加堆,也就是运行时的”小金库”.
//
// 如果这个差值明显比堆的大小大很多,说明最近在活动堆的上有一次尖峰.
HeapIdle uint64
// 正在使用的span的字节大小.
//
// 正在使用的span是值它至少包含一个对象在其中.
// HeapInuse 减去 HeapAlloc的值是为特殊大小保留的内存,但是当前还没有被使用.
HeapInuse uint64
// HeapReleased 是返还给操作系统的物理内存的字节数.
//
// 它统计了从idle span中返还给操作系统,没有被重新获取的内存大小.
HeapReleased uint64
// HeapObjects 实时统计的分配的堆对象的数量,类似HeapAlloc.
HeapObjects uint64
// 栈span使用的字节数。
// 正在使用的栈span是指至少有一个栈在其中.
//
// 注意并没有idle的栈span,因为未使用的栈span会被返还给堆(HeapIdle).
StackInuse uint64
// 从操作系统取得的栈内存大小.
// 等于StackInuse 再加上为操作系统线程栈获得的内存.
StackSys uint64
// 分配的mspan数据结构的字节数.
MSpanInuse uint64
// 从操作系统为mspan获取的内存字节数.
MSpanSys uint64
// 分配的mcache数据结构的字节数.
MCacheInuse uint64
// 从操作系统为mcache获取的内存字节数.
MCacheSys uint64
// 在profiling bucket hash tables中的内存字节数.
BuckHashSys uint64
// 垃圾回收元数据使用的内存字节数.
GCSys uint64 // Go 1.2
// off-heap的杂项内存字节数.
OtherSys uint64 // Go 1.2
// 下一次垃圾回收的目标大小,保证 HeapAlloc ≤ NextGC.
// 基于当前可访问的数据和GOGC的值计算而得.
NextGC uint64
// 上一次垃圾回收的时间.
LastGC uint64
// 自程序开始 STW 暂停的累积纳秒数.
// STW的时候除了垃圾回收器之外所有的goroutine都会暂停.
PauseTotalNs uint64
// 一个循环buffer,用来记录最近的256个GC STW的暂停时间.
PauseNs [256]uint64
// 最近256个GC暂停截止的时间.
PauseEnd [256]uint64 // Go 1.4
// GC的总次数.
NumGC uint32
// 强制GC的次数.
NumForcedGC uint32 // Go 1.8
// 自程序启动后由GC占用的CPU可用时间,数值在 0 到 1 之间.
// 0代表GC没有消耗程序的CPU. GOMAXPROCS * 程序运行时间等于程序的CPU可用时间.
GCCPUFraction float64 // Go 1.5
// 是否允许GC.
EnableGC bool
// 未使用.
DebugGC bool
// 按照大小进行的内存分配的统计,具体可以看Go内存分配的文章介绍.
BySize [61]struct {
// Size is the maximum byte size of an object in this
// size class.
Size uint32
// Mallocs is the cumulative count of heap objects
// allocated in this size class. The cumulative bytes
// of allocation is Size*Mallocs. The number of live
// objects in this size class is Mallocs - Frees.
Mallocs uint64
// Frees is the cumulative count of heap objects freed
// in this size class.
Frees uint64
}
}
Go运行时的内存分配算法可以查看文章: A visual guide to Go Memory Allocator from scratch (Golang) , 或者中文翻译: Go 内存分配器可视化指南,这是目前第一篇全面介绍Go运行时内存管理的文章。



runtime.SetGCPercent
GOGC设置垃圾回收的目标百分比。什么时候会触发Go运行时的垃圾回收操作呢,主要靠这个值。当这次新分配的数据和上一次垃圾回收后存活数据之比达到这个数值之后就会触发一次垃圾回收。



GOGC的默认值是100。设置GOGC=off会禁止垃圾回收。



你也可以通过代码设置这个参数,调用runtime.SetGCPercent进行设置。



MADV
MADV是Linux的一个特性,,可以看相关的介绍:MADV_FREE functionality



一直以来 go 的 runtime 在释放内存返回到内核时,在 Linux 上使用的是 MADV_DONTNEED,虽然效率比较低,但是会让 RSS(resident set size 常驻内存集)数量下降得很快。不过在 go 1.12 里专门针对这个做了优化,runtime 在释放内存时,使用了更加高效的 MADV_FREE 而不是之前的 MADV_DONTNEED。这样带来的好处是,一次 GC 后的内存分配延迟得以改善,runtime 也会更加积极地将释放的内存归还给操作系统,以应对大块内存分配无法重用已存在的堆空间的问题。不过也会带来一个副作用:RSS 不会立刻下降,而是要等到系统有内存压力了,才会延迟下降。需要注意的是,MADV_FREE 需要 4.5 以及以上内核,否则 runtime 会继续使用原先的 MADV_DONTNEED 方式。当然 go 1.12 为了避免像这样一些靠判断 RSS 大小的自动化测试因此出问题,也提供了一个 GODEBUG=madvdontneed=1 参数可以强制 runtime 继续使用 MADV_DONTNEED:runtime: provide way to disable MADV_FREE。



相关issue和资料
这里列出了Go官方库中的一些内存泄漏相关的issue,以及关于Go内存泄漏的一些文章,感兴趣的同学可以进一步阅读。



https://golang.org/pkg/runtime/#MemStats
https://github.com/golang/go/issues/33684
https://github.com/golang/go/issues/33376
https://github.com/golang/go/issues/32284
https://github.com/golang/go/issues/16843
https://github.com/golang/go/issues/14521
https://go101.org/article/memory-leaking.html
http://play.golang.org/p/Nb39COQgxr
https://www.freecodecamp.org/news/how-i-investigated-memory-leaks-in-go-using-pprof-on-a-large-codebase-4bec4325e192/
https://medium.com/dm03514-tech-blog/sre-debugging-simple-memory-leaks-in-go-e0a9e6d63d4d
https://github.com/golang/go/issues/16930
https://github.com/golang/go/issues/30333
https://go-review.googlesource.com/c/go/+/135395/
https://github.com/golang/go/issues/23687
https://ms2008.github.io/2019/06/30/golang-madvfree/
https://golang.org/doc/go1.12#runtime


Category golang