1. 程式人生 > 其它 >golang 效能分析

golang 效能分析

1. 效能分析

golang 自身提供的工具中包括效能分析工具 - pprof。

  • runtime/pprof:採集器,負責採集應用程式的執行資料供給 pprof 視覺化工具
  • net/http/pprof:通過一個 HTTP Server 將 prof 資料進行視覺化分析。

golang 內建提供了多種效能收集器,它們負責收集這些效能資料:

  • Goroutine: stack traces of all current Goroutines。Go Routine 分析。
  • CPU: stack traces of CPU returned by runtime。CPU 分析。按照一定的頻率採集所監聽的應用程式 CPU(含暫存器)的使用情況,可確定應用程式在主動消耗 CPU 週期時花費時間的位置
  • Heap: a sampling of memory allocations of live objects。記憶體分析,在應用程式進行堆分配時記錄堆疊跟蹤,用於監視當前和歷史記憶體使用情況,以及檢查記憶體洩漏
  • Allocation: a sampling of all past memory allocations。記憶體分析,物件分配統計以及記憶體洩漏等。
  • Thread: stack traces that led to the creation of new OS threads。OS 執行緒建立情況。
  • Block: stack traces that led to blocking on synchronization primitives。阻塞分析。記錄 go routine 阻塞情況,等待以及同步情況,timer/channel 通訊等各項細節。
  • Mutex: stack traces of holders of contended mutexes。互斥鎖分析。包括各種競爭情況。

2. pprof工具分析

(1.)通過在main函式中新增效能監控

package main

import 	(
  _ "net/http/pprof" // 引入 pprof 模組
  _ "github.com/mkevac/debugcharts"  // 可選,圖形化外掛
)

func main(){
    // ...
    // 記憶體分析
	go func() {
		http.ListenAndServe("0.0.0.0:8090", nil) // 監控埠
	}()
    // ...
}

"net/http/pprof" 包將會自動地新增一組 api 端點,該包的 init 函式會做這些事:

func init() {
	http.HandleFunc("/debug/pprof/", Index)
	http.HandleFunc("/debug/pprof/cmdline", Cmdline)
	http.HandleFunc("/debug/pprof/profile", Profile)
	http.HandleFunc("/debug/pprof/symbol", Symbol)
	http.HandleFunc("/debug/pprof/trace", Trace)
}
2.1 web介面檢視

直接通過瀏覽器訪問http://localhost:8090/debug/pprof, 就會看到如下介面:

引數說明:

  • cpu(CPU Profiling): $HOST/debug/pprof/profile,預設進行 30s 的 CPU Profiling,得到一個分析用的 profile 檔案
  • block(Block Profiling):$HOST/debug/pprof/block,檢視導致阻塞同步的堆疊跟蹤
  • goroutine:$HOST/debug/pprof/goroutine,檢視當前所有執行的 goroutines 堆疊跟蹤
  • heap(Memory Profiling): $HOST/debug/pprof/heap,檢視活動物件的記憶體分配情況
  • mutex(Mutex Profiling):$HOST/debug/pprof/mutex,檢視導致互斥鎖的競爭持有者的堆疊跟蹤
  • threadcreate:$HOST/debug/pprof/threadcreate,檢視建立新OS執行緒的堆疊跟蹤

說明:如果引用了github.com/mkevac/debugcharts 包,可以訪問http://localhost:8090/ui實時的檢視到記憶體和CPU以及GC的執行情況。

2.2 命令列互動

(1.)CPU分析

go tool pprof http://localhost:6060/debug/pprof/profile\?seconds\=60

Fetching profile over HTTP from http://localhost:6060/debug/pprof/profile?seconds=60
Saved profile in /Users/eddycjy/pprof/pprof.samples.cpu.007.pb.gz
Type: cpu
Duration: 1mins, Total samples = 26.55s (44.15%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) 

通過輸入 top10 即可檢視CPU佔用前10的函式。通過list func_name 可以檢視具體函式佔用的cpu情況。通過輸入pdf 可以匯出為pdf檔案進行分析。通過輸入web 可以生成svg檔案,這裡需要提前安裝graphviz 程式。 也可以使用tree 顯示呼叫結構和佔用cpu,記憶體的百分比。使用traces 可以列印所有呼叫棧,以及呼叫棧的指標資訊。help 命令列印所有的可用命令。

(pprof) top10
Showing nodes accounting for 25.92s, 97.63% of 26.55s total
Dropped 85 nodes (cum <= 0.13s)
Showing top 10 nodes out of 21
      flat  flat%   sum%        cum   cum%
    23.28s 87.68% 87.68%     23.29s 87.72%  syscall.Syscall
     0.77s  2.90% 90.58%      0.77s  2.90%  runtime.memmove
     0.58s  2.18% 92.77%      0.58s  2.18%  runtime.freedefer
     0.53s  2.00% 94.76%      1.42s  5.35%  runtime.scanobject
     0.36s  1.36% 96.12%      0.39s  1.47%  runtime.heapBitsForObject
     0.35s  1.32% 97.44%      0.45s  1.69%  runtime.greyobject
     0.02s 0.075% 97.51%     24.96s 94.01%  main.main.func1
     0.01s 0.038% 97.55%     23.91s 90.06%  os.(*File).Write
     0.01s 0.038% 97.59%      0.19s  0.72%  runtime.mallocgc
     0.01s 0.038% 97.63%     23.30s 87.76%  syscall.Write

引數說明:

  • flat:給定函式上執行耗時
  • flat%:同上的 CPU 執行耗時總比例
  • sum%:給定函式累積使用 CPU 總比例
  • cum:當前函式加上它之上的呼叫執行總耗時
  • cum%:同上的 CPU 執行耗時總比例

(2.)記憶體分析

go tool pprof http://localhost:8080/debug/pprof/heap

// 停掉後,過一分鐘後再次執行上述命令,使其生成兩個檔案,進行比較
go tool pprof -base pprof.demo2.alloc_objects.alloc_space.inuse_objects.inuse_space.001.pb.gz pprof.demo2.alloc_objects.alloc_space.inuse_objects.inuse_space.002.pb.gz

// 使用top命令檢視佔用較多的,再使用list檢視具體佔用情況

記憶體分析有幾個引數:

-alloc_objects 申請物件的記憶體佔用情況
-inuse_objects 在使用中的物件記憶體佔用情況
-inuse_space 使用中的記憶體空間

使用pprof的heap能夠獲取程式執行時的記憶體資訊,在程式平穩執行的情況下,每個一段時間使用heap獲取記憶體的profile,然後使用base能夠對比兩個profile檔案的差別,需要不斷的比較兩次的記憶體申請和佔用情況,關注哪些物件的申請不斷的增長,哪些物件在程式結束後,仍然在使用中,沒有釋放記憶體。

要點:

  • 記憶體profiling記錄的是堆記憶體分配的情況,以及呼叫棧資訊,並不是程序完整的記憶體情況
  • 棧記憶體的分配是在呼叫棧結束後會被釋放的記憶體,所以並不在記憶體profile中。
  • 記憶體profiling是基於抽樣的,預設是每1000次堆記憶體分配,執行1次profile記錄。
  • 因為記憶體profiling是基於抽樣和它跟蹤的是已分配的記憶體,而不是使用中的記憶體,(比如有些記憶體已經分配,看似使用,但實際以及不使用的記憶體,比如記憶體洩露的那部分),所以不能使用記憶體profiling衡量程式總體的記憶體使用情況。
  • 在進行堆分配時,記憶體分析會記錄呼叫棧跟蹤,棧分配被認為是無成本的,並且在記憶體 profile 中不被追蹤。
  • 使用記憶體profiling不能夠發現記憶體洩露
2.3 火焰圖

(1.) 安裝go-torch

# 下載並複製flamegraph.pl到/usr/local/bin下
git clone https://github.com/brendangregg/FlameGraph.git
cp FlameGraph/flamegraph.pl /usr/local/bin

# 安裝go-torch
go get -v github.com/uber/go-torch

(2.) 使用go-torch檢視

// 使用
go-torch -u http://10.11.209.102:9911 -t 30
go-torch -u http://10.0.2.15:6060 --suffix=/debug/pprof/block -p > torch.svg
go-torch cpu.prof  // top  list

3. 使用goland自帶的基準測試分析

goland2020版本,提供了基準測試,可以進行記憶體、CPU的分析:

如果golang版本較低,可能沒有自帶的執行按鈕,可以使用以下命令執行:

go test -cpuprofile cpu.prof -memprofile mem.prof -bench .

// 對生成的檔案,使用go tool進行分析
go tool pprof cpu.pprof
top10 -cum // 檢視top10佔用情況
list xxx // 檢視具體某個函式的記憶體

go tool pprof -http=":8080" cpu.pprof  // 使用web介面進行分析

4.自行寫指令碼檢視記憶體佔用情況

4.1 使用shell命令來實時檢視記憶體佔用情況

(1.)建立一個指令碼prog_mem.sh,獲取程序佔用的實體記憶體情況,也可以直接使用pidstat -r -p $pid 1, 這裡的pid是程式執行的程序id,表示每隔一秒列印一次記憶體使用情況。

vim prog_mem.sh
#!/bin/bash
prog_name="your_programe_name"
prog_mem=$(pidstat  -r -u -h -C $prog_name |awk 'NR==4{print $12}')
time=$(date "+%Y-%m-%d %H:%M:%S")
echo $time"    memory(Byte):"$prog_mem >>~/record/prog_mem.log

(2.) 使用crontab建立定時任務,每分鐘記錄1次.

crontab -e
*/1 * * * * /record/prog_mem.sh

(3.) 將輸出的日誌資訊prog_mem.log進行分析,可以使用視覺化工具進行檢視。

4.2 使用golang程式開啟記憶體、CPU採集

在要測試的程式碼段中呼叫該函式即可,需要傳輸生成檔案的路徑。由於生成的檔案為二進位制檔案,無法直接檢視,需要使用go tool pprof工具檢視,go tool pprof -http=:6060 cpu.prof.

func enableCpuProfile(cpuProfilePath string) (closer func()) {
	closer = func() {}
	if cpuProfilePath != "" {
		f, err := os.Create(cpuProfilePath)
		if err != nil {
			log.Fatal("could not create cpu profile: %v", err)
		}
		err = pprof.StartCPUProfile(f)
		if err != nil {
			log.Fatal("error: %v", err)
		}
		closer = pprof.StopCPUProfile
	}
	runtime.SetBlockProfileRate(20)
	return
}

func enableMemProfile(memProfilePath string) (closer func()) {
	closer = func() {}
	if memProfilePath != "" {
		closer = func() {
			f, err := os.Create(memProfilePath)
			if err != nil {
				log.Fatal("could not create memory profile: ", err)
			}
			defer f.Close()
			runtime.GC() // get up-to-date statistics
			if err := pprof.WriteHeapProfile(f); err != nil {
				log.Fatal("could not write memory profile: ", err)
			}
		}
	}
	return
}

也可以簡化程式,在main中加入這兩行程式碼,在程式退出時,會生成pprof檔案。

	# 這裡profile引用包:github.com/pkg/profile
	defer profile.Start(profile.CPUProfile).Stop()  // CPU
	defer profile.Start(profile.MemProfile).Stop()  // 記憶體
	defer profile.Start(profile.GoroutineProfile).Stop() // goroutine
	defer profile.Start(profile.BlockProfile).Stop()  // 阻塞
	defer profile.Start(profile.MutexProfile, profile.MemProfile).Stop()  // 合併寫法

5.常見的記憶體洩露

5.1 goroutine洩露

每個goroutine佔用2KB記憶體,洩露1百萬goroutine至少洩露2KB * 1000000 = 2GB記憶體。goroutine執行過程中還存在一些變數,如果這些變數指向堆記憶體中的記憶體,GC會認為這些記憶體仍在使用,不會對其進行回收,這些記憶體誰都無法使用,造成了記憶體洩露。

所以goroutine洩露有2種方式造成記憶體洩露:

  • goroutine本身的棧所佔用的空間造成記憶體洩露。
  • goroutine中的變數所佔用的堆記憶體導致堆記憶體洩露,這一部分是能通過heap profile體現出來的。

判斷依據:在節點正常執行的情況下,隔一段時間獲取goroutine的數量,如果後面獲取的那次,某些goroutine比前一次多,如果多獲取幾次,是持續增長的,就極有可能是goroutine洩露。

定位:

http://ip:port/debug/pprof/goroutine?debug=1  //檢視當前阻塞在此goroutine的數量
http://ip:port/debug/pprof/goroutine?debug=2  // 可以檢視goroutine阻塞的時長

總結:

goroutine洩露常見的場景是channel阻塞,無法繼續向下執行,導致此goroutine關聯的記憶體都無法釋放,進一步造成記憶體洩露。

channel的讀或者寫:

  • 無緩衝channel的阻塞通常是寫操作因為沒有讀而阻塞
  • 有緩衝的channel因為緩衝區滿了,寫操作阻塞
  • 期待從channel讀資料,結果沒有goroutine寫
  • select操作,select裡也是channel操作,如果所有case上的操作阻塞,goroutine也無法繼續執行。
5.2 time.After 記憶體洩露
# 錯誤示例:
package main

import (
    "time"
    )

func main()  {
    ch := make(chan int, 10)

    go func() {
        var i = 1
        for {
            i++
            ch <- i
        }
    }()

    for {
        select {
        case x := <- ch:
            println(x)
        case <- time.After(3 * time.Minute):
            println(time.Now().Unix())
        }
    }
}

在for迴圈每次select的時候,都會例項化一個一個新的定時器。該定時器在3分鐘後,才會被啟用,但是啟用後已經跟select無引用關係,被gc給清理掉。time.After定時器在定時任務到達之前,會一直存在於時間堆中,不會釋放資源,直到定時任務時間到達後才會釋放資源。

在go程式碼中,在for迴圈裡不要使用select + time.After的組合,可以使用time.NewTimer替代:

 1 package main
 2 
 3 import (
 4     "time"
 5     )
 6 
 7 func main()  {
 8     ch := make(chan int, 10)
 9 
10     go func() {
11         for {
12             ch <- 100
13         }
14     }()
15 
16     idleDuration := 3 * time.Minute
17     idleDelay := time.NewTimer(idleDuration)
18     defer idleDelay.Stop()
19 
20     for {
21         idleDelay.Reset(idleDuration)
22 
23         select {
24             case x := <- ch:
25                 println(x)
26             case <-idleDelay.C:
27                 return
28             }
29     }
30 }

6.開發建議:

  • 對頻繁分配的物件,使用 sync.Pool 物件池減少分配時GC壓力

    var pool = sync.Pool{New: func() interface{} { return make([]byte, 4096) }}
    
    func fn() {
    	buf := pool.Get().([]byte) // takes from pool or calls New
    	// do work
    	pool.Put(buf) // returns buf to the pool
    }
    
  • 自動化的 DeepCopy 是非常耗時的,其中涉及到反射,記憶體分配,容器(如 map)擴充套件等,大概比手動拷貝慢一個數量級

  • 用 atomic.Load/StoreXXX,atomic.Value, sync.Map 等代替 Mutex。(優先順序遞減)

  • 使用高效的第三方庫,如用fasthttp替代 net/http

  • 在開發環境加上-race編譯選項進行競態檢查

  • 在開發或線上環境開啟 net/http/pprof,方便實時pprof

  • 將所有外部IO(網路IO,磁碟IO)做成非同步

  • 避免[]byte和string轉換,在Go中,使用string()或[]byte()來實現[]byte和string的型別轉換,會額外申請一塊記憶體來複制,可以*(*[]byte)(unsafe.Pointer(&s))使用。

  • 字串的拼接優先考慮bytes.Buffer

  • slice和map採make建立時,預估大小指定容量

  • map 不會收縮 “不再使用” 的空間。就算把所有鍵值刪除,它依然保留記憶體空間以待後用

參考連結:

https://juejin.cn/post/6951078043922202631

https://github.com/sxs2473/go-performane-tuning

https://www.cnblogs.com/sunsky303/p/11077030.html

https://www.cnblogs.com/erenming/p/14256868.html

https://dave.cheney.net/high-performance-go-workshop/dotgo-paris.html#memory-and-gc

https://www.jetbrains.com/help/go/2020.3/memory-profiler.html#run-memory-profiling

【勵志篇】: 古之成大事掌大學問者,不惟有超世之才,亦必有堅韌不拔之志。