このセクションでは、乱数生成に伴う JVM の処理遅延を回避する方法について、紹介します。 JVM には、認証フィルターでランダム値を生成しそのランダム値が 認証チェック中に値が変更されていないかを確認した上で、 ログインチェックを行い、認証成功と判断する機能があり、その処理が遅いために Tomcat の起動が遅くなる問題が発生します。
Tomcat 起動時に、Tomcat の catalina.out( /usr/local/tomcat/logs/catalina.out )を確認すると、Creation of SecureRandom に 820,211 ミリ秒かかっていることがわかります。状況によってはもっと遅くなることがあります。
[root@java-1 ~]# tail -F /usr/local/tomcat/logs/catalina.out 30-Dec-2018 19:35:38.413 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/usr/local/tomcat 30-Dec-2018 19:35:38.415 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat 30-Dec-2018 19:35:38.416 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp 30-Dec-2018 19:35:38.425 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] 30-Dec-2018 19:35:39.937 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"] 30-Dec-2018 19:35:40.917 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-8009"] 30-Dec-2018 19:35:40.971 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [12,177] milliseconds 30-Dec-2018 19:35:42.190 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina] 30-Dec-2018 19:35:42.207 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.14] 30-Dec-2018 19:35:42.643 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/ROOT] 30-Dec-2018 19:49:29.888 WARNING [main] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [820,211] milliseconds.
インストールされた JVM のパスを確認します。ここでは、JVM のパスが /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.191.b12-1.el7_6.x86_64 であることが確認できます。
[root@java-1 ~]# dirname $(dirname $(readlink $(readlink $(which javac)))) /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.191.b12-1.el7_6.x86_64 [root@java-1 ~]#
java.security ファイル( /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.191.b12-1.el7_6.x86_64/jre/lib/security/java.security )を編集し、以下設定を変更します。
[root@java-1 ~]# vi /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.191.b12-1.el7_6.x86_64/jre/lib/security/java.security
securerandom.source=file:/dev/random ↓ securerandom.source=file:/dev/./urandom
変更後、Tomcat を再起動します。
[root@java-1 ~]# systemctl restart tomcat [root@java-1 ~]#
Tomcat の catalina.out( /usr/local/tomcat/logs/catalina.out )を再度確認すると、Creation of SecureRandom に 188 ミリ秒で処理されていることがわかります。この対策で、Tomcat の起動がこれまでより早くなります。
[root@java-1 ~]# tail -F /usr/local/tomcat/logs/catalina.out 30-Dec-2018 19:55:47.057 INFO [main] org.apache.catalina.core.StandardServer.await A valid shutdown command was received via the shutdown port. Stopping the Server instance. 30-Dec-2018 19:55:47.109 INFO [main] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["http-nio-8080"] 30-Dec-2018 19:56:03.450 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name: Apache Tomcat/9.0.14 30-Dec-2018 19:56:03.502 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built: Dec 6 2018 21:13:53 UTC 30-Dec-2018 19:56:03.504 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 9.0.14.0 30-Dec-2018 19:56:03.505 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name: Linux 30-Dec-2018 19:56:03.505 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version: 3.10.0-957.1.3.el7.x86_64 30-Dec-2018 19:56:03.506 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture: amd64 30-Dec-2018 19:56:03.533 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home: /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.191.b12-1.el7_6.x86_64/jre 30-Dec-2018 19:56:03.535 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version: 1.8.0_191-b12 30-Dec-2018 19:56:03.536 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor: Oracle Corporation 30-Dec-2018 19:56:03.537 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE: /usr/local/tomcat 30-Dec-2018 19:56:03.538 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME: /usr/local/tomcat 30-Dec-2018 19:56:03.542 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties 30-Dec-2018 19:56:03.575 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager 30-Dec-2018 19:56:03.588 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048 30-Dec-2018 19:56:03.592 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources 30-Dec-2018 19:56:03.618 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027 30-Dec-2018 19:56:03.623 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs= 30-Dec-2018 19:56:03.627 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/usr/local/tomcat 30-Dec-2018 19:56:03.634 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat 30-Dec-2018 19:56:03.640 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp 30-Dec-2018 19:56:03.658 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] 30-Dec-2018 19:56:05.741 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"] 30-Dec-2018 19:56:06.705 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-8009"] 30-Dec-2018 19:56:06.827 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [12,365] milliseconds 30-Dec-2018 19:56:07.427 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina] 30-Dec-2018 19:56:07.429 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.14] 30-Dec-2018 19:56:07.686 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/ROOT] 30-Dec-2018 19:56:14.499 WARNING [main] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [188] milliseconds.