Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Critical Critical
    • Resolution: Fixed
    • Affects Version/s: 1.3
    • Fix Version/s: 1.5.1, 2.0
    • Labels:
      None

      Description

      Under high load commons-dbcp (or commons-pool) exhibits thread safety issues and begins throwing various exceptions. I don't yet know the cause of the issue but it looks like a connection maybe handed out to multiple threads concurrently. Here's a few examples of the exceptions we are getting:

      jvm 1    | Caused by: java.sql.SQLException: Attempted to use PooledConnection after closed() was called.
      jvm 1    |      at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.assertOpen(PooledConnectionImpl.java:163)
      jvm 1    |      at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:174)
      jvm 1    |      at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768)
      jvm 1    |      at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676)
      jvm 1    |      at uk.co.webessence.kernel.database.DriverAdapterConnectionPool.acquireConnection(DriverAdapterConnectionPool.java:101)
      jvm 1    |      ... 94 more
      
      jvm 1    | Caused by: java.sql.SQLException: PooledConnection was reused, withoutits previous Connection being closed.
      jvm 1    |      at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:179)
      jvm 1    |      at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768)
      jvm 1    |      at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676)
      jvm 1    |      at uk.co.webessence.kernel.database.DriverAdapterConnectionPool.acquireConnection(DriverAdapterConnectionPool.java:101)
      jvm 1    |      ... 77 more
      
      jvm 1    | Caused by: java.sql.SQLException: Invalid state, the ResultSet object is closed.
      jvm 1    |      at net.sourceforge.jtds.jdbc.JtdsResultSet.checkOpen(JtdsResultSet.java:299)
      jvm 1    |      at net.sourceforge.jtds.jdbc.JtdsResultSet.getColumn(JtdsResultSet.java:273)
      jvm 1    |      at net.sourceforge.jtds.jdbc.JtdsResultSet.getObject(JtdsResultSet.java:840)
      jvm 1    |      at org.apache.commons.dbcp.DelegatingResultSet.getObject(DelegatingResultSet.java:325)
      jvm 1    |      at uk.co.webessence.kernel.persistence.Preloader.getDataArray(Preloader.java:428)
      jvm 1    |      at uk.co.webessence.kernel.persistence.Preloader.processSingleRow(Preloader.java:175)
      jvm 1    |      at uk.co.webessence.kernel.persistence.PersistenceHandler.processRecordReload(PersistenceHandler.java:471)
      jvm 1    |      at uk.co.webessence.kernel.persistence.PersistenceHandler$1.doLoad(PersistenceHandler.java:447)
      jvm 1    |      ... 71 more
      
      Message:   TDS Protocol error: Invalid packet type 0x4
      jvm 1    | Caused by: java.sql.SQLException: TDS Protocol error: Invalid packet type 0x4
      jvm 1    |      at net.sourceforge.jtds.jdbc.TdsCore.nextToken(TdsCore.java:2314)
      jvm 1    |      at net.sourceforge.jtds.jdbc.TdsCore.getNextRow(TdsCore.java:764)
      jvm 1    |      at net.sourceforge.jtds.jdbc.JtdsResultSet.next(JtdsResultSet.java:593)
      jvm 1    |      at org.apache.commons.dbcp.DelegatingResultSet.next(DelegatingResultSet.java:207)
      jvm 1    |      at uk.co.webessence.kernel.persistence.Preloader.loadData(Preloader.java:142)
      jvm 1    |      at uk.co.webessence.kernel.persistence.PersistenceHandler$3.doLoad(PersistenceHandler.java:592)
      jvm 1    |      ... 111 more
      jvm 1    | Caused by: net.sourceforge.jtds.jdbc.ProtocolException: Invalid packet type 0x4
      jvm 1    |      at net.sourceforge.jtds.jdbc.TdsCore.nextToken(TdsCore.java:2301)
      jvm 1    |      ... 116 more
      
      1. dbcp_bug.tar.gz
        3 kB
        Dave Oxley
      2. DBCP-376.diff
        3 kB
        Dave Oxley

        Activity

        Dave Oxley created issue -
        Dave Oxley made changes -
        Field Original Value New Value
        Description Under high load commons-dbcp (or commons-pool) exhibits thread safety issues and begins throwing various exceptions. I don't yet know the cause of the issue but it looks like a connection maybe handed out to multiple threads concurrently. Here's a few examples of the exceptions we are getting:

        {jvm 1 | Caused by: java.sql.SQLException: Attempted to use PooledConnection after closed() was called.
        jvm 1 | at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.assertOpen(PooledConnectionImpl.java:163)
        jvm 1 | at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:174)
        jvm 1 | at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768)
        jvm 1 | at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676)
        jvm 1 | at uk.co.webessence.kernel.database.DriverAdapterConnectionPool.acquireConnection(DriverAdapterConnectionPool.java:101)
        jvm 1 | ... 94 more}

        {jvm 1 | Caused by: java.sql.SQLException: PooledConnection was reused, withoutits previous Connection being closed.
        jvm 1 | at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:179)
        jvm 1 | at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768)
        jvm 1 | at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676)
        jvm 1 | at uk.co.webessence.kernel.database.DriverAdapterConnectionPool.acquireConnection(DriverAdapterConnectionPool.java:101)
        jvm 1 | ... 77 more}

        {jvm 1 | Caused by: java.sql.SQLException: Invalid state, the ResultSet object is closed.
        jvm 1 | at net.sourceforge.jtds.jdbc.JtdsResultSet.checkOpen(JtdsResultSet.java:299)
        jvm 1 | at net.sourceforge.jtds.jdbc.JtdsResultSet.getColumn(JtdsResultSet.java:273)
        jvm 1 | at net.sourceforge.jtds.jdbc.JtdsResultSet.getObject(JtdsResultSet.java:840)
        jvm 1 | at org.apache.commons.dbcp.DelegatingResultSet.getObject(DelegatingResultSet.java:325)
        jvm 1 | at uk.co.webessence.kernel.persistence.Preloader.getDataArray(Preloader.java:428)
        jvm 1 | at uk.co.webessence.kernel.persistence.Preloader.processSingleRow(Preloader.java:175)
        jvm 1 | at uk.co.webessence.kernel.persistence.PersistenceHandler.processRecordReload(PersistenceHandler.java:471)
        jvm 1 | at uk.co.webessence.kernel.persistence.PersistenceHandler$1.doLoad(PersistenceHandler.java:447)
        jvm 1 | ... 71 more}

        {Message: TDS Protocol error: Invalid packet type 0x4
        jvm 1 | Caused by: java.sql.SQLException: TDS Protocol error: Invalid packet type 0x4
        jvm 1 | at net.sourceforge.jtds.jdbc.TdsCore.nextToken(TdsCore.java:2314)
        jvm 1 | at net.sourceforge.jtds.jdbc.TdsCore.getNextRow(TdsCore.java:764)
        jvm 1 | at net.sourceforge.jtds.jdbc.JtdsResultSet.next(JtdsResultSet.java:593)
        jvm 1 | at org.apache.commons.dbcp.DelegatingResultSet.next(DelegatingResultSet.java:207)
        jvm 1 | at uk.co.webessence.kernel.persistence.Preloader.loadData(Preloader.java:142)
        jvm 1 | at uk.co.webessence.kernel.persistence.PersistenceHandler$3.doLoad(PersistenceHandler.java:592)
        jvm 1 | ... 111 more
        jvm 1 | Caused by: net.sourceforge.jtds.jdbc.ProtocolException: Invalid packet type 0x4
        jvm 1 | at net.sourceforge.jtds.jdbc.TdsCore.nextToken(TdsCore.java:2301)
        jvm 1 | ... 116 more}
        Under high load commons-dbcp (or commons-pool) exhibits thread safety issues and begins throwing various exceptions. I don't yet know the cause of the issue but it looks like a connection maybe handed out to multiple threads concurrently. Here's a few examples of the exceptions we are getting:

        {noformat}
        jvm 1 | Caused by: java.sql.SQLException: Attempted to use PooledConnection after closed() was called.
        jvm 1 | at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.assertOpen(PooledConnectionImpl.java:163)
        jvm 1 | at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:174)
        jvm 1 | at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768)
        jvm 1 | at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676)
        jvm 1 | at uk.co.webessence.kernel.database.DriverAdapterConnectionPool.acquireConnection(DriverAdapterConnectionPool.java:101)
        jvm 1 | ... 94 more
        {noformat}

        {noformat}
        jvm 1 | Caused by: java.sql.SQLException: PooledConnection was reused, withoutits previous Connection being closed.
        jvm 1 | at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:179)
        jvm 1 | at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768)
        jvm 1 | at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676)
        jvm 1 | at uk.co.webessence.kernel.database.DriverAdapterConnectionPool.acquireConnection(DriverAdapterConnectionPool.java:101)
        jvm 1 | ... 77 more
        {noformat}

        {noformat}
        jvm 1 | Caused by: java.sql.SQLException: Invalid state, the ResultSet object is closed.
        jvm 1 | at net.sourceforge.jtds.jdbc.JtdsResultSet.checkOpen(JtdsResultSet.java:299)
        jvm 1 | at net.sourceforge.jtds.jdbc.JtdsResultSet.getColumn(JtdsResultSet.java:273)
        jvm 1 | at net.sourceforge.jtds.jdbc.JtdsResultSet.getObject(JtdsResultSet.java:840)
        jvm 1 | at org.apache.commons.dbcp.DelegatingResultSet.getObject(DelegatingResultSet.java:325)
        jvm 1 | at uk.co.webessence.kernel.persistence.Preloader.getDataArray(Preloader.java:428)
        jvm 1 | at uk.co.webessence.kernel.persistence.Preloader.processSingleRow(Preloader.java:175)
        jvm 1 | at uk.co.webessence.kernel.persistence.PersistenceHandler.processRecordReload(PersistenceHandler.java:471)
        jvm 1 | at uk.co.webessence.kernel.persistence.PersistenceHandler$1.doLoad(PersistenceHandler.java:447)
        jvm 1 | ... 71 more
        {noformat}

        {noformat}
        Message: TDS Protocol error: Invalid packet type 0x4
        jvm 1 | Caused by: java.sql.SQLException: TDS Protocol error: Invalid packet type 0x4
        jvm 1 | at net.sourceforge.jtds.jdbc.TdsCore.nextToken(TdsCore.java:2314)
        jvm 1 | at net.sourceforge.jtds.jdbc.TdsCore.getNextRow(TdsCore.java:764)
        jvm 1 | at net.sourceforge.jtds.jdbc.JtdsResultSet.next(JtdsResultSet.java:593)
        jvm 1 | at org.apache.commons.dbcp.DelegatingResultSet.next(DelegatingResultSet.java:207)
        jvm 1 | at uk.co.webessence.kernel.persistence.Preloader.loadData(Preloader.java:142)
        jvm 1 | at uk.co.webessence.kernel.persistence.PersistenceHandler$3.doLoad(PersistenceHandler.java:592)
        jvm 1 | ... 111 more
        jvm 1 | Caused by: net.sourceforge.jtds.jdbc.ProtocolException: Invalid packet type 0x4
        jvm 1 | at net.sourceforge.jtds.jdbc.TdsCore.nextToken(TdsCore.java:2301)
        jvm 1 | ... 116 more
        {noformat}
        Hide
        Dave Oxley added a comment -

        A sample application that recreates the issue. I've found that after a few runs it stop reproducing the issue on Linux. Clearing the file cache makes reproduce the issue again:

        sudo sync && echo 3 | sudo tee /proc/sys/vm/drop_caches
        

        Here is an example of output from running the application:

        Loading JDBC driver:
        JDBC driver loaded succesfully
        java.sql.SQLException: Attempted to use PooledConnection after closed() was called.
        	at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.assertOpen(PooledConnectionImpl.java:163)
        	at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:174)
        	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768)
        	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676)
        	at com.daveoxley.dbcpbug.App$TestThread.run(App.java:140)
        	at java.lang.Thread.run(Thread.java:662)
        
        java.sql.SQLException: Attempted to use PooledConnection after closed() was called.
        	at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.assertOpen(PooledConnectionImpl.java:163)
        	at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:174)
        	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768)
        	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676)
        	at com.daveoxley.dbcpbug.App$TestThread.run(App.java:140)
        	at java.lang.Thread.run(Thread.java:662)
        
        Show
        Dave Oxley added a comment - A sample application that recreates the issue. I've found that after a few runs it stop reproducing the issue on Linux. Clearing the file cache makes reproduce the issue again: sudo sync && echo 3 | sudo tee /proc/sys/vm/drop_caches Here is an example of output from running the application: Loading JDBC driver: JDBC driver loaded succesfully java.sql.SQLException: Attempted to use PooledConnection after closed() was called. at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.assertOpen(PooledConnectionImpl.java:163) at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:174) at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768) at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676) at com.daveoxley.dbcpbug.App$TestThread.run(App.java:140) at java.lang.Thread.run(Thread.java:662) java.sql.SQLException: Attempted to use PooledConnection after closed() was called. at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.assertOpen(PooledConnectionImpl.java:163) at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:174) at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768) at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676) at com.daveoxley.dbcpbug.App$TestThread.run(App.java:140) at java.lang.Thread.run(Thread.java:662)
        Dave Oxley made changes -
        Attachment dbcp_bug.tar.gz [ 12511462 ]
        Hide
        Dave Oxley added a comment -

        I've just recreated the same issue with snapshots of dbcp2 and pool2. Here is the output:

        Loading JDBC driver:
        JDBC driver loaded succesfully
        INFO  - checkpointClose start
        INFO  - checkpointClose end
        CLOSING DOWN CONNECTION AS IT COULD NOT BE RETURNED TO THE POOL
        java.sql.SQLException: PooledConnection was reused, withoutits previous Connection being closed.
        	at org.apache.commons.dbcp2.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:184)
        	at org.apache.commons.dbcp2.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:778)
        	at org.apache.commons.dbcp2.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:685)
        	at com.daveoxley.dbcpbug.App$TestThread.run(App.java:143)
        	at java.lang.Thread.run(Thread.java:662)
        
        CLOSING DOWN CONNECTION AS IT COULD NOT BE RETURNED TO THE POOL
        CLOSING DOWN CONNECTION AS IT COULD NOT BE RETURNED TO THE POOL
        java.sql.SQLException: Attempted to use PooledConnection after closed() was called.
        	at org.apache.commons.dbcp2.cpdsadapter.PooledConnectionImpl.assertOpen(PooledConnectionImpl.java:167)
        	at org.apache.commons.dbcp2.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:179)
        	at org.apache.commons.dbcp2.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:778)
        	at org.apache.commons.dbcp2.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:685)
        	at com.daveoxley.dbcpbug.App$TestThread.run(App.java:143)
        	at java.lang.Thread.run(Thread.java:662)
        
        Show
        Dave Oxley added a comment - I've just recreated the same issue with snapshots of dbcp2 and pool2. Here is the output: Loading JDBC driver: JDBC driver loaded succesfully INFO - checkpointClose start INFO - checkpointClose end CLOSING DOWN CONNECTION AS IT COULD NOT BE RETURNED TO THE POOL java.sql.SQLException: PooledConnection was reused, withoutits previous Connection being closed. at org.apache.commons.dbcp2.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:184) at org.apache.commons.dbcp2.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:778) at org.apache.commons.dbcp2.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:685) at com.daveoxley.dbcpbug.App$TestThread.run(App.java:143) at java.lang.Thread.run(Thread.java:662) CLOSING DOWN CONNECTION AS IT COULD NOT BE RETURNED TO THE POOL CLOSING DOWN CONNECTION AS IT COULD NOT BE RETURNED TO THE POOL java.sql.SQLException: Attempted to use PooledConnection after closed() was called. at org.apache.commons.dbcp2.cpdsadapter.PooledConnectionImpl.assertOpen(PooledConnectionImpl.java:167) at org.apache.commons.dbcp2.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:179) at org.apache.commons.dbcp2.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:778) at org.apache.commons.dbcp2.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:685) at com.daveoxley.dbcpbug.App$TestThread.run(App.java:143) at java.lang.Thread.run(Thread.java:662)
        Hide
        Mark Thomas added a comment -

        That the pooling implementation has been completely re-written between 1.x and 2.x yet the problem continues points to a problem in DBCP or the app.

        I'll try and take a look at this when I get some cycles but that might not be for a while. On the plus side, having the test case you provided should make investigating this a lot easier.

        Show
        Mark Thomas added a comment - That the pooling implementation has been completely re-written between 1.x and 2.x yet the problem continues points to a problem in DBCP or the app. I'll try and take a look at this when I get some cycles but that might not be for a while. On the plus side, having the test case you provided should make investigating this a lot easier.
        Hide
        William R. Speirs added a comment -

        For what it's worth, all of the creating of the table and selects calls don't impact the issue. I've stripped down the run method in the thread to the following and still get similar errors (SELECT_LOOPS = 5000):

                public void run() {
                    Connection c = null;
                    try {
                        for (int j=0; j < SELECT_LOOPS; j++) {
                            c = ds.getConnection();
        
                            c.close();
                        }
                    } catch (SQLException sqle) {
                        handleException(sqle);
                    }
                }
        
        Loading JDBC driver:
        JDBC driver loaded succesfully
        Exception in thread "Thread-161" java.lang.IllegalStateException: close() was called on a Connection, but I have no record of the underlying PooledConnection.
        	at org.apache.commons.dbcp.datasources.KeyedCPDSConnectionFactory.connectionClosed(KeyedCPDSConnectionFactory.java:249)
        	at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.notifyListeners(PooledConnectionImpl.java:229)
        	at org.apache.commons.dbcp.cpdsadapter.ConnectionImpl.close(ConnectionImpl.java:78)
        	at com.daveoxley.dbcpbug.App$TestThread.run(App.java:96)
        	at java.lang.Thread.run(Thread.java:662)
        
        Exception in thread "Thread-143" java.lang.IllegalStateException: close() was called on a Connection, but I have no record of the underlying PooledConnection.
        	at org.apache.commons.dbcp.datasources.KeyedCPDSConnectionFactory.connectionClosed(KeyedCPDSConnectionFactory.java:249)
        	at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.notifyListeners(PooledConnectionImpl.java:229)
        	at org.apache.commons.dbcp.cpdsadapter.ConnectionImpl.close(ConnectionImpl.java:78)
        	at com.daveoxley.dbcpbug.App$TestThread.run(App.java:96)
        	at java.lang.Thread.run(Thread.java:662)
        
        java.sql.SQLException: PooledConnection was reused, withoutits previous Connection being closed.
        	at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:179)
        	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768)
        	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676)
        	at com.daveoxley.dbcpbug.App$TestThread.run(App.java:94)
        	at java.lang.Thread.run(Thread.java:662)
        
        java.sql.SQLException: PooledConnection was reused, withoutits previous Connection being closed.
        	at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:179)
        	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768)
        	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676)
        	at com.daveoxley.dbcpbug.App$TestThread.run(App.java:94)
        	at java.lang.Thread.run(Thread.java:662)
        
        java.sql.SQLException: Attempted to use PooledConnection after closed() was called.
        	at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.assertOpen(PooledConnectionImpl.java:163)
        	at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:174)
        	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768)
        	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676)
        	at com.daveoxley.dbcpbug.App$TestThread.run(App.java:94)
        	at java.lang.Thread.run(Thread.java:662)
        
        java.sql.SQLException: PooledConnection was reused, withoutits previous Connection being closed.
        	at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:179)
        	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768)
        	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676)
        	at com.daveoxley.dbcpbug.App$TestThread.run(App.java:94)
        	at java.lang.Thread.run(Thread.java:662)
        
        Show
        William R. Speirs added a comment - For what it's worth, all of the creating of the table and selects calls don't impact the issue. I've stripped down the run method in the thread to the following and still get similar errors (SELECT_LOOPS = 5000): public void run() { Connection c = null ; try { for ( int j=0; j < SELECT_LOOPS; j++) { c = ds.getConnection(); c.close(); } } catch (SQLException sqle) { handleException(sqle); } } Loading JDBC driver: JDBC driver loaded succesfully Exception in thread "Thread-161" java.lang.IllegalStateException: close() was called on a Connection, but I have no record of the underlying PooledConnection. at org.apache.commons.dbcp.datasources.KeyedCPDSConnectionFactory.connectionClosed(KeyedCPDSConnectionFactory.java:249) at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.notifyListeners(PooledConnectionImpl.java:229) at org.apache.commons.dbcp.cpdsadapter.ConnectionImpl.close(ConnectionImpl.java:78) at com.daveoxley.dbcpbug.App$TestThread.run(App.java:96) at java.lang.Thread.run(Thread.java:662) Exception in thread "Thread-143" java.lang.IllegalStateException: close() was called on a Connection, but I have no record of the underlying PooledConnection. at org.apache.commons.dbcp.datasources.KeyedCPDSConnectionFactory.connectionClosed(KeyedCPDSConnectionFactory.java:249) at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.notifyListeners(PooledConnectionImpl.java:229) at org.apache.commons.dbcp.cpdsadapter.ConnectionImpl.close(ConnectionImpl.java:78) at com.daveoxley.dbcpbug.App$TestThread.run(App.java:96) at java.lang.Thread.run(Thread.java:662) java.sql.SQLException: PooledConnection was reused, withoutits previous Connection being closed. at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:179) at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768) at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676) at com.daveoxley.dbcpbug.App$TestThread.run(App.java:94) at java.lang.Thread.run(Thread.java:662) java.sql.SQLException: PooledConnection was reused, withoutits previous Connection being closed. at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:179) at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768) at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676) at com.daveoxley.dbcpbug.App$TestThread.run(App.java:94) at java.lang.Thread.run(Thread.java:662) java.sql.SQLException: Attempted to use PooledConnection after closed() was called. at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.assertOpen(PooledConnectionImpl.java:163) at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:174) at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768) at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676) at com.daveoxley.dbcpbug.App$TestThread.run(App.java:94) at java.lang.Thread.run(Thread.java:662) java.sql.SQLException: PooledConnection was reused, withoutits previous Connection being closed. at org.apache.commons.dbcp.cpdsadapter.PooledConnectionImpl.getConnection(PooledConnectionImpl.java:179) at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:768) at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:676) at com.daveoxley.dbcpbug.App$TestThread.run(App.java:94) at java.lang.Thread.run(Thread.java:662)
        Hide
        Dave Oxley added a comment -

        Attached patch fixes this issue by synchronising validatingMap and pcMap in KeyedCPDSConnectionFactory and CPDSConnectionFactory.

        Show
        Dave Oxley added a comment - Attached patch fixes this issue by synchronising validatingMap and pcMap in KeyedCPDSConnectionFactory and CPDSConnectionFactory.
        Dave Oxley made changes -
        Attachment DBCP-376.diff [ 12513905 ]
        Hide
        Mark Thomas added a comment -

        Thanks for the report and test case. Sorry it has taken so long to fix this.

        A variation of the fix has been applied to trunk for 2.0 and to the 1.5.x branch. Assuming that the next 1.3.x and 1.4.x releases are auto generated from the 1.5.x branch they should pick up the fix too.

        I have also added a unit test, again based on your sample code.

        Show
        Mark Thomas added a comment - Thanks for the report and test case. Sorry it has taken so long to fix this. A variation of the fix has been applied to trunk for 2.0 and to the 1.5.x branch. Assuming that the next 1.3.x and 1.4.x releases are auto generated from the 1.5.x branch they should pick up the fix too. I have also added a unit test, again based on your sample code.
        Mark Thomas made changes -
        Status Open [ 1 ] Resolved [ 5 ]
        Fix Version/s 1.5.1 [ 12325670 ]
        Fix Version/s 2.0 [ 12313721 ]
        Resolution Fixed [ 1 ]
        Phil Steitz made changes -
        Status Resolved [ 5 ] Closed [ 6 ]
        Hide
        Phil Steitz added a comment -

        Should be resolved, but not closed (pending 1.4.1 release)

        Show
        Phil Steitz added a comment - Should be resolved, but not closed (pending 1.4.1 release)
        Phil Steitz made changes -
        Resolution Fixed [ 1 ]
        Status Closed [ 6 ] Reopened [ 4 ]
        Phil Steitz made changes -
        Status Reopened [ 4 ] Resolved [ 5 ]
        Resolution Fixed [ 1 ]
        Transition Time In Source Status Execution Times Last Executer Last Execution Date
        Open Open Resolved Resolved
        738d 13h 40m 1 Mark Thomas 30/Jan/14 14:45
        Resolved Resolved Closed Closed
        389d 12h 38m 1 Phil Steitz 24/Feb/15 03:23
        Closed Closed Reopened Reopened
        21h 3m 1 Phil Steitz 25/Feb/15 00:27
        Reopened Reopened Resolved Resolved
        7s 1 Phil Steitz 25/Feb/15 00:27

          People

          • Assignee:
            Unassigned
            Reporter:
            Dave Oxley
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development