HibernateUtil does not return connection to c3p0 pool

0
votes

After some problems with database connections timing out using Hibernate in our GWT webapp we chose to use c3p0 as a connection pool provider. Now I have a different problem: The app does not seem to return connections to the pool. Instead it stalls on the first database access.

To debug the issue I followed the recommendations in this question, as my code hangs in awaitAvailable as well. So I used checkoutTimeout to prevent clients from waiting indefinitely and unreturnedConnectionTimeout together with debugUnreturnedConnectionStackTraces to get the stack traces of the part of the code which does not return the connection. Surprisingly, it's all the same code (both waiting for a connection and the one not returning it) and it's all in my HibernateUtil class which initializes the session factory.

Here is the stack trace saved by debugUnreturnedConnectionStackTraces:

java.lang.Exception: DEBUG STACK TRACE: Overdue resource check-out stack trace.
at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:555)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutAndMarkConnectionInUse(C3P0PooledConnectionPool.java:755)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:682)
at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140)
at org.hibernate.c3p0.internal.C3P0ConnectionProvider.getConnection(C3P0ConnectionProvider.java:90)
at org.jadira.usertype.spi.shared.AbstractUserTypeHibernateIntegrator.use42Api(AbstractUserTypeHibernateIntegrator.java:80)
at org.jadira.usertype.spi.shared.AbstractUserTypeHibernateIntegrator.integrate(AbstractUserTypeHibernateIntegrator.java:61)
at org.hibernate.internal.SessionFactoryImpl.<init>(SessionFactoryImpl.java:312)
at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1859)
at my.package.domain.hibernate.HibernateUtil.<clinit>(HibernateUtil.java:17)
[... snip ...] // user code calling HibernateUtil.getSessionFactory()

A similar stack trace for the awaitAvailable() timeout:

com.mchange.v2.resourcepool.TimeoutException: A client timed out while waiting to acquire a resource from com.mchange.v2.resourcepool.BasicResourcePool@ae6163 -- timeout at awaitAvailable()
at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1416)
at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:606)
at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:526)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutAndMarkConnectionInUse(C3P0PooledConnectionPool.java:755)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:682)
at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140)
at org.hibernate.c3p0.internal.C3P0ConnectionProvider.getConnection(C3P0ConnectionProvider.java:90)
at org.jadira.usertype.spi.shared.AbstractUserTypeHibernateIntegrator.use42Api(AbstractUserTypeHibernateIntegrator.java:80)
at org.jadira.usertype.spi.shared.AbstractUserTypeHibernateIntegrator.integrate(AbstractUserTypeHibernateIntegrator.java:61)
at org.hibernate.internal.SessionFactoryImpl.<init>(SessionFactoryImpl.java:312)
at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1859)
at my.package.domain.hibernate.HibernateUtil.<clinit>(HibernateUtil.java:17)
[... snip ...] // same client code calling HibernateUtil.getSessionFactory()

One request to the server is enough to cause this problem, so there are no multiple requests. But the code calling getSessionFactory looks like this:

public class MyClass
{
    private SessionFactory sessionFactory = HibernateUtil.getSessionFactory();
    // [...] snip
}

So it might be that objects of MyClass are instantiated in different parts of the app in parallel, which could cause several calls to getSessionFactory().

But as far as I understand the stack trace it actually stalls in the class loading (not in the call to getSessionFactory()), which I expected to be thread-safe. But is java class loading and corresponding static blocks actually thread-safe?

Here is my code for HibernateUtil:

public class HibernateUtil
{
    private static SessionFactory sessionFactory;

    static
    {
        Configuration configuration = new Configuration().configure();
        StandardServiceRegistryBuilder builder = new StandardServiceRegistryBuilder().applySettings(configuration.getProperties());
        sessionFactory = configuration.buildSessionFactory(builder.build());
    }

    public static SessionFactory getSessionFactory()
    {
        return sessionFactory;
    }
}

Should it work like that? Is there anything I should improve?

For completeness sake here are my hibernate.cfg.xml

<hibernate-configuration>
<session-factory>
    <property name="connection.driver_class">com.mysql.jdbc.Driver</property>
    <property name="hibernate.connection.url">
    <property name="show_sql">true</property>
    <property name="dialect">org.hibernate.dialect.MySQLDialect</property>

    <!-- Connection pool configuration -->
    <property name="connection.provider_class">org.hibernate.connection.C3P0ConnectionProvider</property>
    <property name="hibernate.c3p0.min_size">1</property>
    <property name="hibernate.c3p0.max_size">1</property>
    <property name="hibernate.c3p0.timeout">300</property>
    <property name="hibernate.c3p0.max_statements">50</property>
    <property name="hibernate.c3p0.idle_test_period">90</property>
    <property name="hibernate.c3p0.checkoutTimeout">10000</property><!-- milliseconds -->
    <property name="hibernate.c3p0.debugUnreturnedConnectionStackTraces">true</property><!-- do not use in production -->
    <property name="hibernate.c3p0.unreturnedConnectionTimeout">60</property>

    <!-- Configure automatic session management: https://developer.jboss.org/wiki/Sessionsandtransactions#jive_content_id_Transaction_demarcation_with_plain_JDBC -->
    <property name="hibernate.transaction.factory_class">org.hibernate.transaction.JDBCTransactionFactory</property>
    <property name="hibernate.current_session_context_class">thread</property>

    <!-- Configure automatic mapping for Joda Time classes like DateTime and 
        Instant -->
    <property name="jadira.usertype.autoRegisterUserTypes">true</property>
    <property name="jadira.usertype.javaZone">UTC</property>
    <property name="jadira.usertype.databaseZone">UTC</property>

    <property name="hibernate.hbm2ddl.auto">update</property>
    <!-- lots of mapped classes -->

</session-factory>
</hibernate-configuration>

EDIT: Following @Steve Waldmann's suggestion I increased the maxPoolSize with the following results:

* 2 Connections lead to the same problem
* 4 Connections lead to the same problem
* __8 Connections worked__

I then tried again with a smaller maxPoolSize and now 4 connections worked as well. But 3 connections still fails. I think the problem was due to a schema update I did. Apparently hibernate needs more connections to do the schema upgrade but at least in my case at least 3 connections to do the initial setup.

So I guess the only remaining question is, why does Hibernate need several connections to do the setup? Why isn't one enough?

2
javamultithreadinghibernateconnection-poolingc3p0
The first thing to do is to set a reasonable maxPoolSize (here as hibernate.c3p0.max_size). c3p0 is a Connection pool, not a Connection singleton. A pool of 1 will become exhausted, um, very easily, and may freeze if any operation requires the use of the more than one Connection similtaneously.. Setting a reasonable maxPoolSize may not be sufficient to resolve your issue, in which case we'll talk then. But there's no point spending much time on this until you resolve that. And what's with "hibernate.c3p0. "? Maybe that was once debugUnreturnedConnectionStackTraces? – Steve Waldman
Sorry, the debugUnreturnedConnectionStackTraces somehow got lost in copying the code over. Yes, you are right the missing bit is debugUnreturnedConnectionStackTraces, fixed it in the question now. – Joachim Kurz
About the maxPoolSize: I was under the impression it is good practice to use a small pool during development to find connection leaks early on. I maybe naively assumed that all the stuff I'm doing should be fine with just one connection as I'm not doing any database operations in parallel and only use one hibernate session at a time. For just one request there also shouldn't be any multithreading going on which could cause parallel connections. – Joachim Kurz
@Steve Waldmann I increased the maxPoolSize and that actually solves the problem. However, as mentioned above I thought one connection should be enough for just one request. But apparently Hibernate needs more than one connection for the initial setup, especially when it performs a schema update on the database. Do you happen to know why that is the case? Anyway, if you add the "increase maxPoolSize, it's the right thing to do" as an answer I will accept it. ;-) – Joachim Kurz
A small pool is fine, but too small is asking for trouble. As you've run into, if there's any single operation that expects more than maxPoolSize Connections at once, that's a guaranteed freeze. I don't know the internals of hiberante's SessionFactory and schema initialization, but your experience does suggest the use of multiple Connections internally under some circumstances. – Steve Waldman

2 Answers

1
votes

maxPoolSize — which you set via hibernate.c3p0.max_size — should be greater than one. A value very small leaves your application liable to freezes, if one operation requires more than maxPoolSize Connections and fails to complete util it has them. Please refer to the comment thread beneath the main question.

1
votes

is java class loading and corresponding static blocks actually thread-safe?

Yes. From the Java Virtual Machine Specification:

Because the Java Virtual Machine is multithreaded, initialization of a class or interface requires careful synchronization, since some other thread may be trying to initialize the same class or interface at the same time. There is also the possibility that initialization of a class or interface may be requested recursively as part of the initialization of that class or interface. The implementation of the Java Virtual Machine is responsible for taking care of synchronization and recursive initialization by using the following procedure.

Note that it's possible that a class can be loaded by more than one classloader, in which case you'd see the static initializer called twice.

But as far as I understand the stack trace it actually stalls in the class loading

Sort of. That's what the clinit in the stack trace is (JVM spec 2.9). That's actually happening during initialization, not loading.

<property name="hibernate.c3p0.timeout">300</property>

Are you sure this value isn't in milliseconds? 300 is awfully short and could easily explain the debugUnreturnedConnectionStackTraces that you're seeing.