pprof是Go的效能分析工具,在程式運行過程中,可以記錄程式的運行信息,可以是CPU使用情況、記憶體使用情況、goroutine運行等,當需要效能調優或定位Bug時候,這些記錄的資訊是相當重要。使用pprof有多種方式,Go已經現成封裝好了1個“net/http/pprof”,使用簡單的幾行命令,就可以開啟pprof,記錄運行信息,並且提供了Web服務。
本教學操作環境:windows7系統、GO 1.18版本、Dell G3電腦。
profile 一般稱為效能分析,字典上的翻譯是概況(名詞)或是描述…的概況(動詞)。對於計算機程式來說,它的 profile,就是一個程式在運行時的各種概況信息,包括 cpu 佔用情況,內存情況,線程情況,線程阻塞情況等等。知道了程式的這些訊息,也就能容易的定位程式中的問題和故障原因 。
pprof是Go的效能分析工具,在程式運行過程中,可以記錄程式的運行信息,可以是CPU使用情況、記憶體使用情況、goroutine運行等,當需要效能調優或定位Bug時候,這些記錄的資訊是相當重要。
golang 對於profiling 支援的比較好,標準函式庫提供了profile庫“runtime/pprof” 和“net/http/pprof”,而且也提供了很多好用的視覺化工具來輔助開發者做profiling。
對於線上服務,對於一個 HTTP Server,存取 pprof 提供的 HTTP 接口,取得效能資料。當然,實際上這裡底層也是呼叫的 runtime/pprof 提供的函數,封裝成介面對外提供網路訪問,本文主要介紹"net/http/pprof"的使用。
使用pprof有多種方式,Go已經現成封裝好了1個:net/http/pprof,使用簡單的幾行命令,就可以開啟pprof,記錄運行信息,並且提供了Web服務,能夠透過瀏覽器和命令列2種方式獲取運行數據。
web服務中如何開啟監控,來看一個簡單的範例。
package main import ( "fmt" "net/http" _ "net/http/pprof" ) func main() { // 开启pprof,监听请求 ip := "0.0.0.0:8080" if err := http.ListenAndServe(ip, nil); err != nil { fmt.Printf("start pprof failed on %s\n", ip) } dosomething() }
在程式中導入 "net/http/pprof"包,並打開監聽端口,這時候便可以獲取程式的profile,在實際生產中,我們一般將這個功能封裝成一個goroutine。那麼開啟之後該如何查看呢?有三種方式:
#開啟一個瀏覽器輸入ip:port/debug/pprof,回車。
pprof會提供很多效能資料。具體意義為:
allocs是所有物件的記憶體分配,heap是活躍物件的記憶體分配,後文會有詳細的描述。
1、當 CPU 效能分析啟用後,Go runtime 會每 10ms 就暫停一下,記錄目前執行的 goroutine 的呼叫堆疊及相關資料。當效能分析資料儲存到硬碟後,我們就可以分析程式碼中的熱點了。
2、記憶體效能分析則是在堆(Heap)分配的時候,記錄一下呼叫堆疊。預設情況下,每 1000 次分配,取樣一次,這個數值可以改變。棧(Stack)分配 由於隨時會釋放,因此不會被記憶體分析所記錄。由於內存分析是取樣方式,並且也因為其記錄的是分配內存,而不是使用內存。因此使用記憶體效能分析工具來準確判斷程式具體的記憶體使用量是比較困難的。
3、阻塞分析是一個很獨特的分析,它有點類似 CPU 效能分析,但是它所記錄的是 goroutine 等待資源所花的時間。阻塞分析對分析程式並發瓶頸非常有幫助,阻塞效能分析可以顯示出何時出現了大批的 goroutine 被阻塞了。阻塞效能分析是特殊的分析工具,在排除 CPU 和記憶體瓶頸前,不應該用它來分析。
當然,如果你點進任何一個鏈接,便會發現,可讀性差,幾乎無法分析。如圖:
點擊heap,拉到最底部,可以看到一些有趣的數據,有時候也有可能會對問題排查有幫助,但一般不用。
heap profile: 3190: 77516056 [54762: 612664248] @ heap/1048576 1: 29081600 [1: 29081600] @ 0x89368e 0x894cd9 0x8a5a9d 0x8a9b7c 0x8af578 0x8b4441 0x8b4c6d 0x8b8504 0x8b2bc3 0x45b1c1 # 0x89368d github.com/syndtr/goleveldb/leveldb/memdb.(*DB).Put+0x59d # 0x894cd8 xxxxx/storage/internal/memtable.(*MemTable).Set+0x88 # 0x8a5a9c xxxxx/storage.(*snapshotter).AppendCommitLog+0x1cc # 0x8a9b7b xxxxx/storage.(*store).Update+0x26b # 0x8af577 xxxxx/config.(*config).Update+0xa7 # 0x8b4440 xxxxx/naming.(*naming).update+0x120 # 0x8b4c6c xxxxx/naming.(*naming).instanceTimeout+0x27c # 0x8b8503 xxxxx/naming.(*naming).(xxxxx/naming.instanceTimeout)-fm+0x63 ...... # runtime.MemStats # Alloc = 2463648064 # TotalAlloc = 31707239480 # Sys = 4831318840 # Lookups = 2690464 # Mallocs = 274619648 # Frees = 262711312 # HeapAlloc = 2463648064 # HeapSys = 3877830656 # HeapIdle = 854990848 # HeapInuse = 3022839808 # HeapReleased = 0 # HeapObjects = 11908336 # Stack = 655949824 / 655949824 # MSpan = 63329432 / 72040448 # MCache = 38400 / 49152 # BuckHashSys = 1706593 # GCSys = 170819584 # OtherSys = 52922583 # NextGC = 3570699312 # PauseNs = [1052815 217503 208124 233034 ......] # NumGC = 31 # DebugGC = false
除了浏览器,Go还提供了命令行的方式,能够获取以上信息,这种方式用起来更方便。
使用命令go tool pprof url
可以获取指定的profile文件,此命令会发起http请求,然后下载数据到本地,之后进入交互式模式,就像gdb一样,可以使用命令查看运行信息,以下为使用示例:
# 下载cpu profile,默认从当前开始收集30s的cpu使用情况,需要等待30s go tool pprof http://localhost:8080/debug/pprof/profile # 30-second CPU profile go tool pprof http://localhost:8080/debug/pprof/profile?seconds=120 # wait 120s # 下载heap profile go tool pprof http://localhost:8080/debug/pprof/heap # heap profile # 下载goroutine profile go tool pprof http://localhost:8080/debug/pprof/goroutine # goroutine profile # 下载block profile go tool pprof http://localhost:8080/debug/pprof/block # goroutine blocking profile # 下载mutex profile go tool pprof http://localhost:8080/debug/pprof/mutex
接下来用一个例子来说明最常用的四个命令:web、top、list、traces
。
接下来以内存分析举例,cpu和goroutine等分析同理,读者可以自行举一反三。
首先,我们通过命令go tool pprof url
获取指定的profile/heap文件,随后自动进入命令行。如图:
第一步,我们首先输入web
命令,这时浏览器会弹出各个函数之间的调用图,以及内存的之间的关系。如图:
这个图的具体读法,可参照:中文文档 或者英文文档 这里不多赘述。只需要了解越红越大的方块,有问题的可能性就越大,代表可能占用了更多的内存,如果在cpu的图中代表消耗了更多cpu资源,以此类推。
接下来 top、list、traces
三步走可以看出很多想要的结果。
top 按指标大小列出前10个函数,比如内存是按内存占用多少,CPU是按执行时间多少。
top会列出5个统计数据:
cum%: 是累计量占总量的百分比。
这样我们可以看到到底是具体哪些函数占用了多少内存。
当然top后也可以接参数,top n
可以列出前n个函数。
list可以查看某个函数的代码,以及该函数每行代码的指标信息,如果函数名不明确,会进行模糊匹配,比如list main
会列出main.main
和runtime.main
。现在list sendToASR
试一下。
可以看到切片中增加元素时,占用了很多内存,左右2个数据分别是flat和cum。
traces 打印所有调用栈,以及调用栈的指标信息。使用方式为traces+函数名
(模糊匹配)。
在命令行之中,还有一个重要的参数 -base
,假设我们已经通过命令行得到profile1与profile2,使用go tool pprof -base profile1 profile2
,便可以以profile1为基础,得出profile2在profile1之上出现了哪些变化。通过两个时间切片的比较,我们可以清晰的了解到,两个时间节点之中发生的变化,方便我们定位问题(很重要!!!!)
打开可视化界面的方式为:go tool pprof -http=:1234 http://localhost:8080/debug/pprof/heap
其中1234是我们指定的端口
Top
该视图与前面所讲解的 top 子命令的作用和含义是一样的,因此不再赘述。
Graph
为函数调用图,不在赘述.
Peek
此視圖相較於Top 視圖,增加了所屬的上下文資訊的展示,也就是函數的輸出呼叫者/被呼叫者。
Source
這個視圖主要是增加了面向原始程式碼的追蹤和分析,可以看到其開銷主要消耗在哪裡。
Flame Graph
#對應資源消耗的火焰圖,火焰圖的讀法,這裡不贅述,不是本文的重點。
第二個下拉式選單如圖所示:
alloc_objects,alloc_space
表示應用程式指派過的資源,不管有沒有釋放,inuse_objects,inuse_space
表示應用程式的尚未釋放的資源常配情況。
Name | Meaning |
---|---|
#inuse_space | amount of memory allocated and not released yet |
inuse_objects | amount of objects allocated and not released yet |
alloc_space | #total amount of memory allocated (regardless of released) |
alloc_objects | total amount of objects allocated (regardless of released) |
第一个下拉菜单可以与第二个下拉菜单相组合,可以查看临时变量的火焰图,常驻变量的内存调用图等。
tips:
上面我们已经看完了go pprof 的所有操作,接下来讲解一下go tool pprof 的具体使用流程。
go tool pprof -base
比较两个不同时间点的状态更方便我们定位问题。启动程序后,用浏览器方式打开profile:
发现内存持续上升,同时goroutine也在持续上升,初步判断,内存泄漏是由于goroutine泄漏导致的。
接下来通过命令行方式抓取goroutine的情况:命令行输入:go tool pprof localhost:8080/debug/pprof/goroutine
,获取结果。
一、使用web命令查看调用图,大概了解目前的goroutine的泄露情况:
通过观察,最引入注目的便是runtime.gopark这个函数,这个函数在所有goroutine泄漏时都会出现,并且是大头,接下来我们研究一下这个函数的作用:
func gopark(unlockf func(*g, unsafe.Pointer) bool, lock unsafe.Pointer, reason waitReason, traceEv byte, traceskip int) { mp := acquirem() gp := mp.curg status := readgstatus(gp) mp.waitlock = lock mp.waitunlockf = unlockf gp.waitreason = reason mp.waittraceev = traceEv mp.waittraceskip = traceskip releasem(mp) mcall(park_m) }
该函数的作用为:
1、调用acquirem
函数:获取当前goroutine所绑定的m,设置各类所需参数。调用 releasem
函数将当前 goroutine 和其 m 的绑定关系解除。
2、调用 park_m
函数:将当前 goroutine 的状态从 _Grunning 切换为 _Gwaiting,也就是等待状态。删除 m 和当前 goroutine m→curg(简称gp)之间的关联。
3、调用 mcall
函数,仅会在需要进行 goroutiine 切换时会被调用:切换当前线程的堆栈,从 g 的堆栈切换到 g0 的堆栈并调用 fn(g) 函数。将 g 的当前 PC/SP 保存在 g->sched 中,以便后续调用 goready 函数时可以恢复运行现场。
综上:该函数的关键作用就是将当前的 goroutine 放入等待状态,这意味着 goroutine 被暂时被搁置了,也就是被运行时调度器暂停了。
所以出现goroutine泄漏一定会调用这个函数,这个函数不是goroutine泄漏的原因,而是goroutine泄漏的结果。
此外,我们发现有两个函数的goroutine的达到了67,很可疑,在我们接下来的验证中要格外留意。
二、使用top命令,获取更加具体的函数信息:
与上面分析的结论相似,我们要将关注点放在三个开启了67个goroutine的函数。
三、traces+函数名
,查看调用栈,这一步在函数调用很复杂,无法从调用图里面清晰的看出时使用,帮助我们更清晰的了解函数的调用堆栈:
四、使用list+函数名,查看具体代码的问题。
通过list命令我们可以清楚的看出问题代码是堵塞在哪里。接下来的篇幅我们来分析一下这个问题:
什么是goroutine泄漏:如果你启动了一个 goroutine,但并没有符合预期的退出,直到程序结束,此goroutine才退出,这种情况就是 goroutine 泄露。当 goroutine 泄露发生时,该 goroutine 的栈(一般 2k 内存空间起)一直被占用不能释放,goroutine 里的函数在堆上申请的空间也不能被 垃圾回收器 回收。这样,在程序运行期间,内存占用持续升高,可用内存越来也少,最终将导致系统崩溃。
什么时候出现goroutine泄漏:goroutine泄露一般是因为channel操作阻塞而导致整个routine一直阻塞等待或者 goroutine 里有死循环。
具体细分一下:
select底层也是channel实现的,如果所有case上的操作阻塞,select内部的channel便会阻塞,goroutine也无法继续执行。所以我们使用channel时一定要格外小心。
通过分析上面两幅图的情况,可以判断是因为select在所有case上死锁了,再深入代码分析,是因为项目中的的语音模型并发能力弱,在语音发包速度快起来的时候无法处理,导致select不满足条件,导致goroutine泄漏,应该在for循环之外加一个asr←nil
,保证func2的select一定会满足,同时提高模型的并发能力,使得func1的不会阻塞。
防止goroutine泄漏的建议:
我们通过grafana发现内存出现泄漏:
这一次我们不使用命令行,而是使用图形化界面来定位问题。
输入 go tool pprof -http=:1234 localhost:8080/debug/pprof/heap
:
发现内存占用很有可能是byte.makeSlice()
导致的,火焰图看的更加清晰:
而调用byte.makeSlice()
的函数为标准库中的ioutil.ReadAll()
,接下来我们只需要研究这个标准库函数的实现即可。
func readAll(r io.Reader, capacity int64) (b []byte, err error) { buf := bytes.NewBuffer(make([]byte, 0, capacity)) defer func() { e := recover() if e == nil { return } if panicErr, ok := e.(error); ok && panicErr == bytes.ErrTooLarge { err = panicErr } else { panic(e) } }() _, err = buf.ReadFrom(r) return buf.Bytes(), err } // bytes.MinRead = 512 func ReadAll(r io.Reader) ([]byte, error) { return readAll(r, bytes.MinRead) }
可以看到 ioutil.ReadAll
每次都会分配初始化一个大小为 bytes.MinRead 的 buffer ,bytes.MinRead 在 Golang 里是一个常量,值为 512 。就是说每次调用 ioutil.ReadAll 都先会分配一块大小为 512 字节的内存。
接下来看一下ReadFrom
函数的实现:
func (b *Buffer) ReadFrom(r io.Reader) (n int64, err error) { b.lastRead = opInvalid // If buffer is empty, reset to recover space. if b.off >= len(b.buf) { b.Truncate(0) } for { if free := cap(b.buf) - len(b.buf); free < MinRead { // not enough space at end newBuf := b.buf if b.off+free < MinRead { // not enough space using beginning of buffer; // double buffer capacity newBuf = makeSlice(2*cap(b.buf) + MinRead) } copy(newBuf, b.buf[b.off:]) b.buf = newBuf[:len(b.buf)-b.off] b.off = 0 } m, e := r.Read(b.buf[len(b.buf):cap(b.buf)]) b.buf = b.buf[0 : len(b.buf)+m] n += int64(m) if e == io.EOF { break } if e != nil { return n, e } } return n, nil // err is EOF, so return nil explicitly }
ReadFrom
函数主要作用就是从 io.Reader 里读取的数据放入 buffer 中,如果 buffer 空间不够,就按照每次 2x + MinRead 的算法递增,这里 MinRead 的大小也是 512 Bytes 。
项目读取的音频文件一般很大,buffer不够用,会一直调用makeSlice
扩容,消耗大量内存,但是仅仅这样,只是程序执行时消耗了比较多的内存,并未有内存泄露的情况,那服务器又是如何内存不足的呢?这就不得不扯到 Golang 的 GC 机制。
GC算法的触发时机
golang的GC算法为三色算法,按理说会回收临时变量,但是触发GC的时机导致了这个问题:
ioutil.ReadAll
会将全部的数据加载到内存,一个大请求会多次调用makeSlice
分配很多内存空间,并发的时候,会在很短时间内占用大量的系统内存,然后将 GC 阈值增加到一个很高的值,这个时候要 GC 就只有等 2 分钟一次的强制 GC。这样内存中的数据无法及时GC,同时阈值还在不停的升高,导致GC的效率越来越低,最终导致缓慢的内存泄漏。
解决方法
//req.AduioPack,err=ioutil.ReadAll(c.Resquest.Body) buffer:=bytes.NewBuffer(make[]byte,0,6400) _,err:=io.Copy(buffer,c.Resquest.Body) temp:=buffer.Bytes() req.AduioPack=temp
不是一次性把文件读入内存,而是申请固定的内存大小。
以上是go pprof是什麼的詳細內容。更多資訊請關注PHP中文網其他相關文章!