网关配置错误导致spring boot项目启动慢

问题描述

网卡信息中GATEWAY配置错误，导致该机器可以连接内网，但是连接不上外网。ping DNS时会出现多次请求失败。

[root@xxx ~]# vi /etc/sysconfig/network-scripts/ifcfg-eth0NAME=eth0DEVICE=eth0TYPE=EthernetBOOTPROTO=staticONBOOT=yesIPADDR=192.168.139.203NETMASK=255.255.240.0GATEWAY=192.168.128.100 [root@xxx ~]# ping 114.114.114.114PING 114.114.114.114 (114.114.114.114) 56(84) bytes of data.From 192.168.139.203 icmp_seq=1 Destination Host UnreachableFrom 192.168.139.203 icmp_seq=2 Destination Host UnreachableFrom 192.168.139.203 icmp_seq=3 Destination Host UnreachableFrom 192.168.139.203 icmp_seq=4 Destination Host UnreachableFrom 192.168.139.203 icmp_seq=5 Destination Host UnreachableFrom 192.168.139.203 icmp_seq=6 Destination Host UnreachableFrom 192.168.139.203 icmp_seq=7 Destination Host UnreachableFrom 192.168.139.203 icmp_seq=8 Destination Host Unreachable^C--- 114.114.114.114 ping statistics ---8 packets transmitted, 0 received, +8 errors, 100% packet loss, time 7000mspipe 4

使用apache-tomcat-7.0.69发布war格式打包的springboot项目，执行bin/startup.sh。

.   ____          _            __ _ _ /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \ \\/  ___)| |_)| | | | | || (_| |  ) ) ) )  '  |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot ::        (v1.5.3.RELEASE)Aug 24, 2017 12:23:21 PM org.apache.catalina.startup.HostConfig deployWARINFO: Deployment of web application archive /apache-tomcat-7.0.69/webapps/xxx.war has finished in 76,815 msAug 24, 2017 12:23:21 PM org.apache.coyote.AbstractProtocol startINFO: Starting ProtocolHandler ["http-bio-9080"]Aug 24, 2017 12:23:21 PM org.apache.coyote.AbstractProtocol startINFO: Starting ProtocolHandler ["ajp-bio-9009"]Aug 24, 2017 12:23:21 PM org.apache.catalina.startup.Catalina startINFO: Server startup in 76930 ms

网络配置正常的场景下，执行bin/startup.sh。

 .   ____          _            __ _ _ /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \ \\/  ___)| |_)| | | | | || (_| |  ) ) ) )  '  |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot ::        (v1.5.3.RELEASE)Aug 24, 2017 12:08:50 PM org.apache.catalina.startup.HostConfig deployWARINFO: Deployment of web application archive /apache-tomcat-7.0.69/webapps/xxx.war has finished in 19,514 msAug 24, 2017 12:08:50 PM org.apache.coyote.AbstractProtocol startINFO: Starting ProtocolHandler ["http-bio-9080"]Aug 24, 2017 12:08:50 PM org.apache.coyote.AbstractProtocol startINFO: Starting ProtocolHandler ["ajp-bio-9009"]Aug 24, 2017 12:08:50 PM org.apache.catalina.startup.Catalina startINFO: Server startup in 19594 ms

可以发现执行速度相差了3倍。

问题分析

在配置错误的场景下，再次启动tomcat,使用jstack获取线程dump。

[root@xxx ~]# ps -ef | grep 'apache-tomcat-7.0.69' | grep -v grep | awk '{print $2}' | xargs jstack >> 1218dump.txt

为保证数据量最好多执行几次，追加到同一个文件。

打开dump文件发现有大量的如下线程：

"localhost-startStop-1" #12 daemon prio=5 os_prio=0 tid=0x00007f69a4002800 nid=0x1746 runnable [0x00007f69d96c2000]   java.lang.Thread.State: RUNNABLE    at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method)    at java.net.InetAddress$2.lookupAllHostAddr(InetAddress.java:928)    at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1323)    at java.net.InetAddress.getLocalHost(InetAddress.java:1500)    - locked <0x00000000c574e990> (a java.lang.Object)    at sun.management.VMManagementImpl.getVmId(VMManagementImpl.java:140)    at sun.management.RuntimeImpl.getName(RuntimeImpl.java:59)    at org.springframework.boot.ApplicationPid.getPid(ApplicationPid.java:46)    at org.springframework.boot.ApplicationPid.<init>(ApplicationPid.java:37)    at org.springframework.boot.logging.LoggingSystemProperties.apply(LoggingSystemProperties.java:59)    at org.springframework.boot.logging.LoggingSystemProperties.apply(LoggingSystemProperties.java:48)    at org.springframework.boot.logging.LoggingApplicationListener.initialize(LoggingApplicationListener.java:270)    at org.springframework.boot.logging.LoggingApplicationListener.onApplicationEnvironmentPreparedEvent(LoggingApplicationListener.java:239)    at org.springframework.boot.logging.LoggingApplicationListener.onApplicationEvent(LoggingApplicationListener.java:212)    at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:167)    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:122)    at org.springframework.boot.context.event.EventPublishingRunListener.environmentPrepared(EventPublishingRunListener.java:73)    at org.springframework.boot.SpringApplicationRunListeners.environmentPrepared(SpringApplicationRunListeners.java:54)    at org.springframework.boot.SpringApplication.prepareEnvironment(SpringApplication.java:336)    at org.springframework.boot.SpringApplication.run(SpringApplication.java:307)    at org.springframework.boot.web.support.SpringBootServletInitializer.run(SpringBootServletInitializer.java:151)    at org.springframework.boot.web.support.SpringBootServletInitializer.createRootApplicationContext(SpringBootServletInitializer.java:131)    at org.springframework.boot.web.support.SpringBootServletInitializer.onStartup(SpringBootServletInitializer.java:86)    at org.springframework.web.SpringServletContainerInitializer.onStartup(SpringServletContainerInitializer.java:169)    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5573)    - locked <0x00000000c4f2d5d0> (a org.apache.catalina.core.StandardContext)    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)    - locked <0x00000000c4f2d5d0> (a org.apache.catalina.core.StandardContext)    at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:899)    at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:875)    at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:652)    at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:1092)    at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1984)    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)    at java.util.concurrent.FutureTask.run(FutureTask.java:266)    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)    at java.lang.Thread.run(Thread.java:745)

于是google搜索发现了
http://justthesam.com/2016/10/fixing-java-net-inet6addressimpl-lookupallhostaddr-slowdown/。

The slowness is caused by a domain name lookup that’s taking a few seconds each time, because for some reason your computer is asking the network about its own address, and timing out. I don’t fully understand the mechanics frankly, but the fix was simple in my case.First, figure out what your computer thinks its hostname is, by running hostname in the terminal. Then use the value returned from that to add lines like this to your /etc/hosts file:    # This works around slow lookup that we sometimes see in    # java.net.Inet6AddressImpl.lookupAllHostAddr    127.0.0.1 Sams-MacBook-Pro.local    ::1 Sams-MacBook-Pro.localThis provides a direct answer for both IPv4 and IPv6, avoiding the slowness. This had the nice effect of bringing my Gradle build time down from 2 minutes to just 44 seconds, including all the tests. 

再次回到测试机，修改/etc/hosts。

[root@xxx ~]# hostnamexxx[root@xxx ~ ]# vi /etc/hosts127.0.0.1   localhost localhost.localdomain localhost4 localhost4.localdomain4 xxx::1         localhost localhost.localdomain localhost6 localhost6.localdomain6 xxx

再次重启tomcat，查看启动时间。

 .   ____          _            __ _ _ /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \ \\/  ___)| |_)| | | | | || (_| |  ) ) ) )  '  |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot ::        (v1.5.3.RELEASE)Aug 24, 2017 12:31:21 PM org.apache.catalina.startup.HostConfig deployWARINFO: Deployment of web application archive /apache-tomcat-7.0.69/webapps/xxx.war has finished in 19,354 msAug 24, 2017 12:31:21 PM org.apache.coyote.AbstractProtocol startINFO: Starting ProtocolHandler ["http-bio-9080"]Aug 24, 2017 12:31:21 PM org.apache.coyote.AbstractProtocol startINFO: Starting ProtocolHandler ["ajp-bio-9009"]Aug 24, 2017 12:31:21 PM org.apache.catalina.startup.Catalina startINFO: Server startup in 19413 ms

思考

为什么会出现上述问题？目前只是知其然而不知其所以然。