云服务器启动tomcat巨慢,很慢

自己再阿里云申请了一台1G1核的机器,每次重启自己的服务tomcat都需要卡住很长时间,每次都是日志停在
Root WebApplicationContext: initialization completed in 744 ms这个地方,然后也不知道发生了什么,在等待
什么,网上看到了一篇博文,mark下

问题现象

美女同事找我解决一个问题,说Tomcat启动很慢。开始我以为是程序写的问题,所以把webapps下所有程序都删除掉。(只保留Tomcat自带)灵异的事情发生了,Tomcat停止在——

我查看了一下进程,Tomcat所在的JVM进程已经被启动了所以可以排除是JVM退出引起的问题。那么问题真的就是JVM因为某种原因被阻塞了。
分析

问题比较棘手,我排除了CPU、内存不足引起的问题;排除了硬盘空间不足引起的问题;我甚至去观察了网络I/O、硬盘I/O情况,都非常正常。程序被阻塞一般来说一定是要等待某个资源,而现在的情况是所有资源都充足,所以我几乎想不到是什么问题引起的。我开始怀疑是KVM Hypervisor虚拟化的问题(用的是虚拟机)我改变了策略在VMWare开了两台虚拟机上直接下载Tomcat启动。其中一台很快启动,另一台居然也被阻塞,问题被重现了。眼看要在美女面前丢脸,我光辉伟岸的形象要荡然无存。这种情况下我不能去“撸”代码吧?况且Tomcat那么多人用,真有这么明显的Bug早就炸开锅了。(Tomcat还是很靠谱的不像xxxxStack那么狗屎)仔细想想我需要找到Tomcat停止在了哪里?代码里发生了什么事情,但是我又不可能去撸代码。无可奈何的情况下我决定试一下 strace,这是一个跟踪系统调用(System Call)的工具,无论是Java还是Pyhton很多资源申请都会变成都会变成System Call。(比如打开文件、新建线程、读写数据、等待I/O)通过这个工具我至少可以知道Tomcat是停止在哪个System Call上的,这样可以方便我推断出问题的原因。
strace -f -o strace.out ./catalina.sh run

strace有很多参数,我用了二个参数
-f 跟踪fork的子进程,通俗的说会跟踪所有线程的系统调用

-o把内容输出到文件

其他参数请自行搜索下面分析strace.out文件,分析的方法是从下往上(被阻塞的地方肯定是在最后咯)。首先我们需要去掉Tomcat停止引起的System Call,它们不是我们需要的。从后往前搜索找到SIGINT

红色部分以上就是引起阻塞的系统调用了,上面有一大堆一大堆的futex
的调用,它是Linux中的一种轻量级的同步方法,所以我们可以判断出最上面肯定是有某个System Call就是阻塞的真正元凶。跳过所有的futex
这个read
就是引起后面一串futex
的真正原因,strace非常聪明它不仅仅给出了System Call还给出了传递的参数和返回值,read读取的是51号文件句柄,没有返回成功(unfinished)。顺着这条路,我们看一下51号文件句柄是什么
/dev/random是Linux下的随机函数生成器,读取它相当于生成随机数字。搜索它,第一个是wiki
至此似乎一切真相大白了,/dev/random会根据噪音产生随机数,如果噪音不够它就会阻塞。Linux是通过I/O,键盘终端、内存使用量、CPU利用率等方式来收集噪音的,如果噪音不够生成随机数的时候就会被阻塞
深入分析

如果用Tomcat /dev/random作为关键字基本上就能够回答我们的疑惑了。Tocmat的Session ID是通过SHA1算法计算得到的,计算Session ID的时候必须有一个密钥。为了提高安全性Tomcat在启动的时候回通过随机生成一个密钥。在 http://wiki.apache.org/tomcat/HowTo/FasterStartUp (Entropy Source部分)有一段解释。stackoverflow上面也有一大批这方面的说明,所以这里就不再多做介绍。明白了问题的原因解决起来就非常简单了——替换/dev/random为/dev/unrandom,用伪随机函数生成器(/dev/urandom)来替代随机函数生成器(/dev/random)。
通过修改Tomcat启动文件-Djava.security.egd=file:/dev/urandom

通过修改JRE中的java.security文件securerandom.source=file:/dev/urandom

当然JVM的开发者不是傻瓜,Tomcat的开发者也不是二百五。他们之所以没有选择/dev/urandom是为了提高系统的安全性,/dev/urandom并不是真正的随机行为。(其实一般情况下/dev/urandom也是足够安全的不太容易被“重复”)
彻底解决问题

上面介绍的两种方式都是用/dev/urandom替换/dev/random,其实还有第三种方式——增大/dev/random的熵池。问题的原因是由于熵池不够大,所以增大它是最彻底的方法。通过cat /proc/sys/kernel/random/entropy_avail
我们可以查看现在的熵池大小;我们需要找到一种方式来提高这个值就行了。如果你的CPU带有DRNG特性,可以充分利用硬件来提高熵池产生的速度 。通过cat /proc/cpuinfo | grep rdrand
可以查看自己的CPU是否支持,一般来说Intel的Ivy_Bridge架构的CPU都支持(i3、i5需要注意是否采用该种架构,i7和xeon基本上都支持);AMD的CPU在2015年以后生成的都支持。(如果你是虚拟机需要开启额外的参数)。如果你的硬件不支持,也没有关系,我们可以让/dev/unrandom来做“熵源”。以Centos7为例,
yum install rngd-tools
或者yum install rng-tools
安装rngd服务(熵服务)

systemctl start rngd
启动服务
如果你的CPU不支持DRNG特性或者像我一样使用虚拟机,可以使用/dev/unrandom来模拟。

cp /usr/lib/systemd/system/rngd.service /etc/systemd/system

编辑/etc/systemd/system/rngd.service
service小结,ExecStart=/sbin/rngd -f -r /dev/urandom

systemctl daemon-reload
重新载入服务

systemctl restart rngd
重启服务

经过上面的修改,我们再观察/proc/sys/kernel/random/entropy_avail
基本上在3000左右。我们可以测试一下随机数的生成速度
watch -n 1 cat /proc/sys/kernel/random/entropy_avail
观察这个值

新打开一个shell,用dd命令测试随机数。dd if=/dev/random of=random.dat count=40960

[root@localhost bin]# dd if=/dev/random of=random.dat count=40960记录了0+40960 的读入记录了6004+1 的写出3074362字节(3.1 MB)已复制,5.01017 秒,614 kB/秒

5秒产生了40960个随机数,/proc/sys/kernel/random/entropy_avail会有剧烈的变化,所有随机数产生之后它又会保持在3000左右。
选择哪种解决方法

个人建议选择第三种方式,熵池不仅仅Tomcat用,Linux下的所有应用程序产生随机数都会用到这个,所以不仅仅是Tomcat可能被阻塞。如果你搜索会发现Apache、Nginx、OpenSSL都被这个问题坑过。如果我们通过修改Java的配置来解决这个问题其实只是解决Java应用程序的问题,只能是治标不治本。根治的方法应该是通过rngd
提高随机数生成的速度。
总结

经验不是经历。用别人的经验解决一个问题不难,难的是自己从头走一遍这条路,更加难的是推翻前人的经验对一个问题能够有自己的看法和领悟。这个案例加深了我对strace
的理解,对于空中加油
这种类型的系统调试有了自己的经验;通过对原因的深入分析我找到了更好的办法。这就是康德精神——思考、批判、理性。
如何重现故障

可以很容易的重现文章中描述的故障
systemctl stop rngd
停止rngd服务(如果你有启动rngd)

查看当前熵池的大小cat /proc/sys/kernel/random/entropy_avail

head -c1024 /dev/random
,强制消费1024个随机数,系统会长时间没有反应。直接ctrl+c

再次查看熵池的大小cat /proc/sys/kernel/random/entropy_avail
,保证它的大小在尽可能的小

启动tomcat,会发现长时间很长时间的等待

还有一个解决方案

在sun的bug database中也已经有人给出,即在java程序启动参数中添加:-Djava.security.egd=file:/dev/urandom,使用/dev/urandom生成随机数。

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

推荐阅读更多精彩内容