Windows – Tomcat 8 slow applications initialization

tomcatwindows

I found quite a few threads on "slow start" of Tomcat, but none related to slow web applications initialization.

I am using a Tomcat 8 with Java 8. Most of the time it uses only a fraction of the memory and CPU capacity. The server starts quickly but the web applications themselves initialize very slowly (10-15 minutes for a dozen simple apps).

Some details that might be relevant:

  • The servers are Tomcat 8 running on Java 8.
  • The applications are all built with Spring MVC.
  • All applications rely on the exact same stack of open source libraries, with their classpaths specified in catalina.properties common.loader. (cas, commons-beanutils, commons-dbcp2, cxf, itext, jackson, jt400, mssql jdbc driver, poi, sitemesh and spring, plus the libraries they depend on)
  • We have a similar servers also running Tomcat 8 on Java 8, but using Java 6 emulation to run older applications. Those applications rely on older versions of the same open source libraries. These old-app servers do start in a reasonable time. The only obvious difference is the open source packing model (the older approach of collecting them into a few dozen jars compared to the modern hundreds of smaller jars).
  • A native Java 8 application that uses the same newer version of the library stack starts up even faster, in seconds.

A 10-15 minute wait before the web applications are initialized and available is too long. I assume that we are doing something wrong to cause such slow initialization.

Can I ask for some hints on how to troubleshoot and solve this problem?

Thanks.


In case it is relevant, this is the start of the catalina.log, including the first couple apps that come with Tomcat:


26-Jun-2019 05:59:02.952 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.0.28
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Oct 7 2015 18:25:21 UTC
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server number:         8.0.28.0
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Windows Server 2012 R2
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            6.3
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             D:\java\jdk8.144\jre
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_144-b01
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         D:\tomcat\apache-tomcat-8.0.28
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         D:\tomcat\apache-tomcat-8.0.28
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=D:\tomcat\apache-tomcat-8.0.28
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=D:\tomcat\apache-tomcat-8.0.28
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.endorsed.dirs=D:\tomcat\apache-tomcat-8.0.28\endorsed
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=D:\tomcat\apache-tomcat-8.0.28\temp
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=D:\tomcat\apache-tomcat-8.0.28\conf\logging.properties
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xdebug
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xrunjdwp:transport=dt_socket,address=8000,server=y,suspend=n
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: exit
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xms3000m
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xmx4000m
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded APR based Apache Tomcat Native library 1.1.33 using APR version 1.5.1.
26-Jun-2019 05:59:02.967 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
26-Jun-2019 05:59:04.030 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized (OpenSSL 1.0.1m 19 Mar 2015)
26-Jun-2019 05:59:04.561 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-apr-80"]
26-Jun-2019 05:59:04.623 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-443"]
26-Jun-2019 05:59:05.108 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
26-Jun-2019 05:59:05.108 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-apr-8009"]
26-Jun-2019 05:59:05.123 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 3442 ms
26-Jun-2019 05:59:05.170 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service Catalina
26-Jun-2019 05:59:05.170 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.0.28
26-Jun-2019 05:59:05.202 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory D:\tomcat\apache-tomcat-8.0.28\webapps\docs
26-Jun-2019 05:59:40.780 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars 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.
26-Jun-2019 05:59:40.936 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory D:\tomcat\apache-tomcat-8.0.28\webapps\docs has finished in 35,750 ms
26-Jun-2019 05:59:40.936 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory D:\tomcat\apache-tomcat-8.0.28\webapps\examples
26-Jun-2019 06:00:11.998 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars 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.
26-Jun-2019 06:00:12.467 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory D:\tomcat\apache-tomcat-8.0.28\webapps\examples has finished in 31,531 ms

Best Answer

Setting a high value for Xms seems excessive. Try leaving this at default, a minimum of 3g rising to max of 4g is quite narrow. You apps may need this RAM but they should grow to fill space on their own