10

I can't wrap my head around why the initialization of a c3p0 connection pool takes 2 min in my Hibernate application.

This is in my Hibernate.cfg.xml:

<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">1</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."></property>

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

        <property name="hbm2ddl.auto">create</property>
 </session-factory>
</hibernate-configuration>

The connection settings are set in my HibernateUtil file when building the session factory.

The pool is initialize when the first transaction in my tests is openend. Connecting and querying the db works just fine afterwards, it only hangs on the following line for a while before it will start. I formated the output a bit as I assume the problem may be with one of the settings mentioned here.:

INFO: Initializing c3p0 pool... 
com.mchange.v2.c3p0.PoolBackedDataSource@30670080 [
  connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@ecfec4d0 [
    acquireIncrement -> 1,
    acquireRetryAttempts -> 30,
    acquireRetryDelay -> 1000,
    autoCommitOnClose -> false,
    automaticTestTable -> null,
    breakAfterAcquireFailure -> false,
    checkoutTimeout -> 0,
    connectionCustomizerClassName -> null,
    connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester,        
    debugUnreturnedConnectionStackTraces -> false,
    factoryClassLocation -> null,
    forceIgnoreUnresolvedTransactions -> false,
    identityToken -> I-REMOVED-THIS,
    idleConnectionTestPeriod -> 3000,
    initialPoolSize -> 3,
    maxAdministrativeTaskTime -> 0,
    maxConnectionAge -> 0,
    maxIdleTime -> 300,
    maxIdleTimeExcessConnections -> 0,
    maxPoolSize -> 10,
    maxStatements -> 50,
    maxStatementsPerConnection -> 0,
    minPoolSize -> 3,
    nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@b17e5c65 [
      description -> null,
      driverClass -> null,
      factoryClassLocation -> null,
      identityToken -> I-REMOVED-THIS,
      jdbcUrl -> jdbc:postgresql://URL-TO-MY_DB,
      properties -> {user=******, password=******, default_schema=}
    ],
    preferredTestQuery -> null,
    propertyCycle -> 0,
    testConnectionOnCheckin -> false,
    testConnectionOnCheckout -> false,
    unreturnedConnectionTimeout -> 0,
    usesTraditionalReflectiveProxies -> false;
    userOverrides: {}
  ],
  dataSourceName -> null,
  factoryClassLocation -> null,
  identityToken -> I-REMOVED-THIS,
  numHelperThreads -> 3
]

It's the first time I'm using Hibernate and c3p0 and I was expecting it to be much quicker when starting the pool? Is it a misconception of mine?

It's no difference between using the remote DB nor a local PostgreSQL instance.

(Edit: This is not true. I made a mistake when comparing local and remote db server. Locally, initialization is pretty much immediately, remotely it takes around 2 minutes.)

Edit2: Here is a log of the connection process.

Jonathan Hall
  • 75,165
  • 16
  • 143
  • 189
bentrm
  • 1,018
  • 3
  • 10
  • 26
  • Typically it should be "immidiatly". Maybe try another pooling lib to make sure it is a c3p0 problem, like BoneCP (http://jolbox.com/). – Adrian Jan 19 '13 at 19:05
  • hi. first, what version of c3p0 are you using? can you try upgrading to the most recent (c3p0-0.9.2-pre8), if you are using c3p0-0.9.1.x? re your settings: please choose an acquireIncrement greater than 1 (the default of three is probably ok, given your pool size). you might try setting acquireRetryDelay to a lower value -- if that speeds up your initialization, it means c3p0 is experiencing occasional failures on Connection acquisition. (if you set the level of the logger to com.mchange.v2.resourcepool.BasicResourcePool to FINE or DEBUG, you'll see these failures.) – Steve Waldman Jan 19 '13 at 19:41
  • I made a mistake when comparing initialization on local and remote db server. Sry, for the confusion. Locally, initialization is pretty much immediately, remotely it takes around 2 minutes. I tested it with a Heroku Dev instance of Postgres. Is this still an atypical long time? – bentrm Jan 20 '13 at 10:39
  • @SteveWaldman The c3p0 logging is set to debug and I could not find a way to have more granular logging of the init and connection process. Could you offer a hint how to enable logging for com.mchange.v2.resourcepool.BasicResourcePool? – bentrm Jan 20 '13 at 10:43
  • 1
    it depends on your logging library -- com.mchange.v2.resourcepool.BasicResourcePool is the logger for which you want to enable more detailed loggers. if you are using the Java standard logging library, there should be a logging.properties file. if you are using log4j, log4j.properties. c3p0 dumps which logging framework it is using on startup, look for a line like "MLog clients using", and then a string identifying the logging lib. – Steve Waldman Jan 21 '13 at 08:11
  • (two minutes is a very long time to have to await availability of your first Connection. unless your network is VERY high latency, something is amiss.) – Steve Waldman Jan 21 '13 at 08:13
  • @SteveWaldman I edited my post attaching a log. Would be happy if someone took a look. – bentrm Jan 21 '13 at 18:31
  • so, in this log, it looks like three Connections are acquired and one checked out within 2 secs. there's a gap in log output between 19:19 and 19:21, which I suppose is there the hang that you are seeing is. but all Connections have been acquired by the pool by this point. i'd pull a Thread dump during the hang to try to get a better sense of what's going on. [also, i'd again recommend the 0.9.2 seris over 0.9.1. 0.9.2 final will be done just as soon as I can get some time to publish it. other than doc changes, it's just 0.9.2-pre8.] – Steve Waldman Jan 22 '13 at 20:48
  • @SteveWaldman thanks for your support. I'm not that comfortable with logs and thread dumps as just yet. Anyhow, in the end I don't think c3p0 is the reason for this delay. In fact, in a moment of despair I changed my backend to MySQL today and it turns out everything is going smoothly now. I can't really tell what the reason for all this has been though. This is a follow up post that I made on the issue: http://stackoverflow.com/questions/14445838/hibernate-startup-very-slow – bentrm Jan 22 '13 at 21:15

1 Answers1

12

Set the property hibernate.temp.use_jdbc_metadata_defaults to false in the configuration of your session factory (documentation). This will indicate to Hibernate using metadata dialect instead of the connection, which makes the slow startup. You must also configure an appropriate dialect for your driver.

milchreis
  • 79
  • 7
fabriciobc
  • 136
  • 2
  • 4
  • 11
    Just a note for other people who landed here for the same reason as I did: make sure your Database is running, or c3p0 initialization will hang forever ;) – Nick Redmark Mar 17 '16 at 08:00
  • @NicolaMarcacciRossi What do you mean by database is running? Do you mean connected to the database? – Yigit Alparslan Nov 14 '20 at 01:55