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