我使用 Golang 写的一个融合日志服务, 定时融合不同云厂商的日志, 该服务部署在 K8S 上.

在国庆期间日志量倍增, 该服务频繁被 Killed.

通过仪表盘, 发现该服务运行一次后, 内存不会释放, 怀疑是内存泄露导致的. 见下图.

最终, 我通过使用 pprof 解决了该问题.

1. 开启 pprof 服务

pprof 是 Golang 自带的性能分析工具. 可以 2 步 开启 pprof 服务.

 // 1. 引入 net/http/pprof 包
_ import "net/http/pprof"

// 2. 开启 http 服务
go http.ListenAndServe(":9999", nil)
  

2. 通过 pprof 的 Web 页面分析 goroutine

执行完步骤 1 后, 程序启动后, 打开 以页面的形式获取程序当前的运行情况.

如图:

• 使用 full goroutine stack dump 来排查是否有 goroutine 运行时间过长. 如下图, 如果有的 goroutine 运行的时间非常长, 就要查看对应的代码, 是否是代码 hang 住导致的.

• 使用 goroutine 来排查是否创建了大量的 goroutine. 我的程序是定时任务, 正常情况下在 sleep 期间没有任务运行, goroutine 的数量应该非常少的. 可以使用这点进行排查. 如下图, 可以看到总的 goroutine 数量和每个 goroutine 实例的数量. 根据代码逻辑去推断 goroutine 实例的数量是否正常.

我在 Web 页面上并未发现有价值的信息, 于是使用命令行分析.

3. 通过 pprof 的命令行分析 heap

命令行执行命令: go tool pprof -inuse_space

这个命令的作用是, 抓取当前程序已使用的 heap. 抓取后, 就可以进行类似于 gdb 的交互操作.

• top 命令, 默认能列出当前程序中内存占用排名前 10 的函数. 如图. 当时进行到这一步的时候, 我就非常惊讶, 因为 time.NewTimer 居然占据了 6 个多 G 的内存.

• list <函数名>, 展现函数内部的内存占用. 使用 list time.NewTimer 查看了该函数的内部, 真相大白了, 原来每次调用 NewTimer 都会创建一个 channel, 还会生成一个 结构体 runtimeTimer, 应该就是这两个地方内存没有释放造成的内存泄露.

修改 for … select … time.After 造成的内存泄露

原来程序中存在如下代码:

 for {
select {

case a := <-chanA:
...

case b := <-chanB:
....

case <-time.After(20*time.Minutes):
return nil, errors.New("download timeout")
} 
  

time.After 就是封装了一层的 NewTimer, time.After 的源码:

 func After(d Duration) <-chan Time {
return NewTimer(d).C
}
  

修复该错误, 只调用一次 NewTimer:

 downloadTimeout := time.NewTimer(20 * time.Minute)
defer downloadTimeout.Stop()

for {
select {

case a := <-chanA:
...

case b := <-chanB:
....

case <-downloadTimeout.C:
return nil, errors.New("download timeout")
}