Hey Guys,
I'm having some trouble rolling back a spring transaction once deployed to weblogic 10.3 using a datasource connection pool. My
JUnit test rolls back fine but once deployed it seems like the
JDBC connection is being returned to the datasource before the roll back.
Here is the log info comparisons.
JUnit Log
2012-08-23 15:26:01,071 DEBUG [main] (DataSourceTransactionManager) - Creating new transaction with name [com.yes.delegate.ITxService.handleAcdnt]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2012-08-23 15:26:01,071 DEBUG [main] (DataSourceTransactionManager) - Acquired Connection [jdbc:oracle:thin:@ldap://prod.yes.yes.com:389/TESTDB,cn=OracleContext,dc=yes,dc=yes,dc=com, UserName=USRNM, Oracle JDBC driver] for JDBC transaction
2012-08-23 15:26:01,071 DEBUG [main] (DataSourceTransactionManager) - Switching JDBC Connection [jdbc:oracle:thin:@ldap://prod.yes.yes.com:389/TESTDB,cn=OracleContext,dc=yes,dc=yes,dc=com, UserName=USRNM, Oracle JDBC driver] to manual commit
2012-08-23 15:26:01,071 INFO [main] (TxService) - txHandleAccident
2012-08-23 15:26:01,071 DEBUG [main] (JdbcTemplate) - Executing prepared SQL query
2012-08-23 15:26:01,071 DEBUG [main] (JdbcTemplate) - Executing prepared SQL statement [SELECT tcsg.nextval FROM dual]
2012-08-23 15:26:01,087 DEBUG [main] (JdbcTemplate) - Executing prepared SQL update
2012-08-23 15:26:01,087 DEBUG [main] (JdbcTemplate) - Executing prepared SQL statement [INSERT INTO tc() VALUES()]
2012-08-23 15:26:01,087 DEBUG [main] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 1, parameter value [1234], value class [java.lang.String], SQL type 12
2012-08-23 15:26:01,087 DEBUG [main] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 2, parameter value [1234], value class [java.lang.String], SQL type 12
2012-08-23 15:26:01,087 DEBUG [main] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 3, parameter value [1234.0], value class [java.lang.Double], SQL type 8
2012-08-23 15:26:01,087 DEBUG [main] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 4, parameter value [1234.0], value class [java.lang.Double], SQL type 8
2012-08-23 15:26:01,087 DEBUG [main] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 5, parameter value [rollback test], value class [java.lang.String], SQL type 12
2012-08-23 15:26:01,087 DEBUG [main] (JdbcTemplate) - SQL update affected 1 rows
2012-08-23 15:26:01,087 INFO [main] (TxService) - SUCCESSFULLY INSERT INTO TC
2012-08-23 15:26:01,087 DEBUG [main] (JdbcTemplate) - Executing prepared SQL update
2012-08-23 15:26:01,087 DEBUG [main] (JdbcTemplate) - Executing prepared SQL statement [This statement fails. want to roll back previous insert]
2012-08-23 15:26:01,087 DEBUG [main] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 1, parameter value [1234], value class [java.lang.String], SQL type 12
2012-08-23 15:26:01,087 DEBUG [main] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 2, parameter value [1234.0], value class [java.lang.Double], SQL type 8
2012-08-23 15:26:01,087 DEBUG [main] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 3, parameter value [2012-08-23T15:26:01.024-04:00], value class [org.apache.xmlbeans.XmlCalendar], SQL type 93
2012-08-23 15:26:01,087 DEBUG [main] (JdbcTemplate) - SQL update affected 0 rows
2012-08-23 15:26:01,087 INFO [main] (EIDao) - Error Updating eq. Returned 0 Rows Updated.
2012-08-23 15:26:01,087 ERROR [main] (TxService) - ERROR: Error updating eq
2012-08-23 15:26:01,087 INFO [main] (TxException) - Handling Tx Exception
2012-08-23 15:26:01,087 DEBUG [main] (DataSourceTransactionManager) - Triggering beforeCompletion synchronization
2012-08-23 15:26:01,087 DEBUG [main] (DataSourceTransactionManager) - Initiating transaction rollback
2012-08-23 15:26:01,087 DEBUG [main] (DataSourceTransactionManager) - Rolling back JDBC transaction on Connection [jdbc:oracle:thin:@ldap://prod.yes.yes.com:389/TESTDB,cn=OracleContext,dc=yes,dc=yes,dc=com, UserName=USRNM, Oracle JDBC driver]
2012-08-23 15:26:01,087 DEBUG [main] (DataSourceTransactionManager) - Triggering afterCompletion synchronization
2012-08-23 15:26:01,087 DEBUG [main] (DataSourceTransactionManager) - Releasing JDBC Connection [jdbc:oracle:thin:@ldap://prod.yes.yes.com:389/TESTDB,cn=OracleContext,dc=yes,dc=yes,dc=com, UserName=USRNM, Oracle JDBC driver] after transaction
2012-08-23 15:26:01,087 DEBUG [main] (DataSourceUtils) - Returning JDBC Connection to DataSource
Server Log
2012-08-24 09:27:36,967 DEBUG [5] (DataSourceTransactionManager) - Creating new transaction with name [com.yes.delegate.ITxService.handleAcdnt]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2012-08-24 09:27:36,968 DEBUG [5] (DataSourceTransactionManager) - Acquired Connection [weblogic.jdbc.wrapper.PoolConnection_oracle_jdbc_driver_T4CConnection@a085] for JDBC transaction
2012-08-24 09:27:36,971 DEBUG [5] (DataSourceTransactionManager) - Switching JDBC Connection [weblogic.jdbc.wrapper.PoolConnection_oracle_jdbc_driver_T4CConnection@a085] to manual commit
2012-08-24 09:27:36,976 INFO [5] (TxService) - txHandleAccident
2012-08-24 09:27:36,977 DEBUG [5] (JdbcTemplate) - Executing prepared SQL query
2012-08-24 09:27:36,977 DEBUG [5] (JdbcTemplate) - Executing prepared SQL statement [SELECT tcsg.nextval FROM dual]
2012-08-24 09:27:36,977 DEBUG [5] (DataSourceUtils) - Fetching JDBC Connection from DataSource
2012-08-24 09:27:36,977 DEBUG [5] (DataSourceUtils) - Registering transaction synchronization for JDBC Connection
2012-08-24 09:27:36,979 DEBUG [5] (JdbcTemplate) - Executing prepared SQL update
2012-08-24 09:27:36,979 DEBUG [5] (JdbcTemplate) - Executing prepared SQL statement [INSERT INTO tc(qry)]
2012-08-24 09:27:36,980 DEBUG [5] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 1, parameter value [1234], value class [java.lang.String], SQL type 12
2012-08-24 09:27:36,980 DEBUG [5] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 2, parameter value [1234], value class [java.lang.String], SQL type 12
2012-08-24 09:27:36,980 DEBUG [5] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 3, parameter value [1234.0], value class [java.lang.Double], SQL type 8
2012-08-24 09:27:36,980 DEBUG [5] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 4, parameter value [1234.0], value class [java.lang.Double], SQL type 8
2012-08-24 09:27:36,980 DEBUG [5] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 5, parameter value [Test
String Rollback], value class [java.lang.String], SQL type 12
2012-08-24 09:27:36,981 DEBUG [5] (JdbcTemplate) - SQL update affected 1 rows
2012-08-24 09:27:36,981 INFO [5] (TxService) - SUCCESSFULLY INSERT INTO TC
2012-08-24 09:27:36,982 DEBUG [5] (JdbcTemplate) - Executing prepared SQL update
2012-08-24 09:27:36,982 DEBUG [5] (JdbcTemplate) - Executing prepared SQL statement [This statement fails. want to roll back previous insert]
2012-08-24 09:27:36,982 DEBUG [5] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 1, parameter value [1234], value class [java.lang.String], SQL type 12
2012-08-24 09:27:36,982 DEBUG [5] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 2, parameter value [1234.0], value class [java.lang.Double], SQL type 8
2012-08-24 09:27:36,983 DEBUG [5] (StatementCreatorUtils) - Setting SQL statement parameter value: column index 3, parameter value [2012-08-24T09:05:41.000-04:00], value class [org.apache.xmlbeans.XmlCalendar], SQL type 93
2012-08-24 09:27:36,986 DEBUG [5] (JdbcTemplate) - SQL update affected 0 rows
2012-08-24 09:27:36,986 INFO [5] (EIDao) - Error Updating eq. Returned 0 Rows Updated.
2012-08-24 09:27:36,987 ERROR [5] (TxService) - ERROR: Error updating eq
2012-08-24 09:27:36,988 INFO [5] (TxException) - Handling Tx Exception
2012-08-24 09:27:36,991 DEBUG [5] (DataSourceTransactionManager) - Triggering beforeCompletion synchronization
2012-08-24 09:27:36,993 DEBUG [5] (DataSourceUtils) - Returning JDBC Connection to DataSource
2012-08-24 09:27:36,993 DEBUG [5] (DataSourceTransactionManager) - Initiating transaction rollback
2012-08-24 09:27:36,993 DEBUG [5] (DataSourceTransactionManager) - Rolling back JDBC transaction on Connection [weblogic.jdbc.wrapper.PoolConnection_oracle_jdbc_driver_T4CConnection@a085]
2012-08-24 09:27:36,994 DEBUG [5] (DataSourceTransactionManager) - Triggering afterCompletion synchronization
2012-08-24 09:27:36,996 DEBUG [5] (DataSourceTransactionManager) - Releasing JDBC Connection [weblogic.jdbc.wrapper.PoolConnection_oracle_jdbc_driver_T4CConnection@a085] after transaction
2012-08-24 09:27:36,996 DEBUG [5] (DataSourceUtils) - Returning JDBC Connection to DataSource
My JUnit test does not call directly into the TX Service I call a standard Service Layer that calls the TX Service. The weblogic deployed layer is a standard Spring web service follows the flow endpoint --> service layer --> Tx Service.
Here is my @Transaction annotated method
Here is my configuration
Let me know if more info is needed. Thanks