OK I got the Trace log. This is real big so I just started a page or so above the time where the MDB gets the first message and stopped after a few messages were received. Tell me if this isn't enough information:
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.GetIDMsg13046161[msgType: m_getID, msgID: -2147483645, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.GetIDMsg13046161[msgType: m_getID, msgID: -2147483645, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.PingMsg22178007[msgType: m_ping, msgID: -2147483644, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.PingMsg22178007[msgType: m_ping, msgID: -2147483644, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_getID, msgID: -2147483645
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.PingMsg22178007[msgType: m_ping, msgID: -2147483644, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.GetIDMsg23136580[msgType: m_getID, msgID: -2147483645, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 9
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_ping, msgID: -2147483644
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : getID
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.PingMsg27750365[msgType: m_ping, msgID: -2147483644, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 21
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : ping
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : 1118189842093
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.PingMsg19645447[msgType: m_pong, msgID: -2147483643, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.PingMsg19645447[msgType: m_pong, msgID: -2147483643, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : ping
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 21
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.PingMsg19645447[msgType: m_pong, msgID: -2147483643, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_pong, msgID: -2147483643
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.PingMsg5428820[msgType: m_pong, msgID: -2147483643, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.sm.jdbc.JDBCStateManager] Client id 'ID:3' is logged in.
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : getID
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.GetIDMsg23136580[msgType: m_getID, msgID: -2147483645, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.GetIDMsg23136580[msgType: m_getID, msgID: -2147483645, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.UILClientILService] Begin handleMsg, msgType: 24
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.GetIDMsg23136580[msgType: m_getID, msgID: -2147483645, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 9
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.Connection] PONG serverTime=1118189842093 Connection@14252445[token=ConnectionToken:null/13b4ca0ce43f059ed183a45362b3cd77 rcvstate=STOPPED]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.UILClientILService] End handleMsg
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_getID, msgID: -2147483645
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Found replyMap msg: org.jboss.mq.il.uil2.msgs.GetIDMsg13046161[msgType: m_getID, msgID: -2147483645, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msg reply: org.jboss.mq.il.uil2.msgs.GetIDMsg13046161[msgType: m_getID, msgID: -2147483645, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.GetIDMsg13046161[msgType: m_getID, msgID: -2147483645, error: null]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.Connection] ClientID established Connection@14252445[token=ConnectionToken:ID:3/13b4ca0ce43f059ed183a45362b3cd77 rcvstate=STOPPED]
2005-06-07 17:17:22,093 TRACE [org.jboss.mq.SpySession] New session SpySession@20942907[tx=false ack=AUTO txid=null RUNNING connection=Connection@14252445[token=ConnectionToken:ID:3/13b4ca0ce43f059ed183a45362b3cd77 rcvstate=STOPPED]]
2005-06-07 17:17:22,109 TRACE [org.jboss.mq.SpyMessageProducer] New message producer SpyMessageProducer@342828[ dest=QUEUE.TestMessageQueue delivery=persist priority=4 ttl=0 disableMessageID=false disableTS=false session=SpySession@20942907[tx=false ack=AUTO txid=null RUNNING connection=Connection@14252445[token=ConnectionToken:ID:3/13b4ca0ce43f059ed183a45362b3cd77 rcvstate=STOPPED]]]
2005-06-07 17:17:22,109 TRACE [org.jboss.mq.SpySession] Adding producer SpyMessageProducer@342828[ dest=QUEUE.TestMessageQueue delivery=persist priority=4 ttl=0 disableMessageID=false disableTS=false session=SpySession@20942907[tx=false ack=AUTO txid=null RUNNING connection=Connection@14252445[token=ConnectionToken:ID:3/13b4ca0ce43f059ed183a45362b3cd77 rcvstate=STOPPED]]]
2005-06-07 17:17:22,125 INFO [STDOUT] Sending message: This is message 1
2005-06-07 17:17:22,140 TRACE [org.jboss.mq.SpyMessageProducer] Sending message SpyMessageProducer@342828[ dest=QUEUE.TestMessageQueue delivery=persist priority=4 ttl=0 disableMessageID=false disableTS=false session=SpySession@20942907[tx=false ack=AUTO txid=null RUNNING connection=Connection@14252445[token=ConnectionToken:ID:3/13b4ca0ce43f059ed183a45362b3cd77 rcvstate=STOPPED]]]
SpyTextMessage {
Header {
jmsDestination : QUEUE.TestMessageQueue
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:3-11181898421401
jmsTimeStamp : 1118189842140
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: true
msgReadOnly : false
producerClientId: ID:3
}
Body {
text :This is message 1
}
}
2005-06-07 17:17:22,140 TRACE [org.jboss.mq.SpySession] Sending message to server ID:3-11181898421401 SpySession@20942907[tx=false ack=AUTO txid=null RUNNING connection=Connection@14252445[token=ConnectionToken:ID:3/13b4ca0ce43f059ed183a45362b3cd77 rcvstate=STOPPED]]
2005-06-07 17:17:22,140 TRACE [org.jboss.mq.Connection] SendToServer message=ID:3-11181898421401 Connection@14252445[token=ConnectionToken:ID:3/13b4ca0ce43f059ed183a45362b3cd77 rcvstate=STOPPED]
2005-06-07 17:17:22,140 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.AddMsg13078018[msgType: m_addMessage, msgID: -2147483642, error: null]
2005-06-07 17:17:22,140 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.AddMsg13078018[msgType: m_addMessage, msgID: -2147483642, error: null]
2005-06-07 17:17:22,140 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_addMessage, msgID: -2147483642
2005-06-07 17:17:22,140 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.AddMsg20735572[msgType: m_addMessage, msgID: -2147483642, error: null]
2005-06-07 17:17:22,140 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 2
2005-06-07 17:17:22,140 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : addMessage
2005-06-07 17:17:22,140 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : SpyTextMessage {
Header {
jmsDestination : QUEUE.TestMessageQueue
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:3-11181898421401
jmsTimeStamp : 1118189842140
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: true
msgReadOnly : false
producerClientId: ID:3
}
Body {
text :This is message 1
}
}
2005-06-07 17:17:22,140 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
Principal: guest
Principal: Roles(members:j2ee,guest,john)
;principal=null;roles=Roles(members:j2ee,guest,john) for rolePrincipals [publisher, guest]
2005-06-07 17:17:22,140 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] About to add message 1 msg=0 hard NOT_STORED PERSISTENT queue=QUEUE.TestMessageQueue priority=4 lateClone=false hashCode=30035636 transaction=null
2005-06-07 17:17:22,140 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 1 msg=0 hard NOT_STORED PERSISTENT queue=QUEUE.TestMessageQueue priority=4 lateClone=false hashCode=30035636 transaction=null
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 1 msg=0 hard STORED PERSISTENT queue=QUEUE.TestMessageQueue priority=4 lateClone=false hashCode=30035636 transaction=null
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.server.BasicQueue] addMessage 1 msg=0 hard STORED PERSISTENT queue=QUEUE.TestMessageQueue priority=4 lateClone=false hashCode=30035636 null org.jboss.mq.server.PersistentQueue@14e3d95{id=QUEUE.TestMessageQueue}
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.server.BasicQueue] internalAddMessage 1 msg=0 hard STORED PERSISTENT queue=QUEUE.TestMessageQueue priority=4 lateClone=false hashCode=30035636 org.jboss.mq.server.PersistentQueue@14e3d95{id=QUEUE.TestMessageQueue}
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.server.BasicQueue] queueMessageForSending Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] 1 msg=0 hard STORED PERSISTENT queue=QUEUE.TestMessageQueue priority=4 lateClone=false hashCode=30035636 org.jboss.mq.server.PersistentQueue@14e3d95{id=QUEUE.TestMessageQueue}
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.AddMsg20735572[msgType: m_addMessage, msgID: -2147483642, error: null]
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.AddMsg20735572[msgType: m_addMessage, msgID: -2147483642, error: null]
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 2
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.AddMsg20735572[msgType: m_addMessage, msgID: -2147483642, error: null]
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_addMessage, msgID: -2147483642
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.Connection] Async deliver requests=[ReceiveRequest[message=ID:3-11181898421401 subscription=-2147483648] Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.il.uil2.SocketManager] Found replyMap msg: org.jboss.mq.il.uil2.msgs.AddMsg13078018[msgType: m_addMessage, msgID: -2147483642, error: null]
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.Connection] Processing request=ReceiveRequest[message=ID:3-11181898421401 subscription=-2147483648 Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msg reply: org.jboss.mq.il.uil2.msgs.AddMsg13078018[msgType: m_addMessage, msgID: -2147483642, error: null]
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.AddMsg13078018[msgType: m_addMessage, msgID: -2147483642, error: null]
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.Connection] Delivering messageid=0 to consumer=SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] messages=0 waitingForMessage=true internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] id=1,5,jboss] sessionPool=org.jboss.jms.asf.StdServerSessionPool@6742d0 connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]
2005-06-07 17:17:22,156 INFO [STDOUT] Sending message: This is message 2
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.SpyConnectionConsumer] Add message=ID:3-11181898421401 SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] messages=0 waitingForMessage=true internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] id=1,5,jboss] sessionPool=org.jboss.jms.asf.StdServerSessionPool@6742d0 connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.SpyMessageProducer] Sending message SpyMessageProducer@342828[ dest=QUEUE.TestMessageQueue delivery=persist priority=4 ttl=0 disableMessageID=false disableTS=false session=SpySession@20942907[tx=false ack=AUTO txid=null RUNNING connection=Connection@14252445[token=ConnectionToken:ID:3/13b4ca0ce43f059ed183a45362b3cd77 rcvstate=STOPPED]]]
SpyTextMessage {
Header {
jmsDestination : QUEUE.TestMessageQueue
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:3-11181898421562
jmsTimeStamp : 1118189842156
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: true
msgReadOnly : false
producerClientId: ID:3
}
Body {
text :This is message 2
}
}
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.SpyConnectionConsumer] run() got message message=ID:3-11181898421401 SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] messages=0 waitingForMessage=false internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] id=1,5,jboss] sessionPool=org.jboss.jms.asf.StdServerSessionPool@6742d0 connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.SpySession] Sending message to server ID:3-11181898421562 SpySession@20942907[tx=false ack=AUTO txid=null RUNNING connection=Connection@14252445[token=ConnectionToken:ID:3/13b4ca0ce43f059ed183a45362b3cd77 rcvstate=STOPPED]]
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.Connection] SendToServer message=ID:3-11181898421562 Connection@14252445[token=ConnectionToken:ID:3/13b4ca0ce43f059ed183a45362b3cd77 rcvstate=STOPPED]
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, round-trip msg=org.jboss.mq.il.uil2.msgs.AddMsg27035453[msgType: m_addMessage, msgID: -2147483641, error: null]
2005-06-07 17:17:22,156 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.AddMsg27035453[msgType: m_addMessage, msgID: -2147483641, error: null]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpyConnectionConsumer] Waiting for serverSesionPool SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] messages=0 waitingForMessage=false internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] id=1,5,jboss] sessionPool=org.jboss.jms.asf.StdServerSessionPool@6742d0 connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]
2005-06-07 17:17:22,171 TRACE [org.jboss.jms.asf.StdServerSessionPool] getting a server session
2005-06-07 17:17:22,171 TRACE [org.jboss.jms.asf.StdServerSessionPool] using server session: org.jboss.jms.asf.StdServerSession@1539d49
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpyConnectionConsumer] Waited serverSesion=org.jboss.jms.asf.StdServerSession@1539d49 session=SpySession@18621578[tx=true txid=null XA RUNNING connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]] SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] messages=0 waitingForMessage=false internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] id=1,5,jboss] sessionPool=org.jboss.jms.asf.StdServerSessionPool@6742d0 connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpySession] Add message msgid=ID:3-11181898421401 SpySession@18621578[tx=true txid=null XA RUNNING connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpyConnectionConsumer] Starting the ServerSession=org.jboss.jms.asf.StdServerSession@1539d49 SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] messages=0 waitingForMessage=false internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] id=1,5,jboss] sessionPool=org.jboss.jms.asf.StdServerSessionPool@6742d0 connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]
2005-06-07 17:17:22,171 TRACE [org.jboss.jms.asf.StdServerSession] starting invokes on server session
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.Connection] Receive subscription=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] wait=-1
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : receive
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : -2147483648
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : -1
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.security.ServerSecurityInterceptor] Checking receive authorize on ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a subId=-2147483648
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
Principal: guest
Principal: Roles(members:j2ee,guest,john)
;principal=null;roles=Roles(members:j2ee,guest,john) for rolePrincipals [publisher, guest]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.BasicQueue] receive Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] wait=false org.jboss.mq.server.PersistentQueue@14e3d95{id=QUEUE.TestMessageQueue}
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : receive
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpyConnectionConsumer] run() receivedNoWait got no messageSpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] messages=0 waitingForMessage=false internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] id=1,5,jboss] sessionPool=org.jboss.jms.asf.StdServerSessionPool@6742d0 connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.Connection] Receive subscription=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] wait=0
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_addMessage, msgID: -2147483641
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : receive
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.il.uil2.SocketManager] Read new msg: org.jboss.mq.il.uil2.msgs.AddMsg21023091[msgType: m_addMessage, msgID: -2147483641, error: null]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : -2147483648
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : 0
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.security.ServerSecurityInterceptor] Checking receive authorize on ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a subId=-2147483648
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin handleMsg, msgType: 2
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
Principal: guest
Principal: Roles(members:j2ee,guest,john)
;principal=null;roles=Roles(members:j2ee,guest,john) for rolePrincipals [publisher, guest]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED : addMessage
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.BasicQueue] receive Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] wait=true org.jboss.mq.server.PersistentQueue@14e3d95{id=QUEUE.TestMessageQueue}
2005-06-07 17:17:22,171 TRACE [org.jboss.jms.asf.StdServerSession] running...
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : SpyTextMessage {
Header {
jmsDestination : QUEUE.TestMessageQueue
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:3-11181898421562
jmsTimeStamp : 1118189842156
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: true
msgReadOnly : false
producerClientId: ID:3
}
Body {
text :This is message 2
}
}
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.BasicQueue] addReceiver Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] org.jboss.mq.server.PersistentQueue@14e3d95{id=QUEUE.TestMessageQueue}
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpySession] Run messages=1 SpySession@18621578[tx=true txid=null XA RUNNING connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.security.SecurityManager] Checking authorize on subjectInfo: SubjectInfo {subject=Subject:
Principal: guest
Principal: Roles(members:j2ee,guest,john)
;principal=null;roles=Roles(members:j2ee,guest,john) for rolePrincipals [publisher, guest]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : receive
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpyXAResourceManager] Starting tx with new xid=-9223372036854775808
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] About to add message 2 msg=1 hard NOT_STORED PERSISTENT queue=QUEUE.TestMessageQueue priority=4 lateClone=false hashCode=32844677 transaction=null
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpyConnectionConsumer] run() waiting for message SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] messages=0 waitingForMessage=true internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] id=1,5,jboss] sessionPool=org.jboss.jms.asf.StdServerSessionPool@6742d0 connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpySession] Setting current tx xid=-9223372036854775808 previous: null SpySession@18621578[tx=true txid=null XA RUNNING connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpyMessageConsumer] consumer() acking message in tx message=ID:3-11181898421401 SpyMessageConsumer@8084664[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@1539d49 session=SpySession@18621578[tx=true txid=-9223372036854775808 XA RUNNING connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpyXAResourceManager] Adding acked message xid=-9223372036854775808 ID:3-11181898421401
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Inserting message 2 msg=1 hard NOT_STORED PERSISTENT queue=QUEUE.TestMessageQueue priority=4 lateClone=false hashCode=32844677 transaction=null
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpyMessageConsumer] consumer() before onMessage=ID:3-11181898421401 SpyMessageConsumer@8084664[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] listening=true receiving=false sessionConsumer=true waitingForMessage=false messages=0 listener=org.jboss.jms.asf.StdServerSession@1539d49 session=SpySession@18621578[tx=true txid=-9223372036854775808 XA RUNNING connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]]
2005-06-07 17:17:22,171 TRACE [org.jboss.jms.asf.StdServerSession] onMessage running (pool, session, xaSession, useLocalTX): , SpySession@18621578[tx=true txid=-9223372036854775808 XA RUNNING connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]], SpySession@18621578[tx=true txid=-9223372036854775808 XA RUNNING connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]], false
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpyXAResource] Start xid=XidImpl[FormatId=257, GlobalId=webreachdmz01/20, BranchQual=1, localId=20], flags=0 SpyXAResource[session=SpySession@18621578[tx=true txid=-9223372036854775808 XA RUNNING connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpyXAResourceManager] Converting tx anonXid=-9223372036854775808, xid=XidImpl[FormatId=257, GlobalId=webreachdmz01/20, BranchQual=1, localId=20]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpySession] Setting current tx xid=XidImpl[FormatId=257, GlobalId=webreachdmz01/20, BranchQual=1, localId=20] previous: -9223372036854775808 SpySession@18621578[tx=true txid=-9223372036854775808 XA RUNNING connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]
2005-06-07 17:17:22,171 TRACE [org.jboss.jms.asf.StdServerSession] XAResource 'SpyXAResource[session=SpySession@18621578[tx=true txid=XidImpl[FormatId=257, GlobalId=webreachdmz01/20, BranchQual=1, localId=20] XA RUNNING connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]]' enlisted.
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager] Added message 2 msg=1 hard STORED PERSISTENT queue=QUEUE.TestMessageQueue priority=4 lateClone=false hashCode=32844677 transaction=null
2005-06-07 17:17:22,171 TRACE [org.jboss.ejb.plugins.jms.JMSContainerInvoker] processing message: SpyTextMessage {
Header {
jmsDestination : QUEUE.TestMessageQueue
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:3-11181898421401
jmsTimeStamp : 1118189842140
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: false
msgReadOnly : true
producerClientId: ID:3
}
Body {
text :This is message 1
}
}
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.BasicQueue] addMessage 2 msg=1 hard STORED PERSISTENT queue=QUEUE.TestMessageQueue priority=4 lateClone=false hashCode=32844677 null org.jboss.mq.server.PersistentQueue@14e3d95{id=QUEUE.TestMessageQueue}
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.BasicQueue] internalAddMessage 2 msg=1 hard STORED PERSISTENT queue=QUEUE.TestMessageQueue priority=4 lateClone=false hashCode=32844677 org.jboss.mq.server.PersistentQueue@14e3d95{id=QUEUE.TestMessageQueue}
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.BasicQueue] queueMessageForSending Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] 2 msg=1 hard STORED PERSISTENT queue=QUEUE.TestMessageQueue priority=4 lateClone=false hashCode=32844677 org.jboss.mq.server.PersistentQueue@14e3d95{id=QUEUE.TestMessageQueue}
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN : addMessage
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.AddMsg21023091[msgType: m_addMessage, msgID: -2147483641, error: null]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.AddMsg21023091[msgType: m_addMessage, msgID: -2147483641, error: null]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End handleMsg, msgType: 2
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.il.uil2.SocketManager] Write msg: org.jboss.mq.il.uil2.msgs.AddMsg21023091[msgType: m_addMessage, msgID: -2147483641, error: null]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msgType: m_addMessage, msgID: -2147483641
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.il.uil2.SocketManager] Found replyMap msg: org.jboss.mq.il.uil2.msgs.AddMsg27035453[msgType: m_addMessage, msgID: -2147483641, error: null]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.il.uil2.SocketManager] Read msg reply: org.jboss.mq.il.uil2.msgs.AddMsg27035453[msgType: m_addMessage, msgID: -2147483641, error: null]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.Connection] Async deliver requests=[ReceiveRequest[message=ID:3-11181898421562 subscription=-2147483648] Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.Connection] Processing request=ReceiveRequest[message=ID:3-11181898421562 subscription=-2147483648 Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.Connection] Delivering messageid=0 to consumer=SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] messages=0 waitingForMessage=true internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] id=1,5,jboss] sessionPool=org.jboss.jms.asf.StdServerSessionPool@6742d0 connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.SpyConnectionConsumer] Add message=ID:3-11181898421562 SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] messages=0 waitingForMessage=true internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a destination=QUEUE.TestMessageQueue messageSelector=null Local Create] id=1,5,jboss] sessionPool=org.jboss.jms.asf.StdServerSessionPool@6742d0 connection=Connection@12716179[token=ConnectionToken:ID:1/8fb3d6c946ff131386c233fbbf84ee5a rcvstate=STARTED]]
2005-06-07 17:17:22,171 TRACE [org.jboss.mq.il.uil2.SocketManager] End internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.AddMsg27035453[msgType: m_addMessage, msgID: -2147483641, error: null]
2005-06-07 17:17:22,171 INFO [STDOUT] Sending message: This is message 3
2005-06-07 17:17:22,187 TRACE [org.jboss.mq.SpyMessageProducer] Sending message SpyMessageProducer@342828[ dest=QUEUE.TestMessageQueue delivery=persist priority=4 ttl=0 disableMessageID=false disableTS=false session=SpySession@20942907[tx=false ack=AUTO txid=null RUNNING connection=Connection@14252445[token=ConnectionToken:ID:3/13b4ca0ce43f059ed183a45362b3cd77 rcvstate=STOPPED]]]
SpyTextMessage {
Header {
jmsDestination : QUEUE.TestMessageQueue
jmsDeliveryMode : 2
jmsExpiration : 0
jmsPriority : 4
jmsMessageID : ID:3-11181898421873
jmsTimeStamp : 1118189842187
jmsCorrelationID: null
jmsReplyTo : null
jmsType : null
jmsRedelivered : false
jmsProperties : {}
jmsPropReadWrite: true
msgReadOnly : false
producerClientId: ID:3
}
Body {
text :This is message 3
}
}