4 Replies Latest reply on Sep 9, 2003 1:29 PM by alen

EJB/CMT, my rollback doesn't seem to be working

alen Sep 8, 2003 12:34 PM

I'm using JBoss 3.2.1 at this stage and am trying to make use of the JBossTX
for handling managed transactions.

Scenario:

I have deployed a Stateless Session Bean (using CMT with */Required) that
has a method named createPerson(...).
This method manipulates a DTO and passes it on to my underlying persistence
manager that stores the person's info into the underlying datastore. My
datastore is a MySQL 3.x DB and I'm using a MySQL Connector/J 3.0.7 Stable
driver.

Session bean code snippet
----------------------------------

public void createPerson(Person p) {
Session s = null;
try {
Context ctx = new InitialContext();
SessionFactory factory =
(SessionFactory) ctx.lookup("java:/hibernate/HibernateFactory");

s = factory.openSession();

s.save(p);
//s.flush();

if (1==1) {
//sessionContext.setRollbackOnly();
throw new Exception("JTS test...");
}
} catch(Exception e) {
e.printStackTrace();
// this throw should automatically perform a rollback
throw new EJBException(
"Transaction failed: " + e.getMessage());
} finally {
if(s!=null) try { s.close(); } catch(Exception e) {}
}
}

Now as you can see above, I throw an Exception that rethrows a system-level
exception named EJBException.
In this case, Container should automatically rollback the running
transaction.
However my database shows that INSERT statement has been committed as it
reflects the inserted change.

Alternatively, I have tried to set the ROLLBACK-ONLY using the session
context's
setRollbackOnly method and then throw an application-level exception.
Unfortunately this didn't work either.

My transaction-service.xml is running with default settings.
And I'm running a service for MySQL datasource using the
local-tx-datasource:

mysql-ds.xml
--------------------

<local-tx-datasource>
<jndi-name>jdbc/ejbPool</jndi-name>
<connection-url>jdbc:mysql://localhost:3306/MyDB</connection-url>
<driver-class>com.mysql.jdbc.Driver</driver-class>
<user-name></user-name>

</local-tx-datasource>

Do I perhaps require to use the XA protocol for some reason?

Any suggestions or ideas that I can try to help me find the solution to my
problem, much appreciated.
Maybe a way in which I can monitor the JBossTX invoking the begins, commits
and rollbacks on my methods?

1. Re: EJB/CMT, my rollback doesn't seem to be working

adrian.brock Sep 8, 2003 7:18 PM (in response to alen)

Just enable TRACE for org.jboss.ejb.plugins (example in log4j.xml)
It should give you information about what TxInterceptorCMT is doing

How do you know hibernate is using a MySQL connection
enlisted in the transaction?

Regards,
Adrian
Actions
2. Re: EJB/CMT, my rollback doesn't seem to be working

alen Sep 9, 2003 3:47 AM (in response to alen)

Thanks Adrian, I have enabled trace on jboss.ejb.plugins and monitor the TxInterceptorCMT.

With regards to

> How do you know hibernate is using a MySQL ?
> connection enlisted in the transaction?

Hibernate has a configuration that gives me the ability to configure the JTA Transaction Fatory and JBoss Transaction Manager lookup + Datasource...

Service I coinfigured looks like this...

jboss.jca:service=RARDeployer
jboss.jca:service=LocalTxCM,name=jdbc/ejbPool

Person.hbm.xml
java:/hibernate/HibernateFactory
java:jdbc/ejbPool
net.sf.hibernate.dialect.MySQLDialect
net.sf.hibernate.transaction.JTATransactionFactory
net.sf.hibernate.transaction.JBossTransactionManagerLookup
true
true
java:/UserTransaction

The above does seem to be working according to the log.
Below is the log writen when I run the client agains the createPerson SSB method.
I'm throwing an exception that when cought rethrows the system-level javax.ejb.EJBException.
AFAIK this should rollback the transaction automatically.
(I have tried setting the setRollbackOnly() and throwing a apllication-level exception but that don't work either)

2003-09-09 11:25:33,713 TRACE [org.jboss.ejb.plugins.LogInterceptor] Start method=create
2003-09-09 11:25:33,728 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] Current transaction in MI is null
2003-09-09 11:25:33,728 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] TX_REQUIRED for create
2003-09-09 11:25:33,728 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] Thread came in with tx null
2003-09-09 11:25:33,728 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] Starting new tx TransactionImpl:XidImpl [FormatId=257, GlobalId=alen//3, BranchQual=]
2003-09-09 11:25:33,869 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] TxInterceptorCMT: In finally
2003-09-09 11:25:33,869 TRACE [org.jboss.ejb.plugins.LogInterceptor] End method=create
2003-09-09 11:25:34,182 TRACE [org.jboss.ejb.plugins.LogInterceptor] Start method=createPerson
2003-09-09 11:25:34,182 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] Current transaction in MI is null
2003-09-09 11:25:34,182 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] TX_REQUIRED for createPerson
2003-09-09 11:25:34,197 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] Thread came in with tx null
2003-09-09 11:25:34,197 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] Starting new tx TransactionImpl:XidImpl [FormatId=257, GlobalId=alen//5, BranchQual=]
2003-09-09 11:25:34,197 TRACE [org.jboss.ejb.plugins.StatelessSessionInstancePool] Get instance org.jboss.ejb.plugins.StatelessSessionInstancePool@ed7d11#0#class com.alen.hibernatest.PersonServiceBean
2003-09-09 11:25:34,744 DEBUG [net.sf.hibernate.impl.SessionFactoryObjectFactory] JNDI lookup: hibernate/HibernateFactory
2003-09-09 11:25:34,744 DEBUG [net.sf.hibernate.impl.SessionFactoryObjectFactory] lookup: uid=40288082nullf785a786null00f7null85a7905bnull0000
2003-09-09 11:25:37,385 DEBUG [net.sf.hibernate.impl.SessionImpl] opened session
2003-09-09 11:25:37,416 DEBUG [net.sf.hibernate.impl.SessionImpl] saving [com.alen.hibernatest.Person#]
2003-09-09 11:25:37,416 DEBUG [net.sf.hibernate.persister.EntityPersister] Inserting entity: com.alen.hibernatest.Person (native id)
2003-09-09 11:25:37,416 DEBUG [net.sf.hibernate.persister.EntityPersister] Version: 1
2003-09-09 11:25:37,416 DEBUG [net.sf.hibernate.impl.BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
2003-09-09 11:25:37,478 DEBUG [net.sf.hibernate.impl.SessionFactoryImpl] prepared statement get: insert into Person (version, identifier, createdBy, createdOn, updatedBy, updatedOn) values (?, ?, ?, ?, ?, ?)
2003-09-09 11:25:37,478 INFO [STDOUT] Hibernate: insert into Person (version, identifier, createdBy, createdOn, updatedBy, updatedOn) values (?, ?, ?, ?, ?, ?)
2003-09-09 11:25:37,713 DEBUG [net.sf.hibernate.impl.SessionFactoryImpl] preparing statement
2003-09-09 11:25:37,916 DEBUG [net.sf.hibernate.persister.EntityPersister] Dehydrating entity: com.alen.hibernatest.Person#null
2003-09-09 11:25:37,916 DEBUG [net.sf.hibernate.type.IntegerType] binding '1' to parameter: 1
2003-09-09 11:25:37,916 DEBUG [net.sf.hibernate.type.StringType] binding '12AC29' to parameter: 2
2003-09-09 11:25:37,916 DEBUG [net.sf.hibernate.type.StringType] binding 'alen' to parameter: 3
2003-09-09 11:25:37,916 DEBUG [net.sf.hibernate.type.TimestampType] binding '09 September 2003 11:25:34' to parameter: 4
2003-09-09 11:25:38,166 DEBUG [net.sf.hibernate.type.StringType] binding 'alen' to parameter: 5
2003-09-09 11:25:38,166 DEBUG [net.sf.hibernate.type.TimestampType] binding '09 September 2003 11:25:34' to parameter: 6
2003-09-09 11:25:38,510 DEBUG [net.sf.hibernate.impl.BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
2003-09-09 11:25:38,510 DEBUG [net.sf.hibernate.impl.SessionFactoryImpl] closing statement
2003-09-09 11:25:38,510 DEBUG [net.sf.hibernate.impl.BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets
2003-09-09 11:25:38,510 DEBUG [net.sf.hibernate.impl.SessionFactoryImpl] prepared statement get: SELECT LAST_INSERT_ID()
2003-09-09 11:25:38,510 INFO [STDOUT] Hibernate: SELECT LAST_INSERT_ID()
2003-09-09 11:25:38,510 DEBUG [net.sf.hibernate.impl.SessionFactoryImpl] preparing statement
2003-09-09 11:25:38,650 DEBUG [net.sf.hibernate.persister.EntityPersister] Natively generated identity: 1
2003-09-09 11:25:38,650 DEBUG [net.sf.hibernate.impl.BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets
2003-09-09 11:25:38,650 DEBUG [net.sf.hibernate.impl.SessionFactoryImpl] closing statement
2003-09-09 11:25:38,650 ERROR [STDERR] java.lang.Exception: JTS test...
2003-09-09 11:25:38,650 ERROR [STDERR] at com.alen.hibernatest.PersonServiceBean.createPerson(Unknown Source)
2003-09-09 11:25:38,650 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2003-09-09 11:25:38,650 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
2003-09-09 11:25:38,650 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
2003-09-09 11:25:38,650 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:324)
2003-09-09 11:25:38,650 ERROR [STDERR] at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:629)
2003-09-09 11:25:38,650 ERROR [STDERR] at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:186)
2003-09-09 11:25:38,650 ERROR [STDERR] at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:72)
2003-09-09 11:25:38,650 ERROR [STDERR] at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
2003-09-09 11:25:38,650 ERROR [STDERR] at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:243)
2003-09-09 11:25:38,650 ERROR [STDERR] at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:104)
2003-09-09 11:25:38,650 ERROR [STDERR] at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:117)
2003-09-09 11:25:38,650 ERROR [STDERR] at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
2003-09-09 11:25:38,650 ERROR [STDERR] at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
2003-09-09 11:25:38,666 ERROR [STDERR] at org.jboss.ejb.StatelessSessionContainer.internalInvoke(StatelessSessionContainer.java:322)
2003-09-09 11:25:38,666 ERROR [STDERR] at org.jboss.ejb.Container.invoke(Container.java:674)
2003-09-09 11:25:38,666 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2003-09-09 11:25:38,666 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
2003-09-09 11:25:38,666 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
2003-09-09 11:25:38,666 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:324)
2003-09-09 11:25:38,666 ERROR [STDERR] at org.jboss.mx.capability.ReflectedMBeanDispatcher.invoke(ReflectedMBeanDispatcher.java:284)
2003-09-09 11:25:38,666 ERROR [STDERR] at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:549)
2003-09-09 11:25:38,666 ERROR [STDERR] at org.jboss.invocation.jrmp.server.JRMPInvoker.invoke(JRMPInvoker.java:359)
2003-09-09 11:25:38,666 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2003-09-09 11:25:38,666 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
2003-09-09 11:25:38,666 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
2003-09-09 11:25:38,666 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:324)
2003-09-09 11:25:38,666 ERROR [STDERR] at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:261)
2003-09-09 11:25:38,666 ERROR [STDERR] at sun.rmi.transport.Transport$1.run(Transport.java:148)
2003-09-09 11:25:38,666 ERROR [STDERR] at java.security.AccessController.doPrivileged(Native Method)
2003-09-09 11:25:38,666 ERROR [STDERR] at sun.rmi.transport.Transport.serviceCall(Transport.java:144)
2003-09-09 11:25:38,666 ERROR [STDERR] at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460)
2003-09-09 11:25:38,666 ERROR [STDERR] at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701)
2003-09-09 11:25:38,666 ERROR [STDERR] at java.lang.Thread.run(Thread.java:536)
2003-09-09 11:25:38,666 DEBUG [net.sf.hibernate.impl.SessionImpl] closing session
2003-09-09 11:25:38,666 DEBUG [net.sf.hibernate.impl.SessionImpl] disconnecting session
2003-09-09 11:25:38,666 DEBUG [net.sf.hibernate.impl.SessionImpl] transaction completion
2003-09-09 11:25:38,682 TRACE [org.jboss.ejb.plugins.StatelessSessionInstancePool] Discard instance:org.jboss.ejb.plugins.StatelessSessionInstancePool@ed7d11#org.jboss.ejb.StatelessSessionEnterpriseContext@dbf04d#TransactionImpl:XidImpl [FormatId=257, GlobalId=alen//5, BranchQual=]#true#class com.alen.hibernatest.PersonServiceBean
2003-09-09 11:25:38,682 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] TxInterceptorCMT: In finally
2003-09-09 11:25:38,728 ERROR [org.jboss.ejb.plugins.LogInterceptor] EJBException:
javax.ejb.EJBException: Transaction failed: JTS test...
at com.alen.hibernatest.PersonServiceBean.createPerson(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:629)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:186)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:72)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:243)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:104)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:117)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
at org.jboss.ejb.StatelessSessionContainer.internalInvoke(StatelessSessionContainer.java:322)
at org.jboss.ejb.Container.invoke(Container.java:674)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at org.jboss.mx.capability.ReflectedMBeanDispatcher.invoke(ReflectedMBeanDispatcher.java:284)
at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:549)
at org.jboss.invocation.jrmp.server.JRMPInvoker.invoke(JRMPInvoker.java:359)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:261)
at sun.rmi.transport.Transport$1.run(Transport.java:148)
at java.security.AccessController.doPrivileged(Native Method)
at sun.rmi.transport.Transport.serviceCall(Transport.java:144)
at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701)
at java.lang.Thread.run(Thread.java:536)
2003-09-09 11:25:38,760 TRACE [org.jboss.ejb.plugins.LogInterceptor] End method=createPerson
Actions
3. Re: EJB/CMT, my rollback doesn't seem to be working

adrian.brock Sep 9, 2003 7:48 AM (in response to alen)

My guess is you have a version of MySQL that doesn't
support transactions or you are using the wrong table type.
http://www.mysql.com/press/release_2002_11.html

Regards,
Adrian
Actions
4. Re: EJB/CMT, my rollback doesn't seem to be working

alen Sep 9, 2003 1:29 PM (in response to alen)

I got the problem resolved.

The issue was around my Database system.
I'm using MySQL 3.23.x and didn't have my transaction support in place.
Once I enabled MySQL for transaction support and modified my tables in my db to correct table types (InnoDB) it all worked.

Good idea was that I ran "BEGIN", "INSERT some data", "ROLLBACK" against my db and got following message which gave me the final clue.

"ERROR 1196: Warning: Some non-transactional changed tables couldn't be rolledack"

So I just ran "ALTER TABLE table_name TYPE = InnoDB;" against my tables and that was it.

My CMT now work as expected.

Thanks Adrian (@jboss.org) for your clues.
Actions

Go to original post