BoneCP detected an unclosed connection

[CookieMonster]

Hi,

First off, thank you for a such an awesome library! We switched from C3P0 because we didn't like the way threads would get a connection from a pool based on luck rather than the order they were in.

Anyway, so we were using 0.7.1. Everything was fine until we needed to have the locking bug fix of 0.8.0 (When release of the lock wasn't in a finally block). We switched the library version and all of a sudden out test are failing all over the place. What we are finding is that the connection tracking is classing checked out connections as needing to be closed.

WARN [com.google.common.base.internal.Finalizer] c.jolbox.bonecp.ConnectionPartition - BoneCP detected an unclosed connection and will now attempt to close it for you. You should be closing this connection in your application - enable connectionWatch for additional debugging assistance.

(n.b. I have tried enabling the connectionWatch but I don't see anything extra being logged except for the 'this is a debug only setting' message)

This then leads to the transaction failing because the connection has been closed. What is interesting it takes a while for it to happen,
this varies depending on the amount of the Threads we have in the test. But it will always happen a set amount of usages.

We are using Spring 3.0.6 and using the @Transactional transaction demarcation.

The other interesting thing that occurs is we use the following

Code: Select all

SimpleJdbcTestUtils.executeSqlScript(new SimpleJdbcTemplate(ourTemplate), new ClassPathResource("ourSetupSQL.sql"), false);

(n.b. We have 2 datasources to different to DB's.)

at the the start of our test and when the connection tracking kicks in and warns about unclosed connections it also says that there is an unclosed connection associated with the datasource used with the SimpleJdbcTestUtil. How can this be I stepped through the code and saw it close it.

After looking through the config I see it is noted that if we were using Spring to managed our connections, which I believe is what we are doing with the Spring TX'ing, then we can turn off the tracking. But what concerns me is the change between the 2 versions of BoneCP that would suddenly cause us to have this issue. Is 0.8.0 not really production ready? I note it is alpha in the name, if it isn't I may just back port the change that we want for the locking to 0.7.1-RELEASE.

Any thoughts would be much appreciated

James

[sony3002]

I am also getting the same warning

Code: Select all

1098 [main] DEBUG com.jolbox.bonecp.BoneCPDataSource - JDBC URL = jdbc:mysql://localhost:3306/mydbapp?zeroDateTimeBehavior=convertToNull&useUnicode=true&characterEncoding=utf8, Username = root, partitions = 3, max (per partition) = 10, min (per partition) = 5, helper threads = 3, idle max age = 20 min, idle test period = 10 min, strategy = DEFAULT
1283 [main] WARN  com.jolbox.bonecp.BoneCP - Thread close connection monitoring has been enabled. This will negatively impact on your performance. Only enable this option for debugging purposes!
2093 [com.google.common.base.internal.Finalizer] WARN  c.jolbox.bonecp.ConnectionPartition - BoneCP detected an unclosed connection and will now attempt to close it for you. You should be closing this connection in your application - enable connectionWatch for additional debugging assistance.
2730 [com.google.common.base.internal.Finalizer] WARN  c.jolbox.bonecp.ConnectionPartition - BoneCP detected an unclosed connection and will now attempt to close it for you. You should be closing this connection in your application - enable connectionWatch for additional debugging assistance.
3808 [com.google.common.base.internal.Finalizer] WARN  c.jolbox.bonecp.ConnectionPartition - BoneCP detected an unclosed connection and will now attempt to close it for you. You should be closing this connection in your application - enable connectionWatch for additional debugging assistance.
4418 [main] DEBUG c.j.bonecp.PreparedStatementHandle - insert into store (created_by, created_on, store_admin_email, store_deleted, store_desc, store_enabled, store_name, parent_store_id, store_under_maint, store_url) values (6, 2012-09-27 12:57:44.588, 'admin@adm.com', false, 'This is a nre store from service test', true, 'New Store1', '[SQL NULL of type -5]', false, 'www.newstore1.com')


only one insert statement is performed, this is a simple test
I am using 0.8.0-alpha1 with spring + JPA + hibernate
here is the spring config file for datasource,

Code: Select all

    <!-- Spring bean configuration. Tell Spring to bounce off BoneCP -->
    <bean id="dataSource" class="org.springframework.jdbc.datasource.LazyConnectionDataSourceProxy">
        <property name="targetDataSource">
            <ref local="mainDataSource" />
        </property>
    </bean>

    <!-- BoneCP configuration -->
    <bean id="mainDataSource" class="com.jolbox.bonecp.BoneCPDataSource" destroy-method="close">
        <property name="driverClass" value="${database.driver}" />
        <property name="jdbcUrl" value="${database.url}" />
        <property name="username" value="${database.user}"/>
        <property name="password" value="${database.password}"/>
        <property name="idleConnectionTestPeriodInMinutes" value="${database.pool.idleConnectionTestPeriodInMinutes}"/>
        <property name="idleMaxAgeInMinutes" value="${database.pool.idleMaxAgeInMinutes}"/>
        <property name="maxConnectionsPerPartition" value="${database.pool.maxConnectionsPerPartition}"/>
        <property name="minConnectionsPerPartition" value="${database.pool.minConnectionsPerPartition}"/>
        <property name="partitionCount" value="${database.pool.partitionCount}"/>
        <property name="acquireIncrement" value="${database.pool.acquireIncrement}"/>
        <property name="statementsCacheSize" value="${database.pool.statementsCacheSize}"/>
        <property name="releaseHelperThreads" value="${database.pool.releaseHelperThreads}"/>
        <property name="logStatementsEnabled" value="${database.pool.logStatementsEnabled}"/><!-- for debug purpose only ! disable this later -->
        <property name="closeConnectionWatch" value="${database.pool.connectionWatch}"/><!-- for debug purpose only ! disable this later -->
    </bean>


and in my java code i just use this style

Code: Select all

@PersistenceContext
protected EntityManager entityManager;

public void createStore(Store store)(){
entityManager.persist(store);
}


no connection closing or any other, all are managed by spring

and then i get this warning

Code: Select all

1098 [main] DEBUG com.jolbox.bonecp.BoneCPDataSource - JDBC URL = jdbc:mysql://localhost:3306/sophiabooksdbapp?zeroDateTimeBehavior=convertToNull&useUnicode=true&characterEncoding=utf8, Username = root, partitions = 3, max (per partition) = 10, min (per partition) = 5, helper threads = 3, idle max age = 20 min, idle test period = 10 min, strategy = DEFAULT
1283 [main] WARN  com.jolbox.bonecp.BoneCP - Thread close connection monitoring has been enabled. This will negatively impact on your performance. Only enable this option for debugging purposes!
2093 [com.google.common.base.internal.Finalizer] WARN  c.jolbox.bonecp.ConnectionPartition - BoneCP detected an unclosed connection and will now attempt to close it for you. You should be closing this connection in your application - enable connectionWatch for additional debugging assistance.
2730 [com.google.common.base.internal.Finalizer] WARN  c.jolbox.bonecp.ConnectionPartition - BoneCP detected an unclosed connection and will now attempt to close it for you. You should be closing this connection in your application - enable connectionWatch for additional debugging assistance.
3808 [com.google.common.base.internal.Finalizer] WARN  c.jolbox.bonecp.ConnectionPartition - BoneCP detected an unclosed connection and will now attempt to close it for you. You should be closing this connection in your application - enable connectionWatch for additional debugging assistance.
4418 [main] DEBUG c.j.bonecp.PreparedStatementHandle - insert into store (created_by, created_on, store_admin_email, store_deleted, store_desc, store_enabled, store_name, parent_store_id, store_under_maint, store_url) values (6, 2012-09-27 12:57:44.588, 'admin@adm.com', false, 'This is a nre store from service test', true, 'New Store1', '[SQL NULL of type -5]', false, 'www.newstore1.com')


please help, is this a small bug that can be ignored ??? or is this a critical problem in my configuration ????

[wwadge]

If your connections are managed via spring, you can safely disable connection tracking for even more speed.

That was a bug in the 0.8.x branch that has hopefully been fixed. (A lot has changed in 0.8, chief of which is that the connection handle wrapper you return to the pool is destroyed, this triggered the bug)