在 Go 1.11 下調試延遲問題

來源:互聯網
上載者:User
這是一個建立於 的文章,其中的資訊可能已經有所發展或是發生改變。診斷和調試複雜系統是一件複雜的事。經常需要多個層次的診斷資料來弄清楚延遲問題可能的原因。一個分布式系統由多個伺服器組成,這些伺服器互相依賴,共同完成對使用者請求的服務。在任何時候,- 系統中的一個進程可能會處理大量的請求。- 在高並發的伺服器中,沒有容易的途徑能將一個請求生命週期內的各個事件分離出來。- 在高並發的伺服器中,對於響應一個請求所發生的事件,我們沒有很好的可見度。隨著 Go 在近些年來變成編寫伺服器的一門流行語言,我們意識到理解 Go 進程在一個請求的生命週期內發生了什麼事的必要性。在程式執行過程中會發生許多運行時活動:調度、記憶體配置、記憶體回收等等。但是要將使用者代碼與運行時事件關聯起來,並協助使用者分析運行時事件如何影響他們的效能,這在過去是不可能的。網站可靠工程師(SRE)可能會在診斷一個延遲問題時尋求協助,並希望有人能協助他們理解並最佳化一個特定的伺服器。甚至對於那些精通 Go 的人來說,能夠估計出運行時對於他們遇到的特定情況的影響,也是非常複雜的。沒有容易的方式能說明為什麼某些請求延遲很高。分布式追蹤讓我們定位出哪個 handler 需要仔細查看,但我們需要深挖下去。是 GC,調度器還是 I/O 讓我們在服務一個請求的時候等待如此之久? — SRE在系統外部的人看來,經曆延遲問題時,他們僅知道的一個事實就是自己等待了超出預期的時間(356ms)才收到響應,除此之外他們不知道別的。![](https://raw.githubusercontent.com/studygolang/gctt-images/master/debugging-latency/1.png)*使用者使用 GET 方法訪問 /messages 時等待了 356 ms 才收到響應。*從那些能夠接觸到分布追蹤的開發人員的角度來看,看到延遲的明細及每個服務對於總的延遲貢獻了多少是有可能的。通過分布式追蹤,我們對於境況有更好的可見度。![](https://raw.githubusercontent.com/studygolang/gctt-images/master/debugging-latency/2.png)*通過你收集到的分布式追蹤來看延遲明細。*在這種情況下,為了服務 /messages, 我們寫了三個內部的 RPC: auth.AccessToken, cache.Lookup 和 spanner.Query。我們可以看到每個 RPC 對延遲貢獻了多少。這個時候,我們看出是 **auth.AccessToken** 花費了比平時間長度的時間。我們成功的將問題縮小到一個特定的服務。我們可以通過關聯特定的進程查看 auth.AccessToken 的源碼,找到導致高延遲的代碼,或者我們可以隨意看看這個問題是否會在某個驗證服務的執行個體上重現。在 Go 1.11 下,我們將對執行追蹤器有額外的支援,以便能指出 RPC 調用時的運行時事件。有了這個新特性,對於一個調用生命週期所發生的事,使用者可以收集到更多的資訊。在這個案例中,我們將聚焦於 auth.AccessToken 範圍內的部分。在網路上一共花費了 30 + 18 µs,阻塞的系統調用 5µs,記憶體回收 21µs,真正執行 handler 花費了 123µs,其中大部分都花在序列化和還原序列化上。![](https://raw.githubusercontent.com/studygolang/gctt-images/master/debugging-latency/3.png)通過查看這一層次的詳細資料,我們最終可以說我們很不幸的在 RPC 調用期間遇到了 GC,而且我們在序列化/還原序列化上竟然花費了很長的時間。然後,工程師們就可以指出最近對於 auth.AccessToken 的訊息進行的修改,從而改善效能問題。他們還可以看看記憶體回收是否經常會在關鍵路徑上對這個請求的處理造成影響,對記憶體配置的方式進行最佳化。## Go 1.11在 Go 1.11 下,Go 的執行追蹤器將引入一些新的概念、API 及追蹤特性:- 使用者事件及使用者註解,參見 [runtime/trace](http://tip.golang.org/pkg/runtime/trace).- 使用者代碼和運行時之間的關聯。- 執行追蹤器與分布式追蹤進行關聯的可行性。執行追蹤器引入兩個上層的概念:*region* 及 *task*,以便使用者來對他們的代碼進行插樁。Region 是你希望收集追蹤資料的代碼地區。一個 region 開始和結束在同一個 goroutine 內。另一方面,task 是一個邏輯上的群組,將相關的 region 歸在一起。一個 task 的開始和結束可以在不同的 goroutine 中。我們預期使用者為每個分布式追蹤的 span 都啟動一個執行追蹤器,通過建立 region, 當問題發生時即刻啟用執行追蹤器,記錄一些資料,分析輸出,來對他們的 RPC 架構進行全面的插樁。## 親手進行測試儘管這些新特性只能在 Go 1.11 中使用,你依然可以[按照說明從源碼安裝](http://golang.org/doc/install/source)。我也推薦你在分布式追蹤裡試試。我最近在 [Census](https://github.com/census-instrumentation/opencensus-go) 建立的 span 中增加了對執行追蹤器中 task 的支援。```goimport ("runtime/trace""go.opencensus.io/trace")ctx, span := trace.StartSpan(ctx, "/messages")defer span.End()trace.WithRegion(ctx, "connection.init", conn.init)```如果你用的是 [gRPC](https://github.com/census-instrumentation/opencensus-go/tree/master/examples/grpc) 或者 [HTTP](https://github.com/census-instrumentation/opencensus-go/tree/master/examples/http),那麼你不需要手動建立 span,因為他們已經自動建立好了。在你的 handler 裡面,你可以簡單的對接收到的 context 使用 runtime/trace。註冊 [pprof.Trace](https://golang.org/pkg/net/http/pprof/#Trace) 的 handler,當你需要用執行追蹤器的資料進行診斷時進行資料收集。```goimport _ "net/http/pprof"go func() {log.Println(http.ListenAndServe("localhost:6060", nil))}()```如果你需要執行追蹤器的資料,那就馬上記錄,並啟動視覺化檢視:```$ curl http://server:6060/debug/pprof/trace?seconds=5 -o trace.out$ go tool trace trace.out2018/05/04 10:39:59 Parsing trace...2018/05/04 10:39:59 Splitting trace...2018/05/04 10:39:59 Opening browser. Trace viewer is listening on http://127.0.0.1:51803```接著你就可以在 /usertasks 看到由 helloworld.Greeter.SayHello 建立的執行追蹤器任務的一個分布。![](https://raw.githubusercontent.com/studygolang/gctt-images/master/debugging-latency/4.png)*RPC task 的時間分布。*你可以點擊 3981µs 的那個異常的 bucket,進一步分析在那個特定 RPC 的生命週期裡發生了什麼。同時,/userregions 讓你列出收集到的 region。你可以看到 connection.init 這個 region 以及所對應的多條記錄。(注意到 connection.init 是為了示範而手動整合到 gRPC 架構的源碼中的,更多的插樁工作還在進行中。)![](https://raw.githubusercontent.com/studygolang/gctt-images/master/debugging-latency/5.png)*region 的時間分布。*如果你點擊了任意一個連結,它會給你更多關於處於那個延遲 bucket 中的 region 的詳細資料。在下面的例子中,我們看到有一個 region 位於 1000µs 的 bucket。![](https://raw.githubusercontent.com/studygolang/gctt-images/master/debugging-latency/6.png)*1000µs 的 region 在等待 GC 和調度器上花費了額外的時間。*這樣你就看到了細粒度的延遲明細。你可以看到 1309µs 的 region 交疊了記憶體回收。這以記憶體回收和調度的形式在關鍵路徑上增加了不少開銷。除此之外,執行 handler 與處理阻塞的系統調用花費了差不多的時間。## 局限儘管新的執行追蹤器的特性很強大,但還是有一些局限。- Region 只能在同一個 goroutine 中開始和結束。執行追蹤器目前還不能自動記錄跨越多個 goroutine 的資料。這就需要我們手動地插樁 region。下一個大的步伐將是在 RPC 架構及 net/http 這樣的標準包裡增加細粒度的插樁。- 執行追蹤器輸出的格式比較難解析,`go tool trace`是唯一的能理解這種格式的標準工具。並沒有簡單的方式能夠自動將執行追蹤器的資料與分布式追蹤資料關聯起來 - 所以我們分別搜集它們,之後再做關聯。## 結論Go 正在努力成為強大的線上服務運行時。有了來自執行追蹤器的資料,我們距離對線上伺服器的高可見度近了一步,當問題出現時,能提供的可行資料也更多了。

via: https://medium.com/observability/debugging-latency-in-go-1-11-9f97a7910d68

作者:JBD 譯者:krystollia 校對:polaris1119

本文由 GCTT 原創編譯,Go語言中文網 榮譽推出

本文由 GCTT 原創翻譯,Go語言中文網 首發。也想加入譯者行列,為開源做一些自己的貢獻嗎?歡迎加入 GCTT!
翻譯工作和譯文發表僅用於學習和交流目的,翻譯工作遵照 CC-BY-NC-SA 協議規定,如果我們的工作有侵犯到您的權益,請及時聯絡我們。
歡迎遵照 CC-BY-NC-SA 協議規定 轉載,敬請在本文中標註並保留原文/譯文連結和作者/譯者等資訊。
文章僅代表作者的知識和看法,如有不同觀點,請樓下排隊吐槽

2197 次點擊  
相關文章

聯繫我們

該頁面正文內容均來源於網絡整理,並不代表阿里雲官方的觀點,該頁面所提到的產品和服務也與阿里云無關,如果該頁面內容對您造成了困擾,歡迎寫郵件給我們,收到郵件我們將在5個工作日內處理。

如果您發現本社區中有涉嫌抄襲的內容,歡迎發送郵件至: info-contact@alibabacloud.com 進行舉報並提供相關證據,工作人員會在 5 個工作天內聯絡您,一經查實,本站將立刻刪除涉嫌侵權內容。

A Free Trial That Lets You Build Big!

Start building with 50+ products and up to 12 months usage for Elastic Compute Service

  • Sales Support

    1 on 1 presale consultation

  • After-Sales Support

    24/7 Technical Support 6 Free Tickets per Quarter Faster Response

  • Alibaba Cloud offers highly flexible support services tailored to meet your exact needs.