记录一次 内存溢出 and 性能调优的经历

后端 / 2023-03-20

写在前面

大家都知道 Golang 是一门带GC的语言。 大多数情况下我们不需要担心内存溢出问题。但是。。。并不代表他完全不会内存溢出,我将之前一个服务进行重构(改了150多个文件) 当我进行灰度发布的时候,发现:居然内存溢出了!

image.png

左边是重构前的版本,右边是灰度发布版本。 可以清楚看到内存飙升 CPU 不稳定.

于是就开始了一系列的问题探索,修复后大概这样。
image.png

可以看到 CPU 占用率和 内存占用都降低了不少

问题定位

在开始问题定位之前,这里说下用到的工具。 pprof

pprof是一个Go语言标准库自带的性能分析工具,可用于收集应用程序的 CPU、内存以及 goroutine 使用情况等性能数据,从而帮助开发人员优化和调试应用程序。

开始性能分析

改代码前要记得新建 hotfix 分支喔

// 导入 pprof 包
import _ "net/http/pprof"

// 添加调试路由
router.GET("/debug/pprof/*pprof", gin.WrapH(http.DefaultServeMux))

然后我们编译发布服务,上线让他跑一段时间

查看性能指标

在控制台输入

go tool pprof http://server_host/debug/pprof/heap

查看内存占用

(pprof) top
Showing nodes accounting for 29610.75kB, 93.53% of 31658.92kB total
Showing top 10 nodes out of 97
      flat  flat%   sum%        cum   cum%
10265.04kB 32.42% 32.42% 10265.04kB 32.42%  github.com/go-redis/redis/v8/internal/pool.NewConnPool
 8224.04kB 25.98% 58.40%  8224.04kB 25.98%  bufio.NewReaderSize
 6168.03kB 19.48% 77.88%  6168.03kB 19.48%  bufio.NewWriterSize
 1552.34kB  4.90% 82.79%  1552.34kB  4.90%  regexp/syntax.(*compiler).inst
  768.26kB  2.43% 85.21%   768.26kB  2.43%  go.uber.org/zap/zapcore.newCounters
  544.67kB  1.72% 86.93%   544.67kB  1.72%  google.golang.org/grpc/internal/transport.newBufWriter
  540.51kB  1.71% 88.64%   540.51kB  1.71%  golang.org/x/text/encoding/ianaindex.init
  519.03kB  1.64% 90.28%   519.03kB  1.64%  time.startTimer
  516.64kB  1.63% 91.91%   516.64kB  1.63%  runtime.procresize
  512.20kB  1.62% 93.53%   512.20kB  1.62%  runtime.malg
(pprof) 

我们看到 redis 相关 函数占用了 100M

查看函数详情

(pprof) list github.com/go-redis/redis/v8/internal/pool.NewConnPool
Total: 30.92MB
ROUTINE ======================== github.com/go-redis/redis/v8/internal/pool.NewConnPool in /Users/luckyfang/go/pkg/mod/github.com/go-redis/redis/v8@v8.11.5/internal/pool/pool.go
   10.02MB    10.02MB (flat, cum) 32.42% of Total
         .          .     96:func NewConnPool(opt *Options) *ConnPool {
  512.08kB   512.08kB     97:   p := &ConnPool{
         .          .     98:           opt: opt,
         .          .     99:
         .          .    100:           queue:     make(chan struct{}, opt.PoolSize),
    4.51MB     4.51MB    101:           conns:     make([]*Conn, 0, opt.PoolSize),
    5.01MB     5.01MB    102:           idleConns: make([]*Conn, 0, opt.PoolSize),
         .          .    103:           closedCh:  make(chan struct{}),
         .          .    104:   }
         .          .    105:
         .          .    106:   p.connsMu.Lock()
         .          .    107:   p.checkMinIdleConns()
(pprof) 

到这里,其实就能看出个大概了。 是不是连接池创建了没有关闭呢?
别急 我们继续向下分析,看看是哪里调用了这个 函数

分析调用链

image.png
image.png

可以看到 在 UserService 这里耗费了大量的内存。 为了验证我们上面的猜想,进一步查看火焰图
image.png

果然在 RedisClient 这里耗费了大量内存

定位问题

我们继续查看 是谁调用了它?

image.png

Total:           0    72.72MB (flat, cum) 93.17%
    125            .          .            
    126            .          .           func (u *userScoreService) GetContinueChatDays(openid string) (int, error) { 
    127            .          .           	var err error 
    128            .          .           	var client *redis.Client 
    129            .          .            
    130            .    72.72MB           	if client, err = common.NewRedisClient(); err != nil { 
    131            .          .           		return 0, err 
    132            .          .           	} 
    133            .          .           	//defer client.Close() 
    134            .          .           	return client.HGet(context.Background(), openid, "chat_days").Int() 
    135            .          .           } 

最终我们发现了问题在: NewRedisClient

那我们看看有问题的代码叭

func NewRedisClient() (*redis.Client, error) {
	client := redis.NewClient(&redis.Options{
		Addr:     config.RedisAddr,
		DB:       config.RedisDB,
		Password: config.RedisPassword,
	})
	return client, client.Ping(context.Background()).Err()
}

到这里就真相大白了: 创建Redis连接池没有及时关闭

经验心得

  • 通过 pprof 我们定位到了 有问题的代码
  • top 命令显示 函数占用情况
  • list 命令查看函数信息
  • 通过火焰图跟跟踪调用链