這是一個建立於 的文章,其中的資訊可能已經有所發展或是發生改變。
有一段時間,我們的推送服務socket佔用很不正常,我們自己統計的同時線上就10w的使用者,但是佔用的socket竟然達到30w,然後查看goroutine的數量,發現已經60w+。
每個使用者佔用一個socket,而一個socket,有read和write兩個goroutine,簡化的代碼如下:
c, _ := listerner.Accept()go c.run()func (c *conn) run() { go c.onWrite() c.onRead()}func (c *conn) onRead() { stat.AddConnCount(1) //on something stat.AddConnCount(-1) //clear //notify onWrite to quit}
當時我就懷疑,使用者同時線上的統計是正確的,也就是之後的clear階段出現了問題,導致兩個goroutine都無法正常結束。在檢查代碼之後,我們發現了一個可疑的地方,因為我們不光有自己的統計,還會將一些統計資訊發送到我們公司的統計平台,代碼如下:
ch = make([]byte, 100000)func send(msg []byte) { ch <- msg}//在另一個goroutine的地方,msg <- msghttpsend(msg)
我們channel的緩衝分配了10w,如果公司統計平台出現了問題,可能會導致channel阻塞。但到底是不是這個原因呢?
幸運的是,我們先前已經在代碼裡面內建了pprof的功能,通過pprof goroutine的資訊,發現大量的goroutine的當前運行函數在httpsend裡面,也就是說,公司的統計平台在大並發下面服務不可用,雖然我們有http逾時的處理,但是因為發送的資料量太頻繁,導致整體阻塞。
臨時的解決辦法就是關閉了統計資訊的發送,後續我們會考慮將其發送到自己的mq上面,雖然也可能會出現mq服務停用問題,但是說句實話,比起自己實現的mq,公司的統計平台更讓我不可信。
這同時也給了我一個教訓,訪問外部服務一定要好好處理外部服務停用情況,即使可用,也要考慮壓力問題。
對於pprof如何查看了goroutine的問題,可以通過一個簡單的例子說明:
package mainimport ( "net/http" "runtime/pprof")var quit chan struct{} = make(chan struct{})func f() { <-quit}func handler(w http.ResponseWriter, r *http.Request) { w.Header().Set("Content-Type", "text/plain") p := pprof.Lookup("goroutine") p.WriteTo(w, 1)}func main() { for i := 0; i < 10000; i++ { go f() } http.HandleFunc("/", handler) http.ListenAndServe(":11181", nil)}
這上面的例子中,我們啟動了10000個goroutine,並阻塞,然後通過訪問http://localhost:11181/,我們就可以得到整個goroutine的資訊,僅列出關鍵資訊:
goroutine profile: total 1000410000 @ 0x186f6 0x616b 0x6298 0x2033 0x188c0# 0x2033 main.f+0x33 /Users/siddontang/test/pprof.go:11
可以看到,在main.f這個函數中,有10000個goroutine正在執行,符合我們的預期。
在go裡面,還有很多運行時查看機制,可以很方便的幫我們定位程式問題,不得不贊一下。