記一次latency問題排查：談Go的公平調度的缺陷

這是一個建立於 的文章，其中的資訊可能已經有所發展或是發生改變。

我們有一個對延遲很敏感的模組，這個模組需要訪問網路中的另一台機器去取一個時間戳記。實現一次分散式交易，需要執行這個操作兩次，如果這裡拿時間戳記慢了，整個事務的延遲就會上升。理論上內網環境同機房一次網路的round trip應該在0.5ms以內，大部分簡單讀請求應該落在1ms，80%請求的延遲預期也是4ms以內。有客戶反鐀說這裡有30ms以上的延時，在內網環境用sysbench跑OLTP測試了一下能夠複現，於是查了一下這個問題。

在opentracing裡面觀察，這一步確實存在較大的延時，日誌裡面也有列印大量的慢log，影響了事務整體的完成時間。首先方向是確定慢在哪裡，到底是網路有問題還是runtime有問題。

一個同事觀察到，跑這個模組的benchmark時，額外開啟1000個goroutine的worker，每秒鐘tick空轉，跟只跑benchmark對比，發現前者的延遲要比後者高出許多。懷疑runtime有問題。

另一個同事先單獨跑測試，並觀察網路，會發現網路重傳對結果有明顯影響；然後改到用戶端伺服器在同一機器上再測試，排除掉網路幹擾，結果發現進程之間會相互影響；再將伺服器和用戶端分別綁到不同核之後，服務端處理時間比較穩定，而用戶端仍然出現高延遲。到這一步的結論基本上是：runtime和網路都不能保證穩定。

然而runtime的影響能使達到幾十ms層級嗎？看起來不太合理。在我印象中，怎麼都應該控制在微秒數量級，即便回到Go語言1.0的版本，stop the world的GC也不見得這麼挫。何況現在都最佳化到1.9了，GC早就不會stop the world的了。於是我使用go tool trace工具，繼續分析問題。不看不知道，一看還真嚇了一跳。

抓的這一段圖，紅線箭頭是指收到網路訊息，ublock了goroutine的Read操作。注意，從網路訊息可讀，到讀網路的goroutine被再次調度，中間花費了4.368ms !!! 我甚至找到一些更極端的情境，從收到網路訊息可讀，到goroutine實際被喚醒，花費了19ms。這裡先插入講一下業務情況，出於效能考慮，業務實現是做了batch的，所以請求都會通過channel轉寄到一個goroutine上，由那個goroutine去batch的發請求。顯然這個goroutine是非常關鍵的，因為其它的goroutine都是依賴於它。這裡ms層級的調度延遲，直接會對業務整體延遲產生很大影響。

然後說下goroutine的調度時機，goroutine是協程，如果可以執行，會一直執行，直到阻塞才會放棄CPU。比如執行遇到鎖了，或者讀channel，或者讀io請求等等。goroutine被切換出去之後，如果條件滿足了，會被丟到ready隊列裡面去排隊，等待被再次運行。然而，具體什麼時候會被執行，是不確定的，跟排隊的任務隊列長度，排在它前面的任務要執行的時間，以及當時的負載情況等等很多因素有關。

這裡的問題不是GC，而是調度。最終的延遲問題是跟Go的調度設計相關的，主要是協程的公平調度策略：

• 不可以搶佔
• 沒有優先順序的概念

由於不可以搶佔，假設網路訊息好了，但這個時刻所有的CPU上面都正好有goroutine在跑著，並不能將誰踢掉，於是讀網路的那個goroutine並沒機會被喚醒。

由於沒有優先順序的概念，假設終於有goroutine阻塞並讓出CPU了，這時讓誰執行完全是看調度器的心情，讀網路的那個goroutine運氣不好，又沒被喚醒。

只要goroutine不走到函數調用，是沒有機會觸發調度，不會讓出CPU的。

Go聲稱可以開千千萬萬個goroutine，其實是有開銷的：越多的goroutine被“公平”調度，越可能影響其中重要goroutine的喚醒，進而影響整體延遲。

回頭再想之前同事那個測試，空跑worker會影響延時，也就能解釋通了：由於被調度機率均等，越多無關的goroutine，則幹活的那個goroutine被調度的機率越低，於是導致延遲增加。

Go的記憶體回收雖然不stop the world，仍然可能影響延遲：GC是可以打斷goroutine，要求讓出CPU的，而什麼時候goroutine被再次調回來又看臉。

有太多太多的因素來影響調度，使整個runtime內的延遲變得不可控。平時壓力小時調度上可能看不出什麼來，然而尤其在壓力大的時候，就表現得越差。