[jboss-user] [Persistence, JBoss/CMP, Hibernate, Database] - Connection with active local transaction being reused?

[brent.atkinson]

I have an MBean that accesses a database using a datasource configured as a local-tx-datasource. The usual client code (which is used by multiple applications) is a stateless session bean, but the MBean uses straight JDBC with autocommit set to false. The code has been running for quite a while in production with no snags, until a connection timeout on a connection causes an SQL statement to fail, and prevents the rollback code from executing. 

Since that happened, I see the following behavior again and again in the logs. It appears that the managed connection is being reused even though it hasn't rolled back, and the connection manager is detecting that and trying to clean it up. The end result is that anything calling getConnection() on that datasource and gets that connection continues to fail with the same error, the connection is not being removed and the rollbacks are not completing. Because the applications are not under heavy load this is effectively causing all client apps to fail as most (all) of the getConnection() calls are returning the offending connection.

I am using JBoss 4.0.5 GA, using a datasource configured as the following:

<datasources>
  | 	<local-tx-datasource>
  | 		<jndi-name>jdbc/AppName</jndi-name>
  | 
  | 		<connection-url>
  | 			jdbc:oracle:thin:@host:1521:DEV
  | 		</connection-url>
  | 		<driver-class>oracle.jdbc.driver.OracleDriver</driver-class>
  | 
  | 		<exception-sorter-class-name>
  | 			org.jboss.resource.adapter.jdbc.vendor.OracleExceptionSorter
  | 		</exception-sorter-class-name>
  | 		<metadata>
  | 			<type-mapping>Oracle9i</type-mapping>
  | 		</metadata>
  | 	</local-tx-datasource>
  | 
  | </datasources>

with client code that does the following:


  | DataSource ds = (DataSource)ctx.lookup("java:jdbc/AppName");
  | Connection c = null;
  | 
  | try {
  |   c = ds.getConnection();
  |   c.setAutoCommit(false);
  | ... do important *stuff*
  |   c.commit();
  | }
  | catch (Throwable t) {
  |   if (c != null) try { c.rollback(); } catch (SQLException sqle) { /* log... */ }
  | }
  | finally {
  |   if (c != null) try { c.close(); } catch (SQLException sqle) { /* log... */ }
  | }

yields:

java.sql.SQLException: Io exception: Connection timed out
  |         at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:125)
  |         at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:162)
  |         at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:274)
  |         at oracle.jdbc.driver.T4CPreparedStatement.execute_for_describe(T4CPreparedStatement.java:432)
  |         at oracle.jdbc.driver.OracleStatement.execute_maybe_describe(OracleStatement.java:896)
  |         at oracle.jdbc.driver.T4CPreparedStatement.execute_maybe_describe(T4CPreparedStatement.java:452)
  |         at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:986)
  |         at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:2888)
  |         at oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:2929)
  |         at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:236)
  | ...

and then when trying to rollback because of the exception...

2007-12-23 07:06:28,532 ERROR [MBeanCode] failed to roll back
  | java.sql.SQLException: Closed Connection
  |         at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:125)
  |         at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:162)
  |         at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:227)
  |         at oracle.jdbc.driver.PhysicalConnection.rollback(PhysicalConnection.java:994)
  |         at org.jboss.resource.adapter.jdbc.BaseWrapperManagedConnection.jdbcRollback(BaseWrapperManagedConnection.java:581)
  |         at org.jboss.resource.adapter.jdbc.WrappedConnection.rollback(WrappedConnection.java:340)
  | ...

After this occurs, I see the JCA connection manager try to cleanup...

2007-12-23 07:06:28,533 DEBUG [org.jboss.resource.connectionmanager.TxConnectionManager] Unfinished local transaction was rolled back.org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener at 172e189[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection at d2c59f handles=0 lastUse=1198410045635 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool at 1ac4e3f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool at 1452dd5 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource at c4153f txSync=null]
  | 

I then see the same managed connection and the same LocalXAResource fail when other requests are given what seems to be the same connection? 

For instance, one of many log messages the appear after that (for 2 days in production at least):

2007-12-23 07:26:28,556 DEBUG [org.jboss.resource.connectionmanager.TxConnectionManager] Unfinished local transaction was rolled back.org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener at 172e189[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection at d2c59f handles=0 lastUse=1198412188545 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool at 1ac4e3f context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool at 1452dd5 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource at c4153f txSync=null]

1.) Why is the connection being reused?
2.) What can I do to prevent this from occurring?

View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4115701#4115701

Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=4115701