4 Replies Latest reply on Jul 29, 2013 9:32 AM by miha.sandor

    On recovery Hornetq hangs and throws: XAException.XAER_RMERR: javax.transaction.xa.XAException

    miha.sandor

      My environment is as follows: jboss 6.1.0 and hornetq standalone server 2.3.0 configured with resource recovery

      While my application is running on jboss if i bring down the hornetq server for a few minutes and then back up i can no longer connect to the messaging server.

      It seems stuck while trying to recover a transaction and keeps throwing the following exception when trying to create a new session:

       

      ARJUNA-16086 TransactionImple.enlistResource setTransactionTimeout on XAResource < formatId=131076, gtrid_length=29, bqual_length=28, tx_uid=0:ffffc0a808d7:126a:51f12cdc:1162, node_name=1, branch_uid=0:ffffc0a808d7:126a:51f12cdc:1169, eis_name=unknown eis name > threw: XAException.XAER_RMERR: javax.transaction.xa.XAException

           at org.hornetq.core.client.impl.ClientSessionImpl.setTransactionTimeout(ClientSessionImpl.java:1696) [:]

           at org.hornetq.ra.HornetQRAXAResource.setTransactionTimeout(HornetQRAXAResource.java:249) [:]

           at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:604) [:6.1.0.Final]

           at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:390) [:6.1.0.Final]

           at org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener$TransactionSynchronization.enlist(TxConnectionManager.java:975) [:6.1.0.Final]

           at org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener.enlist(TxConnectionManager.java:729) [:6.1.0.Final]

           at org.jboss.resource.connectionmanager.TxConnectionManager.managedConnectionReconnected(TxConnectionManager.java:459) [:6.1.0.Final]

           at org.jboss.resource.connectionmanager.BaseConnectionManager2.reconnectManagedConnection(BaseConnectionManager2.java:625) [:6.1.0.Final]

           at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:499) [:6.1.0.Final]

           at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:941) [:6.1.0.Final]

           at org.hornetq.ra.HornetQRASessionFactoryImpl.allocateConnection(HornetQRASessionFactoryImpl.java:832) [:]

           at org.hornetq.ra.HornetQRASessionFactoryImpl.createSession(HornetQRASessionFactoryImpl.java:465) [:]

           at a.b.c.d.addWO(Facade.java:25) [:1.3 (1.131.1.0)]

       

       

      The recovery configuration on jboss side:

       

           <bean name="JTAEnvironmentBean" class="com.arjuna.ats.jta.common.JTAEnvironmentBean">

       

              <annotation>@org.jboss.aop.microcontainer.aspects.jmx.JMX(name="jboss.jta:name=JTAEnvironmentBean", exposedInterface=com.arjuna.ats.jta.common.JTAEnvironmentBeanMBean.class, registerDirectly=true)</annotation>

              <constructor factoryClass="com.arjuna.ats.jta.common.jtaPropertyManager" factoryMethod="getJTAEnvironmentBean"/>

              <property name="lastResourceOptimisationInterface">org.jboss.tm.LastResource</property>

              <property name="transactionManagerClassName">com.arjuna.ats.jbossatx.jta.TransactionManagerDelegate</property>

              <property name="userTransactionClassName">com.arjuna.ats.internal.jta.transaction.arjunacore.UserTransactionImple</property>

              <property name="transactionSynchronizationRegistryClassName">com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionSynchronizationRegistryImple</property> 

              <property name="com.arjuna.ats.jta.jtaTMImplementation" value="com.arjuna.ats.internal.jta.transaction.jts.TransactionManagerImple"/>          

              <property name="com.arjuna.ats.arjuna.recovery.recoveryExtension5" value="com.arjuna.ats.internal.jta.recovery.jts.XARecoveryModule"/>

              <property name="xaResourceRecoveryClassNames" preinstantiate="false">

                    <list elementClass="java.lang.String">

                      <value>org.hornetq.jms.server.recovery.HornetQXAResourceRecovery;org.hornetq.core.remoting.impl.netty.NettyConnectorFactory,guest,guest,host=192.168.8.215,port=5445</value>

                    </list>

                </property>    

       

           <property name="xaRecoveryNodes" preinstantiate="false">

               <list elementClass="java.lang.String">

                   <value>1</value>

               </list>

           </property>

       

           <property name="xaResourceOrphanFilterClassNames" preinstantiate="false">

               <list elementClass="java.lang.String">

                   <value>com.arjuna.ats.internal.jta.recovery.arjunacore.JTATransactionLogXAResourceOrphanFilter</value>

                   <value>com.arjuna.ats.internal.jta.recovery.arjunacore.JTANodeNameXAResourceOrphanFilter</value>

               </list>

           </property>

          </bean>

       

      And the netty acceptor on the standalone hornetq server:

       

       

          <acceptors>

            <acceptor name="netty">

               <factory-class>org.hornetq.core.remoting.impl.netty.NettyAcceptorFactory</factory-class>

               <param key="host"  value="${hornetq.remoting.netty.host:localhost}"/>

               <param key="port"  value="${hornetq.remoting.netty.port:5445}"/>

            </acceptor>

           

            <acceptor name="netty-throughput">

               <factory-class>org.hornetq.core.remoting.impl.netty.NettyAcceptorFactory</factory-class>

               <param key="host"  value="${hornetq.remoting.netty.host:localhost}"/>

               <param key="port"  value="${hornetq.remoting.netty.batch.port:5455}"/>

               <param key="batch-delay" value="50"/>

               <param key="direct-deliver" value="false"/>

            </acceptor>

         </acceptors>

       

       

       

      This seems like the basic scenario for recovery and it does not work. Not only does it not recover the lost transaction but reconnecting to the queues is not possible.

       

      I would really appreciate it if you could give me some pointers in how to debug this. Is there something else I need to configure?

      I've looked around a bit and noticed that this exception is related to permissions when dealing with recovery for db sources but found nothing for messaging.

       

      I've also tried a little debugging by myself but I got stuck on this:

       

      From ClientSessionImpl (hornetq-core-client 2.3.0.Final)

       

        public boolean setTransactionTimeout(final int seconds) throws XAException

        {

           checkXA();

           try

           {

              SessionXASetTimeoutResponseMessage response = (SessionXASetTimeoutResponseMessage)channel.sendBlocking(new SessionXASetTimeoutMessage(seconds), PacketImpl.SESS_XA_SET_TIMEOUT_RESP);

              return response.isOK();

           }

           catch (HornetQException e)

           {

             // This should never occur

              throw new XAException(XAException.XAER_RMERR);

           }

        }

       

       

      10x!

        • 1. Re: On recovery Hornetq hangs and throws: XAException.XAER_RMERR: javax.transaction.xa.XAException
          ataylor

          Hornetq 2 3 uses auto recovery, at least with as7, can't remember if it's available in as 6? If it's not you will have to configure it to use HA, reconnect-attempts etc. I'm away on vacation at the moment so don't forgave the exact info to hand

          • 2. Re: On recovery Hornetq hangs and throws: XAException.XAER_RMERR: javax.transaction.xa.XAException
            miha.sandor

            Thanks for your reply.

             

            I do have the recovery settings in my environmet and as I've set the hornetq logging level to TRACE I can see the reconnection attempts.

             

                  <ha>true</ha>

                  <retry-interval>1000</retry-interval>

                  <retry-interval-multiplier>1.0</retry-interval-multiplier>

                  <reconnect-attempts>-1</reconnect-attempts>

             

            Here's a bit from the logs:

             

            Hornetq is down:

             

            2013-07-29 13:15:08,353 DEBUG [org.hornetq.core.client] (Thread-66 (HornetQ-client-global-threads-1960112110)) Trying reconnection attempt 248/-1

            2013-07-29 13:15:08,353 DEBUG [org.hornetq.core.client] (Thread-66 (HornetQ-client-global-threads-1960112110)) Trying to connect with connector = org.hornetq.core.remoting.impl.netty.NettyConnectorFactory@41fdd67f, parameters = {port=5445, host=192.168.8.215} connector = NettyConnector [host=192.168.8.215, port=5445, httpEnabled=false, useServlet=false, servletPath=/messaging/HornetQServlet, sslEnabled=false, useNio=false]

            2013-07-29 13:15:08,353 DEBUG [org.hornetq.core.client] (Thread-66 (HornetQ-client-global-threads-1960112110)) Started Netty Connector version 3.6.2.Final-c0d783c

            2013-07-29 13:15:08,353 DEBUG [org.hornetq.core.client] (Thread-66 (HornetQ-client-global-threads-1960112110)) Trying to connect at the main server using connector :TransportConfiguration(name=5a574f95-f836-11e2-ab59-a929c684d0c1, factory=org-hornetq-core-remoting-impl-netty-NettyConnectorFactory) ?port=5445&host=192-168-8-215

            2013-07-29 13:15:08,353 DEBUG [org.hornetq.core.client] (Thread-66 (HornetQ-client-global-threads-1960112110)) Remote destination: /192.168.8.215:5445

            2013-07-29 13:15:08,353 DEBUG [org.hornetq.core.client] (Thread-79 (HornetQ-client-global-threads-1960112110)) Main server is not up. Hopefully there's a backup configured now!

            2013-07-29 13:15:08,353 DEBUG [org.hornetq.core.client] (Thread-80 (HornetQ-client-global-threads-1960112110)) Trying reconnection attempt 248/-1

            2013-07-29 13:15:08,353 TRACE [org.hornetq.core.client] (Thread-79 (HornetQ-client-global-threads-1960112110)) No Backup configured!: java.lang.Exception: trace

             

             

            Hornetq is starting:

             

            2013-07-29 13:15:24,511 DEBUG [org.hornetq.core.client] (Thread-21 (HornetQ-client-global-threads-1960112110)) ClientSession couldn't be reattached, creating a new session

            2013-07-29 13:15:24,511 TRACE [org.hornetq.core.client] (Old I/O client worker ([id: 0x816751c2, /192.168.8.215:45607 => /192.168.8.215:5445])) handling packet PACKET(Ping)[type=10, channelID=0, packetObject=Ping, connectionTTL=60000]

            2013-07-29 13:15:24,511 TRACE [org.hornetq.core.client] (Old I/O client worker ([id: 0x816751c2, /192.168.8.215:45607 => /192.168.8.215:5445])) handling packet PACKET(CreateSessionResponseMessage)[type=31, channelID=1, packetObject=CreateSessionResponseMessage]

            2013-07-29 13:15:24,484 TRACE [org.hornetq.core.client] (Thread-158 (HornetQ-client-global-threads-1960112110)) Node 778b2aea-f603-11e2-847f-535390526042 going up, connector = Pair[a=null, b=null], isLast=true csf created at

            serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=5adb73d2-f836-11e2-ab59-a929c684d0c1, factory=org-hornetq-core-remoting-impl-netty-NettyConnectorFactory) ?port=5445&host=192-168-8-215], discoveryGroupConfiguration=null]: java.lang.Exception

             

            Hornetq is up:


             

            2013-07-29 13:15:24,509 DEBUG [org.hornetq.core.client] (Thread-93 (HornetQ-client-global-threads-1960112110)) Trying reconnection attempt 256/-1

            2013-07-29 13:15:24,520 DEBUG [org.hornetq.core.client] (Thread-93 (HornetQ-client-global-threads-1960112110)) Trying to connect with connector = org.hornetq.core.remoting.impl.netty.NettyConnectorFactory@3012432a, parameters = {port=5445, host=192.168.8.215} connector = NettyConnector [host=192.168.8.215, port=5445, httpEnabled=false, useServlet=false, servletPath=/messaging/HornetQServlet, sslEnabled=false, useNio=false]

            2013-07-29 13:15:24,520 DEBUG [org.hornetq.core.client] (Thread-93 (HornetQ-client-global-threads-1960112110)) Started Netty Connector version 3.6.2.Final-c0d783c

            2013-07-29 13:15:24,520 DEBUG [org.hornetq.core.client] (Thread-93 (HornetQ-client-global-threads-1960112110)) Trying to connect at the main server using connector :TransportConfiguration(name=5b5585da-f836-11e2-ab59-a929c684d0c1, factory=org-hornetq-core-remoting-impl-netty-NettyConnectorFactory) ?port=5445&host=192-168-8-215

            2013-07-29 13:15:24,521 DEBUG [org.hornetq.core.client] (Thread-93 (HornetQ-client-global-threads-1960112110)) Remote destination: /192.168.8.215:5445

            2013-07-29 13:15:24,521 TRACE [org.hornetq.core.client] (Thread-93 (HornetQ-client-global-threads-1960112110)) Sending packet nonblocking PACKET(Ping)[type=10, channelID=0, packetObject=Ping, connectionTTL=60000] on channeID=0

            2013-07-29 13:15:24,521 TRACE [org.hornetq.core.client] (Thread-93 (HornetQ-client-global-threads-1960112110)) Writing buffer for channelID=0

            2013-07-29 13:15:24,521 TRACE [org.hornetq.core.client] (Thread-93 (HornetQ-client-global-threads-1960112110)) ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=5b5585da-f836-11e2-ab59-a929c684d0c1, factory=org-hornetq-core-remoting-impl-netty-NettyConnectorFactory) ?port=5445&host=192-168-8-215], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=5b5585da-f836-11e2-ab59-a929c684d0c1, factory=org-hornetq-core-remoting-impl-netty-NettyConnectorFactory) ?port=5445&host=192-168-8-215, backupConfig=null]::Subscribing Topology

            2013-07-29 13:15:24,521 TRACE [org.hornetq.core.client] (Thread-93 (HornetQ-client-global-threads-1960112110)) Sending packet nonblocking SubscribeClusterTopologyUpdatesMessage [clusterConnection=false, toString()=PACKET(SubscribeClusterTopologyUpdatesMessageV2)[type=113, channelID=0, packetObject=SubscribeClusterTopologyUpdatesMessageV2]] on channeID=0

            2013-07-29 13:15:24,521 TRACE [org.hornetq.core.client] (Thread-93 (HornetQ-client-global-threads-1960112110)) Writing buffer for channelID=0

            2013-07-29 13:15:24,522 TRACE [org.hornetq.core.client] (Thread-93 (HornetQ-client-global-threads-1960112110)) returning RemotingConnectionImpl [clientID=null, nodeID=null, transportConnection=org.hornetq.core.remoting.impl.netty.NettyConnection@1c479b75[local= /192.168.8.215:45623, remote=/192.168.8.215:5445]]

            2013-07-29 13:15:24,522 DEBUG [org.hornetq.core.client] (Thread-93 (HornetQ-client-global-threads-1960112110)) Reconnection successfull

             

             

            Although the reconnection seems successfull when a new session is created from the client code the exception mentioned in my first post is always thrown.

             

            Any ideas?


            • 3. Re: On recovery Hornetq hangs and throws: XAException.XAER_RMERR: javax.transaction.xa.XAException
              clebert.suconic

              Do you really mean JBoss 6.1? or you meant EAP 6.1?

               

              Because with JBoss 6, we never integrated HornetQ 2.3. The integration bits are slightly different... For instance you're not supposed to setup recovery manually any longer as the RA registers itself.

               

               

              That exception you are showing seems related to the TM failing in some situation... I would need more details...

               

               

              But for now at least confirm the version you're using keeping in mind that EAP != JBoss for what matters for me now.

              • 4. Re: On recovery Hornetq hangs and throws: XAException.XAER_RMERR: javax.transaction.xa.XAException
                miha.sandor

                I'm using JBoss 6.1.0 Final and yes, I've manually upgraded the HornetQ client to version 2.3 and used the standalone HornetQ server version 2.3.