原博客转:疑似jdk bug InetAddress.getLocalHost()引起的应用启动慢问题排查和分析

原新浪博客的内容转到新博客中
http://blog.sina.com.cn/s/blog_65415e870102wtu9.html

背景和现象

环境

想着时髦一把,也响应公司号召软碍件都升级一把:
1.thinkpad换成了mac(OS:macOS Sierra)
2.jdk从1.6升到1.8,目前在用的版本是jdk 1.8.0_131
3.开发工具也从eclipse升级到intellij idea.

现象

原来在windows+jdk1.6环境下应用启动虽然也慢,但是一般在4分钟内肯定是可以完成的。可是现在发现在新环境里启动需要花10+分钟,实在忍受不了。对于有强迫症的我必须要找到原因。
但是​同一套代码,周边同事都是4分钟内启动完成,只有我本地启动超过10分钟。

排查问题

于是开始各种找原因,可是这次软硬件都升级了,不清楚是哪方面的原因造成的。

开始始怀疑intellij idea

第一次真正用intellij idean, 对于出现问题很容易怀疑是新事务引入导致的。刚开始简短的时间怀疑过是不是由intellij idea引起的,但是很快放弃,感觉不应该。

开始怀疑是否是jvm内存调置不合理

提到慢,很自然想到是性能问题,jvm调优等。怀疑是否是jmv内存设置不合理,导致启动慢。

先是通过-xms -xmx调整jvm参数,通过在启动参数中增加堆内存,没发现有明显的效果。然后再通过-XX:+PrintGCDetails增加打印日志的,从日志中发现启动过程中触发了4次full gc,并且出现allocate failur分配内存失败的提示,感觉是内存设置不合理,于是多次通过-xms -xmx调整内存,后来未出现full gc和allocate failur的提示。

但是​启动时间的优化上还是没有明显效果(相对于10+分钟,full gc优化只有几秒)

怀疑电脑网络的问题

再次分析启动日志,系统用到的很多中间件、注册"调用远程rpc服务"、以及连接zk的时候特别耗时,有几个rpc服务注册都需要20s。

js_001QXV1tzy7bAfaytsP9f.jpeg

因为同一套代码,周边的同事都正常,于是怀疑我电脑的网络的问题。
于是ping对应的rpc的对应的域名,响应时间正常。
无果放弃.

查看线程堆栈信息

理论上同一套代码,在线上和其它同事上运行没有问题,一直没有怀疑过是代码或者线程的问题。

但是还是试一试的态度,看一下线程堆栈是否能看出什么问题。通过jvisualvm在启动过程中不断dump 线程堆栈。

不看不知道,一看真看出问题了,原来有好几个线程处于blocked的状态​,并且都是在这个位置。

js_001QXV1tzy7bAfAHi80c0.jpeg
查看源码
js_001QXV1tzy7bAfHvIoK06.jpeg

从源中看总共分5步

第1步,获取本地的hostname;

​第2步,判断hostname是不是localhost,如果是localhost直接解析;

​第3步,查看是否需要走缓存,计算"当前时间"与"上次查询到结果的缓存"时间差不是不是在5s内,如果是直接从缓存中读取;注意now变量是在第3步获取了当前系统时间。

​第4步,如果不走缓存,则调用dns解析ip。这一步比较花时间(我本机调试花了好几秒);

​第5步,如果第4步解析正常,则将当前dns解析结果缓存在本地。

​但是这里特别注意,这里写入最后缓存的时间是在第3步拿的系统时间(now变量是在第3步时获取的),而第4步比较耗费时间(24s),所以放到本地缓存时,纪律的缓存时间已经过去24秒了。

所以一般来说下次进来判断,基本上都会超过5s, 不会走缓存。

​为了验证缓存基本上生效,我在本地写了一个Demo,连续两次调用InetAddress.getLocalHost(),两次返回的时间都是5+s,显示第二次没有走缓存。

js_001QXV1tzy7bAg23ZT0ce.jpeg

原因总结和解决办法

原因分析

对于企业级应用,有很多rpc的调用,以及分布式协调组件zookeeper的调用。
出于服务治理的需要,对于Rpc调用需要服务端和客户端在启动过程把自己注册登记到注册中心去。rpc注册登记时会调用jdk的InetAddress.getLocalHost()方法获取本机地址信息。但是这个过程会费时(每次调用需要5+s),并且这个方法还是用synchronized进行了同步,并行整成了串行,假如系统有100个地方调用此方法,在此就要消耗500s.

从jdk源码中看是有做缓存,但是由于dns解析很耗时,导致缓存达到效果,造成了这次悲剧。

解决方法​

经过各种网络查询,网友给的解决方案是在本地host里做两个host映射绑定,本机的hostname就不走dns解析了。本地hostname不需要走网络解析,达到更快的解析速度,让缓存生效,提高速度。
在本地把本机对应的hostname增加映射到本地ip的host绑定。​

js_001QXV1tzy7bAgkbzYOae.png

结果

经过以上绑定之后,以上demo测试的结果是"连续两次调用InetAddress.getLocalHost()"的时间大缩短,第一次是9毫秒,第二次是0毫秒(走了缓存)​

js_001QXV1tzy7bAgqeYra34.jpeg

再次启动应用,应用的启动时间也从原来10+分钟,加快到现在启动只需要1分钟多一点点。

心情瞬间舒畅很多了!。​

jdk bug还是macOS的bug?

网上有人说是jdk1.8版本的bug, 据说已经有人上报给jdk官方。open jdk据说无此问题。

也有人说此问题jdk1.8在mac最新版本的系统(macO Sierra)上才出现此种现象,我本地的系统是macOS Sierra 10.12.5 本人未验证过其它环境。之所以我同事们没有出现此问题,是因为我周边的同事macOS没有升级到最新版。

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 204,053评论 6 478
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 85,527评论 2 381
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 150,779评论 0 337
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,685评论 1 276
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,699评论 5 366
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,609评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 37,989评论 3 396
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,654评论 0 258
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,890评论 1 298
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,634评论 2 321
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,716评论 1 330
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,394评论 4 319
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 38,976评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,950评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,191评论 1 260
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 44,849评论 2 349
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,458评论 2 342

推荐阅读更多精彩内容

  • Spring Cloud为开发人员提供了快速构建分布式系统中一些常见模式的工具(例如配置管理,服务发现,断路器,智...
    卡卡罗2017阅读 134,591评论 18 139
  • 29.1 引言 本章中我们要讨论另一个常用的应用程序:NFS(网络文件系统),它为客户程序提供透明的文件访问。NF...
    张芳涛阅读 970评论 0 4
  • Android 自定义View的各种姿势1 Activity的显示之ViewRootImpl详解 Activity...
    passiontim阅读 171,413评论 25 707
  • 黄芪是我们日常生活中常见的中药材之一,相信大家对黄芪也不陌生。黄芪是深受中国人喜爱的一种滋补药材,在中国已经有两千...
    享受幸福1阅读 303评论 0 1
  • 2017.6.26星期一 中午放学回家的路上,欣赏绿叶蓝天,听着鸟鸣,悠然自在。爱人签退晚但走得快,赶上来...
    王兆双阅读 388评论 2 4