Hibernate startup very slow

Question

For some reason, the startup of my hibernate application is unbarrably slow. (up to 2 min) I have been thinking that the c3p0 configuration is plain wrong (related question) but studying the logs shows, that there is no activity just after the connection to the server is established. Also, using the built-in polling capabilities of Hibernate shows the same result.

Here is a snippet from the logs:

20:06:51,248 DEBUG BasicResourcePool:422 - decremented pending_acquires: 0
20:06:51,248 DEBUG BasicResourcePool:1644 - trace com.mchange.v2.resourcepool.BasicResourcePool@1acaf0ed [managed: 3, unused: 2, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@5f873eb2)
20:06:51,248 DEBUG BasicResourcePool:1644 - trace com.mchange.v2.resourcepool.BasicResourcePool@1acaf0ed [managed: 3, unused: 2, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@5f873eb2)
20:06:51,273 DEBUG JdbcServicesImpl:121 - Database ->
       name : PostgreSQL
    version : 9.1.6
      major : 9
      minor : 1
20:06:51,274 DEBUG JdbcServicesImpl:127 - Driver ->
       name : PostgreSQL Native Driver
    version : PostgreSQL 9.2 JDBC4 (build 1002)
      major : 9
      minor : 2
20:06:51,274 DEBUG JdbcServicesImpl:133 - JDBC version : 4.0 ##### HANGS FOR 2 MINUTES  ON THIS LINE #####
20:08:14,727  INFO Dialect:123 - HHH000400: Using dialect: org.hibernate.dialect.PostgreSQLDialect
20:08:14,736  INFO LobCreatorBuilder:120 - HHH000424: Disabling contextual LOB creation as createClob() method threw error : java.lang.reflect.InvocationTargetException
20:08:14,736 DEBUG GooGooStatementCache:297 - checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 0; checked out: 0; num connections: 0; num keys: 0
20:08:14,736 DEBUG GooGooStatementCache:297 - checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 0; checked out: 0; num connections: 0; num keys: 0
20:08:14,883 DEBUG BasicResourcePool:1644 - trace com.mchange.v2.resourcepool.BasicResourcePool@1acaf0ed [managed: 3, unused: 2, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@5f873eb2)
20:08:14,883 DEBUG BasicResourcePool:1644 - trace com.mchange.v2.resourcepool.BasicResourcePool@1acaf0ed [managed: 3, unused: 2, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@5f873eb2)
20:08:14,883 DEBUG GooGooStatementCache:297 - checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 0; checked out: 0; num connections: 0; num keys: 0

(Please mind the #comment#.)

I also tried an older Postgres JDBC Driver with no luck whatsoever.

Connecting to a local Database works just fine. Connection is established immediately and I can query the database. This remote db is a Heroku dev instance. I tried it with another remote as well. Same outcome.

I'm out of ideas what I can check now to get rid of this annoyance. Any help would be much appreciated.

Maybe my hibernate.cfg.xml is helpful:

http://www.hibernate.org/dtd/hibernate-

configuration-3.0.dtd">
<hibernate-configuration>
    <session-factory>
        <property name="connection.driver_class">org.postgresql.Driver</property>
        <property name="connection.url"/>
        <property name="connection.default_schema"/>
        <property name="connection.username"/>
        <property name="connection.password"/> 

        <property name="dialect">org.hibernate.dialect.PostgreSQLDialect</property>
            <property name="cache.provider_class">org.hibernate.cache.internal.NoCacheProvider</property>
        <property name="current_session_context_class">thread</property>            
        <property name="hibernate.c3p0.acquire_increment">3</property>
        <property name="hibernate.c3p0.min_size">3</property>
        <property name="hibernate.c3p0.max_size">10</property>
        <property name="hibernate.c3p0.timeout">300</property>
        <property name="hibernate.c3p0.max_statements">50</property>
        <property name="hibernate.c3p0.idle_test_period">3000</property>
        <property name="hibernate.c3p0.acquireRetryDelay">500</property>

        <property name="show_sql">true</property>
        <property name="format_sql">false</property>

        <property name="hbm2ddl.auto">validate</property>

        <mapping class="core.entities.Exam" />
        <mapping class="core.entities.Examination" />
        ...
    </session-factory>
</hibernate-configuration>

EDIT: I tried to find the reason for the delay via logs and profiling but have been widely unsuccessful with it. (I'm not that advanced in this area though.) In the end I did go with try and fail and changed my db for a remote MySQL instance to check if any difference occurs. Turns out, that the connection is established nearly immediately.

Answer 1

Startup slow may be caused by this config:

<property name="hbm2ddl.auto">update</property>

This config means when hibernate start, check if the entity matching with ddl, and do action such as 'create','update'. This will cost too much time.

So the solution is comment this config. Then hibernate will start without validate.

Answer 2

See Hibernate Slow to Acquire Postgres Connection

hibernate.temp.use_jdbc_metadata_defaults=false

To avoid meta-data reload during SessionFactory creation.

Answer 3

What container are you using? c3p0 should be installed in the container, e.g Tomcat. If you are running unit tests, for chrissakes, don't use a connection pool. If you put it into tomcat, you do that with a Resource tag and then connect to it using JNDI. Best way to do it.

Answer 4

For Postgres, add in application config:

spring.jpa.database-platform = org.hibernate.dialect.PostgreSQLDialect
spring.jpa.properties.hibernate.temp.use_jdbc_metadata_defaults=false

First line is necessary if not determine Dialect

Results

Before:

09:10:19.637 [main] INFO  o.h.annotations.common.Version - HCANN000001: Hibernate Commons Annotations {4.0.5.Final}
09:14:17.159 [main] INFO  org.hibernate.dialect.Dialect - HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL9Dialect

~4 minutes

After:

09:40:10.930 [main] INFO  o.h.annotations.common.Version - HCANN000001: Hibernate Commons Annotations {4.0.5.Final}
09:40:11.043 [main] INFO  org.hibernate.dialect.Dialect - HHH000400: Using dialect: org.hibernate.dialect.PostgreSQLDialect

~1 minute

Answer 5

If it is abnormally slow then you probably have a lock in your application, or some resource blocks. In any case download VisualVM (JDK includes jconsole, dumbed down version of it) and check what your threads are doing, where they are stuck (threaddump) and if that doesn't give any quick answers, turn on the profiler.