彻底找到 Tomcat 启动速度慢的元凶

转载 2017年06月04日 17:51:00

问题现象

美女同事找我解决一个问题,说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 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,会发现长时间很长时间的等待

转载自:彻底找到 Tomcat 启动速度慢的元凶(http://www.tuicool.com/articles/uaiURzF)

Tomcat启动慢的测试与解决

问题: 关于Tomcat启动慢问题,相信大家已经都比较熟悉了,如果不熟悉请参考下面三篇文章: 1.  循循善诱的写程序的康德的 《彻底找到Tomcat启动速度慢的元凶》 2. Oracle官方B...
  • wangfei0904306
  • wangfei0904306
  • 2017-07-01 00:50:46
  • 3261

java程序,tomcat启动很慢(300秒+)的处理方法

刚自己从头配置了一台阿里云,但是发现java启动很慢 Creation of SecureRandom instance for session ID generation 这个用时大约300秒 解...
  • kkgbn
  • kkgbn
  • 2016-12-23 19:01:17
  • 4637

tomcat启动很慢很慢,长达122873ms

tomcat在启动非常慢 JVM因为某种原因被阻塞了。 程序被阻塞一般来说一定是要等待某个资源...
  • kane_canpower
  • kane_canpower
  • 2016-12-08 10:19:40
  • 787

tomcat7启动很慢,Eclipse运行也很缓慢

 在使用Eclipse开发项目过程中,一度使Eclipse陷入瘫痪状态,Tomcat启动项目时也异常缓慢,增加了超时限制并没有用,有时候项目根本运行不起来,简直让人崩溃,可能我电脑内存小(4G),配置...
  • qq_24309787
  • qq_24309787
  • 2017-09-29 13:47:45
  • 2082

Tomcat启动速度慢的优化方法

今天启动Tomcat,发现启动很慢,需要几分钟,这个问题值得重视,所以就去查看日志,发现耗时是session引起随机数问题导致的。Tomcat的Session ID通过SHA1算法计算得到的,计算Se...
  • linkkb
  • linkkb
  • 2017-10-12 17:47:39
  • 339

解决 Tomcat 启动速度巨慢问题

日常今天和学弟学妹们在实验室吹水好不快乐,然而自己服务器问题还没解决,具体问题是——之前使用windows服务端,一直想换成linux的,然后最近终于有时间换,却发现问题解决到tomcat部署之后,部...
  • Core00077
  • Core00077
  • 2017-12-28 21:07:43
  • 283

tomcat启动突然很慢的解决办法

今天早上上班,启动tomcat的时候发现总是超时,而且特别慢,启动时候的控制台日志信息好像也不停重复,平常一般二十秒就启动了。今天一百秒都没启动。 解决办法是:  1、去掉debug时的断点    ...
  • zl544434558
  • zl544434558
  • 2015-01-09 10:38:23
  • 4339

Tomcat在阿里云上启动慢的解决办法

Tomcat在本地服务器跑,一切都正常,但部署到阿里云上,发现启动巨慢。 经过在网上搜索,找到了原因: Tomcat 7/8都使用org.apache.catalina.util.Session...
  • xzs1980
  • xzs1980
  • 2017-05-10 16:23:20
  • 3955

Tomcat 7 在 Centos 6 上启动慢的解决办法

问题Tomat 7 在 Centos 6 上,每次重启 Tomcat 时,总要花3~4分钟。通过日志看,是 SecureRandom 的计算用了太长的时间。从网上查,这是 Oracle 的一个 Bug...
  • ginkov
  • ginkov
  • 2016-09-27 08:36:41
  • 2080

阿里云tomcat启动慢的问题怎么解决

今天在服务器上部署网站时 启动tomcat无错 tail -f catalina.out日志 和 catalina.sh run 方式启动时 卡在22-Jul-2016 23:00:53.921 IN...
  • xuyaozhengde
  • xuyaozhengde
  • 2017-03-08 15:04:57
  • 1628
收藏助手
不良信息举报
您举报文章:彻底找到 Tomcat 启动速度慢的元凶
举报原因:
原因补充:

(最多只允许输入30个字)