編譯自: https://www.ostechnix.com/sosreport-a-tool-to-collect-system-logs-and-diagnostic-information/
作者: Sk
譯者: geekpi
如果你是 RHEL 管理員,你可能肯定聽說過 Sosreport :一個可擴展、可移植的支持數據收集工具。它是一個從類 Unix 操作系統中收集系統配置詳細信息和診斷信息的工具。當用戶提出支持服務單時,他/她必須運行此工具并將由 Sosreport 工具生成的結果報告發送給 Red Hat 支持人員。然后,執行人員將根據報告進行初步分析,并嘗試找出系統中的問題。不僅在 RHEL 系統上,你可以在任何類 Unix 操作系統上使用它來收集系統日志和其他調試信息。
Sosreport 在 Red Hat 官方系統倉庫中,因此你可以使用 Yum 或 DNF 包管理器安裝它,如下所示。
$ sudo yum install sos
要么,
$ sudo dnf install sos
在 Debian、Ubuntu 和 Linux Mint 上運行:
$ sudo apt install sosreport
安裝后,運行以下命令以收集系統配置詳細信息和其他診斷信息。
$ sudo sosreport
系統將要求你輸入系統的一些詳細信息,例如系統名稱、案例 ID 等。相應地輸入詳細信息,然后按回車鍵生成報告。如果你不想更改任何內容并使用默認值,只需按回車鍵即可。
我的 CentOS 7 服務器的示例輸出:
sosreport (version 3.5)
This command will collect diagnostic and configuration information from
this CentOS Linux system and installed applications.
An archive containing the collected information will be generated in
/var/tmp/sos.DiJXi7 and may be provided to a CentOS support
representative.
Any information provided to CentOS will be treated in accordance with
the published support policies at:
https://wiki.centos.org/
The generated archive may contain data considered sensitive and its
content should be reviewed by the originating organization before being
passed to any third party.
No changes will be made to system configuration.
Press ENTER to continue, or CTRL-C to quit.
Please enter your first initial and last name [server.ostechnix.local]:
Please enter the case id that you are generating this report for []:
Setting up archive ...
Setting up plugins ...
Running plugins. Please wait ...
Running 73/73: yum...
Creating compressed archive...
Your sosreport has been generated and saved in:
/var/tmp/sosreport-server.ostechnix.local-20180628171844.tar.xz
The checksum is: 8f08f99a1702184ec13a497eff5ce334
Please send this file to your support representative.
如果你不希望系統提示你輸入此類詳細信息,請如下使用批處理模式。
$ sudo sosreport --batch
正如你在上面的輸出中所看到的,生成了一個歸檔報告并保存在 /var/tmp/sos.DiJXi7 中。在 RHEL 6/CentOS 6 中,報告將在 /tmp 中生成。你現在可以將此報告發送給你的支持人員,以便他可以進行初步分析并找出問題所在。
你可能會擔心或想知道報告中的內容。如果是這樣,你可以通過運行以下命令來查看它:
$ sudo tar -tf /var/tmp/sosreport-server.ostechnix.local-20180628171844.tar.xz
要么,
$ sudo vim /var/tmp/sosreport-server.ostechnix.local-20180628171844.tar.xz
請注意,上述命令不會解壓存檔,而只顯示存檔中的文件和文件夾列表。如果要查看存檔中文件的實際內容,請首先使用以下命令解壓存檔:
$ sudo tar -xf /var/tmp/sosreport-server.ostechnix.local-20180628171844.tar.xz
存檔的所有內容都將解壓當前工作目錄中 ssosreport-server.ostechnix.local-20180628171844/ 目錄中。進入目錄并使用 cat 命令或任何其他文本瀏覽器查看文件內容:
$ cd sosreport-server.ostechnix.local-20180628171844/
$ cat uptime
17:19:02 up 1:03, 2 users, load average: 0.50, 0.17, 0.10
有關 Sosreport 的更多詳細信息,請參閱手冊頁。
$ man sosreport
就是這些了。希望這些有用。還有更多好東西。敬請關注!
干杯!
via: https://www.ostechnix.com/sosreport-a-tool-to-collect-system-logs-and-diagnostic-information/
作者: SK 選題: lujun9972 譯者: geekpi 校對: wxy
本文由 LCTT 原創編譯, Linux中國 榮譽推出
Go語言中文網,致力于每日分享編碼、開源等知識,歡迎關注我,會有意想不到的收獲!
最近解決了我們項目中的一個內存泄露問題,事實再次證明pprof是一個好工具,但掌握好工具的正確用法,才能發揮好工具的威力,不然就算你手里有屠龍刀,也成不了天下第一,本文就是帶你用pprof定位內存泄露問題。
關于Go的內存泄露有這么一句話不知道你聽過沒有:
10次內存泄露,有9次是goroutine泄露。
我所解決的問題,也是goroutine泄露導致的內存泄露,所以這篇文章主要介紹Go程序的goroutine泄露,掌握了如何定位和解決goroutine泄露,就掌握了內存泄露的大部分場景。
本文草稿最初數據都是生產壞境數據,為了防止敏感內容泄露,全部替換成了demo數據,demo的數據比生產環境數據簡單多了,更適合入門理解,有助于掌握pprof。
定位goroutine泄露會使用到pprof,pprof是Go的性能工具,在開始介紹內存泄露前,先簡單介紹下pprof的基本使用,更詳細的使用給大家推薦了資料。
什么是pprof
pprof是Go的性能分析工具,在程序運行過程中,可以記錄程序的運行信息,可以是CPU使用情況、內存使用情況、goroutine運行情況等,當需要性能調優或者定位Bug時候,這些記錄的信息是相當重要。
基本使用
使用pprof有多種方式,Go已經現成封裝好了1個:net/http/pprof,使用簡單的幾行命令,就可以開啟pprof,記錄運行信息,并且提供了Web服務,能夠通過瀏覽器和命令行2種方式獲取運行數據。
看個最簡單的pprof的例子:
文件:golang_step_by_step/pprof/pprof/demo.go
package main import ( "fmt" "net/http" _ "net/http/pprof" ) func main() { // 開啟pprof,監聽請求 ip :="0.0.0.0:6060" if err :=http.ListenAndServe(ip, nil); err !=nil { fmt.Printf("start pprof failed on %s\n", ip) } }
提醒:本文所有代碼部分可左右滑動
瀏覽器方式
輸入網址ip:port/debug/pprof/打開pprof主頁,從上到下依次是5類profile信息:
這篇文章我們主要關注goroutine和heap,這兩個都會打印調用棧信息,goroutine里面還會包含goroutine的數量信息,heap則是內存分配信息,本文用不到的地方就不展示了,最后推薦幾篇文章大家去看。
命令行方式
當連接在服務器終端上的時候,是沒有瀏覽器可以使用的,Go提供了命令行的方式,能夠獲取以上5類信息,這種方式用起來更方便。
使用命令go tool pprof url可以獲取指定的profile文件,此命令會發起http請求,然后下載數據到本地,之后進入交互式模式,就像gdb一樣,可以使用命令查看運行信息,以下是5類請求的方式:
# 下載cpu profile,默認從當前開始收集30s的cpu使用情況,需要等待30s go tool pprof http://localhost:6060/debug/pprof/profile # 30-second CPU profile go tool pprof http://localhost:6060/debug/pprof/profile?seconds=120 # wait 120s # 下載heap profile go tool pprof http://localhost:6060/debug/pprof/heap # heap profile # 下載goroutine profile go tool pprof http://localhost:6060/debug/pprof/goroutine # goroutine profile # 下載block profile go tool pprof http://localhost:6060/debug/pprof/block # goroutine blocking profile # 下載mutex profile go tool pprof http://localhost:6060/debug/pprof/mutex
上面的pprof/demo.go太簡單了,如果去獲取內存profile,幾乎獲取不到什么,換一個Demo進行內存profile的展示:
文件:golang_step_by_step/pprof/heap/demo2.go
// 展示內存增長和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)...) } }
上面這個demo會不斷的申請內存,把它編譯運行起來,然后執行:
$ go tool pprof http://localhost:6060/debug/pprof/heap Fetching profile over HTTP from http://localhost:6060/debug/pprof/heap Saved profile in /home/ubuntu/pprof/pprof.demo.alloc_objects.alloc_space.inuse_objects.inuse_space.001.pb.gz //<--- 下載到的內存profile文件 File: demo // 程序名稱 Build ID: a9069a125ee9c0df3713b2149ca859e8d4d11d5a Type: inuse_space Time: May 16, 2019 at 8:55pm (CST) Entering interactive mode (type "help" for commands, "o" for options) (pprof) (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 quit/exit/^D Exit pprof ....
以上信息我們只關注2個地方:
關于命令,本文只會用到3個,我認為也是最常用的:top、list、traces,分別介紹一下。
top
按指標大小列出前10個函數,比如內存是按內存占用多少,CPU是按執行時間多少。
(pprof) top Showing nodes accounting for 814.62MB, 100% of 814.62MB total flat flat% sum% cum cum% 814.62MB 100% 100% 814.62MB 100% main.main 0 0% 100% 814.62MB 100% runtime.main
top會列出5個統計數據:
list
查看某個函數的代碼,以及該函數每行代碼的指標信息,如果函數名不明確,會進行模糊匹配,比如list main會列出main.main和runtime.main。
(pprof) list main.main // 精確列出函數 Total: 814.62MB ROUTINE========================main.main in /home/ubuntu/heap/demo2.go 814.62MB 814.62MB (flat, cum) 100% of Total . . 20: }() . . 21: . . 22: tick :=time.Tick(time.Second / 100) . . 23: var buf []byte . . 24: for range tick { 814.62MB 814.62MB 25: buf=append(buf, make([]byte, 1024*1024)...) . . 26: } . . 27:} . . 28: (pprof) list main // 匹配所有函數名帶main的函數 Total: 814.62MB ROUTINE========================main.main in /home/ubuntu/heap/demo2.go 814.62MB 814.62MB (flat, cum) 100% of Total . . 20: }() . . 21: ..... // 省略幾行 . . 28: ROUTINE========================runtime.main in /usr/lib/go-1.10/src/runtime/proc.go 0 814.62MB (flat, cum) 100% of Total . . 193: // A program compiled with -buildmode=c-archive or c-shared ..... // 省略幾行
可以看到在main.main中的第25行占用了814.62MB內存,左右2個數據分別是flat和cum,含義和top中解釋的一樣。
traces
打印所有調用棧,以及調用棧的指標信息。
(pprof) traces File: demo2 Type: inuse_space Time: May 16, 2019 at 7:08pm (CST) -----------+------------------------------------------------------- bytes: 813.46MB 813.46MB main.main runtime.main -----------+------------------------------------------------------- bytes: 650.77MB 0 main.main runtime.main ....... // 省略幾十行
每個- - - - - 隔開的是一個調用棧,能看到runtime.main調用了main.main,并且main.main中占用了813.46MB內存。
其他的profile操作和內存是類似的,這里就不展示了。
這里只是簡單介紹本文用到的pprof的功能,pprof功能很強大,也經常和benchmark結合起來,但這不是本文的重點,所以就不多介紹了,為大家推薦幾篇文章,一定要好好研讀、實踐:
內存泄露指的是程序運行過程中已不再使用的內存,沒有被釋放掉,導致這些內存無法被使用,直到程序結束這些內存才被釋放的問題。
Go雖然有GC來回收不再使用的堆內存,減輕了開發人員對內存的管理負擔,但這并不意味著Go程序不再有內存泄露問題。在Go程序中,如果沒有Go語言的編程思維,也不遵守良好的編程實踐,就可能埋下隱患,造成內存泄露問題。
在Go中發現內存泄露有2種方法,一個是通用的監控工具,另一個是go pprof:
這2種方式分別介紹一下。
監控工具查看進程內在占用情況
如果使用云平臺部署Go程序,云平臺都提供了內存查看的工具,可以查看OS的內存占用情況和某個進程的內存占用情況,比如阿里云,我們在1個云主機上只部署了1個Go服務,所以OS的內存占用情況,基本是也反映了進程內存占用情況,OS內存占用情況如下,可以看到隨著時間的推進,內存的占用率在不斷的提高,這是內存泄露的最明顯現象:
如果沒有云平臺這種內存監控工具,可以制作一個簡單的內存記錄工具。
1、建立一個腳本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"\tmemory(Byte)\t"$prog_mem >>~/record/prog_mem.log
2、然后使用crontab建立定時任務,每分鐘記錄1次。使用crontab -e編輯crontab配置,在最后增加1行:
*/1 * * * * ~/record/prog_mem.sh
腳本輸出的內容保存在prog_mem.log,只要大體瀏覽一下就可以發現內存的增長情況,判斷是否存在內存泄露。如果需要可視化,可以直接黏貼prog_mem.log內容到Excel等表格工具,繪制內存占用圖。
go pprof發現存在內存問題
有情提醒:如果對pprof不了解,可以先看go pprof基本知識,這是下一節,看完再倒回來看。
如果你Google或者百度,Go程序內存泄露的文章,它總會告訴你使用pprof heap,能夠生成漂亮的調用路徑圖,火焰圖等等,然后你根據調用路徑就能定位內存泄露問題,我最初也是對此深信不疑,嘗試了若干天后,只是發現內存泄露跟某種場景有關,根本找不到內存泄露的根源,如果哪位朋友用heap就能定位內存泄露的線上問題,麻煩介紹下。
后來讀了Dave的《High Performance Go Workshop》,刷新了對heap的認識,內存pprof的簡要內容如下:
Dave講了以下幾點:
基于目前對heap的認知,我有2個觀點:
接下來,我介紹怎么用heap發現問題,然后再解釋為什么heap幾乎不能定位內存泄露的根因。
怎么用heap發現內存問題
使用pprof的heap能夠獲取程序運行時的內存信息,在程序平穩運行的情況下,每個一段時間使用heap獲取內存的profile,然后使用base能夠對比兩個profile文件的差別,就像diff命令一樣顯示出增加和減少的變化,使用一個簡單的demo來說明heap和base的使用,依然使用demo2進行展示。
文件:golang_step_by_step/pprof/heap/demo2.go
// 展示內存增長和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)...) } }
將上面代碼運行起來,執行以下命令獲取profile文件,Ctrl-D退出,1分鐘后再獲取1次。
go tool pprof http://localhost:6060/debug/pprof/heap
我已經獲取到了兩個profile文件:
$ ls 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
使用base把001文件作為基準,然后用002和001對比,先執行top看top的對比,然后執行list main列出main函數的內存對比,結果如下:
$ 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 File: demo2 Type: inuse_space Time: May 14, 2019 at 2:33pm (CST) Entering interactive mode (type "help" for commands, "o" for options) (pprof) (pprof) (pprof) top Showing nodes accounting for 970.34MB, 32.30% of 3003.99MB total flat flat% sum% cum cum% 970.34MB 32.30% 32.30% 970.34MB 32.30% main.main // 看這 0 0% 32.30% 970.34MB 32.30% runtime.main (pprof) (pprof) (pprof) list main.main Total: 2.93GB ROUTINE========================main.main in /home/ubuntu/heap/demo2.go 970.34MB 970.34MB (flat, cum) 32.30% of Total . . 20: }() . . 21: . . 22: tick :=time.Tick(time.Second / 100) . . 23: var buf []byte . . 24: for range tick { 970.34MB 970.34MB 25: buf=append(buf, make([]byte, 1024*1024)...) // 看這 . . 26: } . . 27:} . . 28:
top列出了main.main和runtime.main,main.main就是我們編寫的main函數,runtime.main是runtime包中的main函數,也就是所有main函數的入口,這里不多介紹了,有興趣可以看之前的調度器文章《Go調度器系列(2)宏觀看調度器》。
top顯示main.main 第2次內存占用,比第1次內存占用多了970.34MB。
list main.main告訴了我們增長的內存都在這一行:
buf=append(buf, make([]byte, 1024*1024)...)
001和002 profile的文件不進去看了,你本地測試下計算差值,絕對是剛才對比出的970.34MB。
heap“不能”定位內存泄露
heap能顯示內存的分配情況,以及哪行代碼占用了多少內存,我們能輕易的找到占用內存最多的地方,如果這個地方的數值還在不斷怎大,基本可以認定這里就是內存泄露的位置。
曾想按圖索驥,從內存泄露的位置,根據調用棧向上查找,總能找到內存泄露的原因,這種方案看起來是不錯的,但實施起來卻找不到內存泄露的原因,結果是事半功倍。
原因在于一個Go程序,其中有大量的goroutine,這其中的調用關系也許有點復雜,也許內存泄露是在某個三方包里。舉個栗子,比如下面這幅圖,每個橢圓代表1個goroutine,其中的數字為編號,箭頭代表調用關系。heap profile顯示g111(最下方標紅節點)這個協程的代碼出現了泄露,任何一個從g101到g111的調用路徑都可能造成了g111的內存泄露,有2類可能:
第2種情況,就是goroutine泄露,這是通過heap無法發現的,所以heap在定位內存泄露這件事上,發揮的作用不大。
什么是goroutine泄露
如果你啟動了1個goroutine,但并沒有符合預期的退出,直到程序結束,此goroutine才退出,這種情況就是goroutine泄露。
提前思考:什么會導致goroutine無法退出/阻塞?
goroutine泄露怎么導致內存泄露
每個goroutine占用2KB內存,泄露1百萬goroutine至少泄露2KB * 1000000=2GB內存,為什么說至少呢?
goroutine執行過程中還存在一些變量,如果這些變量指向堆內存中的內存,GC會認為這些內存仍在使用,不會對其進行回收,這些內存誰都無法使用,造成了內存泄露。
所以goroutine泄露有2種方式造成內存泄露:
Dave在文章中也提到了,如果不知道何時停止一個goroutine,這個goroutine就是潛在的內存泄露:
7.1.1 Know when to stop a goroutineIf 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泄露引發的內存泄露
掌握了前面的pprof命令行的基本用法,很快就可以確認是否是goroutine泄露導致內存泄露,如果你不記得了,馬上回去看一下go pprof基本知識。
判斷依據:在節點正常運行的情況下,隔一段時間獲取goroutine的數量,如果后面獲取的那次,某些goroutine比前一次多,如果多獲取幾次,是持續增長的,就極有可能是goroutine泄露。
goroutine導致內存泄露的demo:
文件:golang_step_by_step/pprof/goroutine/leak_demo1.go
// 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
已經通過pprof命令獲取了2個goroutine的profile文件:
$ ls /home/ubuntu/pprof/pprof.leak_demo.goroutine.001.pb.gz /home/ubuntu/pprof/pprof.leak_demo.goroutine.002.pb.gz
同heap一樣,我們可以使用base對比2個goroutine profile文件:
$go tool pprof -base pprof.leak_demo.goroutine.001.pb.gz pprof.leak_demo.goroutine.002.pb.gz File: leak_demo Type: goroutine Time: May 16, 2019 at 2:44pm (CST) Entering interactive mode (type "help" for commands, "o" for options) (pprof) (pprof) top Showing nodes accounting for 20312, 100% of 20312 total flat flat% sum% cum cum% 20312 100% 100% 20312 100% runtime.gopark 0 0% 100% 20312 100% main.alloc2 0 0% 100% 20312 100% main.alloc2.func1 0 0% 100% 20312 100% runtime.chansend 0 0% 100% 20312 100% runtime.chansend1 0 0% 100% 20312 100% runtime.goparkunlock (pprof)
可以看到運行到runtime.gopark的goroutine數量增加了20312個。再通過002文件,看一眼執行到gopark的goroutine數量,即掛起的goroutine數量:
go tool pprof pprof.leak_demo.goroutine.002.pb.gz File: leak_demo Type: goroutine Time: May 16, 2019 at 2:47pm (CST) Entering interactive mode (type "help" for commands, "o" for options) (pprof) top Showing nodes accounting for 24330, 100% of 24331 total Dropped 32 nodes (cum <=121) flat flat% sum% cum cum% 24330 100% 100% 24330 100% runtime.gopark 0 0% 100% 24326 100% main.alloc2 0 0% 100% 24326 100% main.alloc2.func1 0 0% 100% 24326 100% runtime.chansend 0 0% 100% 24326 100% runtime.chansend1 0 0% 100% 24327 100% runtime.goparkunlock
顯示有24330個goroutine被掛起,這不是goroutine泄露這是啥?已經能確定八九成goroutine泄露了。
是什么導致如此多的goroutine被掛起而無法退出?接下來就看怎么定位goroutine泄露。
使用pprof有2種方式,一種是web網頁,一種是go tool pprof命令行交互,這兩種方法查看goroutine都支持,但有輕微不同,也有各自的優缺點。
我們先看Web的方式,再看命令行交互的方式,這兩種都很好使用,結合起來用也不錯。
Web可視化查看
Web方式適合web服務器的端口能訪問的情況,使用起來方便,有2種方式:
方式一
url請求中設置debug=1:
復制
http://ip:port/debug/pprof/goroutine?debug=1
效果如下:
看起來密密麻麻的,其實簡單又十分有用,看上圖標出來的部分,手機上圖看起來可能不方便,那就放大圖片,或直接看下面各字段的含義:
32015 @ 0x42e15a 0x42e20e 0x40534b 0x4050e5 0x6d8559 0x6d831b 0x45abe1 # 0x6d8558 main.alloc2.func1+0xf8 /home/ubuntu/heap/leak_demo.go:53 # 0x6d831a main.alloc2+0x2a /home/ubuntu/heap/leak_demo.go:54
根據上面的提示,就能判斷32015個goroutine運行到leak_demo.go的53行:
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行 }() }
阻塞的原因是outCh這個寫操作無法完成,outCh是無緩沖的通道,并且由于以下代碼是死代碼,所以goroutine始終沒有從outCh讀數據,造成outCh阻塞,進而造成無數個alloc2的goroutine阻塞,形成內存泄露:
if false { <-outCh }
方式二
url請求中設置debug=2:
http://ip:port/debug/pprof/goroutine?debug=2
第2種方式和第1種方式是互補的,它可以看到每個goroutine的信息:
goroutine 20 [chan send, 2 minutes]: main.alloc2.func1(0xc42015e060) /home/ubuntu/heap/leak_demo.go:53 +0xf9 // 這 main.alloc2(0xc42015e060) /home/ubuntu/heap/leak_demo.go:54 +0x2b created by main.alloc1 /home/ubuntu/heap/leak_demo.go:42 +0x3f
命令行交互式方法
Web的方法是簡單粗暴,無需登錄服務器,瀏覽器打開看看就行了。但就像前面提的,沒有瀏覽器可訪問時,命令行交互式才是最佳的方式,并且也是手到擒來,感覺比Web一樣方便。
命令行交互式只有1種獲取goroutine profile的方法,不像Web網頁分debug=1和debug=22中方式,并將profile文件保存到本地:
// 注意命令沒有`debug=1`,debug=1,加debug有些版本的go不支持 $ go tool pprof http://0.0.0.0:6060/debug/pprof/goroutine Fetching profile over HTTP from http://localhost:6061/debug/pprof/goroutine Saved profile in /home/ubuntu/pprof/pprof.leak_demo.goroutine.001.pb.gz // profile文件保存位置 File: leak_demo Type: goroutine Time: May 16, 2019 at 2:44pm (CST) Entering interactive mode (type "help" for commands, "o" for options) (pprof)
命令行只需要掌握3個命令就好了,上面介紹過了,詳細的倒回去看top, list, traces:
我們依然使用leak_demo.go這個demo,
$ go tool pprof -base pprof.leak_demo.goroutine.001.pb.gz pprof.leak_demo.goroutine.002.pb.gz File: leak_demo Type: goroutine Time: May 16, 2019 at 2:44pm (CST) Entering interactive mode (type "help" for commands, "o" for options) (pprof) (pprof) (pprof) top Showing nodes accounting for 20312, 100% of 20312 total flat flat% sum% cum cum% 20312 100% 100% 20312 100% runtime.gopark 0 0% 100% 20312 100% main.alloc2 0 0% 100% 20312 100% main.alloc2.func1 0 0% 100% 20312 100% runtime.chansend 0 0% 100% 20312 100% runtime.chansend1 0 0% 100% 20312 100% runtime.goparkunlock (pprof) (pprof) traces File: leak_demo Type: goroutine Time: May 16, 2019 at 2:44pm (CST) -----------+------------------------------------------------------- 20312 runtime.gopark runtime.goparkunlock runtime.chansend runtime.chansend1 // channel發送 main.alloc2.func1 // alloc2中的匿名函數 main.alloc2 -----------+-------------------------------------------------------
top命令在怎么確定是goroutine泄露引發的內存泄露介紹過了,直接看traces命令,traces能列出002中比001中多的那些goroutine的調用棧,這里只有1個調用棧,有20312個goroutine都執行這個調用路徑,可以看到alloc2中的匿名函數alloc2.func1調用了寫channel的操作,然后阻塞掛起了goroutine,使用list列出alloc2.func1的代碼,顯示有20312個goroutine阻塞在53行:
(pprof) list main.alloc2.func1 Total: 20312 ROUTINE========================main.alloc2.func1 in /home/ubuntu/heap/leak_demo.go 0 20312 (flat, cum) 100% of Total . . 48: // 分配內存,假用一下 . . 49: buf :=make([]byte, 1024*1024*10) . . 50: _=len(buf) . . 51: fmt.Println("alloc done") . . 52: . 20312 53: outCh <- 0 // 看這 . . 54: }() . . 55:} . . 56:
友情提醒:使用list命令的前提是程序的源碼在當前機器,不然可沒法列出源碼。服務器上,通常沒有源碼,那我們咋辦呢?剛才介紹了Web查看的方式,那里會列出代碼行數,我們可以使用wget下載網頁:
$ wget http://localhost:6060/debug/pprof/goroutine?debug=1
下載網頁后,使用編輯器打開文件,使用關鍵字main.alloc2.func1進行搜索,找到與當前相同的調用棧,就可以看到該goroutine阻塞在哪一行了,不要忘記使用debug=2還可以看到阻塞了多久和原因,Web方式中已經介紹了,此處省略代碼幾十行。
文章略長,但全是干貨,感謝閱讀到這。然讀到著了,跟定很想掌握pprof,建議實踐一把,現在和大家溫習一把本文的主要內容。
goroutine泄露的本質
goroutine泄露的本質是channel阻塞,無法繼續向下執行,導致此goroutine關聯的內存都無法釋放,進一步造成內存泄露。
goroutine泄露的發現和定位
利用好go pprof獲取goroutine profile文件,然后利用3個命令top、traces、list定位內存泄露的原因。
goroutine泄露的場景
泄露的場景不僅限于以下兩類,但因channel相關的泄露是最多的。
編碼goroutine泄露的建議
為避免goroutine泄露造成內存泄露,啟動goroutine前要思考清楚:
本文所有示例源碼,及歷史文章、代碼都存儲在Github,閱讀原文可直接跳轉,Github:https://github.com/Shitaibin/golang_step_by_step/tree/master/pprof 。
這些既是參考資料也是推薦閱讀的文章,不容錯過。
【Go Blog關于pprof詳細介紹和Demo】 https://blog.golang.org/profiling-go-programs
【Dave關于高性能Go程序的workshop】 https://dave.cheney.net/high-performance-go-workshop/dotgo-paris.html#using_more_than_one_cpu
【Golang 大殺器之性能剖析 PProf】
【SO上goroutine調用棧各字段的介紹】https://stackoverflow.com/a/38414527/4296218
【我的老文,有runtime.main的介紹,想學習調度器,可以看下系列文章 Go調度器系列(2)宏觀看調度器】http://lessisbetter.site/2019/03/26/golang-scheduler-2-macro-view/ Go調度器系列(2)宏觀看調度器
如果這篇文章對你有幫助,不妨關注下我的Github,有文章會收到通知。本文作者:大彬,原創授權發布如果喜歡本文,隨意轉載,但請保留此原文鏈接:http://lessisbetter.site/2019/05/18/go-goroutine-leak/