golang 关闭gc 并手动gc_Golang 大杀器之跟踪剖析 trace
Go語言中文網(wǎng)，致力于每日分享編碼、開源等知識(shí)，歡迎關(guān)注我，會(huì)有意想不到的收獲！
在 Go 中有許許多多的分析工具，在之前我有寫過一篇 Golang 大殺器之性能剖析 PProf 來介紹 PProf，如果有小伙伴感興趣可以去我博客看看。
但單單使用 PProf 有時(shí)候不一定足夠完整，因?yàn)樵谡鎸?shí)的程序中還包含許多的隱藏動(dòng)作，例如 Goroutine 在執(zhí)行時(shí)會(huì)做哪些操作？執(zhí)行/阻塞了多長時(shí)間？在什么時(shí)候阻止？在哪里被阻止的？誰又鎖/解鎖了它們？GC 是怎么影響到 Goroutine 的執(zhí)行的？這些東西用 PProf 是很難分析出來的，但如果你又想知道上述的答案的話，你可以用本文的主角 go tool trace 來打開新世界的大門。目錄如下：
初步了解
生成跟蹤文件：
$ go run main.go 2> trace.out啟動(dòng)可視化界面：
$ go tool trace trace.out2019/06/22 16:14:52 Parsing trace...2019/06/22 16:14:52 Splitting trace...2019/06/22 16:14:52 Opening browser. Trace viewer is listening on http://127.0.0.1:57321查看可視化界面：
- View trace：查看跟蹤
- Goroutine analysis：Goroutine 分析
- Network blocking profile：網(wǎng)絡(luò)阻塞概況
- Synchronization blocking profile：同步阻塞概況
- Syscall blocking profile：系統(tǒng)調(diào)用阻塞概況
- Scheduler latency profile：調(diào)度延遲概況
- User defined tasks：用戶自定義任務(wù)
- User defined regions：用戶自定義區(qū)域
- Minimum mutator utilization：最低 Mutator 利用率
Scheduler latency profile
在剛開始查看問題時(shí)，除非是很明顯的現(xiàn)象，否則不應(yīng)該一開始就陷入細(xì)節(jié)，因此我們一般先查看 “Scheduler latency profile”，我們能通過 Graph 看到整體的調(diào)用開銷情況，如下：
演示程序比較簡(jiǎn)單，因此這里就兩塊，一個(gè)是 trace 本身，另外一個(gè)是 channel 的收發(fā)。
Goroutine analysis
第二步看 “Goroutine analysis”，我們能通過這個(gè)功能看到整個(gè)運(yùn)行過程中，每個(gè)函數(shù)塊有多少個(gè)有 Goroutine 在跑，并且觀察每個(gè)的 Goroutine 的運(yùn)行開銷都花費(fèi)在哪個(gè)階段。如下：
通過上圖我們可以看到共有 3 個(gè) goroutine，分別是 runtime.main、runtime/trace.Start.func1、main.main.func1，那么它都做了些什么事呢，接下來我們可以通過點(diǎn)擊具體細(xì)項(xiàng)去觀察。如下：
同時(shí)也可以看到當(dāng)前 Goroutine 在整個(gè)調(diào)用耗時(shí)中的占比，以及 GC 清掃和 GC 暫停等待的一些開銷。如果你覺得還不夠，可以把圖表下載下來分析，相當(dāng)于把整個(gè) Goroutine 運(yùn)行時(shí)掰開來看了，這塊能夠很好的幫助我們對(duì) Goroutine 運(yùn)行階段做一個(gè)的剖析，可以得知到底慢哪，然后再?zèng)Q定下一步的排查方向。如下：
名稱含義耗時(shí)Execution Time執(zhí)行時(shí)間3140nsNetwork Wait Time網(wǎng)絡(luò)等待時(shí)間0nsSync Block Time同步阻塞時(shí)間0nsBlocking Syscall Time調(diào)用阻塞時(shí)間0nsScheduler Wait Time調(diào)度等待時(shí)間14nsGC SweepingGC 清掃0nsGC PauseGC 暫停0ns
View trace
在對(duì)當(dāng)前程序的 Goroutine 運(yùn)行分布有了初步了解后，我們?cè)偻ㄟ^ “查看跟蹤” 看看之間的關(guān)聯(lián)性，如下：
這個(gè)跟蹤圖粗略一看，相信有的小伙伴會(huì)比較懵逼，我們可以依據(jù)注解一塊塊查看，如下：
點(diǎn)擊具體的 Goroutine 行為后可以看到其相關(guān)聯(lián)的詳細(xì)信息，這塊很簡(jiǎn)單，大家實(shí)際操作一下就懂了。文字解釋如下：
- Start：開始時(shí)間
- Wall Duration：持續(xù)時(shí)間
- Self Time：執(zhí)行時(shí)間
- Start Stack Trace：開始時(shí)的堆棧信息
- End Stack Trace：結(jié)束時(shí)的堆棧信息
- Incoming flow：輸入流
- Outgoing flow：輸出流
- Preceding events：之前的事件
- Following events：之后的事件
- All connected：所有連接的事件
View Events
我們可以通過點(diǎn)擊 View Options-Flow events、Following events 等方式，查看我們應(yīng)用運(yùn)行中的事件流情況。如下：
通過分析圖上的事件流，我們可得知這程序從 G1 runtime.main 開始運(yùn)行，在運(yùn)行時(shí)創(chuàng)建了 2 個(gè) Goroutine，先是創(chuàng)建 G18 runtime/trace.Start.func1，然后再是 G19 main.main.func1 。而同時(shí)我們可以通過其 Goroutine Name 去了解它的調(diào)用類型，如：runtime/trace.Start.func1 就是程序中在 main.main 調(diào)用了 runtime/trace.Start 方法，然后該方法又利用協(xié)程創(chuàng)建了一個(gè)閉包 func1 去進(jìn)行調(diào)用。
在這里我們結(jié)合開頭的代碼去看的話，很明顯就是 ch 的輸入輸出的過程了。
結(jié)合實(shí)戰(zhàn)
今天生產(chǎn)環(huán)境突然出現(xiàn)了問題，機(jī)智的你早已埋好 _ "net/http/pprof" 這個(gè)神奇的工具，你麻利的執(zhí)行了如下命令：
- curl http://127.0.0.1:6060/debug/pprof/trace?seconds=20 > trace.out
- go tool trace trace.out
View trace
你很快的看到了熟悉的 List 界面，然后不信邪點(diǎn)開了 View trace 界面，如下：
完全看懵的你，穩(wěn)住，對(duì)著合適的區(qū)域執(zhí)行快捷鍵 W 不斷地放大時(shí)間線，如下：
經(jīng)過初步排查，你發(fā)現(xiàn)上述絕大部分的 G 竟然都和 google.golang.org/grpc.(*Server).Serve.func 有關(guān)，關(guān)聯(lián)的一大串也是 Serve 所觸發(fā)的相關(guān)動(dòng)作。
這時(shí)候有經(jīng)驗(yàn)的你心里已經(jīng)有了初步結(jié)論，你可以繼續(xù)追蹤 View trace 深入進(jìn)去，不過我建議先鳥瞰全貌，因此我們?cè)偻驴?“Network blocking profile” 和 “Syscall blocking profile” 所提供的信息，如下：
Network blocking profile
Syscall blocking profile
通過對(duì)以上三項(xiàng)的跟蹤分析，加上這個(gè)泄露，這個(gè)阻塞的耗時(shí)，這個(gè)涉及的內(nèi)部方法名，很明顯就是哪位又忘記關(guān)閉客戶端連接了，趕緊改改改。
總結(jié)
通過本文我們習(xí)得了 go tool trace 的武林秘籍，它能夠跟蹤捕獲各種執(zhí)行中的事件，例如 Goroutine 的創(chuàng)建/阻塞/解除阻塞，Syscall 的進(jìn)入/退出/阻止，GC 事件，Heap 的大小改變，Processor 啟動(dòng)/停止等等。
希望你能夠用好 Go 的兩大殺器 pprof + trace 組合，此乃排查好搭檔，誰用誰清楚，即使他并不萬能。
參考
- https://about.sourcegraph.com/go/an-introduction-to-go-tool-trace-rhys-hiltner
- https://www.itcodemonkey.com/article/5419.html
- https://making.pusher.com/go-tool-trace/
- https://golang.org/cmd/trace/
- https://docs.google.com/document/d/1FP5apqzBgr7ahCCgFO-yoVhk4YZrNIDNf9RybngBc14/pub
- https://godoc.org/runtime/trace
本文作者：煎魚，原創(chuàng)授權(quán)發(fā)布
《新程序員》：云原生和全面數(shù)字化實(shí)踐50位技術(shù)專家共同創(chuàng)作，文字、視頻、音頻交互閱讀總結(jié)
以上是生活随笔為你收集整理的golang 关闭gc 并手动gc_Golang 大杀器之跟踪剖析 trace的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： mysql+keepalived必须要l
- 下一篇： tensorflow环境下的识别食物_T