本文作者： 保护我方李元芳
商业转载请联系作者获得授权，非商业转载请注明出处。
故障现象
某线上埋点上报机器偶尔触发内存占用过多的报警。ssh到机器top发现主要内存被埋点服务占用。之前重启过几次，但是过段时间仍然会发生内存占用过多的警报。下面是报警详情。
[P1][PROBLEM][ali-e-xxx-service03.bj][][ all(#3) mem.memfree.percent 4.19575<5][O3 >2019-10-28 10:20:00]
问题推断
埋点服务主要接收客户端压缩过的上报请求，并对请求数据做解压，投递到kafka，逻辑功能相对简单。初步怀疑是某些资源没有释放导致的内存泄露或Groutine泄露。
问题排查
由于代码不是由我们业务方维护的，首先向相关部门索要了代码权限。阅读了一下源码，所有资源释放都是由defer进行操作的，并没有发现很明显的资源未释放的情况。
1. 修改线上环境配置，打开trace端口
在调试分析问题之前，熟悉go的同学都知道Golang 提供了非常方便的性能诊断工具 go tool trace; go tool trace是golang中的性能大杀器， 能揭露运行中的所有的运行时事件和内存占用等。 它是Go生态系统中用于诊断性能问题时（如延迟，并行化和竞争异常）最有用的工具之一。
由于都是采用公司的基础库，基础库专门对go trace做了封装。只需要在线上机器修改config文件，将trace信息发送到配置文件中的指定端口就可以使用go tool进行分析了。
然后我在本地进行使用go tool 工具发现网络不通，排查了一下发现trace端口没有绑定到0.0.0.0上[狗头]。 随即用proxy工具将 9900 端口反向代理到9999端口，然后使用go tool对正常状态的内存占用做了一个内存火焰图。如下图 2020-01-18-18-11-23.jpg
2. 等待故障发生
等待是个很漫长的过程，可能需要几天或者运气不好的话个把月。此处省去几万字 x#@#@
3. 该来的总归还是来了
过了几天后又收到了服务器警报，由于qps上升，这次比前几次来的都早一些。接到警报后立即对内存做了一个top
go tool pprof -alloc_space http://{addr}/debug/pprof/heap
复制代码Showing top 20 nodes out of 55
flat flat% sum% cum cum%
2.76GB 59.76% 59.76% 2.76GB 59.76% compress/flate.NewReader
0.45GB 9.73% 69.49% 0.45GB 9.73% net/http.newBufioWriterSize
0.29GB 6.33% 75.82% 3.05GB 66.09% compress/gzip.(*Reader).Reset
0.25GB 5.35% 81.17% 0.25GB 5.35% net/http.newBufioReader
0.13GB 2.85% 84.01% 0.13GB 2.85% runtime.rawstringtmp
0.11GB 2.31% 86.32% 0.11GB 2.31% bytes.makeSlice
0.10GB 2.26% 88.58% 0.10GB 2.26% runtime.hashGrow
复制代码每一行表示一个函数的信息。前两列表示函数使用内存以及百分比；第三列是当前所有函数累加使用 Memory 的比例；第四列和第五列代表这个函数以及子函数运行所占用的Memory和比例（也被称为累加值 cumulative），应该大于等于前两列的值；最后一列就是函数的名字。如果应用程序有性能问题，上面这些信息应该能告诉我们内存都花费在哪些函数的执行上了，另外pprof的CPU时间分析也类似。
pprof 不仅能打印出最耗内存的的地方(top)，还能列出函数代码以及对应的取样数据(list)、汇编代码以及对应的取样数据(disasm)，而且能以各种样式进行输出，比如 svg、gv、callgrind、png、gif等等。
可以看到的是大部分内存都被这些Reader占用了.
4. 带着问题重新阅读代码
前面我们进行了占用的初步分析，找到了内存占用多的Fcuntion是flate.NewReader,Package flate 实现了 RFC 1951 中描述的 DEFLATE 压缩数据格式, gzip 包实现了对基于 DEFLATE 的文件格式的访问。所以我们带着问题我们再次定位到相关源码实现，下面是一些关键定义:
var Gzip GzipPool
func GetReader(src io.Reader) (*gzip.Reader, error) {
return Gzip.GetReader(src)
}
func PutReader(reader *gzip.Reader) {
Gzip.PutReader(reader)
}
// GzipPool manages a pool of gzip.Writer.
// The pool uses sync.Pool internally.
type GzipPool struct {
readers sync.Pool
writers sync.Pool
}
复制代码这里用到了sync.Pool 来优化GC, 为了验证内存都在pool上，我们又使用go tool 提供的web工具对查看了一下pool的内存占用，果然大部分占用都在pool上。时间久远这次没图了。。。
5. 什么是 sync.Pool ?
sync包提供了基础的golang并发编程工具。根据官方文档的描述:
Pool's purpose is to cache allocated but unused items for later reuse, relieving pressure on the garbage collector. That is, it makes it easy to build efficient, thread-safe free lists. However, it is not suitable for all free lists.
我们通常用golang来构建高并发场景下的应用，但是由于golang内建的GC机制会影响应用的性能，为了减少GC，golang提供了对象重用的机制，也就是sync.Pool对象池。 sync.Pool是可伸缩的，并发安全的。其大小仅受限于内存的大小，可以被看作是一个存放可重用对象的值的容器。 设计的目的是存放已经分配的但是暂时不用的对象，在需要用到的时候直接从pool中取。看到这里相信许多熟悉GC的同学心里已经有答案的猜测了: 或许和GC有关。
So，Golang的GC触发时机是什么？
Golang GC1.13版本的GC实现是三色标记发配合写屏障和辅助GC。触发条件主要有两个:
- 超过内存大小阈值
- 达到定时时间
阈值是由一个gcpercent的变量控制的,当新分配的内存占已在使用中的内存的比例超过gcprecent时就会触发。 比如一次回收完毕后，内存的使用量为5M，那么下次回收的时机则是内存分配达到10M的时候。也就是说，并不是内存分配越多，垃圾回收频率越高。 如果一直达不到内存大小的阈值呢？这个时候GC就会被定时时间触发，比如一直达不到10M，那就定时（默认2min触发一次）触发一次GC保证资源的回收。
所以我们当内存占用慢慢升高的时候，gc触发次数会减少并且趋近于2min，没有gc就不会对pool中对象进行回收，导致内存占用率逐渐升高。
主动触发GC进行验证
修改代码，限制rlimit，并使用一个goroutine 每30s主动调用gc，然后进行测试后上线。观测线上接口耗时并未发生明显变化，系统运行正常，内存占用报警再也没有被触发过。
问题总结
刚开始对偶尔触发的内存报警并没有过多的在意，有许多侥幸心理，但问题总归是客观存在的，及时发现问题，定时总结才能不断进步成长，尽量避免一有问题就重启，防止成为SRB(Service ReBoot Boy????).
参考文档
[1] golang 内存分析/动态追踪
[2] golang GC
有疑问加站长微信联系（非本文作者）
