glassfish
  1. glassfish
  2. GLASSFISH-19373

Unexpected error occurred in transaction rollback

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 4.0_b63
    • Fix Version/s: 4.0_b79
    • Component/s: jts
    • Labels:
      None

      Description

      I have two beans in my jar,first bean creates a jms connection and sends a message using the JMS 1.1 API and calls a method of the second bean (in which a new jms connection is created also),then calls setRollbackOnly and returns.Unexpected error occurred in transaction rollback.
      It works well in GlassFish 3.1.2.

      Steps to reproduce:
      1.unzip glassfish-4.0-b63
      2.startup glassfish server
      asadmin start-domain domain1
      3.create jms resource
      create-jms-resource --restype javax.jms.QueueConnectionFactory jms/jms_unit_test_QCF
      create-jms-resource --restype javax.jms.QueueConnectionFactory jms/jms_unit_test_QCF2
      create-jmsdest --desttype queue jms_unit_test_Queue
      create-jms-resource --restype javax.jms.Queue --property imqDestinationName=jms_unit_test_Queue jms/jms_unit_test_Queue
      4.deploy jms-injection-stateless-ejb.jar(attached).
      asadmin deploy --name application_name application_path

      5.Use standalone client to call my first bean,run and check the server.log of glassfish

      Context ctx = new InitialContext();
      SessionBeanInjectionRemote1 beanRemote = (SessionBeanInjectionRemote1) ctx.lookup(SessionBeanInjectionRemote1.RemoteJNDIName);
      Boolean flag = beanRemote.sendMessage("text");

      [#|2012-11-23T11:15:56.396+0800|SEVERE|44.0|javax.resourceadapter.mqjmsra.outbound.connection|_ThreadID=520;_ThreadName=p: thread-pool-1; w: 6;_TimeMillis=1353640556396;_LevelValue=1000;|rollbackTransaction (XA) on JMSService:jmsdirect failed for connectionId:7085353170766357504:transactionId=0 due to Unknown JMSService server error NOT_FOUND: com.sun.messaging.jmq.jmsserver.util.BrokerException: Unknown XID 503131434E4D452C7365727665722C50333730302C00070000002162EC2A503131434E4D452C7365727665722C5033373030|#]

      [#|2012-11-23T11:15:56.396+0800|WARNING|44.0|javax.enterprise.system.core.transaction.com.sun.jts.jtsxa|_ThreadID=520;_ThreadName=p: thread-pool-1; w: 6;_TimeMillis=1353640556396;_LevelValue=900;_MessageID=jts.unexpected_error_occurred_twopc_rollback;|JTS5068: Unexpected error occurred in rollback
      javax.transaction.xa.XAException
      at com.sun.messaging.jms.ra.DirectXAResource.rollback(DirectXAResource.java:704)
      at com.sun.jts.jta.TransactionState._rollback(TransactionState.java:202)
      at com.sun.jts.jta.TransactionState.rollback(TransactionState.java:188)
      at com.sun.jts.jtsxa.OTSResourceImpl.rollback(OTSResourceImpl.java:333)
      at com.sun.jts.CosTransactions.RegisteredResources.distributeRollback(RegisteredResources.java:1040)
      at com.sun.jts.CosTransactions.TopCoordinator.rollback(TopCoordinator.java:2291)
      at com.sun.jts.CosTransactions.CoordinatorTerm.rollback(CoordinatorTerm.java:530)
      at com.sun.jts.CosTransactions.TerminatorImpl.rollback(TerminatorImpl.java:286)
      at com.sun.jts.CosTransactions.CurrentImpl.rollback(CurrentImpl.java:767)
      at com.sun.jts.jta.TransactionManagerImpl.rollback(TransactionManagerImpl.java:372)
      at com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.rollbackDistributedTransaction(JavaEETransactionManagerJTSDelegate.java:218)
      at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.rollback(JavaEETransactionManagerSimplified.java:862)
      at com.sun.ejb.containers.EJBContainerTransactionManager.completeNewTx(EJBContainerTransactionManager.java:709)
      at com.sun.ejb.containers.EJBContainerTransactionManager.postInvokeTx(EJBContainerTransactionManager.java:503)
      at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4459)
      at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1994)
      at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1964)
      at com.sun.ejb.containers.EJBObjectInvocationHandler.invoke(EJBObjectInvocationHandler.java:212)
      at com.sun.ejb.containers.EJBObjectInvocationHandlerDelegate.invoke(EJBObjectInvocationHandlerDelegate.java:79)
      at $Proxy306.sendMessage(Unknown Source)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:601)
      at com.sun.corba.ee.impl.presentation.rmi.ReflectiveTie.dispatchToMethod(ReflectiveTie.java:143)
      at com.sun.corba.ee.impl.presentation.rmi.ReflectiveTie._invoke(ReflectiveTie.java:173)
      at com.sun.corba.ee.impl.protocol.ServerRequestDispatcherImpl.dispatchToServant(ServerRequestDispatcherImpl.java:528)
      at com.sun.corba.ee.impl.protocol.ServerRequestDispatcherImpl.dispatch(ServerRequestDispatcherImpl.java:199)
      at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.handleRequestRequest(MessageMediatorImpl.java:1596)
      at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.handleRequest(MessageMediatorImpl.java:1458)
      at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.handleInput(MessageMediatorImpl.java:966)
      at com.sun.corba.ee.impl.protocol.giopmsgheaders.RequestMessage_1_2.callback(RequestMessage_1_2.java:214)
      at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.handleRequest(MessageMediatorImpl.java:718)
      at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.dispatch(MessageMediatorImpl.java:515)
      at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.doWork(MessageMediatorImpl.java:2291)
      at com.sun.corba.ee.impl.threadpool.ThreadPoolImpl$WorkerThread.performWork(ThreadPoolImpl.java:497)
      at com.sun.corba.ee.impl.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:540)
      Caused by: com.sun.messaging.jmq.jmsservice.JMSServiceException: rollbackTransaction: rollback transaction failed. Connection ID: 7085353170766357504, Transaction ID: 0, XID: (Available at FINE log level)
      at com.sun.messaging.jmq.jmsserver.service.imq.IMQDirectService.rollbackTransaction(IMQDirectService.java:1847)
      at com.sun.messaging.jms.ra.DirectXAResource.rollback(DirectXAResource.java:673)
      ... 36 more
      Caused by: com.sun.messaging.jmq.jmsserver.util.BrokerException: Unknown XID 503131434E4D452C7365727665722C50333730302C00070000002162EC2A503131434E4D452C7365727665722C5033373030
      at com.sun.messaging.jmq.jmsserver.data.protocol.ProtocolImpl.rollbackTransaction(ProtocolImpl.java:840)
      at com.sun.messaging.jmq.jmsserver.service.imq.IMQDirectService.rollbackTransaction(IMQDirectService.java:1836)
      ... 37 more

      #]

      [#|2012-11-23T11:15:58.660+0800|INFO|44.0|javax.enterprise.system.container.appclient.org.glassfish.appclient.server.core|_ThreadID=74;_ThreadName=admin-listener(1);_TimeMillis=1353640558660;_LevelValue=800;_MessageID=enterprise.deployment.appclient.jws.stopped;|ACDEPL104: Java Web Start services stopped for the app client jms-injection-stateless-ejbApp/jms-injection-stateless-ejb-client.jar|#]

        Activity

        Hide
        Nigel Deakin added a comment - - edited

        In this test, an application uses two XAResource objects in the same JTA transaction. The sequence of calls on XAResource is as follows:

        xar1.start TMNOFLAGS
        xar1.end TMSUSPEND

        xar1.start TMRESUME
        xar1.end TMSUSPEND

        xar2.start TMJOIN
        xar2.end TMSUCCESS

        xar1.start TMRESUME
        xar1.end TMSUCCESS

        Then the application calls setRollbackOnly and returns. The TM then calls

        xar1.rollback
        xar2.rollback

        Since the two resources have been "joined" in the same transaction, the first call to rollback causes both resources to be rolled back. So the second call to rollback fails with "unknown XID".

        It appears to me that the TM should only be calling rollback() once.

        Show
        Nigel Deakin added a comment - - edited In this test, an application uses two XAResource objects in the same JTA transaction. The sequence of calls on XAResource is as follows: xar1.start TMNOFLAGS xar1.end TMSUSPEND xar1.start TMRESUME xar1.end TMSUSPEND xar2.start TMJOIN xar2.end TMSUCCESS xar1.start TMRESUME xar1.end TMSUCCESS Then the application calls setRollbackOnly and returns. The TM then calls xar1.rollback xar2.rollback Since the two resources have been "joined" in the same transaction, the first call to rollback causes both resources to be rolled back. So the second call to rollback fails with "unknown XID". It appears to me that the TM should only be calling rollback() once.
        Hide
        marina vatkina added a comment -

        Do these resource return true on isSameRM()?

        Show
        marina vatkina added a comment - Do these resource return true on isSameRM()?
        Hide
        Nigel Deakin added a comment -

        I can confirm that isSameRM was called and returns true

        FINE: MQJMSRA_DXA1101: DirectXAResource (1620173139) Start   (GlobalTransactionID=[B@23c6743c, BranchQualifier=[B@39f9217d) (Flags: TMNOFLAGS )
        FINE: MQJMSRA_DXA1101: DirectXAResource (1620173139) End     (GlobalTransactionID=[B@23c6743c, BranchQualifier=[B@39f9217d) (Flags: TMNOFLAGS TMSUCCESS )
        
        FINE: MQJMSRA_DXA1101: isSameRM() (613795445) comparing with 1620173139 result=true
        FINE: MQJMSRA_DXA1101: DirectXAResource (613795445) Start   (GlobalTransactionID=[B@23c6743c, BranchQualifier=[B@39f9217d) (Flags: JOIN TMNOFLAGS )
        FINE: MQJMSRA_DXA1101: DirectXAResource (613795445) End     (GlobalTransactionID=[B@23c6743c, BranchQualifier=[B@39f9217d) (Flags: TMNOFLAGS TMSUCCESS )
        
        FINE: MQJMSRA_DXA1101: DirectXAResource (1620173139) Rollback  (GlobalTransactionID=[B@23c6743c, BranchQualifier=[B@39f9217d) )
        
        FINE: MQJMSRA_DXA1101: isSameRM() (613795445) comparing with 1620173139 result=true
        FINE: MQJMSRA_DXA1101: DirectXAResource (613795445) Rollback  (GlobalTransactionID=[B@23c6743c, BranchQualifier=[B@39f9217d) )
        
        Show
        Nigel Deakin added a comment - I can confirm that isSameRM was called and returns true FINE: MQJMSRA_DXA1101: DirectXAResource (1620173139) Start (GlobalTransactionID=[B@23c6743c, BranchQualifier=[B@39f9217d) (Flags: TMNOFLAGS ) FINE: MQJMSRA_DXA1101: DirectXAResource (1620173139) End (GlobalTransactionID=[B@23c6743c, BranchQualifier=[B@39f9217d) (Flags: TMNOFLAGS TMSUCCESS ) FINE: MQJMSRA_DXA1101: isSameRM() (613795445) comparing with 1620173139 result=true FINE: MQJMSRA_DXA1101: DirectXAResource (613795445) Start (GlobalTransactionID=[B@23c6743c, BranchQualifier=[B@39f9217d) (Flags: JOIN TMNOFLAGS ) FINE: MQJMSRA_DXA1101: DirectXAResource (613795445) End (GlobalTransactionID=[B@23c6743c, BranchQualifier=[B@39f9217d) (Flags: TMNOFLAGS TMSUCCESS ) FINE: MQJMSRA_DXA1101: DirectXAResource (1620173139) Rollback (GlobalTransactionID=[B@23c6743c, BranchQualifier=[B@39f9217d) ) FINE: MQJMSRA_DXA1101: isSameRM() (613795445) comparing with 1620173139 result=true FINE: MQJMSRA_DXA1101: DirectXAResource (613795445) Rollback (GlobalTransactionID=[B@23c6743c, BranchQualifier=[B@39f9217d) )
        Hide
        marina vatkina added a comment -

        Fixed with rev 59969 - related resources should get end() call if still active. Non-active isSameRM resources do not need extra processing.

        Show
        marina vatkina added a comment - Fixed with rev 59969 - related resources should get end() call if still active. Non-active isSameRM resources do not need extra processing.

          People

          • Assignee:
            marina vatkina
            Reporter:
            jigang
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: