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

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

    Alen Ribic Newbie

      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 Master

          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

          • 2. Re: EJB/CMT, my rollback doesn't seem to be working
            Alen Ribic Newbie


            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
            <!-- Make it deploy ONLY after DataSource had been started -->
            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

            • 3. Re: EJB/CMT, my rollback doesn't seem to be working
              Adrian Brock Master

              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

              • 4. Re: EJB/CMT, my rollback doesn't seem to be working
                Alen Ribic Newbie

                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.