1 Reply Latest reply on Jun 27, 2013 9:47 AM by ataylor

    Hornetq: Message Persistence takes more time because of timed out and XA Errors with HornetQ2.2.5 Final

    pradeep_h

      Hello HornetQueue Team,

       

      We are working on a messaging project where we are sending and receiving messages using Hornet Queue2.2.5 Final on Jboss6.1.0 Final with JBOSS ESB 4.10 .

       

      We are sending 100messages/sec to the Queue and we have HornetQ Producers to add the messages to the queue.

       

      We are having 10 Queues and 10 Hornet Queue Clients for Sending the Messages and equal no of consumers to read the messages.

       

      And the  Code for Hornet Queue Client is

      //Using InVMConnectorFactory as both HornetQServer and client runs on same VM

      transportConfiguration = new TransportConfiguration(InVMConnectorFactory.class.getName());

              serverLocator = HornetQClient.createServerLocatorWithoutHA(transportConfiguration);

              // Set properties     

              serverLocator.setAckBatchSize( 1024);

              serverLocator.setBlockOnDurableSend( false);

              serverLocator.setBlockOnNonDurableSend( false);

              serverLocator.setCallTimeout( 300000);

              serverLocator.setMinLargeMessageSize( 1048576);

              serverLocator.setConsumerWindowSize(-1);

              serverLocator.setConfirmationWindowSize( 1048576);

              serverLocator.setUseGlobalPools( false);

              serverLocator.setRetryInterval( 2000);

              serverLocator.setReconnectAttempts( -1);

              serverLocator.setProducerWindowSize( 1048576);

              //

              clientSessionFactory = serverLocator.createSessionFactory();

              clientSession = clientSessionFactory.createSession(!transacted,!transacted, !transacted);

              LOG.info("HornetQ client initiated succesfully for " + queueName);

       

      Using above client properties and session we are sending the messages

       

      Problem definition:Time taken for persisitng message to the queue is taking more than 1 sec and this is happening frequently.

       

      When we run for long time of about 8 to 10 hours we see that more time is taken for message persistence to the queue and some times it goes around 10-20 sec.

       

      And our observation is that, this could be because of exceptions and warnings from HornetQ . 

       

      013-06-20 16:00:00,408 WARN  [org.hornetq.core.protocol.core.impl.RemotingConnectionImpl] (hornetq-failure-check-thread) Connection failure has been detected: Did not receive data from invm:0. It is likely the client has exited or crashed without closing its connection, or the network between the server and client has failed. You also might have configured connection-ttl and client-failure-check-period incorrectly. Please check user manual for more information. The connection will now be closed. [code=3]

      2013-06-20 16:00:00,409 WARN  [org.hornetq.core.server.impl.ServerSessionImpl] (hornetq-failure-check-thread) Client connection failed, clearing up resources for session dca1cca4-d992-11e2-b3fc-000c295a1177

       

      Infact we tried setting large value to the connection-ttl and client-failure-check-period with out any use.

       

       

      2013-06-20 16:03:58,878 ERROR [org.hornetq.core.client.impl.ClientSessionImpl] (Thread-70 (group:HornetQ-client-global-threads-958338935)) Caught jmsexecptione : HornetQException[errorCode=3 message=Timed out waiting for response when sending packet 52]

          at org.hornetq.core.protocol.core.impl.ChannelImpl.sendBlocking(ChannelImpl.java:276) [:6.1.0.Final]

          at org.hornetq.core.client.impl.ClientSessionImpl.end(ClientSessionImpl.java:1275) [:6.1.0.Final]

          at org.hornetq.core.client.impl.DelegatingSession.end(DelegatingSession.java:332) [:6.1.0.Final]

          at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:588) [:6.1.0.Final]

          at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2287) [:6.1.0.Final]

          at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1452) [:6.1.0.Final]

          at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:99) [:6.1.0.Final]

          at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:159) [:6.1.0.Final]

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

          at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:119) [:6.1.0.Final]

          at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75) [:6.1.0.Final]

          at org.jboss.soa.esb.listeners.jca.EndpointProxy.endTransaction(EndpointProxy.java:401) [:]

          at org.jboss.soa.esb.listeners.jca.EndpointProxy.finish(EndpointProxy.java:295) [:]

          at org.jboss.soa.esb.listeners.jca.EndpointProxy.after(EndpointProxy.java:219) [:]

          at org.jboss.soa.esb.listeners.jca.EndpointProxy.invoke(EndpointProxy.java:146) [:]

          at $Proxy219.afterDelivery(Unknown Source)    at org.hornetq.ra.inflow.HornetQMessageHandler.onMessage(HornetQMessageHandler.java:287) [:6.1.0.Final]

          at org.hornetq.core.client.impl.ClientConsumerImpl.callOnMessage(ClientConsumerImpl.java:866) [:6.1.0.Final]

          at org.hornetq.core.client.impl.ClientConsumerImpl.access$100(ClientConsumerImpl.java:44) [:6.1.0.Final]

          at org.hornetq.core.client.impl.ClientConsumerImpl$Runner.run(ClientConsumerImpl.java:983) [:6.1.0.Final]

          at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:100) [:6.1.0.Final]

          at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [:1.6.0_23]

          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [:1.6.0_23]

          at java.lang.Thread.run(Thread.java:662) [:1.6.0_23]

       

      2013-06-20 16:03:58,880 WARN  [com.arjuna.ats.jta] (Thread-70 (group:HornetQ-client-global-threads-958338935)) ARJUNA-16039 onePhaseCommit on < formatId=131076, gtrid_length=29, bqual_length=28, tx_uid=0:ffff7f000001:126a:51c2d6f4:a422, node_name=1, branch_uid=0:ffff7f000001:126a:51c2d6f4:a423, eis_name=unknown eis name > (org.hornetq.core.client.impl.DelegatingSession@45859c3b) failed with exception XAException.XAER_RMERR: javax.transaction.xa.XAException

          at org.hornetq.core.client.impl.ClientSessionImpl.end(ClientSessionImpl.java:1286) [:6.1.0.Final]

          at org.hornetq.core.client.impl.DelegatingSession.end(DelegatingSession.java:332) [:6.1.0.Final]

          at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:588) [:6.1.0.Final]

          at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2287) [:6.1.0.Final]

          at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1452) [:6.1.0.Final]

          at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:99) [:6.1.0.Final]

          at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:159) [:6.1.0.Final]

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

          at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:119) [:6.1.0.Final]

          at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75) [:6.1.0.Final]

          at org.jboss.soa.esb.listeners.jca.EndpointProxy.endTransaction(EndpointProxy.java:401) [:]

          at org.jboss.soa.esb.listeners.jca.EndpointProxy.finish(EndpointProxy.java:295) [:]

          at org.jboss.soa.esb.listeners.jca.EndpointProxy.after(EndpointProxy.java:219) [:]

          at org.jboss.soa.esb.listeners.jca.EndpointProxy.invoke(EndpointProxy.java:146) [:]

          at $Proxy219.afterDelivery(Unknown Source)    at org.hornetq.ra.inflow.HornetQMessageHandler.onMessage(HornetQMessageHandler.java:287) [:6.1.0.Final]

          at org.hornetq.core.client.impl.ClientConsumerImpl.callOnMessage(ClientConsumerImpl.java:866) [:6.1.0.Final]

          at org.hornetq.core.client.impl.ClientConsumerImpl.access$100(ClientConsumerImpl.java:44) [:6.1.0.Final]

          at org.hornetq.core.client.impl.ClientConsumerImpl$Runner.run(ClientConsumerImpl.java:983) [:6.1.0.Final]

          at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:100) [:6.1.0.Final]

          at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [:1.6.0_23]

          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [:1.6.0_23]

          at java.lang.Thread.run(Thread.java:662) [:1.6.0_23]

       

       

      Please let us know if specific configuration has to be made to resolve these errors . Are these errors resolved in any later versions of HornetQ?

       

       

      Please help us if you have come across similar kind of issues.

       

      Regards,

      Pradeep Hegde