8:18 p.m.
Hi,
We are having a production issue at the moment while submitting messages into a queue.
Using Jboss 4.0.4GA
When a message is submitted in the queue, it is consumed successfully. We have about 40
consumers. However when the messages grow in number, we start facing a lot of problem.
The queue depth of the queue drops to 0. Imaging that we have about 3000 messages in the
queue. 40 consumers looking in the same queue, as soon as the consumers are up, the
messages in the queue (watch from jmx-console) drop to 0, even though the messages are
still present in the table. The consumers process the first batch of messages and since
the queue is 0, they wait and only pick up any new message that come in.
The code of the consumer is pretty simple, picks up a message, that would delete it from
the queue, process it and return it back.
On tracing the logs, i found the following messages. I hope someone can throw light on the
messages.
anonymous wrote :
| 2007-07-15 20:34:10,967 34037114 TRACE
[org.jboss.mq.il.uil2.ServerSocketManagerHandler] (UIL2(SocketManager.MsgPool@a425da
client=10.0.10.76:1057)#44:) Begin handleMsg, msgType: 17
| 2007-07-15 20:34:10,967 34037114 TRACE [org.jboss.mq.server.TracingInterceptor]
(UIL2(SocketManager.MsgPool@a425da client=10.0.10.76:1057)#44:) CALLED : transact
| 2007-07-15 20:34:10,967 34037114 TRACE [org.jboss.mq.server.TracingInterceptor]
(UIL2(SocketManager.MsgPool@a425da client=10.0.10.76:1057)#44:) ARG :
org.jboss.mq.TransactionRequest@ced1c1
| 2007-07-15 20:34:10,967 34037114 TRACE [org.jboss.mq.server.BasicQueue]
(UIL2(SocketManager.MsgPool@a425da client=10.0.10.76:1057)#44:) acknowledge
AcknowledgementRequest:NACK,QUEUE.dispatchToNodeQueue,ID:80-11845251473901932 40564
org.jboss.mq.server.PersistentQueue(a)12da4a6{id=QUEUE.dispatchToNodeQ
| ueue}
| 2007-07-15 20:34:10,967 34037114 TRACE [org.jboss.mq.server.BasicQueue]
(UIL2(SocketManager.MsgPool@a425da client=10.0.10.76:1057)#44:) acknowledge
AcknowledgementRequest:NACK,QUEUE.dispatchToNodeQueue,ID:80-11845252759362864 40564
org.jboss.mq.server.PersistentQueue(a)12da4a6{id=QUEUE.dispatchToNodeQ
| ueue}
| 2007-07-15 20:34:10,967 34037114 TRACE [org.jboss.mq.server.BasicQueue]
(UIL2(SocketManager.MsgPool@a425da client=10.0.10.76:1057)#44:) acknowledge
AcknowledgementRequest:NACK,QUEUE.dispatchToNodeQueue,ID:80-11845305688096079 40564
org.jboss.mq.server.PersistentQueue(a)12da4a6{id=QUEUE.dispatchToNodeQ
| ueue}
| 2007-07-15 20:34:10,968 34037115 TRACE [org.jboss.mq.server.BasicQueue]
(UIL2(SocketManager.MsgPool@a425da client=10.0.10.76:1057)#44:) acknowledge
AcknowledgementRequest:NACK,QUEUE.dispatchToNodeQueue,ID:80-11845305690466087 40564
org.jboss.mq.server.PersistentQueue(a)12da4a6{id=QUEUE.dispatchToNodeQ
| ueue}
| ....................
|
followed by
anonymous wrote :
| 2007-07-15 20:34:10,976 34037123 TRACE [org.jboss.mq.server.BasicQueue]
(UIL2(SocketManager.MsgPool@a425da client=10.0.10.76:1057)#44:) Restoring message: 4911
msg=4523 hard STORED PERSISTENT queue=QUEUE.dispatchToNodeQueue priority=4 lateClone=false
hashCode=16957640
| 2007-07-15 20:34:10,976 34037123 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager]
(UIL2(SocketManager.MsgPool@a425da client=10.0.10.76:1057)#44:) Updating message 4911
msg=4523 hard STORED PERSISTENT queue=QUEUE.dispatchToNodeQueue priority=4 lateClone=false
hashCode=16957640 transaction=null
| 2007-07-15 20:34:10,980 34037127 TRACE [org.jboss.mq.pm.jdbc2.PersistenceManager]
(UIL2(SocketManager.MsgPool@a425da client=10.0.10.76:1057)#44:) Updated message 4911
msg=4523 hard STORED PERSISTENT queue=QUEUE.dispatchToNodeQueue priority=4 lateClone=false
hashCode=16957640 transaction=null
| 2007-07-15 20:34:10,982 34037129 TRACE [org.jboss.mq.server.BasicQueue]
(UIL2(SocketManager.MsgPool@a425da client=10.0.10.76:1057)#44:) internalAddMessage 4911
msg=4523 hard STORED PERSISTENT queue=QUEUE.dispatchToNodeQueue priority=4 lateClone=false
hashCode=16957640 org.jboss.mq.server.Persistent
| Queue(a)12da4a6{id=QUEUE.dispatchToNodeQueue}
| 2007-07-15 20:34:10,982 34037129 TRACE [org.jboss.mq.server.BasicQueue]
(UIL2(SocketManager.MsgPool@a425da client=10.0.10.76:1057)#44:) queueMessageForSending
Subscription[subId=-2147483648connection=ConnectionToken:ID:6970/48f674041eb704d4535a29e854646d8f
destination=QUEUE.dispatchToNodeQueue mess
| ageSelector=null Local Create] 4911 msg=4523 hard STORED PERSISTENT
queue=QUEUE.dispatchToNodeQueue priority=4 lateClone=false hashCode=16957640
org.jboss.mq.server.PersistentQueue(a)12da4a6{id=QUEUE.dispatchToNodeQueue}
|
and so on.
At this point, the queue depth rises but drops steadily again.
However this does not happen all the time, I believe it is triggrered by a message Begin
handleMsg, msgType: 17 . I am unable to understand what is invoking the same.
Hope some one can throw light on the same.
I have caught something else as well, the message cache softens all the messages even if
enough memory is available and these messages are lost and are not loaded again.
anonymous wrote : 2007-07-15 14:18:17,740 TRACE [org.jboss.mq.server.MessageCache] Memory
usage serverity=0.22467656
| 2007-07-15 14:18:17,740 TRACE [org.jboss.mq.server.MessageCache] Need to soften 242
messages
| 2007-07-15 14:18:17,740 TRACE [org.jboss.mq.server.MessageCache] Memory usage
serverity=0.22526875
| 2007-07-15 14:18:17,740 TRACE [org.jboss.mq.server.MessageCache] Need to soften 242
messages
| 2007-07-15 14:18:17,740 TRACE [org.jboss.mq.server.MessageCache] Memory usage
serverity=0.22586171
| 2007-07-15 14:18:17,740 TRACE [org.jboss.mq.server.MessageCache] Need to soften 241
messages
| 2007-07-15 14:18:17,740 TRACE [org.jboss.mq.server.MessageCache] Memory usage
serverity=0.22621797
| 2007-07-15 14:18:17,740 TRACE [org.jboss.mq.server.MessageCache] Need to soften 241
messages
| 2007-07-15 14:18:17,740 TRACE [org.jboss.mq.server.MessageCache] Memory usage
serverity=0.2265625
| 2007-07-15 14:18:17,740 TRACE [org.jboss.mq.server.MessageCache] Need to soften 240
messages
| 2007-07-15 14:18:17,740 TRACE [org.jboss.mq.server.MessageCache] Memory usage
serverity=0.22694063
| 2007-07-15 14:18:17,741 TRACE [org.jboss.mq.server.MessageCache] Need to soften 240
messages
|
And after the above gets over - the queue depth is 0.
One more observation:-
anonymous wrote :
| 2007-07-15 11:43:03,179 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] Begin
handleMsg, msgType: 13
| 2007-07-15 11:43:03,179 TRACE [org.jboss.mq.server.TracingInterceptor] CALLED :
receive
| 2007-07-15 11:43:03,179 TRACE [org.jboss.mq.server.TracingInterceptor] ARG :
-2147483648
| 2007-07-15 11:43:03,179 TRACE [org.jboss.mq.server.TracingInterceptor] ARG : 60000
| 2007-07-15 11:43:03,179 TRACE [org.jboss.mq.security.ServerSecurityInterceptor]
Checking receive authorize on ConnectionToken:ID:12/407a40114e31809c640bd2cb2f6f5021
subId=-2147483648
| 2007-07-15 11:43:03,179 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 [guest]
| 2007-07-15 11:43:03,180 TRACE [org.jboss.mq.server.BasicQueue] receive
Subscription[subId=-2147483648connection=ConnectionToken:ID:12/407a40114e31809c640bd2cb2f6f5021
destination=QUEUE.dispatchToNodeQueue messageSelector=null Local Create] wait=true
org.jboss.mq.server.PersistentQueue(a)12da4a6{id=QUEUE.dispatchToNodeQueue}
| 2007-07-15 11:43:03,180 TRACE [org.jboss.mq.server.TracingInterceptor] RETURN :
receive
| 2007-07-15 11:43:03,180 TRACE [org.jboss.mq.il.uil2.SocketManager] Begin
internalSendMessage, one-way msg=org.jboss.mq.il.uil2.msgs.ReceiveMsg33018671[msgType:
m_receive, msgID: 30, error: null]
| 2007-07-15 11:43:03,180 TRACE [org.jboss.mq.il.uil2.SocketManager] End
internalSendMessage, msg=org.jboss.mq.il.uil2.msgs.ReceiveMsg33018671[msgType: m_receive,
msgID: 30, error: null]
| 2007-07-15 11:43:03,180 TRACE [org.jboss.mq.il.uil2.ServerSocketManagerHandler] End
handleMsg, msgType: 13
|
I wonder what msgType:13 stands for. When the above happens the messages drop.
I am at lost what to do. The production system cannot be brought down or experimented
upon. Also we are unable to reproduce the same at a lesser load.
If anyone could provide some suggestions or throw light upon the above events it would be
a great help.
Thanks.
Taj
View the original post :
http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4064396#...
Reply to the post :
http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&a...