01.SpringBoot启动缓慢思考 InetAddress.getLocalHost() slow

SpringBoot项目启动缓慢问题处理

  • 遇到的问
  • 解决方案
  • 问题思考
  • 结语
  • 参考资料

遇到的问题

        在一个风和日丽的下午，某位和蔼的同事破口大骂：“卧槽，我程序每次启动都2分钟，我受不了啦！”。另外一位同事却说：“我没问题呀，我20多秒就OK了”。此言一出，引发了大家集体共鸣，看来程序启动缓慢，一直困扰着大家，后面经过了解，QA发布Test环境也有此问题。
        启动日志截取如下：

部分日志截取
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 启动耗时[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)

解决方案

解决方案其实很简单，只需要在/etc/hosts文件中，增加一段配置，即本机hostname到本机IP的映射。

# shell或者手动添加
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

问题思考

        这个问题似乎大家都存在，起初并没有过多在意，推测是接入的中间件较多，开发环境网络不佳导致，但是ping中间件网络地址后，发现延迟是很低的，网络方面似乎没有问题。
        我在以前的工作经验中，曾经发生过一次线上故障，生产机器修改hostname后，所有服务响应变的非常缓慢（RT增加数秒），最后查询原因是DNS解析有问题，调整本机DNS后遍恢复。随后配置服务器hosts里面本机IP hostname，成为初始化服务器的必要工作。
        出现这个问题后，我第一直觉是尝试修改hosts文件配置，没想到修改后，启动速度马上变快，由以前的120秒缩短至30秒内。
        尝试检查启动时的堆栈信息，发现一个与网络相关的方法。结合修改hosts能解决问题的现象，感觉这个方法很可疑。

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)

        于是乎，找到这段代码，打上断点，debug之，果不其然，在没有配置本地hosts时，getLocalHost()这个方法耗时长达5s，而SpringBoot启动时，会多次调用此方法，导致项目启动时间很长。贴上部分代码。

# 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 {
                        // 从这里进入
                        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 {
                        // 这里耗时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;

        一步步跟踪后发现，底层是native方法，底层调用的是操作系统的getaddrinfo()方法。看来问题确实在这里。根据debug结果推断，getaddrinfo()方法根据hostname查询IP，先从本地hosts查询，没有找到再去局域网络中查找，这样导致了getLocalHost缓慢。

        我以为故事到这里就结束了，随手改了下hostname，奇怪的事情发生了，getLocalHost()反应又变快了！

zhangweideMacBook-Pro:zhangwei root# hostname zhangweideMacBook-Pro.local2

        问题很奇怪，百度一番也无果。打开mac电脑设置看看情况先。

        这里有个置灰的.local，似乎不让你修改。但是使用hostname 查看本机的hostname是zhangweideMacBook-Pro.local，而且可以随意修改。没办法纠结这些了，进一步分析，每次返回都需要5秒左右的时间，看起来似乎是一个超时时间。使用scutil --dns查看本机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)

        惊奇的发现这条记录，domain : local，timeout : 5，与之前发生的现象匹配上了。那么继续分析一下，是否是因为.local结尾的hostnane，走了mdns，对结果产生了影响。

推断结论

        由此推论如果hostname改为非.local结尾，走内网DNS服务器解析IP，很快获取到了IP信息；否则通过MDNS查找，由于mDNS的工作方式，在整个网络中查询对名称有响应的人，这些查找可能会很慢，超过了超市时间5秒之后停止查询。

验证猜想

由于知识面有限，接下来只能通过谷歌的结果来佐证猜想，请读者见谅。

什么是.local

什么是.local

以.local结尾的网络设备主机名通常在私有网络中使用，在那里它们通过多播域名服务(mDNS)或本地域名系统(DNS)服务器进行解析。在同一网络上实现这两种方法可能会有问题。然而，由于计算机、打印机和其他实现零配置网络(zeroconf)的设备越来越普遍，通过单播DNS服务器解决这些名称的做法已经不受欢迎。

Multicast DNS

Multicast DNS

getaddrinfo may be slow on OS X #31665

结语

        经过一番折腾，问题解决了，但是美中不足的是其中详细的原理摸的不是很透。平时要加强知识面的宽度，在遇到问题时，才有解决问题的方向。如果有了解问题根因的同学，希望不吝赐教，说说细节，惠普大众！

相关资料

列出一些比较关键的，有参考意义的资料。

搞懂 macOS 上的主机名/hostname/ComputerName
多播DNS服务器(MDNS)导致本地HTTP请求阻塞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)

最后编辑于 ：
©著作权归作者所有,转载或内容合作请联系作者
  • 人面猴
    序言：七十年代末，一起剥皮案震惊了整个滨河市，随后出现的几起案子，更是在滨河造成了极大的恐慌，老刑警刘岩，带你破解...
    沈念sama阅读 214,588评论 6赞 496
  • 死咒
    序言：滨河连续发生了三起死亡事件，死亡现场离奇诡异，居然都是意外死亡，警方通过查阅死者的电脑和手机，发现死者居然都...
    沈念sama阅读 91,456评论 3赞 389
  • 救了他两次的神仙让他今天三更去死
    文/潘晓璐 我一进店门，熙熙楼的掌柜王于贵愁眉苦脸地迎上来，“玉大人，你说我怎么就摊上这事。” “怎么了？”我有些...
    开封第一讲书人阅读 160,146评论 0赞 350
  • 道士缉凶录：失踪的卖姜人
    文/不坏的土叔 我叫张陵，是天一观的道长。 经常有香客问我，道长，这世上最难降的妖魔是什么？ 我笑而不...
    开封第一讲书人阅读 57,387评论 1赞 288
  • 港岛之恋（遗憾婚礼）
    正文 为了忘掉前任，我火速办了婚礼，结果婚礼上，老公的妹妹穿的比我还像新娘。我一直安慰自己，他们只是感情好，可当我...
    茶点故事阅读 66,481评论 6赞 386
  • 恶毒庶女顶嫁案：这布局不是一般人想出来的
    文/花漫 我一把揭开白布。 她就那样静静地躺着，像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上，一...
    开封第一讲书人阅读 50,510评论 1赞 293
  • 城市分裂传说
    那天，我揣着相机与录音，去河边找鬼。 笑死，一个胖子当着我的面吹牛，可吹牛的内容都是我干的。 我是一名探鬼主播，决...
    沈念sama阅读 39,522评论 3赞 414
  • 双鸳鸯连环套：你想象不到人心有多黑
    文/苍兰香墨 我猛地睁开眼，长吁一口气：“原来是场噩梦啊……” “哼！你这毒妇竟也来了？” 一声冷哼从身侧响起，我...
    开封第一讲书人阅读 38,296评论 0赞 270
  • 万荣杀人案实录
    序言：老挝万荣一对情侣失踪，失踪者是张志新（化名）和其女友刘颖，没想到半个月后，有当地人在树林里发现了一具尸体，经...
    沈念sama阅读 44,745评论 1赞 307
  • 护林员之死
    正文 独居荒郊野岭守林人离奇死亡，尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,039评论 2赞 330
  • 白月光启示录
    正文 我和宋清朗相恋三年，在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,202评论 1赞 343
  • 活死人
    序言：一个原本活蹦乱跳的男人离奇死亡，死状恐怖，灵堂内的尸体忽然破棺而出，到底是诈尸还是另有隐情，我是刑警宁泽，带...
    沈念sama阅读 34,901评论 5赞 338
  • 日本核电站爆炸内幕
    正文 年R本政府宣布，位于F岛的核电站，受9级特大地震影响，放射性物质发生泄漏。R本人自食恶果不足惜，却给世界环境...
    茶点故事阅读 40,538评论 3赞 322
  • 男人毒药：我在死后第九天来索命
    文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹，春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,165评论 0赞 21
  • 一桩弑父案，背后竟有这般阴谋
    文/苍兰香墨 我抬头看了看天上的太阳。三九已至，却和暖如春，着一层夹袄步出监牢的瞬间，已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,415评论 1赞 268
  • 情欲美人皮
    我被黑心中介骗来泰国打工， 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留，地道东北人。 一个月前我还...
    沈念sama阅读 47,081评论 2赞 365
  • 代替公主和亲
    正文 我出身青楼，却偏偏与公主长得像，于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子，可洞房花烛夜当晚...
    茶点故事阅读 44,085评论 2赞 352