10 Replies Latest reply on Jul 9, 2008 5:06 AM by Jerry Jacob

    TwoPhaseOutcome.HEURISTIC_HAZARD

    Jerry Jacob Newbie

      Hi,

      We have a CMT MDB running on Jboss SOA 4.2. This MDB is recieving messages from a Queue running on a JBoss 4.0.4 server. This MDB is internally calling another beans which has user managed transactions. Everything is working in when I have the MDB on JBoss 4.0.4 and Queue on 4.0.4. But when I put my MDB in SOA, I get the below warning

      org.jboss.mq.SpyJMSException: Exiting on IOE; - nested throwable: (java.io.EOFException)
      at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:78)
      at org.jboss.mq.Connection.asynchFailure(Connection.java:420)
      at org.jboss.mq.il.uil2.UILClientILService.asynchFailure(UILClientILService.java:174)
      at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleStop(SocketManager.java:440)
      at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:372)
      at java.lang.Thread.run(Thread.java:595)
      Caused by: java.io.EOFException
      at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2666)
      at java.io.ObjectInputStream.readByte(ObjectInputStream.java:875)
      at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:317)
      ... 1 more


      And after that

      2008-06-26 07:35:56,355 WARN [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.resources.arjunacore.preparefailed] [com.arjuna.ats.internal.jta.resources.arjunacore.preparefailed] XAResourceRecord.prepare - prepare failed with exception XAException.XAER_RMERR
      2008-06-26 07:35:56,358 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_50] - Prepare phase of action ac8abd7:b364:4862f892:25b received heuristic decision: TwoPhaseOutcome.HEURISTIC_HAZARD
      2008-06-26 07:35:56,359 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_36] - BasicAction.End() - prepare phase of action-id ac8abd7:b364:4862f892:25b failed.
      2008-06-26 07:35:56,359 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_37] - Received heuristic: TwoPhaseOutcome.HEURISTIC_HAZARD .
      2008-06-26 07:35:56,359 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_38] - Action Aborting
      2008-06-26 07:35:56,417 ERROR [org.jboss.jms.asf.StdServerSession] failed to commit/rollback
      javax.transaction.HeuristicMixedException
      at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1390)
      at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
      at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87)
      at org.jboss.jms.asf.StdServerSession.onMessage(StdServerSession.java:351)
      at org.jboss.mq.SpyMessageConsumer.sessionConsumerProcessMessage(SpyMessageConsumer.java:902)
      at org.jboss.mq.SpyMessageConsumer.addMessage(SpyMessageConsumer.java:170)
      at org.jboss.mq.SpySession.run(SpySession.java:323)
      at org.jboss.jms.asf.StdServerSession.run(StdServerSession.java:194)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:743)
      at java.lang.Thread.run(Thread.java:595)


      Are we missing something in our SOA Jboss Messaging configuration? Any help is appreciated

      Thanks in advance

        • 1. Re: TwoPhaseOutcome.HEURISTIC_HAZARD
          Mark Little Master

          When you say 'JBoss SOA' I assume you mean the SOA Platform?

          • 2. Re: TwoPhaseOutcome.HEURISTIC_HAZARD
            Jerry Jacob Newbie

            Thanks for looking into this. Yes, thats correct. Its Jboss SOA platform 4.2.

            We did some more research and got a break through. When we disable the transaction in MDB i.e <trans-attribute>NotSupported</trans-attribute>, it goes through. i.e MDB is recieving message and there is no twophase commit Hueristic exception also. Later we read that Arjuna transaction which is used by JBoss AS can support subTransactions but not two phase commit transactions. In that scenario, it will throw a Hueristic exception.

            How can we get rid of this issue without changing our app logic? Can we use someother transaction instead of Arjuna?

            • 3. Re: TwoPhaseOutcome.HEURISTIC_HAZARD
              Mark Little Master

              Your reading of what Arjuna (JBossTS) supports is completely wrong. Yes, it supports nested transactions. But it also most definitely supports 2PC! What on earth makes you think otherwise?!

              • 4. Re: TwoPhaseOutcome.HEURISTIC_HAZARD
                Jerry Jacob Newbie

                I meant two phase commit in sub transactions. Following is the content of a presentation on Jboss Transactions which I came across. I got to know abt it from here


                Nested transactions
                •Optional part of JTS specification
                ô€€¹few sub-transaction-aware resources
                •Registered resources are only informed of transaction termination
                •No two-phase commit for sub-transactions
                ô€€¹can result in heuristic-like outcomes
                ô€€¹Implementation specific extensions


                • 5. Re: TwoPhaseOutcome.HEURISTIC_HAZARD
                  Mark Little Master

                  No, that's not correct either: please read the documentation and don't take a presentation out of context. OTS does not support 2PC for subtransactions. JBossTS is fully compliant with that and does not either. However, since JBossTS has existed for over 20 years and had nested transactions (subtransactions) from the very start, it goes way beyond what the OTS allows. We have 2PC nested transactions. They can be enabled if you are using OTS, but are not used by default. However, if you create nested transactions in ArjunaCore then you get 2PC versions by default.

                  Once again though, read the manuals please. We spent over 20 years writing them and they should be pretty complete by now.

                  • 6. Re: TwoPhaseOutcome.HEURISTIC_HAZARD
                    Jerry Jacob Newbie

                    Really sorry about that. Due to time constraint, we could not go thru the docs properly. We went through it and have some idea abt JbossTS now. And with that, we were able to narrow down our issue to the DB level. i.e we get this HEURISTIC_MIXED_EXCEPTION only when we have a DB call inside the bean. We have configured our datasource to be XA and also we enabled XA at Oracle level. Somehow the DB transaction is commiting without the knowledge of the Transaction Coordinator and when Transaction coordinator tries to do the commit, it throws heuristic mixed exception.

                    Could somebody point us to the right direction of troubleshooting?

                    Thanks in advance

                    • 7. Re: TwoPhaseOutcome.HEURISTIC_HAZARD
                      Mark Little Master

                      If the DB is committing before the TM tells it to, then I think you need to troubleshoot in the direction of your DB vendor.

                      • 8. Re: TwoPhaseOutcome.HEURISTIC_HAZARD
                        Jerry Jacob Newbie

                        I am really sorry about being repeatitve. We are still not able to solve this issue. We enabled JMS Trace and got the below. The MDB reads the message from and MQ queue and performs some DB operation successfully. We thought its due to the DB operation but thats not the case. Everything start going wrong when transaction commiting starts. Following is the Trace enabled log after DB operation


                        2008-07-01 10:45:02,512 TRACE [org.jboss.jms.asf.StdServerSession] Commiting the JMS transaction
                        2008-07-01 10:45:02,513 TRACE [org.jboss.mq.SpyXAResource] End xid=< 131075, 27, 25, 1-ac8abd7:8018:4869bb44:50dac8abd7:8018:4869bb44:50e
                        2008-07-01 10:45:02,513 TRACE [org.jboss.mq.SpySession] Unsetting current tx xid=< 131075, 27, 25, 1-ac8abd7:8018:4869bb44:50dac8abd7:80
                        2008-07-01 10:45:02,513 TRACE [org.jboss.mq.SpyXAResourceManager] Ending xid=< 131075, 27, 25, 1-ac8abd7:8018:4869bb44:50dac8abd7:8018:48
                        2008-07-01 10:45:02,513 TRACE [org.jboss.mq.SpyXAResource] Prepare xid=< 131075, 27, 25, 1-ac8abd7:8018:4869bb44:50dac8abd7:8018:4869bb44
                        2008-07-01 10:45:02,514 TRACE [org.jboss.mq.SpyXAResourceManager] Preparing xid=< 131075, 27, 25, 1-ac8abd7:8018:4869bb44:50dac8abd7:8018
                        2008-07-01 10:45:02,514 TRACE [org.jboss.mq.Connection] Transact request=org.jboss.mq.TransactionRequest@3249fe Connection@23202927[token
                        2008-07-01 10:45:02,515 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.TransactMsg26738776[msgType: m_transact, msgID: 35, error: null]
                        2008-07-01 10:45:02,514 TRACE [org.jboss.mq.Connection] Transact request=org.jboss.mq.TransactionRequest@3249fe Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STARTED]
                        2008-07-01 10:45:02,515 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.TransactMsg26738776[msgType: m_transact, msgID: 35, error: null]
                        2008-07-01 10:45:02,515 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.TransactMsg26738776[msgType: m_transact, msgID: 35, error: null]
                        2008-07-01 10:45:02,520 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[l1-xgbh14if-1-bgoe14if-ttc17r-z5r4k5a] done waiting on lock, buffer is empty
                        2008-07-01 10:45:02,520 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[l1-xgbh14if-1-bgoe14if-ttc17r-z5r4k5a]: 100 ms timeout expired
                        2008-07-01 10:45:02,520 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[l1-xgbh14if-1-bgoe14if-ttc17r-z5r4k5a] receiving, timeout = 100
                        2008-07-01 10:45:02,520 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[l1-xgbh14if-1-bgoe14if-ttc17r-z5r4k5a]: receive, timeout 100 ms, blocking poll on queue
                        2008-07-01 10:45:02,520 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[l1-xgbh14if-1-bgoe14if-ttc17r-z5r4k5a] waiting on main lock, timeout 100 ms
                        2008-07-01 10:45:02,520 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[r-m1zg14if-1-bgoe14if-ttc17r-z5r4k5a] done waiting on lock, buffer is empty
                        2008-07-01 10:45:02,520 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[r-m1zg14if-1-bgoe14if-ttc17r-z5r4k5a]: 100 ms timeout expired
                        2008-07-01 10:45:02,520 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[r-m1zg14if-1-bgoe14if-ttc17r-z5r4k5a] receiving, timeout = 100
                        2008-07-01 10:45:02,520 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[r-m1zg14if-1-bgoe14if-ttc17r-z5r4k5a]: receive, timeout 100 ms, blocking poll on queue
                        2008-07-01 10:45:02,520 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[r-m1zg14if-1-bgoe14if-ttc17r-z5r4k5a] waiting on main lock, timeout 100 ms
                        2008-07-01 10:45:02,521 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[p-c1zg14if-1-bgoe14if-ttc17r-z5r4k5a] done waiting on lock, buffer is empty
                        2008-07-01 10:45:02,521 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[p-c1zg14if-1-bgoe14if-ttc17r-z5r4k5a]: 100 ms timeout expired
                        2008-07-01 10:45:02,521 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[p-c1zg14if-1-bgoe14if-ttc17r-z5r4k5a] receiving, timeout = 100
                        2008-07-01 10:45:02,521 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[p-c1zg14if-1-bgoe14if-ttc17r-z5r4k5a]: receive, timeout 100 ms, blocking poll on queue
                        2008-07-01 10:45:02,521 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[p-c1zg14if-1-bgoe14if-ttc17r-z5r4k5a] waiting on main lock, timeout 100 ms
                        2008-07-01 10:45:02,521 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[j1-6fbh14if-1-bgoe14if-ttc17r-z5r4k5a] done waiting on lock, buffer is empty
                        2008-07-01 10:45:02,521 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[j1-6fbh14if-1-bgoe14if-ttc17r-z5r4k5a]: 100 ms timeout expired
                        2008-07-01 10:45:02,521 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[j1-6fbh14if-1-bgoe14if-ttc17r-z5r4k5a] receiving, timeout = 100
                        2008-07-01 10:45:02,521 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[j1-6fbh14if-1-bgoe14if-ttc17r-z5r4k5a]: receive, timeout 100 ms, blocking poll on queue
                        2008-07-01 10:45:02,521 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[j1-6fbh14if-1-bgoe14if-ttc17r-z5r4k5a] waiting on main lock, timeout 100 ms
                        2008-07-01 10:45:02,538 TRACE [org.jboss.mq.il.uil2.SocketManager] Exiting on IOE
                        java.io.EOFException
                         at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2666)
                         at java.io.ObjectInputStream.readByte(ObjectInputStream.java:875)
                         at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:317)
                         at java.lang.Thread.run(Thread.java:595)
                        2008-07-01 10:45:02,539 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.TransactMsg26738776[msgType: m_transact, msgID: 35, error: java.io.EOFException]
                        2008-07-01 10:45:02,539 TRACE [org.jboss.mq.Connection] Notified of failure reason=Exiting on IOE Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STARTED]
                        java.io.EOFException
                         at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2666)
                         at java.io.ObjectInputStream.readByte(ObjectInputStream.java:875)
                         at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:317)
                         at java.lang.Thread.run(Thread.java:595)
                        2008-07-01 10:45:02,539 TRACE [org.jboss.mq.il.uil2.SocketManager] sendMessage will throw error
                        java.io.EOFException
                         at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2666)
                         at java.io.ObjectInputStream.readByte(ObjectInputStream.java:875)
                         at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:317)
                         at java.lang.Thread.run(Thread.java:595)
                        2008-07-01 10:45:02,539 DEBUG [org.jboss.mq.il.uil2.SocketManager] End ReadTask.run
                        2008-07-01 10:45:02,540 TRACE [org.jboss.mq.il.uil2.SocketManager] WriteTask was interrupted
                        java.lang.InterruptedException
                         at java.lang.Object.wait(Native Method)
                         at java.lang.Object.wait(Object.java:474)
                         at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(LinkedQueue.java:122)
                         at org.jboss.mq.il.uil2.SocketManager$WriteTask.run(SocketManager.java:519)
                         at java.lang.Thread.run(Thread.java:595)
                        2008-07-01 10:45:02,540 DEBUG [org.jboss.mq.il.uil2.SocketManager] End WriteTask.run
                        2008-07-01 10:45:02,541 WARN [org.jboss.ejb.plugins.jms.JMSContainerInvoker] JMS provider failure detected for IPMReceiverBean
                        org.jboss.mq.SpyJMSException: Exiting on IOE; - nested throwable: (java.io.EOFException)
                         at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:78)
                         at org.jboss.mq.Connection.asynchFailure(Connection.java:420)
                         at org.jboss.mq.il.uil2.UILClientILService.asynchFailure(UILClientILService.java:174)
                         at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleStop(SocketManager.java:440)
                         at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:372)
                         at java.lang.Thread.run(Thread.java:595)
                        Caused by: java.io.EOFException
                         at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2666)
                         at java.io.ObjectInputStream.readByte(ObjectInputStream.java:875)
                         at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:317)
                         ... 1 more
                        2008-07-01 10:45:02,542 TRACE [org.jboss.mq.Connection] Stopping connection Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]
                        2008-07-01 10:45:02,542 TRACE [org.jboss.mq.Connection] Stopping connection Connection@33380442[token=ConnectionToken:ID:345/4e78466e11fef91d19a547e94d990da6 rcvstate=STOPPED]
                        2008-07-01 10:45:02,542 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.EnableConnectionMsg30520434[msgType: m_setEnabled, msgID: 36, error: null]
                        2008-07-01 10:45:02,542 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.EnableConnectionMsg30520434[msgType: m_setEnabled, msgID: 36, error: null]
                        2008-07-01 10:45:02,543 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_setEnabled, msgID: 36
                        2008-07-01 10:45:02,543 TRACE [org.jboss.mq.il.uil2.SocketManager] Found replyMap msg: org.jboss.mq.il.uil2.msgs.EnableConnectionMsg30520434[msgType: m_setEnabled, msgID: 36, error: null]
                        2008-07-01 10:45:02,543 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msg reply: org.jboss.mq.il.uil2.msgs.EnableConnectionMsg30520434[msgType: m_setEnabled, msgID: 36, error: null]
                        2008-07-01 10:45:02,543 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.EnableConnectionMsg30520434[msgType: m_setEnabled, msgID: 36, error: null]
                        2008-07-01 10:45:02,544 TRACE [org.jboss.mq.SpyConnectionConsumer] Close SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 destination=QUEUE.SOA_STD messageSelector=null Local Create] CLOSED messages=0 waitingForMessage=true internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 destination=QUEUE.SOA_STD messageSelector=null Local Create] id=2,5,JBossMQ Client Threads] sessionPool=org.jboss.jms.asf.StdServerSessionPool@a8d49 connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,544 WARN [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.resources.arjunacore.preparefailed] [com.arjuna.ats.internal.jta.resources.arjunacore.preparefailed] XAResourceRecord.prepare - prepare failed with exception XAException.XAER_RMERR
                        2008-07-01 10:45:02,544 TRACE [org.jboss.mq.SpyConnectionConsumer] run() closed while waiting SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 destination=QUEUE.SOA_STD messageSelector=null Local Create] CLOSED messages=0 waitingForMessage=true internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 destination=QUEUE.SOA_STD messageSelector=null Local Create] id=2,5,JBossMQ Client Threads] sessionPool=org.jboss.jms.asf.StdServerSessionPool@a8d49 connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,544 TRACE [org.jboss.mq.SpyConnectionConsumer] Joining thread SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 destination=QUEUE.SOA_STD messageSelector=null Local Create] CLOSED messages=0 waitingForMessage=true internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 destination=QUEUE.SOA_STD messageSelector=null Local Create] id=2,5,JBossMQ Client Threads] sessionPool=org.jboss.jms.asf.StdServerSessionPool@a8d49 connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,544 TRACE [org.jboss.mq.SpyConnectionConsumer] Nacking messages on queue SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 destination=QUEUE.SOA_STD messageSelector=null Local Create] CLOSED messages=0 waitingForMessage=false internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 destination=QUEUE.SOA_STD messageSelector=null Local Create] id=2,5,] sessionPool=org.jboss.jms.asf.StdServerSessionPool@a8d49 connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,544 TRACE [org.jboss.mq.Connection] removeConsumer req=Subscription[subId=-2147483648connection=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 destination=QUEUE.SOA_STD messageSelector=null Local Create]
                        2008-07-01 10:45:02,545 TRACE [org.jboss.mq.SpyConnectionConsumer] Ignoring error removing consumer from connection SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 destination=QUEUE.SOA_STD messageSelector=null Local Create] CLOSED messages=0 waitingForMessage=false internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 destination=QUEUE.SOA_STD messageSelector=null Local Create] id=2,5,] sessionPool=org.jboss.jms.asf.StdServerSessionPool@a8d49 connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        org.jboss.mq.SpyJMSException: Cannot unsubscribe to this destination; - nested throwable: (java.io.IOException: Client is not connected)
                         at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:78)
                         at org.jboss.mq.SpyJMSException.rethrowAsJMSException(SpyJMSException.java:63)
                         at org.jboss.mq.Connection.removeConsumer(Connection.java:899)
                         at org.jboss.mq.SpyConnectionConsumer.close(SpyConnectionConsumer.java:223)
                         at org.jboss.ejb.plugins.jms.JMSContainerInvoker.innerStopDelivery(JMSContainerInvoker.java:1070)
                         at org.jboss.ejb.plugins.jms.JMSContainerInvoker$ExceptionListenerImpl$ExceptionListenerRunnable.run(JMSContainerInvoker.java:1570)
                         at java.lang.Thread.run(Thread.java:595)
                        Caused by: java.io.IOException: Client is not connected
                         at org.jboss.mq.il.uil2.SocketManager.internalSendMessage(SocketManager.java:265)
                         at org.jboss.mq.il.uil2.SocketManager.sendMessage(SocketManager.java:221)
                         at org.jboss.mq.il.uil2.UILServerIL.unsubscribe(UILServerIL.java:551)
                         at org.jboss.mq.Connection.removeConsumer(Connection.java:893)
                         ... 4 more
                        2008-07-01 10:45:02,545 DEBUG [org.jboss.jms.asf.StdServerSessionPool] Clearing 14 from ServerSessionPool
                        2008-07-01 10:45:02,545 TRACE [org.jboss.mq.SpySession] Session closing SpySession@374096[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,545 TRACE [org.jboss.mq.SpySession] Closing consumers SpySession@374096[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,546 TRACE [org.jboss.mq.SpyMessageConsumer] Message consumer closing. SpyMessageConsumer@15194381[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@c2c455 session=SpySession@374096[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,546 TRACE [org.jboss.mq.SpyMessageConsumer] Closed. SpyMessageConsumer@15194381[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@c2c455 session=SpySession@374096[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,546 TRACE [org.jboss.mq.SpySession] Close handling unacknowledged messages SpySession@374096[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,546 TRACE [org.jboss.mq.SpySession] Informing connection of close SpySession@374096[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,546 TRACE [org.jboss.mq.Connection] Closing session SpySession@374096[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,546 DEBUG [org.jboss.jms.asf.StdServerSession] closed
                        2008-07-01 10:45:02,546 TRACE [org.jboss.mq.SpySession] Session closing SpySession@22742994[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,546 TRACE [org.jboss.mq.SpySession] Closing consumers SpySession@22742994[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,546 TRACE [org.jboss.mq.SpyMessageConsumer] Message consumer closing. SpyMessageConsumer@12024659[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@15e95b8 session=SpySession@22742994[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,546 TRACE [org.jboss.mq.SpyMessageConsumer] Closed. SpyMessageConsumer@12024659[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@15e95b8 session=SpySession@22742994[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,546 TRACE [org.jboss.mq.SpySession] Close handling unacknowledged messages SpySession@22742994[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,546 TRACE [org.jboss.mq.SpySession] Informing connection of close SpySession@22742994[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,547 TRACE [org.jboss.mq.Connection] Closing session SpySession@22742994[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,547 DEBUG [org.jboss.jms.asf.StdServerSession] closed
                        2008-07-01 10:45:02,547 TRACE [org.jboss.mq.SpySession] Session closing SpySession@113889[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,547 TRACE [org.jboss.mq.SpySession] Closing consumers SpySession@113889[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,547 TRACE [org.jboss.mq.SpyMessageConsumer] Message consumer closing. SpyMessageConsumer@22744135[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@177273 session=SpySession@113889[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,547 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_50] - Prepare phase of action ac8abd7:8018:4869bb44:50d received heuristic decision: TwoPhaseOutcome.HEURISTIC_HAZARD
                        2008-07-01 10:45:02,547 TRACE [org.jboss.mq.SpyMessageConsumer] Closed. SpyMessageConsumer@22744135[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@177273 session=SpySession@113889[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,547 TRACE [org.jboss.mq.SpySession] Close handling unacknowledged messages SpySession@113889[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,547 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_36] - BasicAction.End() - prepare phase of action-id ac8abd7:8018:4869bb44:50d failed.
                        2008-07-01 10:45:02,547 TRACE [org.jboss.mq.SpySession] Informing connection of close SpySession@113889[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,547 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_37] - Received heuristic: TwoPhaseOutcome.HEURISTIC_HAZARD .
                        2008-07-01 10:45:02,547 TRACE [org.jboss.mq.Connection] Closing session SpySession@113889[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,547 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_38] - Action Aborting
                        2008-07-01 10:45:02,548 DEBUG [org.jboss.jms.asf.StdServerSession] closed
                        2008-07-01 10:45:02,548 TRACE [org.jboss.mq.SpySession] Session closing SpySession@8598808[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,548 TRACE [org.jboss.mq.SpySession] Closing consumers SpySession@8598808[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,548 TRACE [org.jboss.mq.SpyMessageConsumer] Message consumer closing. SpyMessageConsumer@28106963[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@12e1e6 session=SpySession@8598808[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,548 TRACE [org.jboss.mq.SpyMessageConsumer] Closed. SpyMessageConsumer@28106963[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@12e1e6 session=SpySession@8598808[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,548 TRACE [org.jboss.mq.SpySession] Close handling unacknowledged messages SpySession@8598808[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,548 TRACE [org.jboss.mq.SpySession] Informing connection of close SpySession@8598808[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,548 TRACE [org.jboss.mq.Connection] Closing session SpySession@8598808[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,548 DEBUG [org.jboss.jms.asf.StdServerSession] closed
                        2008-07-01 10:45:02,548 TRACE [org.jboss.mq.SpySession] Session closing SpySession@14439442[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,548 TRACE [org.jboss.mq.SpySession] Closing consumers SpySession@14439442[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,548 TRACE [org.jboss.mq.SpyMessageConsumer] Message consumer closing. SpyMessageConsumer@32541264[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@11382cd session=SpySession@14439442[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,549 TRACE [org.jboss.mq.SpyMessageConsumer] Closed. SpyMessageConsumer@32541264[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@11382cd session=SpySession@14439442[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,549 TRACE [org.jboss.mq.SpySession] Close handling unacknowledged messages SpySession@14439442[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,549 TRACE [org.jboss.mq.SpySession] Informing connection of close SpySession@14439442[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,549 TRACE [org.jboss.mq.Connection] Closing session SpySession@14439442[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,549 DEBUG [org.jboss.jms.asf.StdServerSession] closed
                        2008-07-01 10:45:02,549 TRACE [org.jboss.mq.SpySession] Session closing SpySession@17348426[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,549 TRACE [org.jboss.mq.SpySession] Closing consumers SpySession@17348426[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,549 TRACE [org.jboss.mq.SpyMessageConsumer] Message consumer closing. SpyMessageConsumer@24483378[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@139953f session=SpySession@17348426[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,549 TRACE [org.jboss.mq.SpyMessageConsumer] Closed. SpyMessageConsumer@24483378[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@139953f session=SpySession@17348426[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,549 TRACE [org.jboss.mq.SpySession] Close handling unacknowledged messages SpySession@17348426[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,549 TRACE [org.jboss.mq.SpySession] Informing connection of close SpySession@17348426[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,549 TRACE [org.jboss.mq.Connection] Closing session SpySession@17348426[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,549 DEBUG [org.jboss.jms.asf.StdServerSession] closed
                        2008-07-01 10:45:02,550 TRACE [org.jboss.mq.SpySession] Session closing SpySession@14144075[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,582 TRACE [org.jboss.mq.SpySession] Closing consumers SpySession@14144075[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,582 TRACE [org.jboss.mq.SpyMessageConsumer] Message consumer closing. SpyMessageConsumer@13992535[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@12f5e43 session=SpySession@14144075[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,582 TRACE [org.jboss.mq.SpyMessageConsumer] Closed. SpyMessageConsumer@13992535[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@12f5e43 session=SpySession@14144075[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,582 TRACE [org.jboss.mq.SpySession] Close handling unacknowledged messages SpySession@14144075[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,582 TRACE [org.jboss.mq.SpySession] Informing connection of close SpySession@14144075[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,582 TRACE [org.jboss.mq.Connection] Closing session SpySession@14144075[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,582 DEBUG [org.jboss.jms.asf.StdServerSession] closed
                        2008-07-01 10:45:02,582 TRACE [org.jboss.mq.SpySession] Session closing SpySession@23079812[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,582 TRACE [org.jboss.mq.SpySession] Closing consumers SpySession@23079812[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,583 TRACE [org.jboss.mq.SpyMessageConsumer] Message consumer closing. SpyMessageConsumer@17142525[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@c90383 session=SpySession@23079812[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,583 TRACE [org.jboss.mq.SpyMessageConsumer] Closed. SpyMessageConsumer@17142525[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@c90383 session=SpySession@23079812[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,583 TRACE [org.jboss.mq.SpySession] Close handling unacknowledged messages SpySession@23079812[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,583 TRACE [org.jboss.mq.SpySession] Informing connection of close SpySession@23079812[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,583 TRACE [org.jboss.mq.Connection] Closing session SpySession@23079812[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,583 DEBUG [org.jboss.jms.asf.StdServerSession] closed
                        2008-07-01 10:45:02,583 TRACE [org.jboss.mq.SpySession] Session closing SpySession@16067020[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,583 TRACE [org.jboss.mq.SpySession] Closing consumers SpySession@16067020[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,583 TRACE [org.jboss.mq.SpyMessageConsumer] Message consumer closing. SpyMessageConsumer@28708442[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@18b3aa0 session=SpySession@16067020[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,583 TRACE [org.jboss.mq.SpyMessageConsumer] Closed. SpyMessageConsumer@28708442[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@18b3aa0 session=SpySession@16067020[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,583 TRACE [org.jboss.mq.SpySession] Close handling unacknowledged messages SpySession@16067020[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,583 TRACE [org.jboss.mq.SpySession] Informing connection of close SpySession@16067020[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,584 TRACE [org.jboss.mq.Connection] Closing session SpySession@16067020[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,584 DEBUG [org.jboss.jms.asf.StdServerSession] closed
                        2008-07-01 10:45:02,584 TRACE [org.jboss.mq.SpySession] Session closing SpySession@23619533[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,584 TRACE [org.jboss.mq.SpySession] Closing consumers SpySession@23619533[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,584 TRACE [org.jboss.mq.SpyMessageConsumer] Message consumer closing. SpyMessageConsumer@27165845[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@176d8f8 session=SpySession@23619533[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,584 TRACE [org.jboss.mq.SpyMessageConsumer] Closed. SpyMessageConsumer@27165845[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@176d8f8 session=SpySession@23619533[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,584 TRACE [org.jboss.mq.SpySession] Close handling unacknowledged messages SpySession@23619533[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,584 TRACE [org.jboss.mq.SpySession] Informing connection of close SpySession@23619533[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,584 TRACE [org.jboss.mq.Connection] Closing session SpySession@23619533[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,584 DEBUG [org.jboss.jms.asf.StdServerSession] closed
                        2008-07-01 10:45:02,584 TRACE [org.jboss.mq.SpySession] Session closing SpySession@1208781[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,584 TRACE [org.jboss.mq.SpySession] Closing consumers SpySession@1208781[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,584 TRACE [org.jboss.mq.SpyMessageConsumer] Message consumer closing. SpyMessageConsumer@25480596[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@ed843d session=SpySession@1208781[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,585 TRACE [org.jboss.mq.SpyMessageConsumer] Closed. SpyMessageConsumer@25480596[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@ed843d session=SpySession@1208781[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,585 TRACE [org.jboss.mq.SpySession] Close handling unacknowledged messages SpySession@1208781[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,585 TRACE [org.jboss.mq.SpySession] Informing connection of close SpySession@1208781[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,585 TRACE [org.jboss.mq.Connection] Closing session SpySession@1208781[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,585 DEBUG [org.jboss.jms.asf.StdServerSession] closed
                        2008-07-01 10:45:02,585 TRACE [org.jboss.mq.SpySession] Session closing SpySession@30718088[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,585 TRACE [org.jboss.mq.SpySession] Closing consumers SpySession@30718088[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,585 TRACE [org.jboss.mq.SpyMessageConsumer] Message consumer closing. SpyMessageConsumer@28995625[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@9efc1f session=SpySession@30718088[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,585 TRACE [org.jboss.mq.SpyMessageConsumer] Closed. SpyMessageConsumer@28995625[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@9efc1f session=SpySession@30718088[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,585 TRACE [org.jboss.mq.SpySession] Close handling unacknowledged messages SpySession@30718088[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,585 TRACE [org.jboss.mq.SpySession] Informing connection of close SpySession@30718088[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,585 TRACE [org.jboss.mq.Connection] Closing session SpySession@30718088[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,585 DEBUG [org.jboss.jms.asf.StdServerSession] closed
                        2008-07-01 10:45:02,585 TRACE [org.jboss.mq.SpySession] Session closing SpySession@18456292[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,586 TRACE [org.jboss.mq.SpySession] Closing consumers SpySession@18456292[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,586 TRACE [org.jboss.mq.SpyMessageConsumer] Message consumer closing. SpyMessageConsumer@2007235[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@10e8c53 session=SpySession@18456292[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,586 TRACE [org.jboss.mq.SpyMessageConsumer] Closed. SpyMessageConsumer@2007235[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@10e8c53 session=SpySession@18456292[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,586 TRACE [org.jboss.mq.SpySession] Close handling unacknowledged messages SpySession@18456292[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,586 TRACE [org.jboss.mq.SpySession] Informing connection of close SpySession@18456292[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,586 TRACE [org.jboss.mq.Connection] Closing session SpySession@18456292[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,586 DEBUG [org.jboss.jms.asf.StdServerSession] closed
                        2008-07-01 10:45:02,586 TRACE [org.jboss.mq.SpySession] Session closing SpySession@13404479[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,586 TRACE [org.jboss.mq.SpySession] Closing consumers SpySession@13404479[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,586 TRACE [org.jboss.mq.SpyMessageConsumer] Message consumer closing. SpyMessageConsumer@14842993[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@46bfed session=SpySession@13404479[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,586 TRACE [org.jboss.mq.SpyMessageConsumer] Closed. SpyMessageConsumer@14842993[sub=Subscription[subId=0 destination=null messageSelector=null Local Create] CLOSED listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@46bfed session=SpySession@13404479[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]]
                        2008-07-01 10:45:02,587 TRACE [org.jboss.mq.SpySession] Close handling unacknowledged messages SpySession@13404479[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,587 TRACE [org.jboss.mq.SpySession] Informing connection of close SpySession@13404479[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,587 TRACE [org.jboss.mq.Connection] Closing session SpySession@13404479[tx=true txid=null XA RUNNING CLOSED connection=Connection@23202927[token=ConnectionToken:ID:344/d43568e3ef3dea56fd8ba64461b31cf3 rcvstate=STOPPED]]
                        2008-07-01 10:45:02,587 DEBUG [org.jboss.jms.asf.StdServerSession] closed
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[q-j1zg14if-1-bgoe14if-ttc17r-z5r4k5a] done waiting on lock, buffer is empty
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[s-p1zg14if-1-bgoe14if-ttc17r-z5r4k5a] done waiting on lock, buffer is empty
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[q-j1zg14if-1-bgoe14if-ttc17r-z5r4k5a]: 100 ms timeout expired
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[s-p1zg14if-1-bgoe14if-ttc17r-z5r4k5a]: 100 ms timeout expired
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[q-j1zg14if-1-bgoe14if-ttc17r-z5r4k5a] receiving, timeout = 100
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[q-j1zg14if-1-bgoe14if-ttc17r-z5r4k5a]: receive, timeout 100 ms, blocking poll on queue
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[n1-6hbh14if-1-bgoe14if-ttc17r-z5r4k5a] done waiting on lock, buffer is empty
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[q-j1zg14if-1-bgoe14if-ttc17r-z5r4k5a] waiting on main lock, timeout 100 ms
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[n1-6hbh14if-1-bgoe14if-ttc17r-z5r4k5a]: 100 ms timeout expired
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[s-p1zg14if-1-bgoe14if-ttc17r-z5r4k5a] receiving, timeout = 100
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[n1-6hbh14if-1-bgoe14if-ttc17r-z5r4k5a] receiving, timeout = 100
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[s-p1zg14if-1-bgoe14if-ttc17r-z5r4k5a]: receive, timeout 100 ms, blocking poll on queue
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[n1-6hbh14if-1-bgoe14if-ttc17r-z5r4k5a]: receive, timeout 100 ms, blocking poll on queue
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[s-p1zg14if-1-bgoe14if-ttc17r-z5r4k5a] waiting on main lock, timeout 100 ms
                        2008-07-01 10:45:02,590 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[n1-6hbh14if-1-bgoe14if-ttc17r-z5r4k5a] waiting on main lock, timeout 100 ms
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[r-m1zg14if-1-bgoe14if-ttc17r-z5r4k5a] done waiting on lock, buffer is empty
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[r-m1zg14if-1-bgoe14if-ttc17r-z5r4k5a]: 100 ms timeout expired
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[r-m1zg14if-1-bgoe14if-ttc17r-z5r4k5a] receiving, timeout = 100
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[r-m1zg14if-1-bgoe14if-ttc17r-z5r4k5a]: receive, timeout 100 ms, blocking poll on queue
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[r-m1zg14if-1-bgoe14if-ttc17r-z5r4k5a] waiting on main lock, timeout 100 ms
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[j1-6fbh14if-1-bgoe14if-ttc17r-z5r4k5a] done waiting on lock, buffer is empty
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[j1-6fbh14if-1-bgoe14if-ttc17r-z5r4k5a]: 100 ms timeout expired
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[j1-6fbh14if-1-bgoe14if-ttc17r-z5r4k5a] receiving, timeout = 100
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[j1-6fbh14if-1-bgoe14if-ttc17r-z5r4k5a]: receive, timeout 100 ms, blocking poll on queue
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[j1-6fbh14if-1-bgoe14if-ttc17r-z5r4k5a] waiting on main lock, timeout 100 ms
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[l1-xgbh14if-1-bgoe14if-ttc17r-z5r4k5a] done waiting on lock, buffer is empty
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[l1-xgbh14if-1-bgoe14if-ttc17r-z5r4k5a]: 100 ms timeout expired
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[l1-xgbh14if-1-bgoe14if-ttc17r-z5r4k5a] receiving, timeout = 100
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[l1-xgbh14if-1-bgoe14if-ttc17r-z5r4k5a]: receive, timeout 100 ms, blocking poll on queue
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[l1-xgbh14if-1-bgoe14if-ttc17r-z5r4k5a] waiting on main lock, timeout 100 ms
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[p-c1zg14if-1-bgoe14if-ttc17r-z5r4k5a] done waiting on lock, buffer is empty
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[p-c1zg14if-1-bgoe14if-ttc17r-z5r4k5a]: 100 ms timeout expired
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[p-c1zg14if-1-bgoe14if-ttc17r-z5r4k5a] receiving, timeout = 100
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[p-c1zg14if-1-bgoe14if-ttc17r-z5r4k5a]: receive, timeout 100 ms, blocking poll on queue
                        2008-07-01 10:45:02,630 TRACE [org.jboss.jms.client.container.ClientConsumer] ClientConsumer[p-c1zg14if-1-bgoe14if-ttc17r-z5r4k5a] waiting on main lock, timeout 100 ms
                        2008-07-01 10:45:02,654 INFO [com.pindartech.clipper.externalservice.ipservice.sb_ipservice.IPServiceMgrBean] IPServiceMgrBean::afterCompletion(On Receive) :: bCommitted::m_RequestUUIDfalse :: null :: com.pindartech.clipper.externalservice.ipservice.sb_ipservice.IPServiceMgrBean@15da7d5
                        2008-07-01 10:45:02,655 ERROR [org.jboss.jms.asf.StdServerSession] failed to commit/rollback
                        javax.transaction.HeuristicMixedException
                         at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1390)
                         at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
                         at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87)
                         at org.jboss.jms.asf.StdServerSession.onMessage(StdServerSession.java:351)
                         at org.jboss.mq.SpyMessageConsumer.sessionConsumerProcessMessage(SpyMessageConsumer.java:902)
                         at org.jboss.mq.SpyMessageConsumer.addMessage(SpyMessageConsumer.java:170)
                         at org.jboss.mq.SpySession.run(SpySession.java:323)
                         at org.jboss.jms.asf.StdServerSession.run(StdServerSession.java:194)
                         at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:743)
                         at java.lang.Thread.run(Thread.java:595)
                        
                        
                        
                        Thanks in advance
                        
                        


                        • 9. Re: TwoPhaseOutcome.HEURISTIC_HAZARD
                          Mark Little Master

                          Have you asked on the JBossMQ forums? Have you tried replacing JBossMQ with JBoss Messaging?

                          • 10. Re: TwoPhaseOutcome.HEURISTIC_HAZARD
                            Jerry Jacob Newbie

                            Finally we decided to upgrade MQ to Jboss messaging and with that it worked. We didnt want to do it as it was a generic application. We are also thinking about Jboss Messaging Bridging option