I see a very high cpu utilization (400% on 8 cpu server) when I connect
consumers to OpenQ. It increase close to 100% for every consumer I add.
Slowly, the consumer comes to a halt, as the producers are sending messages
at a good rate too.
/Environment Setup/
Glassfish version 2.1
com.sun.messaging.jmq Version Information
Product Compatibility Version: 4.3
Protocol Version: 4.3
Target JMS API Version: 1.1
Cluster set up using persistent storage. snippet from broker log.
Java Runtime: 1.6.0_14 Sun Microsystems Inc.
/home/user/foundation/jdk-1.6/jre
[06/Apr/2011:12:48:44 EDT] IMQ_HOME=/home/user/foundation/sges/imq
[06/Apr/2011:12:48:44 EDT]
IMQ_VARHOME=/home/user/foundation/installation/node-agent-server1/server1/imq
[06/Apr/2011:12:48:44 EDT] Linux 2.6.18-164.10.1.el5xen i386 server1 (8 cpu)
user
[06/Apr/2011:12:48:44 EDT] Java Heap Size: max=394432k, current=193920k
[06/Apr/2011:12:48:44 EDT] Arguments: -javahome /home/user/foundation/jdk-1.6
-Dimq.autocreate.queue=false -Dimq.autocreate.topic=false
-Dimq.cluster.masterbroker=mq://server1:37676/
-Dimq.cluster.brokerlist=mq://server1:37676/,mq://server2:37676/
-Dimq.cluster.nowaitForMasterBroker=true -varhome
/home/user/foundation/installation/node-agent-server1/server1/imq
-startRmiRegistry -rmiRegistryPort 37776 -Dimq.imqcmd.user=admin -passfile
/tmp/asmq5711749746025968663.tmp -save -name clusterservercom -port 37676
-bgnd -silent
[06/Apr/2011:12:48:44 EDT] [B1004]: Starting the portmapper service using tcp
[ 37676, 50, * ] with min threads 1 and max threads of 1
[06/Apr/2011:12:48:45 EDT] [B1060]: Loading persistent data...
I followed step in
http://middlewaremagic.com/weblogic/?p=4884 to narrow it
down to Threads that was causing high cpu. Both were around 94%.
Following is the stack for those threads.
"Thread-jms[224]" prio=10 tid=0xd635f400 nid=0x5665 runnable [0xd18fe000]
java.lang.Thread.State: RUNNABLE
at
com.sun.messaging.jmq.jmsserver.data.TransactionList.isConsumedInTransaction(TransactionList.java:697)
at
com.sun.messaging.jmq.jmsserver.core.Session.detatchConsumer(Session.java:918)
- locked <0xf3d35730> (a
java.util.Collections$SynchronizedMap)
at
com.sun.messaging.jmq.jmsserver.core.Session.detatchConsumer(Session.java:810)
at
com.sun.messaging.jmq.jmsserver.data.handlers.ConsumerHandler.destroyConsumer(ConsumerHandler.java:577)
at
com.sun.messaging.jmq.jmsserver.data.handlers.ConsumerHandler.handle(ConsumerHandler.java:422)
at
com.sun.messaging.jmq.jmsserver.data.PacketRouter.handleMessage(PacketRouter.java:181)
at
com.sun.messaging.jmq.jmsserver.service.imq.IMQIPConnection.readData(IMQIPConnection.java:1489)
at
com.sun.messaging.jmq.jmsserver.service.imq.IMQIPConnection.process(IMQIPConnection.java:644)
at
com.sun.messaging.jmq.jmsserver.service.imq.OperationRunnable.process(OperationRunnable.java:170)
at
com.sun.messaging.jmq.jmsserver.util.pool.BasicRunnable.run(BasicRunnable.java:493)
at java.lang.Thread.run(Thread.java:619)
Locked ownable synchronizers:
- None
"Thread-jms[214]" prio=10 tid=0xd56c8000 nid=0x566c waiting for monitor entry
[0xd2838000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
com.sun.messaging.jmq.jmsserver.data.TransactionInformation.isConsumedMessage(TransactionList.java:2544)
- locked <0xdbeeb538> (a
com.sun.messaging.jmq.jmsserver.data.TransactionInformation)
at
com.sun.messaging.jmq.jmsserver.data.TransactionList.isConsumedInTransaction(TransactionList.java:697)
at
com.sun.messaging.jmq.jmsserver.core.Session.detatchConsumer(Session.java:918)
- locked <0xe4c9abf0> (a
java.util.Collections$SynchronizedMap)
at
com.sun.messaging.jmq.jmsserver.core.Session.detatchConsumer(Session.java:810)
at
com.sun.messaging.jmq.jmsserver.data.handlers.ConsumerHandler.destroyConsumer(ConsumerHandler.java:577)
at
com.sun.messaging.jmq.jmsserver.data.handlers.ConsumerHandler.handle(ConsumerHandler.java:422)
at
com.sun.messaging.jmq.jmsserver.data.PacketRouter.handleMessage(PacketRouter.java:181)
at
com.sun.messaging.jmq.jmsserver.service.imq.IMQIPConnection.readData(IMQIPConnection.java:1489)
at
com.sun.messaging.jmq.jmsserver.service.imq.IMQIPConnection.process(IMQIPConnection.java:644)
at
com.sun.messaging.jmq.jmsserver.service.imq.OperationRunnable.process(OperationRunnable.java:170)
at
com.sun.messaging.jmq.jmsserver.util.pool.BasicRunnable.run(BasicRunnable.java:493)
at java.lang.Thread.run(Thread.java:619)
Locked ownable synchronizers:
- None
"Thread-jms[213]" prio=10 tid=0xd65be800 nid=0x5670 runnable [0xd1a28000]
java.lang.Thread.State: RUNNABLE
at
com.sun.messaging.jmq.jmsserver.data.TransactionList.isConsumedInTransaction(TransactionList.java:697)
at
com.sun.messaging.jmq.jmsserver.core.Session.detatchConsumer(Session.java:918)
- locked <0xe4c4bad8> (a
java.util.Collections$SynchronizedMap)
at
com.sun.messaging.jmq.jmsserver.core.Session.detatchConsumer(Session.java:810)
at
com.sun.messaging.jmq.jmsserver.data.handlers.ConsumerHandler.destroyConsumer(ConsumerHandler.java:577)
at
com.sun.messaging.jmq.jmsserver.data.handlers.ConsumerHandler.handle(ConsumerHandler.java:422)
at
com.sun.messaging.jmq.jmsserver.data.PacketRouter.handleMessage(PacketRouter.java:181)
at
com.sun.messaging.jmq.jmsserver.service.imq.IMQIPConnection.readData(IMQIPConnection.java:1489)
at
com.sun.messaging.jmq.jmsserver.service.imq.IMQIPConnection.process(IMQIPConnection.java:644)
at
com.sun.messaging.jmq.jmsserver.service.imq.OperationRunnable.process(OperationRunnable.java:170)
at
com.sun.messaging.jmq.jmsserver.util.pool.BasicRunnable.run(BasicRunnable.java:493)
at java.lang.Thread.run(Thread.java:619)
Locked ownable synchronizers:
- None
--
[Message sent by forum member 'vmiharia']
View Post: http://forums.java.net/node/789360