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...

        • 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.