Nitin Vavdiya Nitin Vavdiya - 15 days ago 10
Java Question

Tomcat7 takes too much time to start

I am using tomcat7 as application server to run my java web application (.war) when I restart tomcat it take 20-25 mins to deploy may war file.
i get this log when i restart tomcat :

Sep 24, 2016 9:45:29 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Sep 24, 2016 9:45:29 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.68 (Ubuntu)
Sep 24, 2016 9:45:29 AM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive /var/lib/tomcat7/webapps/tnu.war
Sep 24, 2016 9:45:30 AM org.apache.catalina.loader.WebappClassLoaderBase validateJarFile
INFO: validateJarFile(/var/lib/tomcat7/webapps/tnu/WEB-INF/lib/javax.servlet-api-3.0.1.jar) - jar not loaded. See Servlet Spec 3.0, section 10.7.2. Offending class: javax/servlet/Servlet.class
Sep 24, 2016 9:45:33 AM org.apache.catalina.startup.TldConfig execute
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Sep 24, 2016 9:46:51 AM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/common/classes], exists: [false], isDirectory: [false], canRead: [false]
Sep 24, 2016 9:46:51 AM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/common], exists: [false], isDirectory: [false], canRead: [false]
Sep 24, 2016 9:46:51 AM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/server/classes], exists: [false], isDirectory: [false], canRead: [false]
Sep 24, 2016 9:46:51 AM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/server], exists: [false], isDirectory: [false], canRead: [false]
Sep 24, 2016 9:46:51 AM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/shared/classes], exists: [false], isDirectory: [false], canRead: [false]
Sep 24, 2016 9:46:51 AM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/shared], exists: [false], isDirectory: [false], canRead: [false]
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server version: Apache Tomcat/7.0.68 (Ubuntu)
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server built: Jun 27 2016 18:13:17 UTC
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server number: 7.0.68.0
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Name: Linux
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Version: 4.4.0-36-generic
INFO: Server version: Apache Tomcat/7.0.68 (Ubuntu)
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server built: Jun 27 2016 18:13:17 UTC
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server number: 7.0.68.0
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Name: Linux
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Version: 4.4.0-36-generic
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Architecture: amd64
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Java Home: /usr/lib/jvm/java-8-openjdk-amd64/jre
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Version: 1.8.0_91-8u91-b14-3ubuntu1~16.04.1-b14
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Vendor: Oracle Corporation
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_BASE: /var/lib/tomcat7
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_HOME: /usr/share/tomcat7
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.config.file=/var/lib/tomcat7/conf/logging.properties
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.awt.headless=true
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xmx128m
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+UseConcMarkSweepGC
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.endorsed.dirs=/usr/share/tomcat7/endorsed
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.base=/var/lib/tomcat7
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.home=/usr/share/tomcat7
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.io.tmpdir=/tmp/tomcat7-tomcat7-tmp
INFO: Command line argument: -Djava.io.tmpdir=/tmp/tomcat7-tomcat7-tmp
Sep 24, 2016 9:46:52 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8080"]
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 744 ms
Sep 24, 2016 9:46:52 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Sep 24, 2016 9:46:52 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.68 (Ubuntu)
Sep 24, 2016 9:46:52 AM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive /var/lib/tomcat7/webapps/tnu.war
Sep 24, 2016 9:46:53 AM org.apache.catalina.loader.WebappClassLoaderBase validateJarFile
INFO: validateJarFile(/var/lib/tomcat7/webapps/tnu/WEB-INF/lib/javax.servlet-api-3.0.1.jar) - jar not loaded. See Servlet Spec 3.0, section 10.7.2. Offending class: javax/servlet/Servlet.class
Sep 24, 2016 9:46:56 AM org.apache.catalina.startup.TldConfig execute
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Sep 24, 2016 10:03:01 AM org.apache.catalina.util.SessionIdGeneratorBase createSecureRandom
INFO: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [965,010] milliseconds.
log4j:WARN No such property [maxBackupIndex] in org.apache.log4j.DailyRollingFileAppender.
log4j:WARN No such property [maxFileSize] in org.apache.log4j.DailyRollingFileAppender.
24 Sep 2016 10:03:01,669 - [localhost-startStop-1] DEBUG [org.jboss.logging] [] - Logging Provider: org.jboss.logging.Log4jLoggerProvider
24 Sep 2016 10:03:01,694 - [localhost-startStop-1] DEBUG [logging.loggers.YWLogger] [] - Sat Sep 24 10:03:01 UTC 2016 - [ ConstantReader ] File Found
File Found
24 Sep 2016 10:03:01,697 - [localhost-startStop-1] DEBUG [reqfilter.interceptor.MobReqFilter] [] - MobRequestFilter : init + webapp path : /var/lib/tomcat7/webapps/tnu/
24 Sep 2016 10:03:01,698 - [localhost-startStop-1] DEBUG [reqfilter.interceptor.MobReqFilter] [] - init params : WEB-INF/classes/log4j.properties
Sep 24, 2016 10:03:05 AM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deployment of web application archive /var/lib/tomcat7/webapps/tnu.war has finished in 973,344 ms
Sep 24, 2016 10:03:05 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /var/lib/tomcat7/webapps/ROOT
Sep 24, 2016 10:03:05 AM org.apache.catalina.core.StandardContext setPath
WARNING: A context path must either be an empty string or start with a '/' and do not end with a '/'. The path [/] does not meet these criteria and has been changed to []
Sep 24, 2016 10:03:06 AM org.apache.catalina.startup.TldConfig execute
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Sep 24, 2016 10:03:06 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /var/lib/tomcat7/webapps/ROOT has finished in 331 ms
Sep 24, 2016 10:03:06 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8080"]
Sep 24, 2016 10:03:06 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 973768 ms


I have to wait for 20-25 mins after i restart tomcat7.Any solution for this?

Note : OS - ubuntu 14.04 on digitalocean cloud.

Answer
INFO: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [965,010] milliseconds.

This is the process that takes a lot of server time. Creation of SecureRandom itself takes 16.0835 Minutes.

Fortunately, Apache wiki has a workaround for this:

Tomcat 7+ heavily relies on SecureRandom class to provide random values for its session ids and in other places. Depending on your JRE it can cause delays during startup if entropy source that is used to initialize SecureRandom is short of entropy. You will see warning in the logs when this happens, e.g.:

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

There is a way to configure JRE to use a non-blocking entropy source by setting the following system property: -Djava.security.egd=file:/dev/./urandom

Comments