golang調試bug及性能監控方式實踐總結

Posted on by

如何分析程序運行所需時間及cpu的使用率？

使用shell內置的time指令

最常見的方式便是linux中內置的time指令，通過time go run '你的程序.go'即可。

$ time go run test.go 

real	0m0.802s
user	0m0.320s
sys	0m0.345s

使用time指令後，會返回三個指標，他們的含義分別是：

  • real：程序實際運行的時長。
  • user：程序在用戶態所消耗的時間
  • sys：程序在系統態所消耗的時間

一般來說，real >= user + sys,這是因為系統在運行當前程序時，可能會調用其他進程，從而導致程序整體的運行時增加。

使用/usr/bin/time指令

在linux中，還存在比time指令更為精準詳細的time指令，相比於系統自帶的time指令，你還需要添加指令的絕對路徑以及參數-v。

$ /usr/bin/time -v go run test.go  
Command being timed: "go run test.go"
	User time (seconds): 0.12
	System time (seconds): 0.06
	Percent of CPU this job got: 115%
	Elapsed (wall clock) time (h:mm:ss or m:ss): 0:00.16
	Average shared text size (kbytes): 0
	Average unshared data size (kbytes): 0
	Average stack size (kbytes): 0
	Average total size (kbytes): 0
	Maximum resident set size (kbytes): 41172
	Average resident set size (kbytes): 0
	Major (requiring I/O) page faults: 1
	Minor (reclaiming a frame) page faults: 15880
	Voluntary context switches: 897
	Involuntary context switches: 183
	Swaps: 0
	File system inputs: 256
	File system outputs: 2664
	Socket messages sent: 0
	Socket messages received: 0
	Signals delivered: 0
	Page size (bytes): 4096
	Exit status: 0

可以看出，這種time指令比系統自帶的要擁有更多的參數。例如：CPU的占用率，內存的使用情況等等。

如何分析go程序的內存使用情況？

聊完瞭go程序的運行時間的監控方式，我們接下來要討論的是如何分析內存使用情況的問題。

先貼出一段測試用代碼

package main
import (
	"log"
	"runtime"
	"time"
)
func main(){
	log.Println("start...")
	test()
	log.Println("force gc...")
	runtime.GC()//強調調用gc回收
	log.Println("done...")
	time.Sleep(3600*time.Second)
}
func test(){
	//由於切片可以動態擴容，所以這裡使用slice進行測試
	container := make([]int, 8)
	log.Println("==> loop start...")
	for i := 0; i < 32*1000*1000; i++ {
		container = append(container, i)
	}
	log.Println("==> loop end...")
}

將test.go文件編譯為可執行的二進制文件並執行

$go build -o test && ./test

此時，我們新開一個終端窗口，並使用top命令查看進程的內存占用情況

$top -p $(pidof test)

結果如下：

如圖所示，可以看出我們的test進程大概有520m的內存占用，這顯然是不正常的，因為test()執行完畢以後，container的內存應該被釋放瞭。

這時，另一種內存分析工具GODEBUG就能派上用場瞭。

GODEBUG與gctrace

首先，我們要開啟打印垃圾回收信息的功能：

$ GODEBUG='gctrace=1' ./test

gctrace=1可以讓垃圾回收器在每次回收垃圾時收集用時和釋放空間的大小，並將其打印到終端上。

格式及其含義

        gc # @#s #%: #+#+# ms clock, #+#/#/#+# ms cpu, #->#-># MB, # MB goal, # P
	gc #        GC次數的編號，每次GC時遞增
	@#s         距離程序開始執行時的時間
	#%          GC占用的執行時間百分比
	#+...+#     GC使用的時間
	#->#-># MB  GC開始，結束，以及當前活躍堆內存的大小，單位M
	# MB goal   全局堆內存大小
	# P         使用processor的數量

如果是由runtime.GC調用觸發的，則消息會以forced結尾。

這裡虛擬一條輸出作為示例：

gc 3 @0.134s 1%: 0.003+28+0.002 ms clock, 0.007+0/0.049/24+0.005 ms cpu, 178-&gt;178-&gt;100 MB, 180 MB goal, 2 P

該條輸出代表的信息如下

  • gc 3：GC調試的編號為3。
  • @0.134s：此時程序已經運行瞭0.134s。
  • 1%：在全部的運行時間中GC所占時間比例為1%。

以上就是golang調試bug及性能監控方式實踐總結的詳細內容，更多關於golang調試bug性能監控的資料請關註WalkonNet其它相關文章！

推薦閱讀：