[[434974]]

一、超時現(xiàn)象反饋

在發(fā)布卡點過程中，有同學反饋在發(fā)布過程中存在偶發(fā)性超時情況。集中在上下游服務較多節(jié)點的服務，幾十個上百個節(jié)點的服務較多。不是必然出現(xiàn)，一批服務偶爾有一個節(jié)點出現(xiàn)。剛出現(xiàn)的前幾例由于沒有觸發(fā)線程dump一直定位不到哪里的問題。

RPC框架中服務端線程池默認使用線程超過80%會觸發(fā)線程dump，方便觀察運行狀態(tài)。直到有兩個服務觸發(fā)了dump才把這個謎底揭開。

二、超時現(xiàn)象跟蹤

鏈路日志： 客戶端AppXXXService調(diào)用服務Appxxx發(fā)生超時，長達50秒。

服務消費方報錯信息：

客戶端等待中取消請求，發(fā)生調(diào)用時間為：2021-11-02 22:11:59.148

耗時監(jiān)控曲線：該服務基本上在同一時間段發(fā)起向下游的服務均發(fā)生超時。

服務端隊列監(jiān)控：隊列顯示瞬間增加很多任務

磁盤IO和CPU都有上升

線程dump情況，通信線程調(diào)用到了SynchronizationContext，底層的work通信線程怎么調(diào)用到了獲取節(jié)點的業(yè)務方法去了。

三、問題根因

RPC框架中代碼中有使用SynchronizationContext，此處與gRPC共用。

SynchronizationContext使用的queue是ConcurrentLinkedQueue隊列，被單線程串行執(zhí)行。

問題原因：再回到上面的線程棧，業(yè)務節(jié)點發(fā)現(xiàn)事件和gRPC底層通信共用了SynchronizationContext造成阻塞，和線程錯亂執(zhí)行。

問題解決：不再和gRPC共用SynchronizationContext，如果使用單獨實例化一個即可。該問題通過測試同學通過故障注入的方式得以復現(xiàn)。