Last night, I created a new server instance on HP Cloud and punched a hole in the firewall for port 8080. I became puzzled when I couldn't reach the Tomcat test page (http://server.ip.address:8080). I waited for a few minutes and the server still hadn't responded. I checked the logs and noticed that Tomcat seemed to be stuck at the point of deploying the default ROOT webapp.
May 31, 2014 7:43:15 AM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/common/classes], exists: [false], isDirectory: [false], canRead: [false]
May 31, 2014 7:43:15 AM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/common], exists: [false], isDirectory: [false], canRead: [false]
May 31, 2014 7:43:16 AM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/server/classes], exists: [false], isDirectory: [false], canRead: [false]
May 31, 2014 7:43:16 AM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/server], exists: [false], isDirectory: [false], canRead: [false]
May 31, 2014 7:43:16 AM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/shared/classes], exists: [false], isDirectory: [false], canRead: [false]
May 31, 2014 7:43:16 AM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/shared], exists: [false], isDirectory: [false], canRead: [false]
May 31, 2014 7:43:22 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8080"]
May 31, 2014 7:43:22 AM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 5612 ms
May 31, 2014 7:43:22 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
May 31, 2014 7:43:22 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.52 (Ubuntu)
May 31, 2014 7:43:22 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /var/lib/tomcat7/webapps/ROOT
I was looking for the following line, but it never came.
INFO: Server startup in 3908 ms
I checked and re-checked the firewall settings in HP Cloud - just in case - and they seemed to be correct. It was 4am EST so I decided to head to bed. This morning, I woke up to check if Tomcat had eventually started. I made a request to the Tomcat test page and received the expected response.
Weird.
I tried to restart Tomcat to see if it was just a network hiccup, but Tomcat continued to stall at the same place in the log file. So I went back through the log from the night before and noticed the last four lines below:
May 31, 2014 7:43:22 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.52 (Ubuntu)
May 31, 2014 7:43:22 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /var/lib/tomcat7/webapps/ROOT
May 31, 2014 9:03:02 AM org.apache.catalina.util.SessionIdGenerator createSecureRandom
INFO: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [4,772,515] milliseconds.
May 31, 2014 9:03:02 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8080"]
May 31, 2014 9:03:02 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 4780082 ms
Looks like it took 4.8 million ms (about 80 minutes) to create the SecureRandom instance (this is used by Tomcat to generate unique session IDs and other random values). I haven't looked into why that might be the case, but I found a workaround here (http://wiki.apache.org/tomcat/HowTo/FasterStartUp) that uses a non-blocking entropy source. The wiki page mentions that the non-blocking entropy source (/dev/urandom) is less secure than the blocking entropy source (/dev/random) because the non-blocking option generates less-random data. However, given that this is a completely unacceptable startup delay, I figured I could live with the workaround until I've had some time to read up on different entropy sources.
In any case, I just needed to add the following system property to Tomcat's startup routine.
-Djava.security.egd=file:/dev/./urandom
On Ubuntu, I generally add command-line properties like this to the setenv.sh script that is called by catalina.sh or startup.sh (/usr/share/tomcat7/bin/setenv.sh). That might be different for Windows or Mac, so you may need to look around to figure out the correct place for this setting -- adding it to Tomcat's start script is generally a bad idea.
export CATALINA_OPTS="-Xms256m -Xmx512m -XX:MaxPermSize=128m -Duser.timezone=EST -Djava.security.egd=file:/dev/./urandom"
I'll try to update this blog entry once I've figured out the best way to resolve this issue for good.
Software versions
Ubuntu 14.04
Tomcat 7.0.52
Java version "1.7.0_55"
OpenJDK Runtime Environment (IcedTea 2.4.7) (7u55-2.4.7-1ubuntu1)
OpenJDK 64-Bit Server VM (build 24.51-b03, mixed mode)
