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

See Hibernate Slow to Acquire Postgres Connection

hibernate.temp.use_jdbc_metadata_defaults=false

To avoid meta-data reload during SessionFactory creation.

Answer 2

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 3

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 4

The issue occured for me when I updated my database from 10g to 11. I found following setting in the code:

    hibernateProperties.setProperty("hibernate.dialect","org.hibernate.dialect.Oracle10gDialect");

and had to change the dialect as follows:

    hibernateProperties.setProperty("hibernate.dialect", "org.hibernate.dialect.Oracle11gDialect");

---

At one point this no longer worked for me and I had to change the following to be not stuck at the "HHH000400: Using dialect: org.hibernate.dialect.Oracle10gDialect":

hibernateProperties.setProperty("hibernate.temp.use_jdbc_metadata_defaults", "false");

Additionally I had to comment out the following to be not stuck at "HV000001: Hibernate Validator 6.1.5.Final":

        // hibernateProperties.setProperty("hibernate.hbm2ddl.auto", "validate");