Search code examples
javamysqlspringhibernatec3p0

SpringMVC, c3p0, hibernate, JPA Application leaking Connections leads to Too Many Connections error


I've googled and searched stackoverflow for a solution to my problem for over 4 hours now, reading and trying to learn what is happening but I have not come across a solution that pertains to my issue so apologies if this sounds like a duplicate, I'll try my best to explain exactly what is happening so I can get some insight into the inner workings of c3p0.

I have a SpringMVC web application running on Tomcat with Hibernate, JPA, and C3P0 as my pooling resource. On page reload, the application as it stand makes a few calls to the database to get a random image and display it on the new page. The application runs fine for about 30 or so page reloads but always eventually crashes and I have to restart mysql in order for the application to work again, it gives the following error:

Apr 04, 2015 12:21:55 PM com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask run WARNING: com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@634d8e3d -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Data source rejected establishment of connection, message from server: "Too many connections" at sun.reflect.GeneratedConstructorAccessor101.newInstance(Unknown Source) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:526) at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) at com.mysql.jdbc.Util.getInstance(Util.java:386) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1015) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:989) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:975) at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1114) at com.mysql.jdbc.ConnectionImpl.coreConnect(ConnectionImpl.java:2493) at com.mysql.jdbc.ConnectionImpl.connectOneTryOnly(ConnectionImpl.java:2526) at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2311) at com.mysql.jdbc.ConnectionImpl.(ConnectionImpl.java:834) at com.mysql.jdbc.JDBC4Connection.(JDBC4Connection.java:47) at sun.reflect.GeneratedConstructorAccessor43.newInstance(Unknown Source) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:526) at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:416) at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:347) at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:135) at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182) at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:171) at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137) at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014) at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32) at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810) at com.mchange.v2.async.ThreadPerTaskAsynchronousRunner$TaskThread.run(ThreadPerTaskAsynchronousRunner.java:255)

Here are pertaining files/configurations to give context to the problem:

spring.xml:

<context:component-scan base-package="com.clathrop.infographyl.dao" />

<bean id="entityManagerFactory"
      class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean">
    <property name="persistenceUnitName" value="infographylPU" />
    <property name="dataSource" ref="dataSource" />
</bean>

<bean id="dataSource" class="com.mchange.v2.c3p0.ComboPooledDataSource" destroy-method="close">
    <!-- Connection properties -->
    <property name="driverClass" value="com.mysql.jdbc.Driver" />
    <property name="jdbcUrl" value="jdbc:mysql://localhost:3306/infographyl_db" />
    <property name="user" value="user" />
    <property name="password" value="passwd" />
    <!-- Pool properties -->
    <property name="minPoolSize" value="5" />
    <property name="maxPoolSize" value="20" />
    <property name="acquireIncrement" value="1" />
    <property name="maxStatements" value="0" />
    <property name="idleConnectionTestPeriod" value="3000" />
    <property name="loginTimeout" value="300" />
</bean>

<bean id="transactionManager" class="org.springframework.orm.jpa.JpaTransactionManager">
    <property name="entityManagerFactory" ref="entityManagerFactory" />
</bean>

persistence.xml:

<persistence-unit name="infographylPU" transaction-type="RESOURCE_LOCAL">
    <class>com.clathrop.infographyl.model.Infographic</class>
    <provider>org.hibernate.ejb.HibernatePersistence</provider>
    <properties>
        <property name="hibernate.dialect" value="org.hibernate.dialect.MySQL5Dialect"/>
    </properties>
</persistence-unit>

Here is what a basic query looks like, in this class I have an EntityManager as an instance variable and i close() the entityManager after every query is finished but it has no affect on the number of connections made in the database.

InfographicDaoImpl.java:

@Repository
public class InfographicDaoImpl implements InfographicDao{

@PersistenceContext
private EntityManager entityManager;

@Override
@Transactional
public void insertInfographic(Infographic infographic){
    try{
        entityManager.persist(infographic);
    } catch (Exception e){
        e.printStackTrace();
    } finally {
        entityManager.close();
    }

}

@Override
public List<Infographic> findAllInfographics(){
    try{
        CriteriaBuilder builder = entityManager.getCriteriaBuilder();
        CriteriaQuery<Infographic> cq = builder.createQuery(Infographic.class);

        Root<Infographic> root = cq.from(Infographic.class);
        cq.select(root);
        List<Infographic> igList = entityManager.createQuery(cq).getResultList();
        return igList;
    } catch (Exception e){
        e.printStackTrace();
        return null;
    } finally {
        entityManager.close();
    }
}

@Override
public Infographic getRandomInfographic(Integer tableSize){
    Random rand = new Random();
    int randomIndex = rand.nextInt((tableSize-1)+1) + 1;

    try{
        CriteriaBuilder builder = entityManager.getCriteriaBuilder();
        CriteriaQuery<Infographic> cq = builder.createQuery(Infographic.class);

        Root<Infographic> root = cq.from(Infographic.class);
        cq.select(root);
        cq.where(builder.equal(root.<Integer>get("id"), randomIndex));
        Infographic randomIg = entityManager.createQuery(cq).getSingleResult();
        return randomIg;
    } catch (Exception e){
        e.printStackTrace();
        return null;
    } finally {
        entityManager.close();
    }


}

@Override
public Integer getRowCount(){
    try{
        Number result = (Number) entityManager.createNativeQuery("Select count(id) from infographics").getSingleResult();
        return result.intValue();
    } catch (Exception e){
        e.printStackTrace();
        return null;
    } finally {
        entityManager.close();
    }
}

@Override
public List<Infographic> listInfographics(Integer startIndex, Integer pageSize){
    List<Infographic> igList = new ArrayList<Infographic>();

    String sStartIndex = Integer.toString(startIndex);
    String sPageSize = Integer.toString(pageSize);

    try{
        List list = entityManager.createNativeQuery("Select * from infographics limit " + sStartIndex + ", " + sPageSize).getResultList();
        for(Object ig : list){
            igList.add((Infographic) ig);
        }
        return igList;
    } catch(Exception e){
        e.printStackTrace();
        return null;
    } finally {
        entityManager.close();
    }


}

}

At this point I have a few questions as to what is happening in my application. The way I understand it is that c3p0 is handling connections made to the database and I thought that with a pooled connection, the connections made would be reused but instead I am getting a growing list of more connections when I look at the processlist in mysql. The number of connections keeps growing until the application finally throws the too many connection warning shown above. My question is why is c3p0 not reusing the connections? Am I missing a configuration somewhere to tell it to reuse the pre-existing connections? Why does entityManager.close() seemingly have no affect? If I am misunderstanding how to use hibernate and c3p0 please let me know what I am missing. Any help is greatly appreciate, thanks in advance.

UPDATE:

SEVERE: The web application [/infographyl] appears to have started a thread named [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0] but has failed to stop it. This is very likely to create a memory leak.

I've narrowed down the problem to a memory leak that is being recognized when tomcat starts up and deploys the application in question. My issue now is trying to find what possible configuration (or missing config) is causing the issue.

My current workaround is to set the wait_timeout in my.cnf to kill processes/connections that are older than 5 seconds, this seems to be ok for now but it is not a sustainable solution and I'd like to know the correct way to close my connections.

UPDATE2: com.mchange.* INFO log:

Apr 05, 2015 10:57:30 PM org.hibernate.service.jdbc.connections.internal.ConnectionProviderInitiator instantiateExplicitConnectionProvider INFO: HHH000130: Instantiating explicit connection provider: org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider Apr 05, 2015 10:57:30 PM com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource getPoolManager INFO: Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [ acquireIncrement -> 1, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, dataSourceName -> z8kfsx98137ghpr10fde73|6aa74262, debugUnreturnedConnectionStackTraces -> false, description -> null, driverClass -> com.mysql.jdbc.Driver, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> z8kfsx98137ghpr10fde73|6aa74262, idleConnectionTestPeriod -> 3000, initialPoolSize -> 3, jdbcUrl -> jdbc:mysql://localhost:3306/infographyl_db, lastAcquisitionFailureDefaultUser -> null, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 0, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 20, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 5, numHelperThreads -> 3, numThreadsAwaitingCheckoutDefaultUser -> 0, preferredTestQuery -> null, properties -> {user=******, password=******}, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false ]


Solution

  • So, from everything that you've described, it sounds like your application is creating and then abandoning multiple c3p0 pools. You don't experience what would be the usual symptom of exhaustion of a single pool (application freezes). Instead, your app opens more Connections than maxPoolSize, and then fails when it hits server-side Connection limits. Unless your server things ~20 Connections is too many, you are likely to be creating more than one pool. Setting wait_timeout hides the problem, as the Connections of the abandonned DataSources get automatically close()ed, but it won't be a good solution. If you are making new DataSources for each client, you'll dramatically slow down rather than speed up your app, and if those DataSources are not close()ed (it seems they aren't, or you'd not accumulate open Connections), you'll create Thread and memory leaks.

    So.

    First, how are you logging things? Please make sure that com.mchange.* classes are logged at INFO, and check look for pool initiation messages. c3p0 dumps a large pool config message at INFO on DataSource initialization. Make sure you see at least one of those messages. Do you see them many times? Then that is the problem.

    If I am right and you are opening then abandoning multiple c3p0 DataSources, the next question becomes why. Pooled DataSources in your app are embedded in an EntityManagerFactory object, of which there should be just one for the lifetime of your application. Spring makes things look easy, but it hides the details of how/when things are constructed, destroyed, etc. I think the key question you may have to answer is why/whether Spring is creating multiple EntityManagerFactory instances (or recreating the c3p0 DataSource multiple times within a single EntityManagerFactory).

    p.s. c3p0 offers no "loginTimeout" config parameter.