golang性能優化看這篇就夠了

golang性能診斷看這篇就夠了

我們日常接觸性能診斷問題，一般分為兩種情況，一是線上應用真的出現性能問題；二是我們需要對准備上線的系統進行性能預估；后者需要壓力測試輔助進行，此處不表。

針對GO應用，性能診斷工具主要分為兩層:OS層面和GO應用層面(go tool pprof /trace /gc)

1.OS診斷

系統診斷，我們一般主要關注三個方面: CPU 、Memory、I/O

1.1 CPU

CPU診斷主要關注平均負載（Load Average），CPU使用率，上下文切換（Context Switch）。常用top命令查看cpu使用率以及服務器負載情況。

平均負載:0.14 0.07 0.06 分別表示過去1分鍾、5分鍾、15分鍾的機器負載的平均值，根據經驗，若負載數值小於0.7*CPU個數則正常，超過或者達到CPU核數的四五倍，則系統的負載就明顯偏高。

CPU的上下文切換情況可通過vmstat命令可以查看，上下文切換發生的場景有如下幾種:

1. 時間片用完，CPU正常調度下一個任務
2. 被其他優先級更高的任務搶占
3. 執行任務碰到I/O阻塞，掛起當前任務，切換到下一個任務
4. 用戶代碼主動掛起當前任務讓出CPU
5. 多任務搶占資源，因沒搶到而被掛起
6. 硬件中斷

1.2 Memory

從操作系統角度，內存關注應用進程是否足夠，可以使用 free –m 命令查看內存的使用情況。

通過 top 命令可以查看進程使用的虛擬內存 VIRT 和物理內存 RES，根據公式 VIRT = SWAP + RES 可以推算出具體應用使用的交換分區（Swap）情況，使用交換分區過大會影響 應用性能，可以將 swappiness 值調到盡可能小

1.3 I/O

I/O 包括磁盤 I/O 和網絡 I/O，一般情況下磁盤更容易出現 I/O 瓶頸。通過iostat可以查看磁盤的讀寫情況，通過 CPU 的 I/O wait 可以看出磁盤 I/O 是否正常。

如果磁盤 I/O 一直處於很高的狀態，說明磁盤太慢或故障，成為了性能瓶頸，需要進行應用優化或者磁盤更換。

除了常用的 top、 ps、vmstat、iostat 等命令，還有其他 Linux 工具可以診斷系統問題，如 mpstat、tcpdump、netstat、pidstat、sar 等 更多Linux性能診斷工具如下圖：

2.GO應用診斷

go生態已經為我們提供了大量的API和診斷工具幫助我們解決go應用的性能問題。我們常用的大致可以分為兩類:

• Profiling 收集程序執行過程中的具體事件，並抽樣統計 方便精確定位問題
• Tracing 一種檢測代碼的方法，用於分析調用或用戶請求整個生命周期中的延遲，且可以跨多個Go進程。

2.1 profiling

profile一般被稱為性能分析，對程序而言，就是程序運行時的各種概況信息，包括cpu占用情況、內存情況、線程情況等。方便分析昂貴或頻繁調用的程序場景。

如何使用？

1.首先profiling代碼埋入

import _ "net/http/pprof"

func main() {
    go func() {
        log.Println(http.ListenAndServe("0.0.0.0:9090", nil))
    }()
    ...
}

2.保存特定時間點的profile，例如保存heap信息

curl http://localhost:6060/debug/pprof/heap --output heap.tar.gz

3.使用go tool pprof 分析保存的profile快照，如分析上述heap信息

go tool pprof heap.tar.gz

2.1.1 CPU Profiling

pprof可以幫忙我們分析出函數執行緩慢問題 CPU占用過高問題

go tool pprof http://localhost:6060/debug/pprof/profile?second=10

命令行方式: 常用命令 top list traces

top: 查看按照占用內存或cpu多少排序的前10的函數信息

• flat:當前函數占用的CPU時長（不包含其調用的其他函數）
• flat%:當前函數使用CPU占總CPU時長的百分比
• sum%:前面每一行flat百分比的和
• cum: 累計量，當前函數及其子函數占用CPU時長
• cum%:累計量占總量的百分比

​ cum>=flat

list: 查看某個函數的代碼 以及該函數每行代碼的指標信息

traces:打印所有函數調用棧 以及調用棧的指標信息

UI界面方式：從服務器download下生成的sample文件

go tool pprof -http=:8080 pprof.xxx.samples.cpu.001.pb.gz

Flame graph很清晰得可以看到當前CPU被哪些函數執行棧占用

2.1.2 Heap Profiling

go tool pprof http://localhost:6060/debug/pprof/heap?second=10

命令行 UI查看方式 同理

graph中方框越大 占用內存越多 火焰圖 寬度越大 占用內存越多

SAMPLE->inuse_objects可以查看當前的對象數量 這個參數對於分析gc線程占用較高cpu時很有用處 它側重查看對象數量

inuse_space圖可以查看具體的內存占用

畢竟對於10個100m的對象和1億個10字節的對象占用內存幾乎一樣大，但是回收起來一億個小對象肯定比10個大對象要慢很多。

go tool pprof -inuse_space http://localhost:6060/debug/pprof/heap : 分析應用程序的常駐內存占用情況 （默認）
go tool pprof -alloc_objects http://localhost:6060/debug/pprof/heap: 分析應用程序的內存臨時分配情況

2.1.3 並發請求問題

查看方式跟上面類似。

go tool pprof http://localhost:6060/debug/pprof/goroutine
go tool pprof http://localhost:6060/debug/pprof/block
go tool pprof http://localhost:6060/debug/pprof/mutex

2.2 tracing

trace並不是萬能的，它更側重於記錄分析 采樣時間內運行時系統具體干了什么。

收集trace數據的三種方式:

\1. 使用runtime/trace包 調用trace.Start()和trace.Stop()

\2. 使用go test -trace= 測試標識

\3. 使用debug/pprof/trace handler 獲取運行時系統最好的方法

例如，通過

go tool pprof http://localhost:6060/debug/pprof/trace?seconds=20 > trace.out

獲取運行時服務的trace信息，使用

go tool trace trace.out

會自動打開瀏覽器展示出UI界面

其中trace view 只能使用chrome瀏覽器查看，這里go截止1.14版本存在一個 bug，解決辦法如下：

go tool trace trace.out 無法查看trace view
go bug:https://github.com/golang/go/issues/25151
mac 解決版本：安裝gotip
go get golang.org/dl/gotip
gotip download
then  使用 gotip tool trace trace.out即可

獲取的trace.out 二進制文件也可以轉化為pprof格式的文件

go tool trace -pprof=TYPE trace.out > TYPE.pprof
Tips:生成的profile文件 支持 network profiling、synchronization profiling、syscall profiling、scheduler profiling
go tool pprof TYPE.pprof

使用gotip tool trace trace.out可以查看到trace view的豐富操作界面：

操作技巧：

ctrl + 1 選擇信息

ctrl + 2 移動選區

ctrl + 3 放大選區

ctrl + 4 指定選區區間

shift + ? 幫助信息

AWSD跟游戲快捷鍵類似 玩起來跟順手

整體的控制台信息 如下圖：

• 時間線: 顯示執行的時間單元 根據時間的緯度不同 可以調整區間
• 堆: 顯示執行期間內存的分配和釋放情況
• 協程(Goroutine): 顯示每個時間點哪些Goroutine在運行 哪些goroutine等待調度 ，其包含 GC 等待（GCWaiting）、可運行（Runnable）、運行中（Running）這三種狀態。

goroutine區域選中時間區間

OS線程(Machine): 顯示在執行期間有多少個線程在運行，其包含正在調用 Syscall（InSyscall）、運行中（Running）這兩種狀態。

• 虛擬處理器Processor: 每個虛擬處理器顯示一行，虛擬處理器的數量一般默認為系統內核數。數量由環境變量GOMAXPROCS控制
• 協程和事件: 顯示在每個虛擬處理器上有什么 Goroutine 正在運行，而連線行為代表事件關聯。

每個Processor分兩層，上一層表示Processor上運行的goroutine的信息，下一層表示processor附加的事件比如SysCall 或runtime system events

ctrl+3 放大選區，選中goroutine 可以查看，特定時間點 特定goroutine的執行堆棧信息以及關聯的事件信息

goroutine analysis

點擊goroutine的id 可以跳到trace view 詳細查看goroutine具體干了什么

名稱	含義
Execution	執行時間
Network wait	網絡等待時間
Sync Block	同步阻塞時間
Blocking syscall	系統調用阻塞時間
Scheduler wait	調度等待時間
GC Sweeping	GC清掃時間
GC Pause	GC暫停時間

實踐 一個延遲問題診斷

當我們一個執行關鍵任務的協程從運行中被阻塞。這里可能的原因：被syscall阻塞 、阻塞在共享內存(channel/mutex etc)、阻塞在運行時(如 GC)、甚至有可能是運行時調度器不工作導致的。這種問題使用pprof很難排查，

使用trace只要我們確定了時間范圍就可以在proc區域很容易找到問題的源頭

上圖可見，GC 的MARK階段阻塞了主協程的運行

2.3 GC

golang的gc算法是根據標記清除改進的三色標記法，大概流程:

初始所有對象都是白色

1. Stack scan階段:從root出發掃描所有可達對象，標記為灰色並放入待處理隊列；root包括全局指針和goroutine棧上的指針
2. Mark階段:1.從待處理隊列取出灰色對象，將其引用的對象標記為灰色並放入隊列，自身標記為黑色 2. re-scan全局指針和棧，因為mark和用戶程序並行運行，故過程1的時候可能會有新的對象分配，這時需要通過寫屏障(write barrier)記錄下來；re-scan再完成檢查；
3. 重復步驟Mark階段，直到灰色對象隊列為空，執行清掃工作（白色即為垃圾對象）

go的三色標記法也存在STW(Stop The World),大致有兩個場景

1. GC即將開始時，需要STW 做一些准備工作， 如enable write barrier
2. re-scan也需要STW，否則上面Mark階段的re-scan無法終止

通過GODEBUG=gctrace=1可以開啟gc日志，查看gc的結果信息

$ GODEBUG=gctrace=1 go run main.go   
gc 1 @0.001s 19%: 0.014+3.7+0.015 ms clock, 0.11+2.8/5.7/3.2+0.12 ms cpu, 5->6->6 MB, 6 MB goal, 8 P
gc 2 @0.024s 6%: 0.004+3.4+0.010 ms clock, 0.032+1.4/4.5/5.3+0.085 ms cpu, 13->14->13 MB, 14 MB goal, 8 P
gc 3 @0.093s 3%: 0.004+6.1+0.027 ms clock, 0.032+0.19/11/15+0.22 ms cpu, 24->25->22 MB, 26 MB goal, 8 P
scvg: 0 MB released
scvg: inuse: 4, idle: 58, sys: 63, released: 58, consumed: 4 (MB)
scvg: 0 MB released
scvg: inuse: 4, idle: 58, sys: 63, released: 58, consumed: 4 (MB)
scvg: 0 MB released
scvg: inuse: 4, idle: 58, sys: 63, released: 58, consumed: 4 (MB)
scvg: 0 MB released
scvg: inuse: 4, idle: 58, sys: 63, released: 58, consumed: 4 (MB)

格式

gc # @#s #%: #+#+# ms clock, #+#/#/#+# ms cpu, #->#-># MB, # MB goal, # P

含義

gc#：GC 執行次數的編號，每次疊加。

@#s：自程序啟動后到當前的具體秒數。

#%：自程序啟動以來在GC中花費的時間百分比。

#+...+#：GC 的標記工作共使用的 CPU 時間占總 CPU 時間的百分比。

#->#-># MB：分別表示 GC 啟動時, GC 結束時, GC 活動時的堆大小.

#MB goal：下一次觸發 GC 的內存占用閾值。

#P：當前使用的處理器 P 的數量。

3. 拓展

當我們的程序陷入CPU 和IO混和負載過高時，我們使用pprof profile只能檢測出CPU耗時的函數，但是屏蔽了IO等待過長的函數。

https://github.com/felixge/fgprof 給出了一個解決方案：

具體做法是:用一個后台協程在采樣時間區間內每秒99次調用runtime.GoruntineProfile，返回的結果忽略了協程當時消耗CPU還是非消耗CPU的區別 進行統計，保存在內存中的map中，可導出轉化為pprof

具體用法：

package main
 
import(
    _ "net/http/pprof"
    "github.com/felixge/fgprof"
)
 
func main() {
    http.DefaultServeMux.Handle("/debug/fgprof", fgprof.Handler())
    go func() {
        log.Println(http.ListenAndServe(":6060", nil))
    }()
 
    // <code to profile>
}
 
git clone https://github.com/brendangregg/FlameGraph
cd FlameGraph
curl -s 'localhost:6060/debug/fgprof?seconds=3' > fgprof.fold
./flamegraph.pl fgprof.fold > fgprof.svg

如果遇到這種CPU消耗型和非CPU消耗型混合的情況下 可以試試排查下。