-
Bug
-
Resolution: Done
-
Major
-
fuse-esb-7.1.0
-
None
-
None
-
fuse-esb-7.1.0.fuse-047
Under certain circumstances, if exception happens during transaction commit() (e.g. SQLException), methods throws javax.transaction.RollbackException
with root cause being set as [org.apache.geronimo.transaction.manager.SetRollbackOnlyException: setRollbackOnly() called] while real cause is lost.
Even though real cause can be found in logs, but makes it really difficult for application code that relies on being able to unwrap the RollbackException
to determine its root cause and therefore take appropriate action or report to a user. RollbackException() should refer real exception as a root cause.
I was able to correlate that this weird behaviour happens when exception occurs in transaction synchronization callback Synchronization.beforeCompletion() and Transaction.setRollbackOnly() is called from within beforeCompletion(). Note, call setRollbackOnly() is legitimate.
The good example who works this way is Hibernate. If Hibernate entity manager works in JTA mode, it registers a tranaction synrchonization and attemtps to
flush session before transaction completion, then if flush fails for any reason (e.g. SQLException), it calls setRollbackOnly() causing RollbackException
with obscure root cause is thrown later on.
If however, setRollbackOnly() is not called from beforeCompletion() then RollbackException() is thrown with real root cause.
I was also able to reproduce this behaviour with pure JDBC/JTA APIs, see code fragment below (Note, should be called in tranaction context)
public String sayHello(String name) { final Connection con; final PreparedStatement stm; try { con = getDataSource().getConnection(); stm = con.prepareStatement("insert into table1 values(?)"); // table with one column and PK contraint on it } catch (SQLException ex) { throw new RuntimeException(ex); } try { getTxManager().getTransaction().registerSynchronization(new Synchronization() { public void beforeCompletion() { try { stm.setInt(1, 1); stm.execute(); stm.execute(); // PK violation should be here } catch (SQLException ex) { try { getTxManager().setRollbackOnly(); } catch (Exception ex1) { logger.warn("Cannot setRollbackOnly: " + ex.getMessage()); } throw new RuntimeException(ex); } finally { try { stm.close(); con.close(); } catch (Exception ex) { logger.warn("Cannot close connection and statement: " + ex.getMessage()); } } } public void afterCompletion(int status) { } }); } catch (Exception ex) { throw new RuntimeException(ex); } return new Date().toString(); }
Stacktrace is below:
15:05:54,562 | ERROR | NAPSHOT-thread-1 | Client activator | 263 - com.redhat.osgi-test-client - 0.0.1.SNAPSHOT | Server Error: org.apache.aries.transaction.exception.TransactionRollbackException: javax.transaction.RollbackException: Unable to commit: transaction marked for rollback at org.apache.aries.transaction.TxInterceptorImpl.postCallWithReturn(TxInterceptorImpl.java:91)[119:org.apache.aries.transaction.blueprint:1.0.1.fuse-71-047] at org.apache.aries.blueprint.proxy.Collaborator.postInvoke(Collaborator.java:105)[8:org.apache.aries.blueprint.core:1.0.1.fuse-71-047] at org.apache.aries.proxy.impl.ProxyHandler$1.invoke(ProxyHandler.java:56)[13:org.apache.aries.proxy.impl:1.0.0] at org.apache.aries.proxy.impl.ProxyHandler.invoke(ProxyHandler.java:119)[13:org.apache.aries.proxy.impl:1.0.0] at $Proxy47.sayHello(Unknown Source)[262:com.redhat.osgi-test-server:0.0.1.SNAPSHOT] at org.redhat.osgi.test.client.Activator.start(Activator.java:17)[263:com.redhat.osgi-test-client:0.0.1.SNAPSHOT] ---------- Caused by: javax.transaction.RollbackException: Unable to commit: transaction marked for rollback at org.apache.geronimo.transaction.manager.TransactionImpl.commit(TransactionImpl.java:272) at org.apache.geronimo.transaction.manager.TransactionManagerImpl.commit(TransactionManagerImpl.java:252) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.6.0_38] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)[:1.6.0_38] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)[:1.6.0_38] at java.lang.reflect.Method.invoke(Method.java:597)[:1.6.0_38] at org.apache.aries.proxy.impl.ProxyHandler$1.invoke(ProxyHandler.java:54)[13:org.apache.aries.proxy.impl:1.0.0] at org.apache.aries.proxy.impl.ProxyHandler.invoke(ProxyHandler.java:119)[13:org.apache.aries.proxy.impl:1.0.0] at $Proxy26.commit(Unknown Source)[95:org.apache.geronimo.specs.geronimo-jta_1.1_spec:1.1.1] at org.apache.aries.transaction.TransactionAttribute$4.finish(TransactionAttribute.java:94)[119:org.apache.aries.transaction.blueprint:1.0.1.fuse-71-047] at org.apache.aries.transaction.TxInterceptorImpl.postCallWithReturn(TxInterceptorImpl.java:85)[119:org.apache.aries.transaction.blueprint:1.0.1.fuse-71-047] ... 14 more Caused by: org.apache.geronimo.transaction.manager.SetRollbackOnlyException: setRollbackOnly() called. See stacktrace for origin at org.apache.geronimo.transaction.manager.TransactionImpl.setRollbackOnly(TransactionImpl.java:126) at org.apache.geronimo.transaction.manager.TransactionManagerImpl.setRollbackOnly(TransactionManagerImpl.java:243) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.6.0_38] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)[:1.6.0_38] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)[:1.6.0_38] at java.lang.reflect.Method.invoke(Method.java:597)[:1.6.0_38] at org.apache.aries.proxy.impl.ProxyHandler$1.invoke(ProxyHandler.java:54)[13:org.apache.aries.proxy.impl:1.0.0] at org.apache.aries.proxy.impl.ProxyHandler.invoke(ProxyHandler.java:119)[13:org.apache.aries.proxy.impl:1.0.0] at $Proxy26.setRollbackOnly(Unknown Source)[95:org.apache.geronimo.specs.geronimo-jta_1.1_spec:1.1.1] at org.redhat.osgi.test.server.TestOSGIServiceImpl$1.beforeCompletion(TestOSGIServiceImpl.java:76)[262:com.redhat.osgi-test-server:0.0.1.SNAPSHOT] at org.apache.geronimo.transaction.manager.TransactionImpl.beforeCompletion(TransactionImpl.java:527) at org.apache.geronimo.transaction.manager.TransactionImpl.beforeCompletion(TransactionImpl.java:511) at org.apache.geronimo.transaction.manager.TransactionImpl.beforePrepare(TransactionImpl.java:413) at org.apache.geronimo.transaction.manager.TransactionImpl.commit(TransactionImpl.java:262) at org.apache.geronimo.transaction.manager.TransactionManagerImpl.commit(TransactionManagerImpl.java:252) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.6.0_38] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)[:1.6.0_38] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)[:1.6.0_38] at java.lang.reflect.Method.invoke(Method.java:597)[:1.6.0_38] at org.apache.aries.proxy.impl.ProxyHandler$1.invoke(ProxyHandler.java:54)[13:org.apache.aries.proxy.impl:1.0.0] at org.apache.aries.proxy.impl.ProxyHandler.invoke(ProxyHandler.java:119)[13:org.apache.aries.proxy.impl:1.0.0] at $Proxy26.commit(Unknown Source)[95:org.apache.geronimo.specs.geronimo-jta_1.1_spec:1.1.1] at org.apache.aries.transaction.TransactionAttribute$4.finish(TransactionAttribute.java:94)[119:org.apache.aries.transaction.blueprint:1.0.1.fuse-71-047] at org.apache.aries.transaction.TxInterceptorImpl.postCallWithReturn(TxInterceptorImpl.java:85)[119:org.apache.aries.transaction.blueprint:1.0.1.fuse-71-047] at org.apache.aries.blueprint.proxy.Collaborator.postInvoke(Collaborator.java:105)[8:org.apache.aries.blueprint.core:1.0.1.fuse-71-047] at org.apache.aries.proxy.impl.ProxyHandler$1.invoke(ProxyHandler.java:56)[13:org.apache.aries.proxy.impl:1.0.0] at org.apache.aries.proxy.impl.ProxyHandler.invoke(ProxyHandler.java:119)[13:org.apache.aries.proxy.impl:1.0.0] at $Proxy47.sayHello(Unknown Source)[262:com.redhat.osgi-test-server:0.0.1.SNAPSHOT] at org.redhat.osgi.test.client.Activator.start(Activator.java:17)[263:com.redhat.osgi-test-client:0.0.1.SNAPSHOT] at org.apache.felix.framework.util.SecureAction.startActivator(SecureAction.java:645)[org.apache.felix.framework-4.0.3.fuse-71-047.jar:] at org.apache.felix.framework.Felix.doActivateBundle(Felix.java:2214)[org.apache.felix.framework-4.0.3.fuse-71-047.jar:] at org.apache.felix.framework.Felix$7.call(Felix.java:2152)[org.apache.felix.framework-4.0.3.fuse-71-047.jar:] at org.apache.felix.framework.Felix$6.call(Felix.java:2098)[org.apache.felix.framework-4.0.3.fuse-71-047.jar:] at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)[:1.6.0_38] at java.util.concurrent.FutureTask.run(FutureTask.java:138)[:1.6.0_38] at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)[:1.6.0_38] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)[:1.6.0_38] at java.lang.Thread.run(Thread.java:662)[:1.6.0_38]
