内存泄漏简直就是down机之源之一。实在可怕。最近线上就是碰到这个这个问题。一开始查到原因的时候我还不太相信。心想这个结构怎么可能消耗了这个大的一个内存？？最后使用工具一看。。好吧。
发现问题
告警显示go服务的内存飙升到近乎100%。而且是每隔一段时间就会上涨一波，直至100%。但是这个版本之前并没有发现这个问题，那么是新增加的功能引入的问题？
定位
go还是有自己的定位手段的。特别是能够上服务器看的时候就不要BB。
go tool pprof http://localhost:23807/debug/pprof/heap
因为在go服务中使用了pprof，所以只要知道端口我们就可以查看当前内存的一个使用情况了。
flat flat% sum% cum cum%
1798.02MB 75.32% 75.32% 1798.02MB 75.32% .../logger.SetLogId
377.02MB 15.79% 91.12% 377.02MB 15.79% .../asyncwriter/cachechan.NewPool
54.36MB 2.28% 93.40% 54.36MB 2.28% github.com/coocood/freecache.NewRingBuf
29MB 1.22% 94.61% 29MB 1.22% reflect.New
可以看到消耗最高的函数是SetLogId…
仔细一看里面备注了要记得释放。然我们看看实现：
gLogIDMap = make(map[int64]string, 1000000)
func SetLogId(logid string) {
if gLogIDMap != nil {
gLogIDMapLock.Lock()
goroutineId := goid.Goid()
// value = ${goid}_${logid}
goroutineIdStr := strconv.FormatInt(goroutineId, 16)
var val = make([]byte, 0, len(goroutineIdStr)+1+len(logid))
val = append(val, goroutineIdStr...)
val = append(val, '_')
val = append(val, logid...)
gLogIDMap[goroutineId] = *(*string)(unsafe.Pointer(&val))
gLogIDMapLock.Unlock()
}
}
func UnsetLogId() {
if gLogIDMap != nil {
gLogIDMapLock.Lock()
delete(gLogIDMap, goid.Goid())
gLogIDMapLock.Unlock()
}
}
是的，log的requestID 是通过gorutineID来绑定的，所以每产生一个协程就会新增一个key-value. 由于后面线上的一个对比。以及一个batch接口会开特别的的协程导致了这个问题。一开始我是不信的。因为但看起来这个str的大小也不是特别大。但是看pprof确实是这么回事，可能在key达到亿级之后就不是一个概念吧。留个坑，后面实验一下
解决和思考
解决就是在协程结束的时候unsetID就可以了。使用defer比较靠谱。但是需要注意的是defer的顺序。
关于requestID是使用context保存还是使用这种KV形式的争论已经很久了。使用context的话看起来稍微繁琐，毕竟每次打印的时候你就需要传递ctx作为参数，在打印的时候获取requestID进行打印。但是是更为安全也是更为普遍的做法。使用map做存储就存在内存泄漏的风险。