Tomcat7 hangs on deploying apps

tomcat deployment

I'm having some very strange behavior in Tomcat 7 on Ubuntu 14.04.

I created a new VPS, installed default-jdk and other simple stuff. Downloaded and unpacked Tomcat 7. Checked that it runs on [myIP]:8080, and saw Tomcat's index page.

Once I rebooted the VPS, I started Tomcat again, and... there is no response on [myIP]:8080. Not even an error. When I checked the logs, I saw that Tomcat just hangs in state of deployment on the first webapp.

My logs:

Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server version:        Apache Tomcat/7.0.57
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server built:          Nov 3 2014 08:39:16 UTC
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server number:         7.0.57.0
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Name:               Linux
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Version:            3.13.0-37-generic
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Architecture:          amd64
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: JAVA_HOME:             /usr/lib/jvm/java-7-openjdk-amd64/jre
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Version:           1.7.0_65-b32
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Vendor:            Oracle Corporation
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_BASE:         /opt/tomcat
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_HOME:         /opt/tomcat
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.config.file=/opt/tomcat/conf/logging.properties
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.endorsed.dirs=/opt/tomcat/endorsed
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.base=/opt/tomcat
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.home=/opt/tomcat
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.io.tmpdir=/opt/tomcat/temp
Dec 31, 2014 9:06:04 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: 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/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
Dec 31, 2014 9:06:04 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8080"]
Dec 31, 2014 9:06:04 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-bio-8009"]
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 2327 ms
Dec 31, 2014 9:06:04 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Dec 31, 2014 9:06:04 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.57
Dec 31, 2014 9:06:04 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /opt/tomcat/webapps/host-manager
Dec 31, 2014 9:11:09 AM org.apache.catalina.util.SessionIdGenerator createSecureRandom
INFO: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [303,104] milliseconds.
Dec 31, 2014 9:11:09 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /opt/tomcat/webapps/host-manager has finished in 304,682 ms
Dec 31, 2014 9:11:09 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /opt/tomcat/webapps/manager
Dec 31, 2014 9:11:09 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /opt/tomcat/webapps/manager has finished in 271 ms
Dec 31, 2014 9:11:09 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /opt/tomcat/webapps/docs
Dec 31, 2014 9:11:09 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /opt/tomcat/webapps/docs has finished in 205 ms
Dec 31, 2014 9:11:09 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /opt/tomcat/webapps/examples
Dec 31, 2014 9:11:11 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /opt/tomcat/webapps/examples has finished in 1,422 ms
Dec 31, 2014 9:11:11 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /opt/tomcat/webapps/ROOT
Dec 31, 2014 9:11:11 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /opt/tomcat/webapps/ROOT has finished in 177 ms
Dec 31, 2014 9:11:11 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8080"]
Dec 31, 2014 9:11:11 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-bio-8009"]
Dec 31, 2014 9:11:11 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 306957 ms
Dec 31, 2014 9:17:35 AM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["http-bio-8080"]
Dec 31, 2014 9:17:35 AM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["ajp-bio-8009"]
Dec 31, 2014 9:17:35 AM org.apache.catalina.core.StandardService stopInternal
INFO: Stopping service Catalina
Dec 31, 2014 9:17:36 AM org.apache.coyote.AbstractProtocol stop
INFO: Stopping ProtocolHandler ["http-bio-8080"]
Dec 31, 2014 9:17:36 AM org.apache.coyote.AbstractProtocol stop
INFO: Stopping ProtocolHandler ["ajp-bio-8009"]
Dec 31, 2014 9:17:36 AM org.apache.coyote.AbstractProtocol destroy
INFO: Destroying ProtocolHandler ["http-bio-8080"]
Dec 31, 2014 9:17:36 AM org.apache.coyote.AbstractProtocol destroy
INFO: Destroying ProtocolHandler ["ajp-bio-8009"]
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server version:        Apache Tomcat/7.0.57
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server built:          Nov 3 2014 08:39:16 UTC
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server number:         7.0.57.0
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Name:               Linux
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Version:            3.13.0-37-generic
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Architecture:          amd64
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: JAVA_HOME:             /usr/lib/jvm/java-7-openjdk-amd64/jre
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Version:           1.7.0_65-b32
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Vendor:            Oracle Corporation
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_BASE:         /opt/tomcat
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_HOME:         /opt/tomcat
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.config.file=/opt/tomcat/conf/logging.properties
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.endorsed.dirs=/opt/tomcat/endorsed
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.base=/opt/tomcat
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.home=/opt/tomcat
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.io.tmpdir=/opt/tomcat/temp
Dec 31, 2014 9:20:01 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: 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/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
Dec 31, 2014 9:20:01 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8080"]
Dec 31, 2014 9:20:01 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-bio-8009"]
Dec 31, 2014 9:20:01 AM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 1536 ms
Dec 31, 2014 9:20:02 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Dec 31, 2014 9:20:02 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.57
Dec 31, 2014 9:20:02 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /opt/tomcat/webapps/host-manager
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server version:        Apache Tomcat/7.0.57
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server built:          Nov 3 2014 08:39:16 UTC
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server number:         7.0.57.0
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Name:               Linux
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Version:            3.13.0-37-generic
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Architecture:          amd64
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: JAVA_HOME:             /usr/lib/jvm/java-7-openjdk-amd64/jre
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Version:           1.7.0_65-b32
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Vendor:            Oracle Corporation
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_BASE:         /opt/tomcat
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_HOME:         /opt/tomcat
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.config.file=/opt/tomcat/conf/logging.properties
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.endorsed.dirs=/opt/tomcat/endorsed
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.base=/opt/tomcat
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.home=/opt/tomcat
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.io.tmpdir=/opt/tomcat/temp
Dec 31, 2014 9:33:38 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: 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/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
Dec 31, 2014 9:33:38 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8080"]
Dec 31, 2014 9:33:38 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-bio-8009"]
Dec 31, 2014 9:33:38 AM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 2495 ms
Dec 31, 2014 9:33:39 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Dec 31, 2014 9:33:39 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.57
Dec 31, 2014 9:33:39 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /opt/tomcat/webapps/host-manager

Up until line 74, this is a normal server startup. All standard webapps were deployed (lines 48-68), but after that it just hangs. So, I stopped the server and rebooted my system. Started tomcat again, and the miracle begins. The next session is in lines 89-136, and you can see there there is no entry for Server startup in xxxx ms.

It just hangs in deployment and this situation repeats all the time. What could be causing this? I've spent hours struggling with this problem and I'm going crazy and getting nowhere.


Solution 1:

A possible problem is Tomcat waiting for entropy to build up. Take a few thread dump with jstack to see who's waiting on what.

Tomcat 7+ heavily relies on SecureRandom class to provide random values for its session ids, and other things. Depending on your JRE, it can cause delays during startup if the entropy source that is used to initialize SecureRandom is short of entropy.

If the problem is entropy, 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

See this related discussion for more details.

Related

How can I check if my IIS site is using NTLM or Kerberos?
Updating Malware cleaning skills
Postfix check outgoing mail for spam
Block outgoing mail to specific address using Postfix
Enabling hardware virtualisation BIOS; anything to beware?
How to change Linux services startup/boot order?
OpenVPN and DNS. How to?
Command to remove computer from non-existant domain
RAID-5: Two disks failed simultaneously?
Conditional DNS forwarding with named on Linux
How to use SAS Expander with RAID card?
Failed SPF for email imported to Gmail because of client IP instead of server's in message when sent through SMTP from one local box to another