7 Replies Latest reply on Jun 9, 2009 1:50 AM by Yong Hao Gao

    OrderingGroup and Transaction Rollback

    Markus Lutum Novice

      Hi!

      I just tested the new function ordering group of 1.4.4.GA because I want to replace my own ordering keeper implementation.
      But What I see is that is does not work with transaction rolled back:

      What I have done:

      I add 4 Messages:

      Connection connection = getConnection();
      Session session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);
      JBossMessageProducer sender = (JBossMessageProducer) session.createProducer(queue);
      sender.enableOrderingGroup("testordergrp");
      
       TextMessage msg1 = session.createTextMessage("1");
       TextMessage msg2 = session.createTextMessage("Ordergrp - shouldrollback");
       TextMessage msg3 = session.createTextMessage("2");
       TextMessage msg4 = session.createTextMessage("3");
       sender.send(msg1);
       sender.send(msg2);
       sender.send(msg3);
       sender.send(msg4);
      closeConnection(connection);
      


      Those messages are added to the testqueue and as I also see they are added to the LinkedList in the OrderingGroup.class. So this seems to be fine.

      On my server I have a service which starts a consumeSingle() method from an Statefull Session bean ( This method bean call automatically creates the XA Transaction). Inside this consumeSingle() method I now receive one message! and delegate it.

       conn = getConnection();
       boolean transacted = true;
       session = conn.createSession(transacted, Session.SESSION_TRANSACTED);
      
      consumer = session.createConsumer(m_queue);
      
       // keep waittime small to ensure handling inside the transaction
       Message msg = consumer.receive(20000);
      
       // now delegate this message to the right handler....
      


      The second message causes an error so the tx is rolled back.
      In the old implementation the Message was also rolled back to the queue and the JMSXDeliveryCount was increased by one.
      Next time consumeSingle() method was called this previous message was received again and again until it was moved to DLQ.

      But with the new version and the orderinggroup on this behaviour changed?!?.
      The second Message is still delivered as the second message but after the rollback first the other messages are delivered and at the end the second one again??

      My server log:


      
      INFO [TestMessageHandlerBean] Got:1 mID:ID:JBM-7228da24-988e-44e9-b1d5-36af6e220d3e
      INFO [TestMessageHandlerBean] Got:Ordergrp - shouldrollback mID:ID:JBM-03e2198d-2e5d-490b-8631-56d596c689fe
      ERROR [TestMessageHandlerBean] Error: Rollback because:For input string: "Ordergrp - shouldrollback"
      INFO [TestMessageHandlerBean] Got:2 mID:ID:JBM-89bc4425-68f6-476e-abbf-b55938d36dca
      INFO [TestMessageHandlerBean] Got:3 mID:ID:JBM-973afa1d-824a-4557-a316-9e9c1d6c9ed2
      INFO [TestMessageHandlerBean] Got:Ordergrp - shouldrollback mID:ID:JBM-03e2198d-2e5d-490b-8631-56d596c689fe
      ERROR [TestMessageHandlerBean] Error: Rollback because:For input string: "Ordergrp - shouldrollback"
      INFO [TestMessageHandlerBean] Got:Ordergrp - shouldrollback mID:ID:JBM-03e2198d-2e5d-490b-8631-56d596c689fe
      ERROR [TestMessageHandlerBean] Error: Rollback because:For input string: "Ordergrp - shouldrollback"
      INFO [TestMessageHandlerBean] Got:Ordergrp - shouldrollback mID:ID:JBM-03e2198d-2e5d-490b-8631-56d596c689fe
      ERROR [TestMessageHandlerBean] Error: Rollback because:For input string: "Ordergrp - shouldrollback"
      INFO [TestMessageHandlerBean] Got:Ordergrp - shouldrollback mID:ID:JBM-03e2198d-2e5d-490b-8631-56d596c689fe
      ERROR [TestMessageHandlerBean] Error: Rollback because:For input string: "Ordergrp - shouldrollback"
      INFO [TestMessageHandlerBean] Got:Ordergrp - shouldrollback mID:ID:JBM-03e2198d-2e5d-490b-8631-56d596c689fe
      ERROR [TestMessageHandlerBean] Error: Rollback because:For input string: "Ordergrp - shouldrollback"
      INFO [TestMessageHandlerBean] Got:Ordergrp - shouldrollback mID:ID:JBM-03e2198d-2e5d-490b-8631-56d596c689fe
      ERROR [TestMessageHandlerBean] Error: Rollback because:For input string: "Ordergrp - shouldrollback"
      INFO [TestMessageHandlerBean] Got:Ordergrp - shouldrollback mID:ID:JBM-03e2198d-2e5d-490b-8631-56d596c689fe
      ERROR [TestMessageHandlerBean] Error: Rollback because:For input string: "Ordergrp - shouldrollback"
      



      Can you explain this? Does the orderingGroup does not work if a transaction is rolled back?

      Just for the history info:
      I don't think that my own solution has something to do with this. I simply receive() one message inside a transaction. This "service" just makes sure that only one message is handles by one consumer at a time. I first had a singleton MDB solution for this but the internal handling of message also queues at least 2 messages before delegating them to the MDB. So I had also problems with ordering and rollback there too...

        • 1. Re: OrderingGroup and Transaction Rollback
          Yong Hao Gao Master

          Hi,

          I'll take a look. Thanks

          • 2. Re: OrderingGroup and Transaction Rollback
            Yong Hao Gao Master

            Hi,

            If you roll back the transaction, the message will be redelivered.
            the second message will not be delivered until the first message is consumed (committed in a Tx or just acknowledged).

            Can you show me the code doing the rollback ? Thanks.

            • 3. Re: OrderingGroup and Transaction Rollback
              Markus Lutum Novice

              Hi!

              Ok. Here is my method which receives the message from the queue.
              There is also a slowdown feature but this can be ignored here.
              The method is called at a statefull sessionbean with CMT so a transaction is just started.

               Session session = null;
               Connection conn = null;
               MessageConsumer consumer = null;
               try {
               conn = getConnection();
               boolean transacted = true;
               session = conn.createSession(transacted, Session.SESSION_TRANSACTED);
              
               consumer = session.createConsumer(m_queue);
              
               Logger.debug(this, "blocking to receive message from queue");
              
               // keep waittime small to ensure handling inside the transaction
               Message msg = consumer.receive(20000);
               if (msg != null) {
               // get deliverycount of the message. If it is the first time the count is 1
               int redeliveryCount = msg.getIntProperty("JMSXDeliveryCount");
               if (redeliveryCount > 1) {
               // at least the second retry so wait to slow consuming down
               // in ms: 10, 20, 40, 80, .... 102400 (at the 10 delivery)
               long waittime = (long) (10 * Math.pow(2, redeliveryCount));
               Logger.info(this, "Redelivery is slowed down. Waittime (ms):" + waittime);
               try {
               Thread.sleep(waittime);
               }
               catch (InterruptedException e) {
               // ignore
               }
               }
               // HERE the message is delegated to a handler. see expl. below
               jmsMessageHandler.handleMessage(msg);
               }
               }
               catch (JMSException e) {
               throw new RuntimeException("Problems handling message.", e);
               }
               finally {
               if (consumer != null)
               try {
               consumer.close();
               }
               catch (Exception ignore) {
               }
               if (session != null)
               try {
               session.close();
               }
               catch (Exception ignore) {
               }
               if (conn != null)
               try {
               conn.close();
               }
               catch (Exception ignore) {
               }
               }
              


              So I open a connection, create a transacted session and receive ONE message. Then I delegate the message to a handler. In the final I close the resources.

              The handler just uses:
              private SessionContext ctx;
              and then calls ctx.setRollbackOnly();

              When I debug I see that the first message is delivered. The OrderingGroup.markSending() is called and the handler handles the message.
              Then while the transaction is commited the unregister is called.

              Now comes the failing message where the transaction is marked as rollback only. While the session is closed in the final block the unregister method is called again!! So the message is removedfrom the linked list!
              Stack trace:

              OrderingGroup.unregister(MessageReference) line: 121
              OrderingGroupMonitor.unmarkSending(MessageReference) line: 178
              MessagingQueue(ChannelSupport).cancelInternal(MessageReference) line: 609
              MessagingQueue(PagingChannelSupport).cancelInternal(MessageReference) line: 323
              MessagingQueue(ChannelSupport).cancel(Delivery) line: 328
              SimpleDelivery.cancel() line: 110
              ServerSessionEndpoint.cancelDeliveryInternal(Cancel) line: 1643
              ServerSessionEndpoint.cancelDelivery(Cancel) line: 456
              SessionAdvised.org$jboss$jms$server$endpoint$advised$SessionAdvised$cancelDelivery$aop(Cancel) line: 145
              SessionAdvised$cancelDelivery_2980985335510575813.invokeNext() line: not available
              ServerLogInterceptor.invoke(Invocation) line: 105
              SessionAdvised$cancelDelivery_2980985335510575813.invokeNext() line: not available
              SessionAdvised.cancelDelivery(Cancel) line: not available
              SessionCancelDeliveryRequest.serverInvoke() line: 84
              JMSServerInvocationHandler.invoke(InvocationRequest) line: 143
              SSLBisocketServerInvoker(ServerInvoker).invoke(InvocationRequest) line: 862
              ServerThread.processInvocation(SocketWrapper) line: 609
              ServerThread.dorun() line: 421
              ServerThread.run() line: 174
              



              What I see in OrderingGroupMonitor is that unmarksending AND messageCompleted has more or less the same code? Can this be right?
              Both call:
              OrderingGroup group = orderingGroups.get(grpName);
              if (group != null)
              {
              group.unregister(ref);
              }


              Greets

              • 4. Re: OrderingGroup and Transaction Rollback
                Yong Hao Gao Master

                Re:
                What I see in OrderingGroupMonitor is that unmarksending AND messageCompleted has more or less the same code? Can this be right?

                Yes, they are pretty much the same. The reason why there are two methods is that originally we keep the topic in mind, so there is a reference count for each message. unmarksending is used to be a method just decrease the ref count, the messageCompleted() is used to unlink the message. But later we decided not to support the topic for now. So the reference count doesn't make much sense now. It should be simplified.

                Howard

                • 5. Re: OrderingGroup and Transaction Rollback
                  Markus Lutum Novice

                  Thx for explanation.

                  But still, why is my message after the rollback not the next message, which is delivered by the JMS System.

                  I still have this reproduceable:

                  1, Rollbackmsg(first try) , 2, 3 , Rollbackmsg(second try), ... , Rollbackmsg(last try)
                  ( simplified: A, B, C, D, B, B, B, B, B)

                  behaviour
                  instead of the expected:

                  1, Rollbackmsg(first try), Rollbackmsg(second try), ... , Rollbackmsg(last try), 2, 3
                  ( simplified: A, B, B, B, B, B, B, C, D )

                  I think is must have something to do with this session.close() call which removes the reference from the Orderinggroup....

                  Can you explain? Bug or Feature :-)?

                  • 6. Re: OrderingGroup and Transaction Rollback
                    Yong Hao Gao Master

                    Hi,

                    It is a obvious bug. The problem is that the unmarkSend() method shouldn't call the unregister() to release the ref in the cancel operation.

                    As for the receiving sequence, I need to find out the reason.
                    I'll create a JIRA.

                    Thanks!

                    Howard

                    • 7. Re: OrderingGroup and Transaction Rollback
                      Yong Hao Gao Master

                      https://jira.jboss.org/jira/browse/JBMESSAGING-1643

                      The reason for the wrong order of delivery:

                      1. msg A is delivered and commited. then B is delivered to client.
                      2. consumer close() cause B cancelled back to queue. But it is wrongly removed from the linked list.
                      3. On next deliver, B cannot be delivered because it is not the first in the ordering group (B still an ordering group message). So C is delivered to client.
                      4. After C is committed, D is delivered to the client and committed.
                      5. then B is delivered as the whole ordering group is empty now.