Go 調優神器 trace 介紹

你想知道你的Go程序在做什么嗎？  go tool trace 可以向你揭示：Go程序運行中的所有的運行時事件。 這種工具是Go生態系統中用于診斷性能問題時（如延遲，并行化和競爭異常）最有用的工具之一。 在我之前的 博客文章 中，我提到我們在Pusher中使用 go tool trace 來跟蹤為何Go垃圾收集器有很長的停頓時間。 在這篇博文中，我更加深入的介紹 go toll trace 。

go tool trace 試用

go tool trace 可以顯示大量的信息，所以從哪里開始是個問題。 我們首先簡要介紹使用界面，然后我們將介紹如何查找具體問題。

go tool trace UI是一個Web應用程序。 下面我已經嵌入了一個這個web程序的實例！  此示例 是可視化并行快速排序實現的追蹤信息：

請嘗試這個例子！有關導航UI的幫助，請單擊右上角的“？”。單擊屏幕上的任何事件可以在下面獲取更多信息。這里有一些你可以從這個追蹤中找到的有價值的信息：

• 這個程序運行多長時間？

• 有多少goroutines運行872微秒？

• 該進程何時第一次升級到使用三個OS線程？

• 什么時候主要調用qSortPar？

• 是什么導致額外的過程（1,2和3）開始工作？

• proc＃2什么時候停止？

太棒了! 我應該怎么在我的程序中使用 go tool trace ?

您必須調整程序以將運行時事件寫入二進制文件。 這涉及從標準庫導入 runtime/trace ，并添加幾行樣板代碼。 這個快速的視頻將引導您：

視頻

以下是需要復制粘貼的代碼：

package main
import (    
    "os"
    "runtime/trace"
)

func main() {
    f, err := os.Create("trace.out")    
    if err != nil {     
       panic(err)
    }   
    defer f.Close()

    err = trace.Start(f)
     if err != nil {
    panic(err)
    }   
    defer trace.Stop()  
    // Your program here
}

這將使您的程序以 二進制格式 在文件trace.out中寫入事件數據。 然后可以運行 go tool trace trace.out 。 這將解析跟蹤文件，并使用可視化程序打開瀏覽器。 該命令還將啟動服務器，并使用跟蹤數據來響應可視化操作。 在瀏覽器中加載初始頁面后，單擊“View trace”。 這將加載跟蹤查看器，如上面嵌入的那樣。

使用go tool trace能解決什么問題?

我們來看一個如何使用這個工具跟蹤典型問題的例子。

診斷延遲問題

當完成關鍵任務的goroutine被阻止運行時，可能會引起延遲問題。 可能的原因有很多：做系統調用時被阻塞; 被共享內存阻塞（通道/互斥等）; 被runtime系統（例如GC）阻塞，甚至可能調度程序不像您想要的那樣頻繁地運行關鍵goroutine。

所有這些都可以使用 go tool trace 來識別。 您可以通過查看PROCs時間線來跟蹤問題，并發現一段時間內goroutine被長時間阻塞。 一旦你確定了這段時間，應該給出一個關于根本原因的線索。

作為延遲問題的一個例子，讓我們看看上一篇博文中 長時間的GC暫停 ：

紅色的事件代表了唯一的程序goroutine正在運行。 在所有四個線程上并行運行的goroutines是垃圾收集器的MARK階段。 這個MARK階段阻止了主要的goroutine。 你能出到阻止runtime.main goroutine的時間長短嗎？

在Go團隊宣布GC暫停時間少于100微秒后 ,我很快就調查了這個延遲問題。 我看到的漫長的停頓時間， go tool trace 的結果看起來很奇怪，特別是可以看到它們(暫停)是在收集器的并發階段發生的。  我在go-nuts 郵件列表中提到了這個問題 ，似乎與 這個問題 有關，現在已經在Go 1.8中修復了。 我的基準測試又出現了 另一個GC暫停問題 ，這在寫本文時依然會出現。 如果沒有 go tool trace 這一工具，我是無法完成調查工作的。

診斷并行問題

假設您已經編寫了一個程序，您希望使用所有的CPU，但運行速度比預期的要慢。 這可能是因為您的程序不像您所期望的那樣并行運行。 這可能是由于在很多關鍵路徑上串行運行太多，而很多代碼原本是可以異步（并行）運行的。

假設我們有一個pub/sub消息總線，我們希望在單個goroutine中運行，以便它可以安全地修改沒有加互斥鎖的用戶map。 請求處理程序將消息寫入消息總線隊列。 總線從隊列中讀取消息，在map中查找訂閱者，并將消息寫入其套接字。 讓我們看看單個消息的 go tool trace 中的內容：

最初的綠色事件是http處理程序讀取發布的消息并將其寫入消息總線事件隊列。 之后，消息總線以單個線程運行 - 第二個綠色事件 - 將消息寫給訂閱者。

紅線顯示消息寫入訂戶的套接字的位置。 寫入所有訂閱者的過程需要多長時間？

問題是四分之一的線程正在閑置。 有沒有辦法利用它們？ 答案是肯定的 我們不需要同步寫入每個用戶; 寫入可以在單獨的goroutine中同時運行。 讓我們看看如果我們作出這個變化，會發生什么：

正如你所看到的，寫給訂閱者消息的過程正在許多goroutines的上同步進行。

但它是否更快？

有趣的是，鑒于我們使用4X的CPU，加速是適合的。 這是因為并行運行代碼有更多的開銷：啟動和停止goroutines; 共享內存以及單獨的緩存。 加速的理論上限使得我們無法實現4倍延遲降低： 阿姆達爾定律 。

實際上，并行運行代碼往往效率較低; 特別是在goroutine是非常短暫的，或者他們之間有很多的競爭的情況下。 這是使用此工具的另一個原因：嘗試這兩種方法，并檢查哪種工作最適合您的用例。

什么時候 go tool trace 不合適？

當然， go tool trace 不能解決一切問題。 如果您想跟蹤運行緩慢的函數，或者找到大部分CPU時間花費在哪里，這個工具就是不合適的。 為此，您應該使用 go tool pprof ，它可以顯示在每個函數中花費的CPU時間的百分比。  go tool trace 更適合于找出程序在一段時間內正在做什么，而不是總體上的開銷。 此外，還有“view trace”鏈接提供的其他可視化功能，這些對于診斷爭用問題特別有用。 了解您的程序在理論上的表現（使用老式Big-O分析）也是無可替代的。

希望這篇文章可以讓您了解如何使用 go tool trace 診斷問題。 即使您沒有解決具體問題，可視化您的程序是檢查程序運行時特性的好方法。 我在這篇文章中使用的例子很簡單，但更復雜的程序中的癥狀應該與此驚人的相似。

這個博客文章給了你一個使用 go tool trace 的介紹，但你可能希望更深入地深入了解該工具。 目前正在進行的 官方 go tool trace 文檔 相當稀少。 有一個 Google文檔 更詳細。 除此之外，我發現參考源代碼是很有用，可以找出 go tool trace 如何工作：

• go tool trace 源代碼

• 二進制跟蹤解析器的源代碼

• trace 源代碼

• go tool trace 的Web界面來自 Catapult項目的跟蹤查看器 。 該查看器可以從許多跟蹤格式生成可視化。 go工具跟蹤使用 基于JSON 的跟蹤事件格式。

 

來自：http://mp.weixin.qq.com/s/nf_-AH_LeBN3913Pt6CzQQ