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