在客戶那部署 Springboot項(xiàng)目,啟動(dòng)非常慢要2-3分鐘. 因?yàn)殚_發(fā)的時(shí)候本地windows啟只要7s,測試環(huán)境也是centos只要7s.
因?yàn)榭蛻裟鞘翘摂M化了3臺機(jī)器, 安裝同樣的操作系統(tǒng),但其中1臺很快7s,其他兩臺很慢.這就非常奇怪了.
網(wǎng)上大部份都說random的原因, 我們?nèi)颊罩牧艘廊缓苈?
通過strace確切知道改成功了,沒改之前全是random,改了之后有urandom.
但是可以發(fā)現(xiàn)還是會調(diào)random, 而且機(jī)器的隨機(jī)數(shù)值一直在3000左右,所以可以排除random原因.
奇怪的是系統(tǒng)也沒有報(bào)錯(cuò),就是啟動(dòng)慢,啟動(dòng)成功后接口頁面都沒有問題.關(guān)鍵是有1臺機(jī)器又很快,所以讓我們只能考慮是機(jī)器原因或虛擬化的原因.然后我們復(fù)制了一臺那個(gè)沒有問題的機(jī)器, 在這一臺上重新部署,結(jié)果依然是很慢.查看cpu 內(nèi)存 io 都沒有什么問題.
通過starce也只能看出是 futex 花費(fèi)了大量時(shí)間,下圖上11254這個(gè)進(jìn)程id,這個(gè)futex花費(fèi)了1.89s,然后往上找到11254的源頭也看不出什么原因?qū)е?
然后懷疑應(yīng)該不是我們項(xiàng)目問題,我拿一個(gè)最簡單的springboot項(xiàng)目測試也是很慢.
然后把springboot日志級別調(diào)成debug, 剛開始查問題的時(shí)候就已經(jīng)試過了調(diào)日志,因?yàn)榘l(fā)現(xiàn)出現(xiàn)Spring那個(gè)logo之前很慢而且也沒有日志, 然后后面的日志又太長,以為找不出什么有用的信息,試過一次后就又調(diào)成info級別了.
我們啟動(dòng)慢的情況是這樣的,啟動(dòng)后, 等幾十秒出現(xiàn)Spring logo, 然后跑了一會兒,又等幾十秒,然后系統(tǒng)啟動(dòng)成功.
所以這一次想到,雖然啟動(dòng)前沒有日志,但是中間的慢,應(yīng)該可以知道它停在哪里.然后google那個(gè)停在那里的日志.
點(diǎn)進(jìn)去后有一句話看的我心頭一愣 , 這個(gè)用戶說,似乎這20s的等待是由于NetworkInterface.getAll
方法
我突然眼前一亮,趕緊看一下我用jstack輸出的文件,我用jstack輸出了三個(gè)文件
1剛啟動(dòng)的時(shí)候,2第二次卡頓的時(shí)候,3啟動(dòng)成功的時(shí)候
果然在第一個(gè)和第二個(gè)文件里都有因?yàn)檎{(diào)用網(wǎng)絡(luò)相關(guān)的接口,而第三個(gè)則沒有.
那么也就是說根本原因就是 InetAddress.getLocalHost 導(dǎo)致很慢的原因了.
然后用那個(gè)最簡單的Springboot項(xiàng)目調(diào)用一下這個(gè)方法,果然不出所料花了20s的時(shí)間.
找到根本原因隨便一搜就知道,是因?yàn)樵?etc/hosts 里并沒有加入當(dāng)前主機(jī)的名字,.
在正式環(huán)境下加入了主機(jī)名后果然快了.
那為什么有一臺很快了,因?yàn)槟且慌_是另一個(gè)同事裝了mq,他修改了這個(gè)hosts文件加了主機(jī)名.
然后復(fù)制這臺機(jī)器的時(shí)候會填一個(gè)新主機(jī)名,所以復(fù)制的那一臺機(jī)器也很慢.
最終解決掉了這個(gè)奇怪的問題,通過這一次經(jīng)歷,也學(xué)會了使用strace,jstack等調(diào)試工具,也有不少的收獲.
