今天帶來一個真實案例,雖然不是什麼故障,但是希望對大家有所幫助。
一、問題現象:
生產環境部署springcloud應用,服務部署之後,有時候需要10幾分鐘才能啟動成功,在開發測試環境則沒有這個問題。最開始是所有微服務都有這種情況,隨著專案週期的進行,zwfw微服務的問題最為突出,每次部署後,需要大概6分鐘才能啟動,在這6分鐘期間,程式沒有任何日誌,控制檯沒有任何輸出。每次部署都會觸發服務不可用的報警。如下:
注:報警是連續2分鐘不可用才開始傳送。
二、問題分析過程
起初懷疑是公司使用的加解密工具Virbox Protector導致的,公司加密程式Virbox Protector畢竟對線上的java可執行程式和待發布的jar包都進行了修改,並且在程式啟動前,java首先要對jar包進行解密,勢必會造成程式的效能造成影響。但是加密組本著“其他組都沒有反饋這個問題,就你們組有問題”的態度,直接將問題踢了回來,導致問題久久不能認真對待。
2021年9月9日研發人員反饋另外一個微服務,也出現了這種啟動慢或者無法啟動的問題,問題被再次提出。這次,我決定再重新觀察一下這個問題,最起碼要找出是加密工具惹禍的證據。
因為zwfw這個服務能穩定復現,所以就拿這個服務進行分析。
2.1 zwfw這個微服務
首先介紹一下zwfw這個服務的背景,這個服務部署在華為雲主機上,不具備訪問網際網路的網路許可權。
2.2 jstack工具介紹
如果你想知道,當前時間,java都在執行哪些任務,那麼就可以使用jstack來觀察。jstack,jmap,jstats都是java生態中非常重要的工具,並且是jvm自帶的命令。使用jstack 程式號,就能列出這個java程式所有的執行緒,及執行緒正在執行的方法棧,預設是將執行緒棧列印在當前控制檯。jstack還可以和作業系統命令top聯合使用排查CPU佔用高的問題。
2.3 排查過程
分析問題之前,首先將這個服務從nacos上面踢下來,防止在除錯期間被前端機器呼叫(因為是直接在生產環境除錯)。
然後將zwfw的程式kill掉,再手工使用命令啟動服務。打出執行命令後,日誌檔案中的日誌開始中斷。
然後執行jstack 程式號,列印出來堆疊,結果真是出乎意料,其中主執行緒的方法棧如下:
比較奇怪,還真是阻塞在專案程式碼上面。這個問題,之前也有人遇到過,如:https://www.javacodegeeks.com/2015/03/inetaddressimpllookupallhostaddr-slowhangs.html
因為之前做專案,碰到過多次沒有配置hostname導致的dns超時的問題(比如說hession呼叫),所以根據我的經驗,這個只需要修改一下host檔案就能解決。
所以就對本機的hostname增加ip的解析。因為怕應用依賴hostname對應的IP,所以hostname對應的ip,要配置成區域網的真實ip。修改host配置後,問題解決,zwfw啟動縮短為正常的10秒以內。
三、解決方法
既然是因為解析hostname導致,那最快的解決方法就是增加hostname的解析。也不知道log4j2,為什麼必須要這樣做。
1、首先檢視本機的hostname,輸入hostname命令。
2、檢視本機的ip和ipv6地址,使用ifconfig命令。
3、編輯/etc/hosts檔案,增加hostname的解析,問題解決
四、問題回顧和總結
團隊之間互相踢皮球不配合導致這個問題持續的時間比較長。我一開始一直認為是公司對java程式進行了修改導致的,導致沒有嘗試排查問題,所以,以後遇到問題,不要輕易懷疑很成熟的基礎元件。