一次帶寬拉滿引發的百分百超時血案！
偈語: 未經他人苦,莫勸他人善
鏖戰兩周有余，為了排查線上某接口百分百超時的原因，如今總算有些成果。雖然仍有疑慮但是礙于時間不允許和個人能力問題先做如下總結以備來日再戰。
出口帶寬拉滿
能夠發現這個問題實屬僥幸。依稀記得這是一個風雨交加的夜晚，這風、這雨注定了今夜的不平凡。果然線上百分百超時的根因被發現了!
我們的線上接口需要對外請求，而我們的流出帶寬被拉滿自然耗時就長因此導致超時。當然這都是結果，畢竟中間過程的艱辛已經遠遠超出老許的文字所能描述的范圍。
反思
結果有了，該有的反思仍舊不能少。比如流出帶寬被拉滿為什么沒有提前預警!無論是自信帶寬足夠還是經驗不足都值得老許記上一筆。
而在帶寬問題被真正發現之前，老許內心對帶寬其實已有所懷疑，但是卻沒有認真進行驗證，只聽信了他人的推測導致發現問題的時間被推遲。
httptrace
有時候不得不吹一波Go對http trace的良好支持。老許也是基于此做了一個demo，該demo可以打印http請求各階段耗時。
上述為一次http請求各階段耗時輸出，有興趣的可去https://github.com/Isites/go-coder/blob/master/httptrace/trace.go拿到源碼。
老許對帶寬的懷疑主要就是基于此demo中的源碼進行線上分析測試給到的推測。
框架問題
本部分更加適合騰訊系的兄弟們去閱讀，其他非騰訊系技術可以直接跳過。
我司的框架為TarsGo，我們在線上設置handletimeout為1500ms，該參數主要用于控制某一接口總耗時不超過1500ms，而我們的超時告警均為3s，因此即使帶寬已滿這個百分百超時告警也不應出現。
為了研究這個原因，老許只好花些零碎的時間去閱讀源碼，最終發現了TarsGo@v1.1.6的handletimeout控制是無效的。
下面看一下有問題的源碼:
- func (s *TarsProtocol) InvokeTimeout(pkg []byte) []byte {
- rspPackage := requestf.ResponsePacket{}
- rspPackage.IRet = 1
- rspPackage.SResultDesc = "server invoke timeout"
- return s.rsp2Byte(&rspPackage)
- }
當某接口總執行時間超過handletimeout時，會調用InvokeTimeout方法告知client調用超時，而上述的邏輯中忽略了IRequestId的響應，這就導致client收到響應包時無法將響應包和某次的請求對應起來，從而導致客戶端一直等待響應直至超時。
最終修改如下：
- func (s *TarsProtocol) InvokeTimeout(pkg []byte) []byte {
- rspPackage := requestf.ResponsePacket{}
- // invoketimeout need to return IRequestId
- reqPackage := requestf.RequestPacket{}
- is := codec.NewReader(pkg[4:])
- reqPackage.ReadFrom(is)
- rspPackage.IRequestId = reqPackage.IRequestId
- rspPackage.IRet = 1
- rspPackage.SResultDesc = "server invoke timeout"
- return s.rsp2Byte(&rspPackage)
- }
后來老許在本地用demo驗證handletimeout終于可以控制生效。當然本次修改老許已經在github上面提交issue和pr，目前已被合入master。相關issue和pr如下：
https://github.com/TarsCloud/TarsGo/issues/294
https://github.com/TarsCloud/TarsGo/pull/295
仍有疑慮
到這里，事情依然沒有得到完美的解決。
上圖為我們對外部請求做的最大耗時統計，毛刺嚴重且耗時簡直不符合常理。圖中標紅部分耗時約為881秒，而實際上我們在發起http請求時均做了嚴格的超時控制，這也是令老許最為頭疼的問題，這幾天臉上冒的痘都是為它熬夜的證明。
更加令人驚恐的事情是，我們將官方的http替換為fasthttp后，毛刺沒有了!老許自認為對go的http源碼還有幾分淺薄的理解，而殘酷的現實簡直令人懷疑人生。
到目前，老許再次簡閱了一遍http的源碼，仍未發現問題，這大概率會成為一樁懸案了，還望各位有經驗的大佬分享一二，至少讓這篇文章有始有終。
替換fasthttp時還未發現帶寬被拉滿
美好愿景
最后，別無他言，直接上圖!
