Hibernate startup very slow

bentrm picture bentrm · Jan 21, 2013 · Viewed 21.5k times · Source

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

Darryl Miles picture Darryl Miles · Sep 18, 2013

See Hibernate Slow to Acquire Postgres Connection

hibernate.temp.use_jdbc_metadata_defaults=false

To avoid meta-data reload during SessionFactory creation.