Tomcat8の起動が遅い問題の解決方法

Tomcat起動の起動が遅い問題

Tomcatの再起動がやたらめったら遅い。
インストールしたGitbucketなのかファイアウォールの設定なのか調べてたら全然違った。
Javaのバグが原因みたい。

解決方法

Tomcatの起動オプションを追加。

ログで確認

createSecureRandom の部分で 463秒もかかっていて、全体で起動に465秒かかってる。

不具合時のログ(catalina.out)

05-May-2017 20:50:21.300 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat
05-May-2017 20:50:21.300 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
05-May-2017 20:50:21.300 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
05-May-2017 20:50:21.466 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
05-May-2017 20:50:21.493 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
05-May-2017 20:50:21.507 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-8009"]
05-May-2017 20:50:21.508 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
05-May-2017 20:50:21.520 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 912 ms
05-May-2017 20:50:21.542 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service Catalina
05-May-2017 20:50:21.542 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.14
05-May-2017 20:50:21.586 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/ROOT
05-May-2017 20:58:05.814 INFO [localhost-startStop-1] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [463,716] milliseconds.
05-May-2017 20:58:05.834 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/ROOT has finished in 464,248 ms
05-May-2017 20:58:05.835 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/docs
05-May-2017 20:58:05.857 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/docs has finished in 23 ms
05-May-2017 20:58:05.857 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/examples
05-May-2017 20:58:06.281 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/examples has finished in 424 ms
05-May-2017 20:58:06.281 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/host-manager
05-May-2017 20:58:06.317 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/host-manager has finished in 36 ms
05-May-2017 20:58:06.317 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/manager
05-May-2017 20:58:06.360 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/manager has finished in 43 ms
05-May-2017 20:58:06.386 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
05-May-2017 20:58:06.396 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
05-May-2017 20:58:06.398 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 464877 ms

対応内容

Tomcatの起動時にJAVA_OPTに下記パラメータを追加。

### 追加
JAVA_OPTS="$JAVA_OPTS -Djava.security.egd=file:/dev/./urandom"

修正後のログ

05-May-2017 21:10:02.234 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.5.14
05-May-2017 21:10:02.236 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Apr 13 2017 12:55:45 UTC
05-May-2017 21:10:02.236 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server number:         8.5.14.0
05-May-2017 21:10:02.236 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
05-May-2017 21:10:02.236 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            3.10.0-514.16.1.el7.x86_64
05-May-2017 21:10:02.236 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
05-May-2017 21:10:02.236 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.131-2.b11.el7_3.x86_64/jre
05-May-2017 21:10:02.236 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_131-b11
05-May-2017 21:10:02.236 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation
05-May-2017 21:10:02.236 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /usr/local/tomcat
05-May-2017 21:10:02.236 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /usr/local/tomcat
05-May-2017 21:10:02.237 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties
05-May-2017 21:10:02.237 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
05-May-2017 21:10:02.237 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.security.egd=file:/dev/./urandom
05-May-2017 21:10:02.237 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
05-May-2017 21:10:02.237 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
05-May-2017 21:10:02.237 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/usr/local/tomcat
05-May-2017 21:10:02.237 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat
05-May-2017 21:10:02.237 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
05-May-2017 21:10:02.237 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
05-May-2017 21:10:02.416 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
05-May-2017 21:10:02.444 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
05-May-2017 21:10:02.459 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-8009"]
05-May-2017 21:10:02.460 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
05-May-2017 21:10:02.472 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 918 ms
05-May-2017 21:10:02.504 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service Catalina
05-May-2017 21:10:02.505 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.14
05-May-2017 21:10:02.539 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/ROOT
05-May-2017 21:10:03.085 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/ROOT has finished in 545 ms
05-May-2017 21:10:03.085 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/docs
05-May-2017 21:10:03.110 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/docs has finished in 25 ms
05-May-2017 21:10:03.110 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/examples
05-May-2017 21:10:03.541 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/examples has finished in 431 ms
05-May-2017 21:10:03.542 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/host-manager
05-May-2017 21:10:03.584 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/host-manager has finished in 41 ms
05-May-2017 21:10:03.584 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/manager
05-May-2017 21:10:03.610 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/manager has finished in 26 ms
05-May-2017 21:10:03.629 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
05-May-2017 21:10:03.646 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
05-May-2017 21:10:03.648 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 1175 ms

参考にさせて頂いたサイト

Tomcatのインストール手順(7.0.50) - 世界の一部
tomcatの起動に時間がかかる - 戯言