Oracle java.sql.SQLException: Closed Connection

[harry_moore]

We are seeing errors similar to this a few times each day. Initially they looked like they were caused by broken pipe errors but we started using custom connection pool settings last night and now we still see the errors but they are not accompanied by broken pipe errors. Has anyone seen this?

2009-06-26 03:52:17,835 INFO  [STDOUT] 03:52:17,835 DEBUG [hibernate.jdbc.ConnectionManager] opening JDBC connection
2009-06-26 03:52:17,863 INFO  [STDOUT] 03:52:17,863 DEBUG [hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2009-06-26 03:52:17,863 INFO  [STDOUT] 03:52:17,863 DEBUG [hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2009-06-26 03:52:17,875 INFO  [STDOUT] 03:52:17,875 DEBUG [hibernate.jdbc.ConnectionManager] opening JDBC connection
2009-06-26 03:52:17,876 INFO  [STDOUT] 03:52:17,876 ERROR [hibernate.transaction.JDBCTransaction] JDBC rollback failed
java.sql.SQLException: Closed Connection
   at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:112)
   at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:146)
   at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:208)
   at oracle.jdbc.driver.PhysicalConnection.rollback(PhysicalConnection.java:1170)
   at org.apache.commons.dbcp.DelegatingConnection.rollback(DelegatingConnection.java:265)
   at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.rollback(PoolingDataSource.java:288)
   at org.hibernate.transaction.JDBCTransaction.rollbackAndResetAutoCommit(JDBCTransaction.java:183)
   at org.hibernate.transaction.JDBCTransaction.rollback(JDBCTransaction.java:162)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:581)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:745)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:722)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.completeTransactionAfterThrowing(TransactionAspectSupport.java:325)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.rollback(SpringAwareUserTransaction.java:531)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:371)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:217)
   at org.alfresco.repo.avm.OrphanReaper.doBatch(OrphanReaper.java:349)
   at org.alfresco.repo.avm.OrphanReaper.execute(OrphanReaper.java:59)
   at org.alfresco.repo.avm.OrphanReaperJob.execute(OrphanReaperJob.java:44)
   at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
   at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
2009-06-26 03:52:17,876 INFO  [STDOUT] 03:52:17,876 DEBUG [hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2009-06-26 03:52:17,876 INFO  [STDOUT] 03:52:17,876 DEBUG [hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2009-06-26 03:52:17,876 INFO  [STDOUT] 03:52:17,876 DEBUG [hibernate.jdbc.ConnectionManager] performing cleanup
2009-06-26 03:52:17,876 INFO  [STDOUT] 03:52:17,876 DEBUG [hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2009-06-26 03:52:17,876 INFO  [STDOUT] 03:52:17,876 ERROR [util.transaction.SpringAwareUserTransaction] Application exception overridden by rollback exception
java.lang.Exception
   at org.alfresco.util.transaction.SpringAwareUserTransaction.rollback(SpringAwareUserTransaction.java:531)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:371)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:217)
   at org.alfresco.repo.avm.OrphanReaper.doBatch(OrphanReaper.java:349)
   at org.alfresco.repo.avm.OrphanReaper.execute(OrphanReaper.java:59)
   at org.alfresco.repo.avm.OrphanReaperJob.execute(OrphanReaperJob.java:44)
   at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
   at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
2009-06-26 03:52:17,887 INFO  [STDOUT] 03:52:17,878 DEBUG [hibernate.jdbc.ConnectionManager] connection already null in cleanup : no action
2009-06-26 03:52:17,889 INFO  [STDOUT] 03:52:17,887 ERROR [repo.transaction.RetryingTransactionHelper] Rollback failure.  Normal retry behaviour will resume.
org.springframework.orm.hibernate3.HibernateJdbcException: JDBC exception on Hibernate data access; nested exception is org.hibernate.exception.GenericJDBCException: Cannot release connection
Caused by: 
org.hibernate.exception.GenericJDBCException: Cannot release connection
   at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
   at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
   at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
   at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:29)
   at org.hibernate.jdbc.ConnectionManager.closeConnection(ConnectionManager.java:455)
   at org.hibernate.jdbc.ConnectionManager.aggressiveRelease(ConnectionManager.java:406)
   at org.hibernate.jdbc.ConnectionManager.afterTransaction(ConnectionManager.java:293)
   at org.hibernate.jdbc.JDBCContext.afterTransactionCompletion(JDBCContext.java:225)
   at org.hibernate.transaction.JDBCTransaction.rollback(JDBCTransaction.java:174)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:581)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:745)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:722)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.completeTransactionAfterThrowing(TransactionAspectSupport.java:325)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.rollback(SpringAwareUserTransaction.java:531)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:371)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:217)
   at org.alfresco.repo.avm.OrphanReaper.doBatch(OrphanReaper.java:349)
   at org.alfresco.repo.avm.OrphanReaper.execute(OrphanReaper.java:59)
   at org.alfresco.repo.avm.OrphanReaperJob.execute(OrphanReaperJob.java:44)
   at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
   at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
Caused by: java.sql.SQLException: Already closed.
   at org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:77)
   at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:180)
   at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.closeConnection(LocalDataSourceConnectionProvider.java:95)
   at org.hibernate.jdbc.ConnectionManager.closeConnection(ConnectionManager.java:451)
   … 16 more
2009-06-26 03:52:17,995 INFO  [STDOUT] 03:52:17,995 DEBUG [hibernate.jdbc.ConnectionManager] opening JDBC connection
2009-06-26 03:52:18,172 INFO  [STDOUT] 03:52:18,172 DEBUG [hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2009-06-26 03:52:18,173 INFO  [STDOUT] 03:52:18,173 DEBUG [hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2009-06-26 03:52:18,175 INFO  [STDOUT] 03:52:18,175 DEBUG [hibernate.jdbc.ConnectionManager] connection already null in cleanup : no action
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

[dward]

Have you changed the value of hibernate.connection.release_mode?

Are you using a JTA transaction manager?

How is your datasource defined?

[dward]

What custom connection pooling settings are you using?

If you are still using commons dbcp, you should probably set a validation query to ensure your connection is tested before use. E.g.

    <!– Datasource bean –>
    <bean id="defaultDataSource" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
        <property name="driverClassName">
            <value>${db.driver}</value>
        </property>
        <property name="url">
            <value>${db.url}</value>
        </property>
        <property name="username">
            <value>${db.username}</value>
        </property>
        <property name="password">
            <value>${db.password}</value>
        </property>
        <property name="initialSize" >
            <value>${db.pool.initial}</value>
        </property>
        <property name="maxActive" >
            <value>${db.pool.max}</value>
        </property>
        <property name="defaultAutoCommit" >
            <value>false</value>
        </property>
        <property name="defaultTransactionIsolation" >
            <value>${db.txn.isolation}</value>
        </property>
        <property name="validationQuery" >
            <value>SELECT NULL FROM DUAL</value>
        </property>
    </bean>‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍