CentOS 7 下Tomcat启动超慢的原因及解决方案

现象

CentOS 7系统中安装好openjdk和Tomcat后,启动过程很慢,长达数分钟,日志如下:

17:27:53.596 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.38
17:27:53.644 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/tomcat_8_5_38/webapps/docs]
17:32:31.001 WARNING [localhost-startStop-1] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [276,660] milliseconds.
17:32:31.022 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/tomcat_8_5_38/webapps/docs] has finished in [277,378] ms
17:32:31.022 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/tomcat_8_5_38/webapps/manager]
17:32:31.101 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/tomcat_8_5_38/webapps/manager] has finished in [79] ms
17:32:31.101 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/tomcat_8_5_38/webapps/examples]
17:32:31.509 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/tomcat_8_5_38/webapps/examples] has finished in [408] ms
17:32:31.510 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/tomcat_8_5_38/webapps/host-manager]
17:32:31.559 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/tomcat_8_5_38/webapps/host-manager] has finished in [49] ms
17:32:31.559 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/tomcat_8_5_38/webapps/ROOT]
17:32:31.576 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/tomcat_8_5_38/webapps/ROOT] has finished in [17] ms
17:32:31.605 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
17:32:31.660 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
17:32:31.662 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 278084 ms

tomcat启动耗时278084ms折合278秒,对于刚刚安装的干净tomcat,这肯定是不对劲的。
其中有一条日志引起了笔者的注意:

17:32:31.001 WARNING [localhost-startStop-1] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [276,660] milliseconds.

显然tomcat执行到这里时出问题了,google了一下,经过一番搜索明白了其中的缘由。

原因

在tomcat官方wiki文档的HowToFasterStartUp章节中,Entropy Source部分有一段这样的说明:

Tomcat 7+严重依赖SecureRandom类为其sessionID和其他地方提供随机值。如果用于初始化SecureRandom的熵源缺少熵,则可能会在启动期间导致延迟,具体取决于您的JRE。发生这种情况时,您会在日志中看到警告,例如:

<DATE> org.apache.catalina.util.SessionIdGenerator createSecureRandom
INFO: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [5172] milliseconds.

有一种方法可以通过设置以下系统属性来配置JRE以使用非阻塞熵源:

-Djava.security.egd = file:/dev/./urandom

另请注意,使用非阻塞源替换阻塞熵源实际上会降低安全性,因为您获得的随机数据较少。

从这里我们得知Tocmat的Session ID是通过SHA1PRNG算法计算得到的,计算Session ID的时候必须有一个密钥,为了提高安全性Tomcat在启动的时候会通过随机生成一个密钥,它强依赖于获取熵池中的随机数来进行创建。
那么什么是/dev/random?什么是熵池

/dev/random
从维基百科得知,在UNIX操作系统(包括类UNIX系统)中,/dev/random是一个特殊的设备文件,可以用作随机数生成器或伪随机数生成器。
Linux内核中的是第一个以背景噪声产生真正的随机数产生的实现,它允许程序访问来自设备驱动程序或其它来源的背景噪声。
Linux上有两个通用的随机设备:/dev/random/dev/urandom。其中/dev/random的随机性最好,因为它是一个阻塞的设备。而/dev/random的一个副本是/dev/urandom(“unblocked”,非阻塞的随机数生成器),它会重复使用熵池中的数据以产生伪随机数据。这表示对/dev/urandom的读取操作不会产生阻塞,但其输出的熵可能小于/dev/random的。所以它可以作为生成较低强度密码的伪随机数生成器,不建议用于生成高强度长期密码。

熵池
熵池本质上是若干字节,/proc/sys/kernel/random/entropy_avail中存储了熵池现在的大小,/proc/sys/kernel/random/poolsize是熵池的最大容量,单位都是bit。如果entropy_avail的值小于要产生的随机数bit数,那么/dev/random就会堵塞。

为什么熵池不够用?

熵池实际上是从各种noice source中获取数据,noice source可能是键盘事件、鼠标事件、设备时钟中等。linux内核从2.4升级到2.6时,处于安全性的考虑,废弃了一些source。source减少了,熵池补给的速度当然也变慢,进而不够用。
其实,通过消耗熵池,可以构造DDOS攻击。原理很简单,熵池空了,依赖随机数的业务(SSL,加密等)就不能正常进行。

通过以上信息,笔者得知该问题是由于熵池不足导致的。怎么解决?

解决方案

方法一、降低熵生成的随机性要求

使用非阻塞性的生成器/dev/urandom代替/dev/random

1、可在JVM环境中配置
通过配置发生器指定熵收集守护进程
修改$JAVA_PATH/jre/lib/security/java.security中参数securerandom.source为:

securerandom.source=file:/dev/./urandom

2、也可在Tomcat环境中配置
通过配置JRE使用非阻塞的Entropy Source获取熵
$TOMCAT_HOME/bin/catalina.sh中加入:

if [[ "$JAVA_OPTS" != *-Djava.security.egd=* ]]; then
    JAVA_OPTS="$JAVA_OPTS -Djava.security.egd=file:/dev/./urandom"
fi

这个系统属性egd表示熵收集守护进程(entropy gathering daemon)。

方法二、使用熵生成器补充熵池(推荐)

1、[硬件随机数生成器]安装并使用rng-tools作为额外的熵随机数生成器(推荐)

# 安装rng-tools
yum install rng-tools -y
# 测试rngd
rngd -f
# 启动rngd
systemctl start rngd
# 设置自启动
systemctl enable rngd
# 查看自启动列表
systemctl list-unit-files

cat /dev/random命令会消耗熵池,rngd守护进程会补充熵池,可使用如下命令来测试随机数生成的情况:

cat /dev/random | rngtest -c 100
# 测试结果
rngtest 6
Copyright (c) 2004 by Henrique de Moraes Holschuh
This is free software; see the source for copying conditions.  There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.

rngtest: starting FIPS tests...
rngtest: bits received from input: 2000032
rngtest: FIPS 140-2 successes: 100
rngtest: FIPS 140-2 failures: 0
rngtest: FIPS 140-2(2001-10-10) Monobit: 0
rngtest: FIPS 140-2(2001-10-10) Poker: 0
rngtest: FIPS 140-2(2001-10-10) Runs: 0
rngtest: FIPS 140-2(2001-10-10) Long run: 0
rngtest: FIPS 140-2(2001-10-10) Continuous run: 0
rngtest: input channel speed: (min=13.823; avg=42.721; max=10761.019)Kibits/s
rngtest: FIPS tests speed: (min=93.041; avg=129.531; max=136.239)Mibits/s
rngtest: Program run time: 45733452 microseconds

2、[软件随机数生成器]在rng-tools仍不满足的情况下,可使用haveged作为额外的熵随机数生成器

haveged项目的目的是提供一个简单易用的不可预测随机数生成器,基于HAVEGE算法。Haveged可以解决在某些情况下,系统熵过低的问题。此程序无法保证熵的质量,如果对安全要求较高,请考虑使用硬件随机数生成器rng-tools。

要检查是否需要 Haveged,可使用下面命令查看当前收集到的熵:

cat /proc/sys/kernel/random/entropy_avail

如果结果比较低 (<1000),建议安装 haveged,否则加密程序会处于等待状态,直到系统有足够的熵。

# 安装haveged
yum install haveged -y
# 启动haveged
systemctl start haveged
# 设置自启动
systemctl enable haveged

安装 haveged 之后,可以再次查看系统熵看下有无提升。


因为方法一存在一定的不安全性,且需要对环境进行配置,为了满足熵的需要,这里笔者选择了第二种方法,使用rng-tools作为额外的熵随机数生成器,同以上操作后顺利解决了问题。

操作后重启tomcat日志如下,启动速度快了两个数量级:

17:58:07.068 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.38
17:58:07.088 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/tomcat_8_5_38/webapps/docs]
17:58:07.740 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/tomcat_8_5_38/webapps/docs] has finished in [652] ms
17:58:07.740 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/tomcat_8_5_38/webapps/manager]
17:58:07.815 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/tomcat_8_5_38/webapps/manager] has finished in [75] ms
17:58:07.816 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/tomcat_8_5_38/webapps/examples]
17:58:08.241 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/tomcat_8_5_38/webapps/examples] has finished in [425] ms
17:58:08.241 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/tomcat_8_5_38/webapps/host-manager]
17:58:08.268 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/tomcat_8_5_38/webapps/host-manager] has finished in [27] ms
17:58:08.269 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/tomcat_8_5_38/webapps/ROOT]
17:58:08.306 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/tomcat_8_5_38/webapps/ROOT] has finished in [37] ms
17:58:08.335 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
17:58:08.424 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
17:58:08.429 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 1411 ms

参考文档:
https://stackoverflow.com/questions/40383430/tomcat-takes-too-much-time-to-start-java-securerandom
https://bugs.java.com/bugdatabase/view_bug.do?bug_id=6202721
http://openjdk.java.net/jeps/123
https://zh.wikipedia.org/zh-hans//dev/random
https://wiki.apache.org/tomcat/HowTo/FasterStartUp
https://access.redhat.com/documentation/en-us/red_hat_enterprise_linux/6/html/security_guide/sect-security_guide-encryption-using_the_random_number_generator
https://wiki.archlinux.org/index.php/Rng-tools
https://wiki.archlinux.org/index.php/Haveged
https://www.digitalocean.com/community/tutorials/how-to-setup-additional-entropy-for-cloud-servers-using-haveged

推荐阅读更多精彩内容

  • 自己再阿里云申请了一台1G1核的机器,每次重启自己的服务tomcat都需要卡住很长时间,每次都是日志停在Root ...
    把爱放下会走更远阅读 19,511评论 8 14
  • 最近项目上线部署的时候,发现一个问题。Tomcat在启动过程中耗费了很长的时间。查看日志,发现耗时最长的地方是: ...
    龙果学院阅读 182评论 0 1
  • 现象 最近新增了一批服务器,运维反馈说,部署的tomcat启动很慢,但是没有报任何异常,启动后应用也能正常运行。正...
    leoss_H阅读 511评论 0 0
  • 最近项目上线部署的时候,发现一个问题。Tomcat在启动过程中耗费了很长的时间。查看日志,发现耗时最长的地方是: ...
    倔强的小亮阅读 3,288评论 0 3
  • 孩子八天偷偷花掉7000块,父亲暴打他,母亲把视频发到朋友圈。 这一个四分多钟的视频,在当地很多群里被疯传。 事情...
    春下春树阅读 13评论 0 0