golang pprof万字详解、再也不用担心内存泄露的问题了
内存泄露
内存泄漏(Memory Leak)是指程序中已动态分配的堆内存由于某种原因程序未释放或无法释放,造成系统内存的浪费,导致程序运行速度减慢甚至系统崩溃等严重后果。内存泄露,一个老生常谈的问题,如果没有可靠的研发流程保证在测试阶段发现问题,问题就容易被带到线上。计算资源始终是有限的,问题也不会因为资源充裕就消失不见,产生影响只是时间问题。影响有多大,就要结合场景来说了。
内存泄漏,最可能的影响就是内存申请失败。但实际上操作系统更聪明,结合系统整体负载情况,它会为每个进程计算一个oom_score,并在内存资源紧张时选择一个合适的进程杀死并回收内存资源,see how does the oom killer decide which process to kill first。
所以,内存泄露的最终结果,大概率会被操作系统kill,通常进程挂掉后,确认其是否是因为oom问题被kill,可以通过查看 /proc/messages 来确认是否有对应日志。有的话,那就坐实了oom killed(但是被oom killed的进程不一定意味着存在内存泄露)。
随着时间的推进,内存的占用率在不断的提高,这是内存泄露的最明显现象
服务质量
结合运维手段的变化,来看看是否内存泄漏问题对服务质量造成的影响。
- 传统人工方式,通过感知告警、人为介入这种方式,效率低,要十几分钟;
- 通过虚拟机自动化部署的方式,感知异常自动重启虚拟机,耗时大约要分钟级;
- 通过docker容器化部署的方式,感知异常自动重启容器,耗时大约在秒级;
看上去现代运维方式一定程度上可以缓解这个问题,是,这也要分情况:
- 如果内存泄露的代码路径不容易被触发,那可能要跑很久才能触发oom kill,如一周;但是如果代码路径在关键代码路径上,且请求量大,频繁触发内存泄露,那可能跑个几分钟就会挂掉;
- 跟每次内存泄露的内存大小也有关系,如果泄露的少,多苟活一阵子,反之容易暴毙;
- 进程一旦挂掉,这段时间就不能响应了,服务的健康监测、名字服务、负载均衡等措施需要一段时间才能感知到,如果请求量大,服务不可用依然会带来比较大的影响。
服务质量保证是不变的,所以别管用了什么运维手段,问题终究是问题,也是要解决的。
采样
概率抽样对象与它的大小成正比,你可以使用 go test --memprofilerate 标志改变抽样比率,或者是在程序启动的时候设置 runtime.MemProfileRate 变量。比率 1 将导致收集所有分配的信息。但是它可能导致执行很慢,默认的采样率是每 512kb 的内存分配 1个样本。
这里顺便提一点
CPU的主频,即CPU内核工作的时钟频率(CPU Clock Speed)。CPU的主频的基本单位是赫兹(Hz),但更多的是以兆赫兹(MHz)或吉赫兹(GHz)为单位。时钟频率的倒数即为时钟周期。时钟周期的基本单位为秒(s),但更多的是以毫秒(ms)、微妙(us)或纳秒(ns)为单位。在一个时钟周期内,CPU执行一条运算指令。也就是说,在1000 Hz的CPU主频下,每1毫秒可以执行一条CPU运算指令。在1 MHz的CPU主频下,每1微妙可以执行一条CPU运算指令。而在1 GHz的CPU主频下,每1纳秒可以执行一条CPU运算指令。
在默认情况下,Go语言的运行时系统会以100 Hz的的频率对CPU使用情况进行取样。也就是说每秒取样100次,即每10毫秒会取样一次。
常见场景
goroutine 导致内存泄漏
- goroutine 申请过多
- 问题描述
- goroutine 申请过多,增长速度快于释放速度,就会导致 goroutine 越来越多。
- 场景举例
- 一次请求就新建一个 client,业务请求量大时 client 建立过多,来不及释放。
- 问题描述
3. 解决方案
1. 使用连接池:针对创建过多的client对象的情况,可以引入连接池来管理这些对象。连接池可以预先创建一定数量的client对象,并在需要时从池中获取可用的对象,而不是每次请求都创建一个新的client。使用完毕后,将client对象释放回连接池,以便其他请求可以重复使用这些对象。这样可以避免频繁地创建和销毁对象,减轻了内存压力。
2. 限制并发goroutine数量
3. 优化goroutine生命周期:仔细审查goroutine的生命周期,确保它们的创建和销毁的时机合理。避免在循环或递归中频繁地创建goroutine,可以将创建goroutine的操作放在循环或递归外部,减少创建goroutine的次数。
4. 使用性能分析工具:可以使用Go语言提供的性能分析工具,如pprof,来分析和监测应用程序的内存使用情况。这些工具可以帮助你找出哪些地方存在内存泄漏问题,并提供相应的调优建议。
什么会导致goroutine无法退出/阻塞?
- Goroutine泄露的本质是channel阻塞,无法继续向下执行,导致此goroutine关联的内存都无法释放,进一步造成内存泄露。
goroutine 阻塞
- IO 问题
- 问题描述
- I/O 连接未设置超时时间,导致 goroutine 一直在等待。
- 场景举例
- 在请求第三方网络连接接口时,因网络问题一直没有接到返回结果,如果没有设置超时时间,则代码会一直阻塞。
- 解决方案
- 使用context.Context:Go语言中的context包提供了管理请求生命周期的机制,包括设置超时时间。可以使用context.WithTimeout函数创建一个带有超时时间的上下文,并将其传递给发起请求的goroutine。一旦超过指定的超时时间,相关的goroutine会收到超时信号,可以通过检查context的Done通道来处理超时情况,并及时取消请求。
- 设置合理的超时时间
- 使用带超时的I/O操作:在进行I/O操作时,可以使用支持超时设置的相关函数或方法。例如,在使用net/http包进行HTTP请求时,可以使用http.Client的Timeout字段设置超时时间。如果在指定的时间内没有接收到响应,请求会被取消并返回超时错误。
- 问题描述
- 互斥锁未释放
- 问题描述
- goroutine 无法获取到锁资源,导致 goroutine 阻塞。
- 场景举例
- 假设有一个共享变量,goroutineA 对共享变量加锁但未释放,导致其他 goroutineB、goroutineC、…、goroutineN 都无法获取到锁资源,导致其他 goroutine 发生阻塞。
- 解决方案
- 优化锁的使用方式:首先,确保在尽可能短的时间内持有锁。这可以减少其他goroutine被阻塞的时间。在使用锁的代码块中,只包含必要的操作,并在完成后立即释放锁。这样其他goroutine就有机会获取到锁并执行它们的任务。
- 避免死锁:死锁是指多个goroutine相互等待对方释放锁,从而导致所有goroutine无法继续执行的情况。要避免死锁,确保在使用锁时遵循以下原则:
- 按照相同的顺序获取锁:如果多个goroutine都需要同时持有多个锁,确保它们以相同的顺序获取锁。这样可以避免出现循环等待的情况。
- 避免长时间持有锁:尽量避免在持有锁的同时执行长时间的操作。如果某个操作需要很长时间才能完成,可以考虑在执行该操作之前释放锁,并在操作完成后重新获取锁。
- 使用读写锁(RWMutex):如果共享资源被频繁地读取而很少被写入,可以考虑使用读写锁。读写锁允许多个goroutine同时获取读锁,但只有一个goroutine可以获取写锁。这样可以提高并发性能。
- 使用通道(Channel)代替锁:在某些情况下,使用通道可以更好地管理并发访问。通过使用带有缓冲区的通道,可以限制对共享资源的访问并避免锁的使用。
- 问题描述
- waitgroup 使用不当
- 问题描述
- waitgroup 的 Add、Done 和 wait 数量不匹配,会导致 wait 一直在等待。
- 场景举例
- WaitGroup 可以理解为一个 goroutine 管理者。他需要知道有多少个 goroutine 在给他干活,并且在干完的时候需要通知他干完了,否则他就会一直等,直到所有的小弟的活都干完为止。加上 WaitGroup 之后,程序会进行等待,直到它收到足够数量的 Done()信号为止。假设 waitgroup Add(2), Done(1),那么此时就剩余一个任务未完成,于是 waitgroup 会一直等待。
- 问题描述
package main
import (
"fmt"
_ "net/http/pprof"
"time"
)
func main() {
ch := make(chan int)
for {
time.Sleep(1 * time.Second)
alloc(ch)
}
}
func alloc(ch chan<- int) {
go func() {
fmt.Println("new goroutine")
ch <- 0
fmt.Println("finished goroutine")
}()
}
只有new goroutine,没有finished goroutine
select 阻塞
- 问题描述
- 写阻塞
- 无缓冲 channel 的阻塞通常是写操作因为没有读而阻塞
- 有缓冲的 channel 因为缓冲区满了,写操作阻塞
- 读阻塞
- 期待从 channel 读数据,结果没有 goroutine 往进写
- 写阻塞
- 场景举例:
package main
import (
"fmt"
"time"
)
func main() {
ch := make(chan int)
go func() {
time.Sleep(2 * time.Second)
ch <- 42
}()
select {
case data := <-ch:
fmt.Println("读取到数据:", data)
case <-time.After(3 * time.Second):
fmt.Println("超时,未能读取到数据")
}
time.Sleep(time.Second * 5)
}
定时器使用不当
- time.after()使用不当
- 问题描述
- 默认的 time.After()是会有内存泄漏问题的,因为每次 time.After(duratiuon x)会产生 NewTimer(),在 duration x 到期之前,新创建的 timer 不会被 GC,到期之后才会 GC。那么随着时间推移,尤其是 duration x 很大的话,会产生内存泄漏的问题。
- 场景举例
- 问题描述
func main() {
ch := make(chan string, 100)
go func() {
for {
ch <- "continue"
}
}()
for {
select {
case <-ch:
case <-time.After(time.Minute * 3):
}
}
}
创建了一个带有缓冲区大小为100的字符串通道ch。然后,在一个匿名的Go协程中,不断向通道发送字符串"continue"。这意味着在通道未被读取之前,它会一直保留这些发送的值。
接下来,在主函数的无限循环中,使用了select语句监听通道和定时器。当通道ch中有数据可读时,会执行空操作(<-ch),而当经过3分钟后,定时器触发后也会执行空操作(<-time.After(time.Minute * 3))。
问题在于,无论是从通道中读取数据还是等待定时器触发,都没有对这些接收到的值进行处理。这会导致通道中的数据越积越多,从而造成内存泄漏。
修改方案
func main() {
ch := make(chan string, 100)
go func() {
defer close(ch) // 关闭通道,确保通知接收者退出
for {
ch <- "continue"
}
}()
for {
select {
case <-ch:
// 处理接收到的数据
case <-time.After(time.Minute * 3):
// 处理定时器超时
}
}
}
- 使用defer close(ch)语句来在协程结束时关闭通道ch。这样可以确保在协程退出后,通道会被正确关闭,通知接收者停止等待并退出循环。
- 在case <-ch分支中,可以添加相应的代码来处理接收到的数据。这可以防止数据在通道中无限累积,从而避免内存泄漏。可以根据实际需求编写处理逻辑,或者将接收到的数据存储到合适的数据结构中。
slice 引起内存泄露
- 问题概述:
- 两个 slice 共享地址,其中一个为全局变量,另一个也无法被 gc;
- append slice 后一直使用,未进行清理。
- 场景举例:
- 直接上代码,采用此方式,b 数组是不会被 gc 的。
var a []int
func test(b []int) {
a = b[:3]
// 此处对切片 a 进行追加操作
a = append(a, 4, 5, 6)
return
}
func main() {
// 创建一个切片并传递给 test 函数
test([]int{1, 2, 3})
// 此时切片 a 包含了 [1, 2, 3, 4, 5, 6]
// b 数组将无法被垃圾回收,因为它与 a 共享底层数组的地址
// 如果没有其他地方引用切片 a,那么 a 将会被垃圾回收
}
修复后的代码
var a []int
func test(b []int) {
// 创建一个新的切片,长度与 b 相同
a = make([]int, len(b))
copy(a, b[:3])
return
}
func main() {
test([]int{1, 2, 3})
// 现在切片 a 不再与 b 共享底层数组的地址
// 在没有其他地方引用切片 a 的情况下,它将被垃圾回收
}
以下一些例子均来自于 Go101
获取长字符串中的一段导致长字符串未释放
场景
var s0 string // a package-level variable
// A demo purpose function.
func f(s1 string) {
s0 = s1[:50]
// Now, s0 shares the same underlying memory block
// with s1. Although s1 is not alive now, but s0
// is still alive, so the memory block they share
// couldn't be collected, though there are only 50
// bytes used in the block and all other bytes in
// the block become unavailable.
}
变量 s0 是一个包级别的变量,而函数 f() 接受一个参数 s1。在函数 f() 中,将 s1 的前50个字符赋值给 s0。这里的问题是,s0 和 s1 共享同一个底层内存块。
尽管在函数 f() 执行完毕后,s1 不再被使用,但 s0 仍然存在并持有对该内存块的引用。这意味着内存块无法被垃圾回收,即使实际上只有其中的50个字节是被使用的,其他字节变得无法访问。
如果这段代码被重复执行多次,每次都会创建一个新的内存块,而旧的内存块则变成无用的垃圾。
解决方案
func f(s1 string) {
s0 = (" " + s1[:50])[1:]
}
获取长slice中的一段导致长slice未释放
问题
var s0 []int
func g(s1 []int) {
// Assume the length of s1 is much larger than 30.
s0 = s1[len(s1)-30:]
}
func demo() {
s := createStringWithLengthOnHeap(1 << 20) // 1M bytes
f(s)
}
解决方案
func g(s1 []int) {
s0 = make([]int, 30)
copy(s0, s1[len(s1)-30:])
// Now, the memory block hosting the elements
// of s1 can be collected if no other values
// are referencing the memory block.
}
长slice新建slice导致泄漏
func h() []*int {
s := []*int{new(int), new(int), new(int), new(int)}
// do something with s ...
return s[1:3:3]
}
解决方案
func h() []*int {
s := []*int{new(int), new(int), new(int), new(int)}
// do something with s ...
// Reset pointer values.
s[0], s[len(s)-1] = nil, nil
return s[1:3:3]
}
time.Ticker未关闭导致泄漏
import (
"fmt"
_ "net/http/pprof"
"time"
)
func main() {
timer := time.NewTicker(time.Duration(2) * time.Second)
//defer timer.Stop()
for {
select {
case <-timer.C:
fmt.Println("on time")
default:
time.Sleep(1 * time.Second)
}
}
}
大数组作为参数导致短期内内存激增
数组是Golang的基本数据类型,每个数组占用不同的内存空间,生命周期互不干扰,很难出现内存泄漏的情况。
但是数组作为形参传输时,遵循的是值拷贝,如果函数被多次调用且数组过大时,则会导致内存使用激增。
func countTarget(nums [1000000]int, target int) int{
num := 0
for i:=0; i<len(nums) && nums[i] == target; i++{
num ++
}
return num
}
例如上面的函数中,每次调用countTarget函数传参时都需要新建一个大小为100万的int数组,大约为8MB内存,
如果在短时间内调用100次就需要约800MB的内存空间了。(未达到GC时间或者GC阀值是不会触发GC的)
如果是在高并发场景下每个协程都同时调用该函数,内存占用量是非常恐怖的。
因此对于大数组放在形参场景下,通常使用切片或者指针进行传递,避免短时间的内存使用激增。
goroutine阻塞拥挤等待,内存浪费
10个生产者1秒生产一次,同时只有1个消费者1秒消费一次,导致9个生产者都在阻塞等待,浪费内存资源
package main
import (
"fmt"
"time"
)
var ch = make(chan string, 1)
func producer(){
for i:=0; i<10; i++ {
go func(pi int) {
n := 0
for {
n += 1
ch <- fmt.Sprintf("%d_%d", pi, n)
fmt.Printf("%s producer write p:%d, n:%d\n", time.Now().String(), pi, n)
time.Sleep(1 * time.Second)
}
}(i)
}
}
func consumer(){
for {
gotS := <- ch
fmt.Printf("%s consumer read n:%s\n", time.Now().String(), gotS)
time.Sleep(1 * time.Second)
}
}
func main() {
go consumer()
go producer()
select{
}
}
Pprof
前面介绍了这么多,接下来就开始pprof的解析之旅了
在pprof图像中并不能够涵盖所有信息,例如一个长时间在等待状态下的协程,其本身是不消耗CPU的,也就不可能出现在pprof中,但是其可能会导致耗时变慢。
trace中的Goroutine analysis,是一个非常有用的工具,可以用来分析某一个协程的具体情况。
一般GC问题需要修改代码,减少频繁的内存分配,或是借助sync.pool等内存池复用内存。
采用http api来将pprof信息暴露出来以供分析,可以采用net/http/pprof 这个package。下面是一个简单的示例:
// pprof 的init函数会将pprof里的一些handler注册到http.DefaultServeMux上
// 当不使用http.DefaultServeMux来提供http api时,可以查阅其init函数,自己注册handler
import _ "net/http/pprof"
go func() {
http.ListenAndServe("0.0.0.0:8080", nil)
}()
通过 Web API 分析
- 访问 http://localhost:6060/debug/pprof/ 页面,可以看到总览
输入网址ip:port/debug/pprof/打开pprof主页,大概有这么几类profile信息:
- block:goroutine的阻塞信息,本例就截取自一个goroutine阻塞的demo,但block为0,没掌握block的用法
- goroutine:所有goroutine的信息,下面的full goroutine stack dump是输出所有goroutine的调用栈,是goroutine的debug=2,后面会详细介绍。
- heap:堆内存的信息
- mutex:锁的信息
- threadcreate:线程信息
- allocs:程序启动之后内存分配的情况
- **cmdline:**当前程序启动的命令行
- profile: CPU profile文件。可以在 debug/pprof?seconds=x秒 GET 参数中指定持续时间。获取pprof文件后,使用 go tool pprof x.prof命令分析pprof文件。
- **threadcreate:**线程信息
- **Trace:**当前系统的代码执行的链路情况
通过 dump 文件进行分析
- 通过执行命令 go tool pprof http://localhost:6060/debug/pprof/profile?seconds=60 会进行 60s 内进行采样(默认 30s),并进入 命令行交互模式:
go tool pprof http://localhost:6060/debug/pprof/profile\?seconds=3
Fetching profile over HTTP from http://localhost:6060/debug/pprof/profile?seconds=3
Saved profile in /Users/youzeliang/pprof/pprof.samples.cpu.002.pb.gz
Type: cpu
Time: Jun 24, 2023 at 6:56pm (CST)
Duration: 3s, Total samples = 0
No samples were found with the default sample value type.
Try "sample_index" command to analyze different sample values.
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
CPU profile 的 top 命令
在 CPU profile 交互页面输入 topN 可以查看 top N 的概况(N 可省略,默认为 10)
(pprof) top
Showing nodes accounting for 29.92s, 94.56% of 31.64s total
Dropped 117 nodes (cum <= 0.16s)
Showing top 10 nodes out of 33
flat flat% sum% cum cum%
28.52s 90.14% 90.14% 28.58s 90.33% runtime.cgocall
0.81s 2.56% 92.70% 0.82s 2.59% runtime.stdcall1
0.24s 0.76% 93.46% 0.25s 0.79% runtime.stdcall3
0.16s 0.51% 93.96% 29.10s 91.97% internal/poll.(*FD).writeConsole
0.05s 0.16% 94.12% 29.28s 92.54% internal/poll.(*FD).Write
0.04s 0.13% 94.25% 0.18s 0.57% runtime.findrunnable
0.03s 0.095% 94.34% 0.18s 0.57% runtime.mallocgc
0.03s 0.095% 94.44% 0.25s 0.79% runtime.mcall
0.02s 0.063% 94.50% 29.49s 93.20% log.(*Logger).Output
0.02s 0.063% 94.56% 29.71s 93.90% log.Println
(pprof)
- 显示的节点在总共 31.64s 的抽样中,占 29.92s,比例 94.56%
- 在 33 个样本中显示了 top 10
- 列表解释(cum: cumulative 堆积的)
- flat: 在给定函数上运行耗时
- flat%: 在给定函数上运行耗时总比例
- sum%: 给定函数 累计 使用 CPU 总比例
- cum: 当前函数 以及包含子函数 的调用运行总耗时
- cum%: 同上的 CPU 运行耗时总比例
- 最后一列为函数名称
heap profile 的 top 命令
go tool pprof http://localhost:6060/debug/pprof/heap
$ go tool pprof http://localhost:6060/debug/pprof/heap
Fetching profile over HTTP from http://localhost:6060/debug/pprof/heap
Saved profile in /Users/youzeliang/pprof/pprof.samples.cpu.001.pb.gz
Type: inuse_space
Time: Jun 17, 2020 at 3:52pm (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
(pprof) top
Showing nodes accounting for 10.04GB, 100% of 10.04GB total
flat flat% sum% cum cum%
10.04GB 100% 100% 10.04GB 100% main.Add
0 0% 100% 10.04GB 100% main.main.func1
(pprof)
- inuse_space: 常驻内存占用情况
- alloc_objects: 内存临时分配情况
查看堆栈调用信息
go tool pprof http://localhost:6060/debug/pprof/heap
# 如果需要下载对应的图片,只需要在后面添加png即可,例如获取heap的图片
go tool pprof -png http://localhost:6060/debug/pprof/heap > heap.png
以上命令转化为图看的
查看 30 秒内的 CPU 信息
go tool pprof http://localhost:6060/debug/pprof/profile # 30-second CPU profile
go tool pprof http://localhost:6060/debug/pprof/profile?seconds=120 # 等待120s
# 同理
go tool pprof -png http://localhost:6060/debug/pprof/profile > profile.png # 转化为图
查看 goroutine 阻塞
go tool pprof http://localhost:6060/debug/pprof/block
收集 5 秒内的执行路径
go tool pprof http://localhost:6060/debug/pprof/trace?seconds=5
争用互斥持有者的堆栈跟踪
go tool pprof http://localhost:6060/debug/pprof/mutex
查看 goroutine profile
go tool pprof http://localhost:6060/debug/pprof/goroutine # goroutine profile
Pprof 分析goroutine泄漏
每1秒创建一个goroutine,每个goroutine分配1M内存,本来内存在goroutine退出以后会自动释放,不存在泄漏的问题,但是由于outCh只有写入没有读取导致channel写入阻塞,整个goroutine也阻塞在37行,进而导致对应分配的内存没有释放,形成内存泄漏
package main
import (
"fmt"
"net/http"
_ "net/http/pprof"
"os"
"time"
)
func main() {
go func() {
ip := "0.0.0.0:6060"
if err := http.ListenAndServe(ip, nil); err != nil {
fmt.Printf("start pprof failed on %s\n", ip)
os.Exit(1)
}
}()
outCh := make(chan int)
stime := time.Now()
// 每1s个goroutine
for {
time.Sleep(1 * time.Second)
go alloc(outCh)
fmt.Printf("last: %dseconds\n", int(time.Now().Sub(stime).Seconds()))
}
}
// alloc分配1M内存,goroutine会阻塞,不释放内存,导致泄漏
func alloc(outCh chan<- int) {
buf := make([]byte, 1024*1024*1)
_ = len(buf)
fmt.Println("alloc make buffer done")
outCh <- 0 // 36行
fmt.Println("alloc finished")
}
go tool pprof -png http://localhost:6060/debug/pprof/goroutine > goroutine.png
从图中看出,有101个goroutine累积了
不过上面的demo太简单了,如果去获取内存profile,几乎获取不到啥。以下demo更好的说明
// 展示内存增长和pprof,并不是泄露
package main
import (
"fmt"
"net/http"
_ "net/http/pprof"
"os"
"time"
)
// 运行一段时间:fatal error: runtime: out of memory
func main() {
// 开启pprof
go func() {
ip := "0.0.0.0:6060"
if err := http.ListenAndServe(ip, nil); err != nil {
fmt.Printf("start pprof failed on %s\n", ip)
os.Exit(1)
}
}()
tick := time.Tick(time.Second / 100)
var buf []byte
for range tick {
buf = append(buf, make([]byte, 1024*1024)...)
}
}
输入
go tool pprof http://10.171.6.230 :8100/debug/pprof/heap
go tool pprof http://localhost:6060/debug/pprof/heap
Fetching profile over HTTP from http://localhost:6060/debug/pprof/heap
Saved profile in /Users/youzeliang/pprof/pprof.alloc_objects.alloc_space.inuse_objects.inuse_space.003.pb.gz //<--- 下载到的内存profile文件
Type: inuse_space
Time: Jun 26, 2023 at 11:00pm (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
(pprof) help // 使用help打印所有可用命令
Commands:
callgrind Outputs a graph in callgrind format
comments Output all profile comments
disasm Output assembly listings annotated with samples
dot Outputs a graph in DOT format
eog Visualize graph through eog
evince Visualize graph through evince
gif Outputs a graph image in GIF format
gv Visualize graph through gv
kcachegrind Visualize report in KCachegrind
list Output annotated source for functions matching regexp
pdf Outputs a graph in PDF format
peek Output callers/callees of functions matching regexp
png Outputs a graph image in PNG format
proto Outputs the profile in compressed protobuf format
ps Outputs a graph in PS format
raw Outputs a text representation of the raw profile
svg Outputs a graph in SVG format
tags Outputs all tags in the profile
text Outputs top entries in text form
top Outputs top entries in text form
topproto Outputs top entries in compressed protobuf format
traces Outputs all profile samples in text form
tree Outputs a text rendering of call graph
web Visualize graph through web browser
weblist Display annotated source in a web browser
o/options List options and their current values
q/quit/exit/^D Exit pprof
Options:
最常用的:top、list、traces
输入 top
按指标大小列出前10个函数,比如内存是按内存占用多少,CPU是按执行时间多少。
(pprof) top
Showing nodes accounting for 213.25MB, 100% of 213.25MB total
flat flat% sum% cum cum%
213.25MB 100% 100% 213.25MB 100% main.main
0 0% 100% 213.25MB 100% runtime.main
top会列出5个统计数据:
- flat: 本函数占用的内存量。
- flat%: 本函数内存占使用中内存总量的百分比。
- sum%: 前面每一行flat百分比的和,比如第2行虽然的100% 是 100% + 0%。
- cum: 是累计量,加入main函数调用了函数f,函数f占用的内存量,也会记进来。
- cum%: 是累计量占总量的百分比。
list
查看某个函数的代码,以及该函数每行代码的指标信息,如果函数名不明确,会进行模糊匹配,比如list main会列出main.main和runtime.main。
(pprof) list main.main // 精确列出函数
Total: 213.25MB
ROUTINE ======================== main.main in /Users/youzeliang/go/src/github.com/youzeliang/goalgorithm/base/pprof/p2/main.go
213.25MB 213.25MB (flat, cum) 100% of Total
. . 13:func main() {
. . 14: // 开启pprof
. . 15: go func() {
. . 16: ip := "0.0.0.0:6060"
. . 17: if err := http.ListenAndServe(ip, nil); err != nil {
. . 18: fmt.Printf("start pprof failed on %s\n", ip)
. . 19: os.Exit(1)
. . 20: }
. . 21: }()
. . 22:
. . 23: tick := time.Tick(time.Second / 100)
. . 24: var buf []byte
. . 25: for range tick {
213.25MB 213.25MB 26: buf = append(buf, make([]byte, 1024*1024)...)
. . 27: }
. . 28:}
可以看到在main.main中的第26行占用了213.25MB内存,左右2个数据分别是flat和cum,含义和top中解释的一样。
traces
打印所有调用栈,以及调用栈的指标信息。
(pprof) traces
Type: inuse_space
Time: Jun 26, 2023 at 11:00pm (CST)
-----------+-------------------------------------------------------
0 main.main
runtime.main
-----------+-------------------------------------------------------
bytes: 213.25MB
213.25MB main.main
runtime.main
-----------+-------------------------------------------------------
bytes: 170.59MB
0 main.main
runtime.main
-----------+-------------------------------------------------------
bytes: 136.47MB
0 main.main
runtime.main
-----------+-------------------------------------------------------
bytes: 109.17MB
0 main.main
runtime.main
-----------+-------------------------------------------------------
bytes: 87.34MB
0 main.main
runtime.main
-----------+-------------------------------------------------------
runtime.main调用了main.main,并且main.main中占用了213.25MB内存。
当然也还可以 用
# 也可使用goroutine
go tool pprof http://localhost:6060/debug/pprof/heap
再生成一下,然后 用
go tool pprof -base pprof.alloc_objects.alloc_space.inuse_objects.inuse_space.001.pb.gz pprof.alloc_objects.alloc_space.inuse_objects.inuse_space.002.pb.gz
其来对比
如果在本机,也可这样
package main
import (
"log"
"net/http"
_ "net/http/pprof"
"time"
)
func main() {
go func() {
log.Fatal(http.ListenAndServe(":6060", nil))
}()
var data [][]byte
for {
data = func1(data)
time.Sleep(1 * time.Second)
}
}
func func1(data [][]byte) [][]byte {
data = func2(data)
return append(data, make([]byte, 1024*1024)) // alloc 1mb
}
func func2(data [][]byte) [][]byte {
return append(data, make([]byte, 1024*1024)) // alloc 1mb
}
go tool pprof -http=":6061" localhost:6060/debug/pprof/heap
Go Heap Top
- Name 列表示相应的函数名
- Flat 列表示该函数自身分配了多少内存
- Flat% 列表示 Flat 相对总分配大小的占比
- Cum 列表示该函数, 及其调用的所有子函数 一共分配了多少内存
- Cum% 列表示 Cum 相对总分配大小的占比
Sum% 列表示自上而下 Flat% 的累加(可以直观的判断出从哪一行往上一共分配的多少内存) 上述两种方式可以帮助定位到具体的函数,Go 提供了更细粒度的代码行数级别的分配源统计,在左上角 View 栏下拉点击 Source:
在左上角 View 栏下拉点击 Source:
Go Heap Source
在 CPU Profiling 中我们常用火焰图找宽顶来快速直观地定位热点函数。当然,由于数据模型的同质性,Heap Profiling 数据也可以通过火焰图来展现,在左上角 View 栏下拉点击 Flame Graph:
退出,这种情况就是goroutine泄露。
goroutine执行过程中还存在一些变量,如果这些变量指向堆内存中的内存,GC会认为这些内存仍在使用,不会对其进行回收,这些内存谁都无法使用,造成了内存泄露。
所以goroutine泄露有2种方式造成内存泄露:
- goroutine本身的栈所占用的空间造成内存泄露。
- goroutine中的变量所占用的堆内存导致堆内存泄露,这一部分是能通过heap profile体现出来的。
Dave在文章中也提到了,如果不知道何时停止一个goroutine,这个goroutine就是潜在的内存泄露:
7.1.1 Know when to stop a goroutine
If you don’t know the answer, that’s a potential memory leak as the goroutine will pin its stack’s memory on the heap, as well as any heap allocated variables reachable from the stack.
怎么确定是goroutine泄露引发的内存泄露
判断依据:在节点正常运行的情况下,隔一段时间获取goroutine的数量,如果后面获取的那次,某些goroutine比前一次多,如果多获取几次,是持续增长的,就极有可能是goroutine泄露。
// goroutine泄露导致内存泄露
package main
import (
"fmt"
"net/http"
_ "net/http/pprof"
"os"
"time"
)
func main() {
// 开启pprof
go func() {
ip := "0.0.0.0:6060"
if err := http.ListenAndServe(ip, nil); err != nil {
fmt.Printf("start pprof failed on %s\n", ip)
os.Exit(1)
}
}()
outCh := make(chan int)
// 死代码,永不读取
go func() {
if false {
<-outCh
}
select {}
}()
// 每s起100个goroutine,goroutine会阻塞,不释放内存
tick := time.Tick(time.Second / 100)
i := 0
for range tick {
i++
fmt.Println(i)
alloc1(outCh)
}
}
func alloc1(outCh chan<- int) {
go alloc2(outCh)
}
func alloc2(outCh chan<- int) {
func() {
defer fmt.Println("alloc-fm exit")
// 分配内存,假用一下
buf := make([]byte, 1024*1024*10)
_ = len(buf)
fmt.Println("alloc done")
outCh <- 0 // 53行
}()
}
编译并运行以上代码,然后使用go tool pprof获取gorourine的profile文件。
go tool pprof http://localhost:6060/debug/pprof/goroutine
然后查看
go tool pprof pprof.goroutine.001.pb.gz
是可以很明显的看出来有很多goroutine被挂起的
所以接下来就要定位goroutine泄漏的地方了
定位goroutine泄露的2种方法
Web可视化查看
方式一
http://ip:port/debug/pprof/goroutine?debug=1
![image.png](https://
bbs-img.huaweicloud.com/blogs/img/20231116/1700144668177121524.png)
以上图 goroutine profile: total 1788 就是总的协程的数量
紧接着 后面就是跟的调用栈、代码行数
根据上面的提示,就能判断1788个goroutine运行到lmain.go的53行:
阻塞的原因是outCh这个写操作无法完成,outCh是无缓冲的通道,并且由于以下代码是死代码,所以goroutine始终没有从outCh读数据,造成outCh阻塞,进而造成无数个alloc2的goroutine阻塞,形成内存泄露:
方式二
url请求中设置debug=2:
http://ip:port/debug/pprof/goroutine?debug=2
第2种方式和第1种方式是互补的,它可以看到每个goroutine的信息:
- goroutine 后面的数字是id []中是当前goroutine的状态,阻塞在写channel,并且阻塞了2分钟,长时间运行的系统,能看到阻塞时间更长的情况。
- 同时,也可以看到调用栈,看当前执行停到哪了:main.go的53行
命令行交互式方法
Web的方法是简单粗暴,无需登录服务器,浏览器打开看看就行了。但就像前面提的,没有浏览器可访问时,命令行交互式才是最佳的方式,并且也是手到擒来,感觉比Web一样方便。
命令行交互式只有1种获取goroutine profile的方法,不像Web网页分debug=1和debug=22中方式,并将profile文件保存到本地:
**使用list命令的前提是程序的源码在当前机器,不然可没法列出源码。**服务器上,通常没有源码,那咋办呢?刚才介绍了Web查看的方式,那里会列出代码行数,我们可以使用wget下载网页:
wget http://localhost:6060/debug/pprof/goroutine?debug=1
下载网页后,使用编辑器打开文件,使用关键字main.alloc2.func1进行搜索,找到与当前相同的调用栈,就可以看到该goroutine阻塞在哪一行了,不要忘记使用debug=2还可以看到阻塞了多久和原因,Web方式中已经介绍了,此处省略代码几十行。
总结
goroutine泄露的本质
- goroutine泄露的本质是channel阻塞,无法继续向下执行,导致此goroutine关联的内存都无法释放,进一步造成内存泄露。goroutine泄露的发现和定位
- 利用好go pprof获取goroutine profile文件,然后利用3个命令top、traces、list定位内存泄露的原因。goroutine泄露的场景
泄露的场景不仅限于以下两类,但因channel相关的泄露是最多的。
- channel的读或者写:
- 无缓冲channel的阻塞通常是写操作因为没有读而阻塞
- 有缓冲的channel因为缓冲区满了,写操作阻塞
- 期待从channel读数据,结果没有goroutine写
- select操作,select里也是channel操作,如果所有case上的操作阻塞,goroutine也无法继续执行。编码goroutine泄露的建议
为避免goroutine泄露造成内存泄露,启动goroutine前要思考清楚:
- goroutine如何退出?
- 是否会有阻塞造成无法退出?如果有,那么这个路径是否会创建大量的goroutine?
Dave的《High Performance Go Workshop》
Dave讲了以下几点:
- 内存profiling记录的是堆内存分配的情况,以及调用栈信息,并不是进程完整的内存情况,猜测这也是在go pprof中称为heap而不是memory的原因。
- 栈内存的分配是在调用栈结束后会被释放的内存,所以并不在内存profile中。
- 内存profiling是基于抽样的,默认是每1000次堆内存分配,执行1次profile记录。
- 因为内存profiling是基于抽样和它跟踪的是已分配的内存,而不是使用中的内存,(比如有些内存已经分配,看似使用,但实际以及不使用的内存,比如内存泄露的那部分),所以不能使用内存profiling衡量程序总体的内存使用情况。
- Dave个人观点:使用内存profiling不能够发现内存泄露。
排查思路总结
今后遇到 golang 内存泄漏问题可以按照以下几步进行排查解决:
- 观察服务器实例,查看内存使用情况,确定内存泄漏问题;
- 判断 goroutine 问题;
- 这里可以使用 1 中提到的监控来观察 goroutine 数量,也可以使用 pprof 进行采样判断,判断 goroutine 数量是否出现了异常增长。
- 判断代码问题;
- 利用 pprof,通过函数名称定位具体代码行数,可以通过 pprof 的 graph、source 等手段去定位;
- 排查整个调用链是否出现了上述场景中的问题,如 select 阻塞、channel 阻塞、slice 使用不当等问题,优先考虑自身代码逻辑问题,其次考虑框架是否存在不合理地方;
- 解决对应问题并在测试环境中观察,通过后上线进行观察;
- pprof: 是 Go 语言中分析程序运行性能的工具,它能提供各种性能数据包括 cpu、heap、goroutine 等等,可以通过报告生成、Web 可视化界面、交互式终端 三种方式来使用 pprof
参考
- 点赞
- 收藏
- 关注作者
评论(0)