记一次资源不释放的问题

前言

　　最近发现一个 GoFrame 服务即使空载 CPU 使用率也很高，每次接受请求后资源没有被释放，一直累积，直到达到报警阈值，人工介入重启服务，于是压测排查了一下。

问题篇

　　先新增代码启动 go 自带的 pprof 服务器：

package main

import (
	"net/http"
	_ "net/http/pprof"
)

func Pprof(pprof_port string) {
	go func(pprof_port string) {
		http.ListenAndServe("0.0.0.0:"+pprof_port, nil)
	}(pprof_port)
}

压测以及 profile 命令：

# 压测命令
wrk -t8 -c1000 -d60s --latency --timeout 10s -s post_script.lua http://host:[srv_port]/post

# profile 整体分析
go tool pprof -http=:8081 http://host:[pprof_port]/debug/pprof/profile?seconds=30

# 查看函数堆栈调用
curl http://host:[pprof_port]/debug/pprof/trace?seconds=30 > ./pprof/trace01
go tool trace -http=:8081 ./pprof/trace01

# 查看内存堆栈
go tool pprof -http=:8081 http://host:[pprof_port]/debug/pprof/heap?seconds=30

　　在压测 30 次后，即使服务空载 CPU 也被打满了，查看服务此时的 profile，发现 goroutine 的数目到了百万级别，查看 cpu 堆栈发现集中调用在 gtimer 上，但遍寻服务代码，没有直接用到 GoFrame 的定时器，问题出在哪也还是没想太明白。吃完饭后偶然灵光一现，既然 CPU 看不出啥，那再看看内存，查看内存发现，内存对象最多的是 glog.Logger，看代码也正好有对应的对象，可算是找到问题真正的元凶了。

　　log 对象一般都是全生命周期的，不主动销毁就会一直伴随着服务运行，所以 log 对象一般都是程序启动时初始化一次，后续调用，都是用这一个对象实例。而这次这个问题就是因为在代码中用 glog 记录了数据库执行日志，每次请求都会重新生成一个 glog 对象，又没有主动释放造成的。

　　知道问题的真正所在，解决问题就相对很简单了，只在程序启动时初始化一个 glog 对象，后续打印日志就用这一个实例，其实更好的方式是生产环境不打印数据库日志，毕竟影响性能。

后记

　　CPU 资源的占用往往伴随着内存资源的占用，当从调用堆栈以及线程资源上看不出问题的时候，可以转过头来看看内存堆栈，毕竟内存堆栈更能指示有问题的对象出在哪，知道内存对象是谁，也相当于提供了排查问题代码的方向。

附录

　　在排查过程中发现 goroutine 数目异常的高，于是想限制一下 goroutine 数目，在网上搜索的时候发现当用容器部署 go 服务时，go 默认最大的 goroutine 数目为宿主机 cpu 核数，而不是容器的 cpu 核数，从而并发时 goroutine 数目可能比容器 cpu 核数高很多，造成资源争抢，导致并发性能下降，可以通过设置环境变量 GOMAXPROCS 指定 goroutine 最大数目，也可以使用 go.uber.org/automaxprocs 库自动修正最大核数为容器 cpu 核数。

自适应设置 GOMAXPROCS 上下限代码：

package main

import (
	_ "go.uber.org/automaxprocs"

	"runtime"
)

func main() {
	procsNum := runtime.GOMAXPROCS(-1)
	if procsNum < 4 {
		procsNum = 4
	} else if procsNum > 16 {
		procsNum = 16
	}

	runtime.GOMAXPROCS(procsNum)

	// todo something...

}

python 内存泄漏排查

方法一是线上程序直接排查，通过 pyrasite 和 guppy 直接对应 python 程序：

step1：绑定 python 程序 pid，开启 pyrasite shell 窗口，执行 pyrasite-shell <pid>；

step2：使用 guppy 查看 python 程序内存情况，

>>> from guppy import hpy
>>> h = hpy()
>>> h.heap()

step3：间隔一定时间后，再次使用 h.heap()，对比两次内存变化

该方法一般只能粗略查看内存泄露的数据对象，可能无法精确定位到指定位置，这时需要用方法二，手动插入代码查看程序运行日志：

Python标准库的gc、sys模块提供了检测的能力

import gc
import sys

gc.get_objects() # 返回一个收集器所跟踪的所有对象的列表
gc.get_referrers(*objs) # 返回直接引用任意一个 ojbs 的对象列表
sys.getsizeof() # 返回对象的大小（以字节为单位）。只计算直接分配给对象的内存消耗，不计算它所引用的对象的内存消耗。

基于这些函数，先把进程中所有的对象引用拿到，得到对象大小，然后从大到小排序，打印出来，代码如下：

import gc
import sys

def show_memory():
    print("*" * 60)
    objects_list = []
    for obj in gc.get_objects():
        size = sys.getsizeof(obj)
        objects_list.append((obj, size))
    for obj, size in sorted(objects_list, key=lambda x: x[1], reverse=True)[:10]:
        print(f"OBJ: {id(obj)}, TYPE: {type(obj)} SIZE: {size/1024/1024:.2f}MB {str(obj)[:100]}")

找到内存占用稳定增长的对象，调用 gc.get_referrers(*objs)，查看该对象的引用信息，即可快速定位泄漏位置

该方法更加灵活精确，不好的地方是有侵入性，需要修改代码后重新上线，同时获取这些信息并打印，对性能有一定的影响，排查完之后，需要将该段代码下线。

参考资料

1、python内存泄露问题定位：附带解决pyrasite timed out

2、技术 · 一次Python程序内存泄露故障的排查过程