SpringBoot項(xiàng)目啟動(dòng)緩慢問題處理
- 遇到的問
- 解決方案
- 問題思考
- 結(jié)語
- 參考資料
遇到的問題
????????在一個(gè)風(fēng)和日麗的下午,某位和藹的同事破口大罵:“臥槽,我程序每次啟動(dòng)都2分鐘,我受不了啦!”。另外一位同事卻說:“我沒問題呀,我20多秒就OK了”。此言一出,引發(fā)了大家集體共鳴,看來程序啟動(dòng)緩慢,一直困擾著大家,后面經(jīng)過了解,QA發(fā)布Test環(huán)境也有此問題。
????????啟動(dòng)日志截取如下:
部分日志截取
2020-06-12 18:22:09.391|49280|INFO|[wms-interfaces,,,,]|main|c.p.f.a.r.p.AlicloudRocketMqProducer : alicloud rocketmq producer loading!
2020-06-12 18:22:24.668|49280|INFO|[wms-interfaces,,,,]|main|c.p.f.a.r.p.AlicloudRocketMqProducer : alicloud rocketmq producer 啟動(dòng)耗時(shí)[15277]
2020-06-12 18:22:34.083|49280|INFO|[wms-interfaces,,,,]|main|c.p.scm.wms.WmsInterfacesApplication : Started WmsInterfacesApplication in 114.212 seconds (JVM running for 120.306)
解決方案
解決方案其實(shí)很簡單,只需要在/etc/hosts文件中,增加一段配置,即本機(jī)hostname到本機(jī)IP的映射。
# shell或者手動(dòng)添加
echo 127.0.0.1 $(hostname) >> /etc/hosts
echo ::1 $(hostname) >> /etc/hosts
#/etc/hosts
127.0.0.1 localhost zhangweideMacBook-Pro.local
::1 localhost zhangweideMacBook-Pro.local
問題思考
????????這個(gè)問題似乎大家都存在,起初并沒有過多在意,推測是接入的中間件較多,開發(fā)環(huán)境網(wǎng)絡(luò)不佳導(dǎo)致,但是ping中間件網(wǎng)絡(luò)地址后,發(fā)現(xiàn)延遲是很低的,網(wǎng)絡(luò)方面似乎沒有問題。
????????我在以前的工作經(jīng)驗(yàn)中,曾經(jīng)發(fā)生過一次線上故障,生產(chǎn)機(jī)器修改hostname后,所有服務(wù)響應(yīng)變的非常緩慢(RT增加數(shù)秒),最后查詢原因是DNS解析有問題,調(diào)整本機(jī)DNS后遍恢復(fù)。隨后配置服務(wù)器hosts里面本機(jī)IP hostname,成為初始化服務(wù)器的必要工作。
????????出現(xiàn)這個(gè)問題后,我第一直覺是嘗試修改hosts文件配置,沒想到修改后,啟動(dòng)速度馬上變快,由以前的120秒縮短至30秒內(nèi)。
????????嘗試檢查啟動(dòng)時(shí)的堆棧信息,發(fā)現(xiàn)一個(gè)與網(wǎng)絡(luò)相關(guān)的方法。結(jié)合修改hosts能解決問題的現(xiàn)象,感覺這個(gè)方法很可疑。
jstack `jps | grep "WmsInterfacesApplication" | awk '{print $1}'`
"main" #1 prio=5 os_prio=31 tid=0x00007f9bd0000800 nid=0xf03 runnable [0x000070000335e000]
java.lang.Thread.State: RUNNABLE
at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method)
at java.net.InetAddress$2.lookupAllHostAddr(InetAddress.java:929)
at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1324)
at java.net.InetAddress.getLocalHost(InetAddress.java:1501)
- locked <0x00000006c0018a98> (a java.lang.Object)
at sun.management.VMManagementImpl.getVmId(VMManagementImpl.java:140)
at sun.management.RuntimeImpl.getName(RuntimeImpl.java:59)
at org.springframework.boot.system.ApplicationPid.getPid(ApplicationPid.java:54)
at org.springframework.boot.system.ApplicationPid.<init>(ApplicationPid.java:45)
????????于是乎,找到這段代碼,打上斷點(diǎn),debug之,果不其然,在沒有配置本地hosts時(shí),getLocalHost()這個(gè)方法耗時(shí)長達(dá)5s,而SpringBoot啟動(dòng)時(shí),會(huì)多次調(diào)用此方法,導(dǎo)致項(xiàng)目啟動(dòng)時(shí)間很長。貼上部分代碼。
# InetAddress.java
# step1
public static InetAddress getLocalHost() throws UnknownHostException {
SecurityManager security = System.getSecurityManager();
try {
String local = impl.getLocalHostName();
if (security != null) {
security.checkConnect(local, -1);
}
if (local.equals("localhost")) {
return impl.loopbackAddress();
}
InetAddress ret = null;
synchronized (cacheLock) {
long now = System.currentTimeMillis();
if (cachedLocalHost != null) {
if ((now - cacheTime) < maxCacheTime) // Less than 5s old?
ret = cachedLocalHost;
else
cachedLocalHost = null;
}
// we are calling getAddressesFromNameService directly
// to avoid getting localHost from cache
if (ret == null) {
InetAddress[] localAddrs;
try {
// 從這里進(jìn)入
localAddrs = InetAddress.getAddressesFromNameService(local, null);
} catch (UnknownHostException uhe) {
// Rethrow with a more informative error message.
UnknownHostException uhe2 =
new UnknownHostException(local + ": " +
uhe.getMessage());
uhe2.initCause(uhe);
throw uhe2;
}
cachedLocalHost = localAddrs[0];
cacheTime = now;
ret = localAddrs[0];
}
}
return ret;
} catch (java.lang.SecurityException e) {
return impl.loopbackAddress();
}
}
# step2
private static InetAddress[] getAddressesFromNameService(String host, InetAddress reqAddr)
throws UnknownHostException
{
InetAddress[] addresses = null;
boolean success = false;
UnknownHostException ex = null;
if ((addresses = checkLookupTable(host)) == null) {
try {
for (NameService nameService : nameServices) {
try {
// 這里耗時(shí)5s
addresses = nameService.lookupAllHostAddr(host);
success = true;
break;
} catch (UnknownHostException uhe) {
if (host.equalsIgnoreCase("localhost")) {
InetAddress[] local = new InetAddress[] { impl.loopbackAddress() };
addresses = local;
success = true;
break;
}
else {
addresses = unknown_array;
success = false;
ex = uhe;
}
}
}
// More to do?
if (reqAddr != null && addresses.length > 1 && !addresses[0].equals(reqAddr)) {
// Find it?
int i = 1;
for (; i < addresses.length; i++) {
if (addresses[i].equals(reqAddr)) {
break;
}
}
// Rotate
if (i < addresses.length) {
InetAddress tmp, tmp2 = reqAddr;
for (int j = 0; j < i; j++) {
tmp = addresses[j];
addresses[j] = tmp2;
tmp2 = tmp;
}
addresses[i] = tmp2;
}
}
cacheAddresses(host, addresses, success);
if (!success && ex != null)
throw ex;
} finally {
updateLookupTable(host);
}
}
return addresses;
}
# step3
public native InetAddress[] lookupAllHostAddr(String hostname) throws UnknownHostException;
????????一步步跟蹤后發(fā)現(xiàn),底層是native方法,底層調(diào)用的是操作系統(tǒng)的getaddrinfo()方法。看來問題確實(shí)在這里。根據(jù)debug結(jié)果推斷,getaddrinfo()方法根據(jù)hostname查詢IP,先從本地hosts查詢,沒有找到再去局域網(wǎng)絡(luò)中查找,這樣導(dǎo)致了getLocalHost緩慢。


????????我以為故事到這里就結(jié)束了,隨手改了下hostname,奇怪的事情發(fā)生了,getLocalHost()反應(yīng)又變快了!
zhangweideMacBook-Pro:zhangwei root# hostname zhangweideMacBook-Pro.local2


????????問題很奇怪,百度一番也無果。打開mac電腦設(shè)置看看情況先。


????????這里有個(gè)置灰的.local,似乎不讓你修改。但是使用hostname 查看本機(jī)的hostname是zhangweideMacBook-Pro.local,而且可以隨意修改。沒辦法糾結(jié)這些了,進(jìn)一步分析,每次返回都需要5秒左右的時(shí)間,看起來似乎是一個(gè)超時(shí)時(shí)間。使用scutil --dns查看本機(jī)dns解析情況:
zhangweideMacBook-Pro:zhangwei root# scutil --dns
DNS configuration
resolver #1
search domain[0] : xxxx-xxx.com(人工脫敏)
nameserver[0] : 10.134.130.61
nameserver[1] : 10.134.130.62
if_index : 9 (en0)
flags : Request A records
reach : 0x00000002 (Reachable)
resolver #2
domain : local
options : mdns
timeout : 5
flags : Request A records
reach : 0x00000000 (Not Reachable)
order : 300000
resolver #3
domain : 254.169.in-addr.arpa
options : mdns
timeout : 5
flags : Request A records
reach : 0x00000000 (Not Reachable)
order : 300200
resolver #4
domain : 8.e.f.ip6.arpa
options : mdns
timeout : 5
flags : Request A records
reach : 0x00000000 (Not Reachable)
order : 300400
resolver #5
domain : 9.e.f.ip6.arpa
options : mdns
timeout : 5
flags : Request A records
reach : 0x00000000 (Not Reachable)
order : 300600
resolver #6
domain : a.e.f.ip6.arpa
options : mdns
timeout : 5
flags : Request A records
reach : 0x00000000 (Not Reachable)
order : 300800
resolver #7
domain : b.e.f.ip6.arpa
options : mdns
timeout : 5
flags : Request A records
reach : 0x00000000 (Not Reachable)
order : 301000
DNS configuration (for scoped queries)
resolver #1
search domain[0] : xxxx-xxx.com(人工脫敏)
nameserver[0] : 10.1xx.1x0.61(人工脫敏)
nameserver[1] : 10.1xx.1x0.62(人工脫敏)
if_index : 9 (en0)
flags : Scoped, Request A records
reach : 0x00000002 (Reachable)
????????驚奇的發(fā)現(xiàn)這條記錄,domain : local,timeout : 5,與之前發(fā)生的現(xiàn)象匹配上了。那么繼續(xù)分析一下,是否是因?yàn)?local結(jié)尾的hostnane,走了mdns,對(duì)結(jié)果產(chǎn)生了影響。

推斷結(jié)論
????????由此推論如果hostname改為非.local結(jié)尾,走內(nèi)網(wǎng)DNS服務(wù)器解析IP,很快獲取到了IP信息;否則通過MDNS查找,由于mDNS的工作方式,在整個(gè)網(wǎng)絡(luò)中查詢對(duì)名稱有響應(yīng)的人,這些查找可能會(huì)很慢,超過了超市時(shí)間5秒之后停止查詢。
驗(yàn)證猜想
由于知識(shí)面有限,接下來只能通過谷歌的結(jié)果來佐證猜想,請(qǐng)讀者見諒。
什么是.local
以.local結(jié)尾的網(wǎng)絡(luò)設(shè)備主機(jī)名通常在私有網(wǎng)絡(luò)中使用,在那里它們通過多播域名服務(wù)(mDNS)或本地域名系統(tǒng)(DNS)服務(wù)器進(jìn)行解析。在同一網(wǎng)絡(luò)上實(shí)現(xiàn)這兩種方法可能會(huì)有問題。然而,由于計(jì)算機(jī)、打印機(jī)和其他實(shí)現(xiàn)零配置網(wǎng)絡(luò)(zeroconf)的設(shè)備越來越普遍,通過單播DNS服務(wù)器解決這些名稱的做法已經(jīng)不受歡迎。
Multicast DNS
getaddrinfo may be slow on OS X #31665

結(jié)語
????????經(jīng)過一番折騰,問題解決了,但是美中不足的是其中詳細(xì)的原理摸的不是很透。平時(shí)要加強(qiáng)知識(shí)面的寬度,在遇到問題時(shí),才有解決問題的方向。如果有了解問題根因的同學(xué),希望不吝賜教,說說細(xì)節(jié),惠普大眾!
相關(guān)資料
列出一些比較關(guān)鍵的,有參考意義的資料。
搞懂 macOS 上的主機(jī)名/hostname/ComputerName
多播DNS服務(wù)器(MDNS)導(dǎo)致本地HTTP請(qǐng)求阻塞5秒鐘問題的解決辦法
Mac OS X slow connections - mdns 4-5 seconds - bonjour slow
什么是 mDNS 組播 DNS 多播 DNS
getaddrinfo may be slow on OS X
InetAddress.getLocalHost() slow to run (30+ seconds)