I recently updated my server installation from Tomcat 6 to Tomcat 7, in order to take advantage of better connection pooling. My project uses Hibernate, for object persistance, a Mysql 5.5.20 database, and memcached for caching. When I was using Tomcat 6, Tomcat would start in about 8 seconds. After moving to Tomcat 7, it now takes between 75 - 80 seconds to start (this is on a Macbook pro 15", core i7 2Ghz, 8Gb of RAM).

The only thing that has really changed between during the move from Tomcat 6 to 7 has been my context.xml file, which controls the connection pooling information:

<Context antiJARLocking="true" reloadable="true" path="">

<Resource name="jdbc/test-db" 
          auth="Container"
          type="javax.sql.DataSource"
          factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"
          testOnBorrow="true"
          testOnReturn="false"
          testWhileIdle="true"
          validationQuery="SELECT 1"
          validationQueryTimeout="20000"
          validationInterval="30000"
          timeBetweenEvictionRunsMillis="60000"
          logValidationErrors="true"
          autoReconnect="true"
          username="webuser" 
          password="xxxxxxx"
          driverClassName="com.mysql.jdbc.Driver"
          url="jdbc:mysql://databasename.us-east-1.rds.amazonaws.com:3306/test-db"
          maxActive="15"
          minIdle="2"
          maxIdle="10"
          maxWait="10000" 
          maxAge="7200000"/>
</Context>

Now, as you can see, the database is running on Amazon RDS (where our live servers are), and thus is about 200ms round trip time away from my machine. I have already checked that I have security permissions to that database from my machine, (and anyway, it connects after 75 secs, so it cant be that).

My initial thought was that Tomcat 7 and hibernate are doing something weird (like pre-instantiating a bunch of connections or something), and the latency to the database is amplifying the effects.

While trying to diagnose the problem, I used jstack to get a stack trace of the Tomcat 7 server while its doing its startup thing.

Here is the stack trace...

Full thread dump Java HotSpot(TM) 64-Bit Server VM (20.12-b01-434 mixed mode):

"Attach Listener" daemon prio=9 tid=7fa4c0038800 nid=0x10c39a000 waiting on condition [00000000]
   java.lang.Thread.State: RUNNABLE

"Abandoned connection cleanup thread" daemon prio=5 tid=7fa4bb810000 nid=0x10f3ba000 in Object.wait() [10f3b9000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <7f40a0070> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
    - locked <7f40a0070> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
    at com.mysql.jdbc.NonRegisteringDriver$1.run(NonRegisteringDriver.java:93)

"PoolCleaner[545768040:1352724902327]" daemon prio=5 tid=7fa4be852800 nid=0x10e772000 in Object.wait() [10e771000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <7f40c7c90> (a java.util.TaskQueue)
    at java.util.TimerThread.mainLoop(Timer.java:509)
    - locked <7f40c7c90> (a java.util.TaskQueue)
    at java.util.TimerThread.run(Timer.java:462)

"localhost-startStop-1" daemon prio=5 tid=7fa4bd034800 nid=0x10d66b000 runnable [10d668000]
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:129)
    at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:114)
    at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:161)
    at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:189)
    - locked <7f3673be0> (a com.mysql.jdbc.util.ReadAheadInputStream)
    at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3014)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3467)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3456)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3997)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2468)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2629)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2713)
    - locked <7f366a1c0> (a com.mysql.jdbc.JDBC4Connection)
    at com.mysql.jdbc.ConnectionImpl.configureClientCharacterSet(ConnectionImpl.java:1930)
    at com.mysql.jdbc.ConnectionImpl.initializePropsFromServer(ConnectionImpl.java:3571)
    at com.mysql.jdbc.ConnectionImpl.connectOneTryOnly(ConnectionImpl.java:2445)
    at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2215)
    - locked <7f366a1c0> (a com.mysql.jdbc.JDBC4Connection)
    at com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:813)
    at com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:47)
    at sun.reflect.GeneratedConstructorAccessor10.newInstance(Unknown Source)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
    at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:399)
    at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:334)
    at org.apache.tomcat.jdbc.pool.PooledConnection.connectUsingDriver(PooledConnection.java:278)
    at org.apache.tomcat.jdbc.pool.PooledConnection.connect(PooledConnection.java:182)
    at org.apache.tomcat.jdbc.pool.ConnectionPool.createConnection(ConnectionPool.java:699)
    at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:631)
    at org.apache.tomcat.jdbc.pool.ConnectionPool.init(ConnectionPool.java:485)
    at org.apache.tomcat.jdbc.pool.ConnectionPool.<init>(ConnectionPool.java:143)
    at org.apache.tomcat.jdbc.pool.DataSourceProxy.pCreatePool(DataSourceProxy.java:116)
    - locked <7f34f0dc8> (a org.apache.tomcat.jdbc.pool.DataSource)
    at org.apache.tomcat.jdbc.pool.DataSourceProxy.createPool(DataSourceProxy.java:103)
    at org.apache.tomcat.jdbc.pool.DataSourceFactory.createDataSource(DataSourceFactory.java:539)
    at org.apache.tomcat.jdbc.pool.DataSourceFactory.getObjectInstance(DataSourceFactory.java:237)
    at org.apache.naming.factory.ResourceFactory.getObjectInstance(ResourceFactory.java:143)
    at javax.naming.spi.NamingManager.getObjectInstance(NamingManager.java:304)
    at org.apache.naming.NamingContext.lookup(NamingContext.java:843)
    at org.apache.naming.NamingContext.lookup(NamingContext.java:154)
    at org.apache.naming.NamingContext.lookup(NamingContext.java:831)
    at org.apache.naming.NamingContext.lookup(NamingContext.java:168)
    at org.apache.catalina.core.NamingContextListener.addResource(NamingContextListener.java:1061)
    at org.apache.catalina.core.NamingContextListener.createNamingContext(NamingContextListener.java:671)
    at org.apache.catalina.core.NamingContextListener.lifecycleEvent(NamingContextListener.java:270)
    at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:119)
    at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:90)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5173)
    - locked <7f46b07f0> (a org.apache.catalina.core.StandardContext)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    - locked <7f46b07f0> (a org.apache.catalina.core.StandardContext)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1559)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1549)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:680)

"Catalina-startStop-1" daemon prio=5 tid=7fa4b7a5e800 nid=0x10d568000 waiting on condition [10d567000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <7f480e970> (a java.util.concurrent.FutureTask$Sync)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:969)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1281)
    at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:218)
    at java.util.concurrent.FutureTask.get(FutureTask.java:83)
    at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:1123)
    - locked <7f453c630> (a org.apache.catalina.core.StandardHost)
    at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:800)
    - locked <7f453c630> (a org.apache.catalina.core.StandardHost)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    - locked <7f453c630> (a org.apache.catalina.core.StandardHost)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1559)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1549)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:680)

"GC Daemon" daemon prio=2 tid=7fa4b9912800 nid=0x10d465000 in Object.wait() [10d464000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <7f4506d28> (a sun.misc.GC$LatencyLock)
    at sun.misc.GC$Daemon.run(GC.java:100)
    - locked <7f4506d28> (a sun.misc.GC$LatencyLock)

"Low Memory Detector" daemon prio=5 tid=7fa4b480b800 nid=0x10c8ae000 runnable [00000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=9 tid=7fa4b480b000 nid=0x10c7ab000 waiting on condition [00000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=9 tid=7fa4b480a000 nid=0x10c6a8000 waiting on condition [00000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=9 tid=7fa4b4809800 nid=0x10c5a5000 runnable [00000000]
   java.lang.Thread.State: RUNNABLE

"Surrogate Locker Thread (Concurrent GC)" daemon prio=5 tid=7fa4b4808800 nid=0x10c4a2000 waiting on condition [00000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=8 tid=7fa4b793f000 nid=0x10c297000 in Object.wait() [10c296000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <7f451c8f0> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
    - locked <7f451c8f0> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=7fa4b793e000 nid=0x10c194000 in Object.wait() [10c193000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <7f452e168> (a java.lang.ref.Reference$Lock)
    at java.lang.Object.wait(Object.java:485)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
    - locked <7f452e168> (a java.lang.ref.Reference$Lock)

"main" prio=5 tid=7fa4b7800800 nid=0x104329000 waiting on condition [104327000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <7f480e9a0> (a java.util.concurrent.FutureTask$Sync)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:969)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1281)
    at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:218)
    at java.util.concurrent.FutureTask.get(FutureTask.java:83)
    at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:1123)
    - locked <7f451fd90> (a org.apache.catalina.core.StandardEngine)
    at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:302)
    - locked <7f451fd90> (a org.apache.catalina.core.StandardEngine)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    - locked <7f451fd90> (a org.apache.catalina.core.StandardEngine)
    at org.apache.catalina.core.StandardService.startInternal(StandardService.java:443)
    - locked <7f451fd90> (a org.apache.catalina.core.StandardEngine)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    - locked <7f453e810> (a org.apache.catalina.core.StandardService)
    at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:732)
    - locked <7f4506d58> (a [Lorg.apache.catalina.Service;)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    - locked <7f44f7ba0> (a org.apache.catalina.core.StandardServer)
    at org.apache.catalina.startup.Catalina.start(Catalina.java:684)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:322)
    at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:451)

"VM Thread" prio=9 tid=7fa4b7939800 nid=0x10c091000 runnable 

"Gang worker#0 (Parallel GC Threads)" prio=9 tid=7fa4b7802000 nid=0x10772b000 runnable 

"Gang worker#1 (Parallel GC Threads)" prio=9 tid=7fa4b7802800 nid=0x10782e000 runnable 

"Gang worker#2 (Parallel GC Threads)" prio=9 tid=7fa4b7803000 nid=0x107931000 runnable 

"Gang worker#3 (Parallel GC Threads)" prio=9 tid=7fa4b7804000 nid=0x107a34000 runnable 

"Gang worker#4 (Parallel GC Threads)" prio=9 tid=7fa4b7804800 nid=0x107b37000 runnable 

"Gang worker#5 (Parallel GC Threads)" prio=9 tid=7fa4b7805000 nid=0x107c3a000 runnable 

"Gang worker#6 (Parallel GC Threads)" prio=9 tid=7fa4b7805800 nid=0x107d3d000 runnable 

"Gang worker#7 (Parallel GC Threads)" prio=9 tid=7fa4b7806800 nid=0x107e40000 runnable 

"Concurrent Mark-Sweep GC Thread" prio=9 tid=7fa4b78e3800 nid=0x10bd0b000 runnable 
"Gang worker#0 (Parallel CMS Threads)" prio=9 tid=7fa4b78e2800 nid=0x10b305000 runnable 

"Gang worker#1 (Parallel CMS Threads)" prio=9 tid=7fa4b78e3000 nid=0x10b408000 runnable 

"VM Periodic Task Thread" prio=10 tid=7fa4b4815800 nid=0x10c9b1000 waiting on condition 

"Exception Catcher Thread" prio=10 tid=7fa4b7801800 nid=0x104554000 runnable 
JNI global references: 919

The only thing I can figure out from this is that it looks like the mysql jdbc drivers might have something to do with the long start up (the various stack traces I took during the start up process all pretty much look the same as this).

Could anyone shed some light on what might be causing this? Have I done something dense in my context.xml? Is hibernate perhaps to blame?