1 Reply Latest reply on Oct 15, 2011 1:05 PM by clebert.suconic

    Messages lost/stuck in queue

    m_b

      Here's a sample scenario:

      Transaction maganer reports a timeout and passes a message to the queue
      defined by "Dead Letter Address", MDB (TransactionManagementType.CONTAINER,
      TransactionAttributeType.REQUIRED ) marks current transaction to be
      rolled back (setRollbackOnly()).

      And here comes the issue: these messages don't show up in the DLQ and
      are nowhere to be found. Message count still includes them but they are
      not visible by any of the jmx-console methods/tools. They are passed to
      the consumer only after the container restart.

      Here's an interresting log message:


      Oct 10 09:19:51 xxxxx JBOSS WARN
       [org.hornetq.core.transaction.impl.ResourceManagerImpl(Thread-0
       (group:HornetQ-scheduled-threads-446070279))] transaction with xid
       XidImpl (920763579
       bq:97.102.102.48.48.48.57.58.100.50.56.51.58.52.101.57.50.57.57.52.53.58.50.56.49.54.97
       formatID:131075
       gtxid:49.45.97.102.102.48.48.48.57.58.100.50.56.51.58.52.101.57.50.57.57.52.53.58.50.56.49.54.56
       timed out
       
      

       

      Here's the code excerpt responsible for that log entry:
      (main/org/hornetq/core/transaction/impl/ResourceManagerImpl,
      TxTimeoutHandle)

       

       

         for (Transaction tx : transactions.values())
                   {
                      if (tx.hasTimedOut(now, defaultTimeoutSeconds))
                      {
                         transactions.remove(tx.getXid());
       *ResourceManagerImpl.log.warn("transaction with xid " + tx.getXid() + "
       timed out");*
                         timedoutTransactions.add(tx);
                      }
                   }
       
                   for (Transaction failedTransaction : timedoutTransactions)
                   {
                      try
                      {
                         failedTransaction.rollback();
                      }
                      catch (Exception e)
                      {
                         ResourceManagerImpl.log.error("failed to timeout
       transaction, xid:" + failedTransaction.getXid(), e);
                      }
                   }
      

       

      In our case there's no information about failedTransaction.rollback()
      failure, but the trasactions are not rolled back properly.

      This is my environment specs:
      OS: Linux 2.6.32.45-grsec (amd64)
      JVM Version: 20.1-b02 (Sun Microsystems Inc.)
      JVM Name: Java HotSpot(TM) 64-Bit Server VM
      JBoss : 5.0.1.GA (build: SVNTag=JBoss_5_0_1_GA date=200902231226)
      Hornetq: 2.2.5.Final (HQ_2_2_5_FINAL_AS7, 121)

      Does it seem it's a configuration issue? I would appreciate any
      suggestions.

      Thanks in advance.

       

      Here's some more log entries regarding this issue:


      Oct 10 09:19:51 xxxxx JBOSS WARN
       [com.arjuna.ats.arjuna.logging.arjLoggerI18N(Thread-8)]
       [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] -
       TransactionReaper::check timeout for TX aff0009:d283:4e929945:28163 in
       state  RUN
       Oct 10 09:19:51 xxxxx JBOSS WARN
       [com.arjuna.ats.arjuna.logging.arjLoggerI18N(Thread-8)]
       [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] -
       TransactionReaper::check timeout for TX aff0009:d283:4e929945:28168 in
       state  RUN
       Oct 10 09:19:51 xxxxx JBOSS WARN
       [com.arjuna.ats.arjuna.logging.arjLoggerI18N(Thread-9)]
       [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id
       aff0009:d283:4e929945:28163 invoked while multiple threads active within it.
       Oct 10 09:19:51 xxxxx JBOSS WARN
       [com.arjuna.ats.arjuna.logging.arjLoggerI18N(Thread-9)]
       [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] -
       CheckedAction::check - atomic action aff0009:d283:4e929945:28163
       aborting with 1 threads active!
       Oct 10 09:19:51 xxxxx JBOSS WARN
       [org.hornetq.core.server.impl.QueueImpl(Thread-28
       (group:HornetQ-server-threads1127638031-70398892))] Message
       Reference[137927]:RELIABLE:ServerMessage[messageID=137927,priority=4,expiration=[null],
       durable=true,
       address=jms.queue.ExampleQueue,properties=TypedProperties[{_HQ_LARGE_SIZE=246153}]]
       has reached maximum delivery attempts, sending it to Dead Letter Address
       jms.queue.ExampleDLQQueue from jms.queue.ExampleQueue
       Oct 10 09:19:51 xxxxx JBOSS WARN
       [org.hornetq.core.transaction.impl.ResourceManagerImpl(Thread-0
       (group:HornetQ-scheduled-threads-446070279))] transaction with xid
       XidImpl (920763579
       bq:97.102.102.48.48.48.57.58.100.50.56.51.58.52.101.57.50.57.57.52.53.58.50.56.49.54.97
       formatID:131075
       gtxid:49.45.97.102.102.48.48.48.57.58.100.50.56.51.58.52.101.57.50.57.57.52.53.58.50.56.49.54.56
       timed out
       Oct 10 09:19:51 xxxxx JBOSS WARN
       [com.arjuna.ats.arjuna.logging.arjLoggerI18N(Thread-8)]
       [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] -
       TransactionReaper::check timeout for TX aff0009:d283:4e929945:28163 in
       state  CANCEL
       Oct 10 09:19:51 xxxxx JBOSS WARN
       [com.arjuna.ats.arjuna.logging.arjLoggerI18N(Thread-8)]
       [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] -
       TransactionReaper::check timeout for TX aff0009:d283:4e929945:28168 in
       state  SCHEDULE_CANCEL
      

        • 1. Re: Messages lost/stuck in queue
          clebert.suconic

          You sure have a prepared transaction with acks and recovery is not properly configured.

           

           

          You could list prepared txs and rollback them manually (heuristically)

           

           

          Or proper configure recovery for XA