为什么SOFA RPC调用30s还不超时？
1. 背景
最近幫客戶處理了一個詭異的RPC調用問題，想跟大家分享一下。關于SOFA RPC，請參考官網[1]。
2. 問題現象
客戶使用 REST 接口觸發RPC的調用，發現每次RPC調用都需要30秒的時間，最終的RPC調用結果是成功的。從業務日志來看，開始處理業務和結束業務之間確實花了30秒。
3. 問題分析
RPC 調用花了30秒調用成功，這本身是一件詭異的事情。因為默認SOFA RPC的框架RPC超時時間是3秒。下面的代碼顯式的設置了超時時間，設置成了默認值。
<sofa:reference jvm-first="false" id="rpcService" interface="com.sofa.rpc.facade.demo.RpcService"><sofa:binding.bolt><sofa:global-attrs timeout="3000" /></sofa:binding.bolt> </sofa:reference>我們首先確定了代碼中確實沒有更改SOFA RPC框架的默認超時時間。所以，理論上RPC調用超過3秒，RPC客戶端就應該報錯了。
那么，我們來看看這30秒到底發生了什么！
3.1 直擊框架核心
我們知道SOFA RPC調用的超時時間是3秒，我們首先需要確認SOFA RPC框架到底花了多少時間。
根據業務日志的時間點（2020-01-21 10:41:34），查看RPC的digest日志： /home/admin/logs/tracelog/rpc-client-digest.log。我們發現RPC執行的時間才54ms。這證明實際上RPC調用是很快的！那么時間到底去哪里了？
難道時間花在獲得RPC provider 的地址上了？
于是，我們查看RPC客戶端的注冊中心尋址日志，/home/admin/logs/rpc/rpc-registry.log。我們發現該接口的地址在三秒前就返回了。所以也不是尋址的問題。
3.2 懷疑業務代碼
基于上述的證據，我們有理由懷疑是業務代碼自身的問題。我們要求客戶檢查業務代碼。客戶在業務代碼中添加了很多日志，顯式的打印業務處理和RPC調用時間，結果證明時間還是消失在調用RPC的過程中。以下是客戶 SOFA RPC調用的具體代碼。
GenericObject result = (GenericObject)serviceName.$genericInvoke(methodName, argTypes, args);看到這個結果，我們百思不得其解：RPC的超時時間是3s，但是實際上這次調用花了30s而沒有超時（因為實際執行RPC的時間才54ms）。那么，時間到底去哪里了？
3.3 逆向推導
從結果來逆向推導，genericInvoke 應該包含了很多處理方法，而在調用真正的RPC方法之前肯定調用了其他處理方法做了其他事情，那么到底做了什么事情？假如你閱讀代碼的話，會發現你會被淹沒在汪洋代碼里面，我們需要其他更有效的方式排查此類問題。
這30秒給人的感覺就是“卡”在了某個地方。這時候，我們需要想，在這種情況下，什么日志或者工具能幫助我們進一步逼近真相？
這時候，jstack登場了。jstack可以幫助我們獲得某一個時刻某個進程里面所有線程的調用堆棧。假如某個線程卡在什么方法上的話，通過多抓幾次 jstack 的方式，我們能清楚的看到卡住的方法。所以我們讓客戶在重現問題的時候每隔5s收集一次 jstack $PID >stack.log，至少收集4個日志。$PID需要使用業務應用的java進程ID替換。
皇天不負有心人，從這幾個jstack日志中，我們通過genericInvoke 快速定位到相應的線程，發現卡在了OS的方法getLocalHostName上（幾個jstack日志都卡在getLocalHostName上）。同時，從調用堆棧來看，線程當時是在初始化RPC的tracer，也就是還沒有開始RPC調用，所以不會有RPC調用超時發生。
那么這個getLocalHostName方法到底在干什么呢？通過網絡搜索，發現這個函數其實就是去查找本機的HostName，IP。CentOS 查找的順序是這樣的：/etc/hosts 文件，DNS，myhostname（只返回本機配置的公共IP地址）。
由于客戶這邊DNS配置錯誤，導致一直卡在該方法DNS超時，所以造成了該問題。同時，經過客戶確認，這幾臺機器并不依賴DNS尋址。
所以我們的解決方案很簡單：在 /etc/hosts 中添加了IP與主機名的映射。
參考文檔
[1]SOFA RPC：https://help.aliyun.com/document_detail/149865.html?spm=a2c4g.11186623.6.560.178c5fb01GxG9Z
我們是阿里云智能全球技術服務-SRE團隊，我們致力成為一個以技術為基礎、面向服務、保障業務系統高可用的工程師團隊；提供專業、體系化的SRE服務，幫助廣大客戶更好地使用云、基于云構建更加穩定可靠的業務系統，提升業務穩定性。我們期望能夠分享更多幫助企業客戶上云、用好云，讓客戶云上業務運行更加穩定可靠的技術，您可用釘釘掃描下方二維碼，加入阿里云SRE技術學院釘釘圈子，和更多云上人交流關于云平臺的那些事。
原文鏈接：https://developer.aliyun.com/article/783846?
版權聲明：本文內容由阿里云實名注冊用戶自發貢獻，版權歸原作者所有，阿里云開發者社區不擁有其著作權，亦不承擔相應法律責任。具體規則請查看《阿里云開發者社區用戶服務協議》和《阿里云開發者社區知識產權保護指引》。如果您發現本社區中有涉嫌抄襲的內容，填寫侵權投訴表單進行舉報，一經查實，本社區將立刻刪除涉嫌侵權內容。 與50位技術專家面對面20年技術見證，附贈技術全景圖總結
以上是生活随笔為你收集整理的为什么SOFA RPC调用30s还不超时？的全部內容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： Apache Flink Meetup，
- 下一篇： 阿里云 EDAS 3.0 助力唱鸭提升微