前幾天在測試環境碰到一個非常奇怪的與 dubbo 相關的問題,事后我在網上搜索了一圈并沒有發現類似的帖子或文章,于是便有了這篇。
希望對還未碰到或正在碰到的朋友有所幫助。
現象
現象是這樣的,有一天測試在測試環境重新部署一個 dubbo 應用的時候發現應用“啟動不起來”。
但過幾個小時候之后又能自己慢慢恢復,并能夠對外提供 dubbo 服務。
但其實經過我后續排查發現剛開始其實并不是啟動不起來,而是啟動速度非常緩慢,所以當應用長時間啟動后才會對外提供服務。而這個速度慢到居然要花費 2 個小時。
導致的一個結果是測試完全不敢在測試環境發版驗證了,每驗證一個功能修復一個 bug 就得等上兩個小時,這誰受得了。
而且經過多次觀察,確實每次都是花費兩小時左右應用才能啟動起來。
嘗試解決
最后測試頂不住了,只能讓我這個“事故報告撰寫專家”來看看。
當我得知這個問題的現象時其實完全沒當一回事:
都不用想,這不就是主線程阻塞了嘛,先看看是否在初始化的時候數據庫、Zookeeper 之類的連不上導致阻塞了-------來之多次事故處理的經驗告訴我。
于是我把這事打回給測試讓他先找運維排查下,不到萬不得已不要影響我 Touch fish。
第二天一早看到測試同學的微信頭像跳動時我都已經準備接受又一句 “膜拜大佬” 的回復時,卻收到 “網絡一切正常,沒人動過,再不解決就要罷工了”。
好吧,忽悠不過去了。
首先這類問題的排查方向應該不會錯,就是主線程阻塞了,至于是啥導致的阻塞就不能像之前那樣瞎猜了。
我將應用重啟后用 jstack pid 將線程快照打印到終端,直接拉到最后看看 main 線程到底在干啥。
前幾次的快照都是很正常:
加載 Spring ---->連接 Zookeeper ---> 連接 Redis,都是依次執行下來沒有阻塞。
隔了一段后應用確實還沒起來,我再次 jstack 后得到如下信息:
翻源碼
我一直等了十幾分鐘再多次 jstack 得到的快照得到的信息都是一樣的。
如圖所示可見主線程是卡在了 dubbo 的某個方法 ServiceConfig.java 的 303 行中。
于是我找到此處的源碼:
簡單來說這里的邏輯就是要獲取本機的 IP 將其注冊到 Zookeeper 中用于其他服務調用。
再往下跟就如堆棧中一樣是卡在了 Inet4AddressImpl.getLocalHostName 處。
但這是一個 native 方法,我們應用也根本干涉不了,最終的現象就是調用這個本地方法非常耗時。
于是這問題貌似也阻塞在這兒了,沒有太多辦法。
最終解決
既然這是一個 native 方法,那說明和應用本身沒有啥關系(確實也是這樣,這個問題是突然間出現的。)
那是否是服務器本身的問題呢,想到在 native 方法里是獲取本機的 hostname,那是否和這個 hostname 有關系呢。
這是在我自己的阿里云服務器上測試,真正的測試環境不是這個名字。
拿到服務器 hostname 后再嘗試 ping 這個 hostname,奇怪的現象發生了:
命令剛開始會卡住一段時間(大概幾十秒),然后才會輸出 hostname 對應的 ip 以及對應的延遲。
而當我直接 ping 這個 ip 時卻能快速響應后面的輸出。
最后我嘗試在 /etc/hosts 配置文件中加入了對應的 host 配置:
xx.xx.xx.xx(ip) hostname
再次 ping hostname 的效果就和直接 ping ip 一樣了。
于是我再次重啟應用,一切都正常了。
總結
最后根據我調整的內容嘗試分析下本次問題的原因:
- 當 Dubbo 在啟動獲取本地 ip 時,是通過服務器 hostname 從 dns 服務器返回當前的 ip 地址。
- 由于 dns 服務器或者是本地服務器與 dns 服務器之間存在網絡問題,導致這個過程的時間被拉長(猜測)。
- 我在本地的 host 文件中配置后,就相當于本地有一個緩存,優先取本地配置的 ip ,避免了和 dns 服務器交互的過程,所以速度提升了。
雖然問題得到解決了,但還是有幾個疑問:
第一個是為什么和 DNS 服務器的交互會這么慢,即便是慢也沒有像應用那樣需要 2 個小時才能返回,這里我也沒搞得太清楚,有相關經驗的朋友可以留言討論。
第二就是 Dubbo 在這個依賴外部獲取資源時健壯性是否可以做的更好,雖說我這問題估計也幾人碰到。
對于這種長時間沒有啟動成功的問題是否可以加上提示,比如直接拋出異常退出程序,將問題可能的原因告訴開發者,方便排查問題。