0 Replies Latest reply on Oct 7, 2011 2:08 PM by azinemanas

    JBoss 6.1 - Deadlock with Transaction propagation over JRMP and Hibernate

    azinemanas

      I have two remote EJBs using transaction propagation over JRMP.

       

      The first EJB is very simple and only invokes the second EJB using jndi:

       

       

      {code}

      @Stateless

      public class MultiOutEJB implements IMultiOutEJB {

       

           public void testOut() {

       

                IMultiInEJB remoteEJB = getRemoteEJB();

                remoteEJB.testIn();

       

                ...

           }

       

      }

      {code}

       

      In the second EJB I use JPA (Hibernate) to update a database:

       

      {code}

      @Stateless

      public class MultiInEJB implements IMultiInEJB {

       

           @PersistenceContext

           private EntityManager em;

       

           public void testIn() {

                Parameter p1 = getParameterById(paramId);

                p1.setValue("ABC");

       

                em.flush();

                em.close();

       

                Parameter p2 = getParameterById(paramId);

                p2.setValue("123");

           }

      }

      {code}

       

      The problem is that the modification of p2 (which is made by Hibernate behind the scene because there is not a explicit flush) apparently is made in a new transaction. Given that the original transaction is not commited the two updates caused a deadlock at the database level.

       

      The stacktrace is:

       


      {code}

      23:03:01,636 WARN  [org.hibernate.util.JDBCExceptionReporter] SQL Error: 1205, SQLState: 41000

      23:03:01,637 ERROR [org.hibernate.util.JDBCExceptionReporter] Lock wait timeout exceeded; try restarting transaction

      23:03:01,640 ERROR [org.hibernate.ejb.AbstractEntityManagerImpl] Unable to mark for rollback on PersistenceException: : java.lang.IllegalStateException: ARJUNA-24035 No such transaction!

          at com.arjuna.ats.internal.jta.transaction.jts.BaseTransaction.setRollbackOnly(BaseTransaction.java:183) [:6.1.0.Final]

          at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.setRollbackOnly(BaseTransactionManagerDelegate.java:123) [:6.1.0.Final]

          at org.hibernate.ejb.AbstractEntityManagerImpl.markAsRollback(AbstractEntityManagerImpl.java:964) [:3.6.7.Final]

          at org.hibernate.ejb.AbstractEntityManagerImpl.handlePersistenceException(AbstractEntityManagerImpl.java:1127) [:3.6.7.Final]

          at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1216) [:3.6.7.Final]

          at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1148) [:3.6.7.Final]

          at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1154) [:3.6.7.Final]

          at org.hibernate.ejb.AbstractEntityManagerImpl$3.mapManagedFlushFailure(AbstractEntityManagerImpl.java:1068) [:3.6.7.Final]

          at org.hibernate.transaction.synchronization.CallbackCoordinator.beforeCompletion(CallbackCoordinator.java:122) [:3.6.7.Final]

          at org.hibernate.transaction.synchronization.HibernateSynchronizationImpl.beforeCompletion(HibernateSynchronizationImpl.java:51) [:3.6.7.Final]

          at com.arjuna.ats.internal.jta.resources.jts.orbspecific.SynchronizationImple.before_completion(SynchronizationImple.java:116) [:6.1.0.Final]

          at com.arjuna.ArjunaOTS.ManagedSynchronizationPOATie.before_completion(ManagedSynchronizationPOATie.java:53) [:6.1.0.Final]

          at com.arjuna.ArjunaOTS.ManagedSynchronizationPOA._invoke(ManagedSynchronizationPOA.java:46) [:6.1.0.Final]

          at org.jacorb.poa.RequestProcessor.invokeOperation(Unknown Source) [:6.1.0.Final]

          at org.jacorb.poa.RequestProcessor.process(Unknown Source) [:6.1.0.Final]

          at org.jacorb.poa.RequestProcessor.run(Unknown Source) [:6.1.0.Final]

      Caused by: java.lang.NullPointerException

          at com.arjuna.ats.internal.jta.transaction.jts.BaseTransaction.setRollbackOnly(BaseTransaction.java:179) [:6.1.0.Final]

          ... 15 more

       

      23:03:01,652 WARN  [com.arjuna.ats.jts] ARJUNA-22024 ArjunaTransactionImple.doBeforeCompletion caught exception: org.omg.CORBA.UNKNOWN: Server-side Exception:   vmcid: 0x0  minor code: 0  completed: No

          at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) [:1.6.0_27]

          at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39) [:1.6.0_27]

          at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27) [:1.6.0_27]

          at java.lang.reflect.Constructor.newInstance(Constructor.java:513) [:1.6.0_27]

          at org.jacorb.orb.SystemExceptionHelper.read(Unknown Source) [:6.1.0.Final]

          at org.jacorb.orb.ReplyReceiver.getReply(Unknown Source) [:6.1.0.Final]

          at org.jacorb.orb.Delegate.invoke_internal(Unknown Source) [:6.1.0.Final]

          at org.jacorb.orb.Delegate.invoke(Unknown Source) [:6.1.0.Final]

          at org.omg.CORBA.portable.ObjectImpl._invoke(ObjectImpl.java:457) [:1.6.0_27]

          at org.omg.CosTransactions._SynchronizationStub.before_completion(_SynchronizationStub.java:33) [:6.1.0.Final]

          at com.arjuna.ats.internal.jts.orbspecific.coordinator.ArjunaTransactionImple.doBeforeCompletion(ArjunaTransactionImple.java:1458) [:6.1.0.Final]

          at com.arjuna.ats.internal.jts.orbspecific.interposition.coordinator.ServerTransaction.doBeforeCompletion(ServerTransaction.java:517) [:6.1.0.Final]

          at com.arjuna.ats.internal.jts.orbspecific.interposition.coordinator.ServerTransaction.doPrepare(ServerTransaction.java:165) [:6.1.0.Final]

          at com.arjuna.ats.internal.jts.orbspecific.interposition.resources.arjuna.ServerTopLevelAction.prepare(ServerTopLevelAction.java:188) [:6.1.0.Final]

          at org.omg.CosTransactions.ResourcePOATie.prepare(ResourcePOATie.java:63) [:6.1.0.Final]

          at org.omg.CosTransactions.ResourcePOA._invoke(ResourcePOA.java:102) [:6.1.0.Final]

          at org.jacorb.poa.RequestProcessor.invokeOperation(Unknown Source) [:6.1.0.Final]

          at org.jacorb.poa.RequestProcessor.process(Unknown Source) [:6.1.0.Final]

          at org.jacorb.poa.RequestProcessor.run(Unknown Source) [:6.1.0.Final]

       

      23:03:01,655 WARN  [com.arjuna.ats.arjuna] ARJUNA-12080 Transaction 0:ffffc0a803a9:12ce:4e8d0bb3:281 marked as rollback only. Will abort.

      23:03:01,708 WARN  [jacorb.poa.controller] rid: 42 opname: rollback cannot process request, because object doesn't exist

      23:03:01,708 WARN  [jacorb.poa.controller] rid: 42 opname: rollback request rejected with exception:

      {code}

       

      Here is the database (MySQL) log:

       

      {code}

      XA START 0x00000000000000000000ffffc0a803a9000012ce4e8d13c00000060c31,0x00000000000000000000ffffc0a803a90000126a4e8d138b00000431,0x20000

      select ... from PARAMETROS parametro0_ where parametro0_.nombre='PARAMETRO_TEST_MULTI' limit 2

      update PARAMETROS set codigoEntidad=null, nombre='PARAMETRO_TEST_MULTI', valor='ABC' where id=120

      select ... from PARAMETROS parametro0_ where parametro0_.nombre='PARAMETRO_TEST_MULTI' limit 2

      XA END 0x00000000000000000000ffffc0a803a9000012ce4e8d13c00000060c31,0x00000000000000000000ffffc0a803a9000012ce4e8d13c000000611,0x20000

      XA PREPARE 0x00000000000000000000ffffc0a803a9000012ce4e8d13c00000060c31,0x00000000000000000000ffffc0a803a9000012ce4e8d13c000000611,0x20000

      update PARAMETROS set codigoEntidad=null, nombre='PARAMETRO_TEST_MULTI', valor='123' where id=120

      {code}

       

      The two updates access the same row. Given that two updates can´t deadlock if are made in the same transaction, thats means the second updateis executed in other transaction.

       

      I don´t now if this is an error of Hibernate or JBossTS, or maybe a configuration error.

       

      My workaround is put a flush in all remote operations.