3 Replies Latest reply on Mar 27, 2012 5:44 AM by danezu

JBM clients hangs when creating connections/sessions

danezu Jan 4, 2012 8:22 AM

Hello guys

We're facing a problem with JMS remote clients hanging like forever when trying to create connections/sessions on a JBoss Messaging 1.4.5.SP1 on JBoss 4.2.3 GA

The setup is the following:

- JBoss Servers:

# 3 JBoss 4.2.3 GA set up in cluster, with the same multi-cast IP address and partition name

# JBoss Messaging 1.4.5 SP1 installed on each one of them, with one queue and 5 topics, all clustered and with durable subscriptions

# MySQL 5.5.9 as persistence layer for JBM

# persisten messages needed, no message should be ever lost

- remote clients

# simple clients that looks up for {code}XAConnectionFactory{code}, and send every 30 secs more than one message, every time with JNDI lookup, create connection & session (all are closed in the finally clause). One addition: on the client side is made XA resource enlisting with the remote target queue and the transaction is managed by hand on both client and JBM side.

The load from the client side to the server is not so high, like 10,000 - 20,000 messages per day, but after 8-10 days the cluster gets unresponsive to new JMS remote connections, and the clinet threads are hanging. The local message processing, i.e. on each node on the topics works, which led me to the fact that can be a problem with JBoss Remoting

The client threads are locking in this point:

{code}

Thread: JMS SessionPool Worker-0 : priority:5, demon:true, threadId:228, threadState:RUNNABLE, lockName:null

java.net.SocketInputStream.socketRead0(Native Method)

java.net.SocketInputStream.read(SocketInputStream.java:129)

java.io.BufferedInputStream.fill(BufferedInputStream.java:218)

java.io.BufferedInputStream.read(BufferedInputStream.java:237)

java.io.FilterInputStream.read(FilterInputStream.java:66)

org.jboss.remoting.transport.socket.MicroSocketClientInvoker.readVersion(MicroSocketClientInvoker.java:1077)

org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:682)

org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:458)

org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:141)

org.jboss.remoting.Client.invoke(Client.java:1925)

org.jboss.remoting.Client.invoke(Client.java:786)

org.jboss.jms.client.delegate.ClientConnectionFactoryDelegate.org$jboss$jms$client$delegate$ClientConnectionFactoryDelegate$createConnectionDelegate$aop(ClientConnectionFactoryDelegate.java:178)

org.jboss.jms.client.delegate.ClientConnectionFactoryDelegate$createConnectionDelegate_N3019492359065420858.invokeNext(ClientConnectionFactoryDelegate$createConnectionDelegate_N3019492359065420858.java)

org.jboss.jms.client.container.StateCreationAspect.handleCreateConnectionDelegate(StateCreationAspect.java:80)

org.jboss.aop.advice.org.jboss.jms.client.container.StateCreationAspect0.invoke(StateCreationAspect0.java)

org.jboss.jms.client.delegate.ClientConnectionFactoryDelegate.createConnectionDelegate(ClientConnectionFactoryDelegate.java)

org.jboss.jms.client.JBossConnectionFactory.createConnectionInternal(JBossConnectionFactory.java:205)

org.jboss.jms.client.JBossConnectionFactory.createXAQueueConnection(JBossConnectionFactory.java:142)

{code}

Have anyone encountered this behavior?

Regards,

Daniel

1. Re: JBM clients hangs when creating connections/sessions

danezu Jan 10, 2012 7:43 AM (in response to danezu)

Hi again

After getting again the same situation a, I made a thread dump on the server side to see what is happening, and there were two types of blocked threads:
- the JBM's get message count:

"RMI TCP Connection(1910)-172.19.60.78" daemon prio=10 tid=0x00007f83f3aa3800 nid=0x1c12 waiting for monitor entry [0x0000000061f66000..0x0000000061f68b20]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.jboss.messaging.core.impl.ChannelSupport.getMessageCount(ChannelSupport.java:480)
        - waiting to lock <0x00007f840e9f3048> (a java.lang.Object)
        at org.jboss.messaging.core.impl.PagingChannelSupport.getMessageCount(PagingChannelSupport.java:148)

- the XA commits made from the remote client:

WorkManager(2)-33444" daemon prio=10 tid=0x00007f83e85eb800 nid=0x1aa5 waiting for monitor entry [0x000000005f23a000..0x000000005f23bca0]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.jboss.messaging.core.impl.ChannelSupport$InMemoryCallback.afterCommit(ChannelSupport.java:1025)
        - waiting to lock <0x00007f840e9f3048> (a java.lang.Object)
        at org.jboss.messaging.core.impl.tx.Transaction.commit(Transaction.java:228)
        - locked <0x00007f84383f5cd0> (a org.jboss.messaging.core.impl.tx.Transaction)
        at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.sendTransaction(ServerConnectionEndpoint.java:517)

All of the threads seems to be waiting for the same object lock: <0x00007f840e9f3048>

The blocking threads (like almost 400 of them) lead to unresponsive JMS queue.

It seems that the getMessageCount and afterCommit are waiting for a lock that tryies to synch the situation inside JBM's table with the memory refs.

Doesn anyone knows where I can find this lock, i.e. the concrete type? The following classes seems to use it: ServerConnectionEndpoint, org.jboss.messaging.core.impl.tx.Transaction, org.jboss.messaging.core.impl.ChannelSupport (->PagingChannelSupport -> MessagingQueue)

Regards,
Actions
2. Re: JBM clients hangs when creating connections/sessions

mgrossmann Feb 22, 2012 3:41 AM (in response to danezu)

Hi Daniel,

in the thread dump you sent to me i found the thread which holds the lock you mentioned above:

"WorkManager(2)-29869" daemon prio=10 tid=0x00007f83f4aaa400 nid=0x78df runnable [0x000000005ba01000..0x000000005ba03c20]
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:129)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
    - locked <0x00007f843449d950> (a java.io.BufferedInputStream)
    at java.io.FilterInputStream.read(FilterInputStream.java:66)
    at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.readVersion(MicroSocketClientInvoker.java:1077)
    at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:682)
    at org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:458)
    at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:141)
    at org.jboss.remoting.Client.invoke(Client.java:1925)
    at org.jboss.remoting.Client.invoke(Client.java:786)
    at org.jboss.remoting.Client.invoke(Client.java:774)
    at org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:189)
    at org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:160)
    at org.jboss.jms.client.delegate.ClientConsumerDelegate.org$jboss$jms$client$delegate$ClientConsumerDelegate$changeRate$aop(ClientConsumerDelegate.java:138)
    at org.jboss.jms.client.delegate.ClientConsumerDelegate$changeRate_N952316153687074823.invokeNext(ClientConsumerDelegate$changeRate_N952316153687074823.java)
    at org.jboss.jms.client.container.FailoverValveInterceptor.invoke(FailoverValveInterceptor.java:92)
    at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
    at org.jboss.jms.client.delegate.ClientConsumerDelegate$changeRate_N952316153687074823.invokeNext(ClientConsumerDelegate$changeRate_N952316153687074823.java)
    at org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170)
    at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
    at org.jboss.jms.client.delegate.ClientConsumerDelegate$changeRate_N952316153687074823.invokeNext(ClientConsumerDelegate$changeRate_N952316153687074823.java)
    at org.jboss.jms.client.delegate.ClientConsumerDelegate.changeRate(ClientConsumerDelegate.java)
    at org.jboss.jms.client.container.ClientConsumer.sendChangeRateMessage(ClientConsumer.java:754)
    at org.jboss.jms.client.container.ClientConsumer.pause(ClientConsumer.java:669)
    - locked <0x00007f8434479d38> (a java.lang.Object)
    at org.jboss.messaging.core.impl.clusterconnection.MessageSucker.setConsuming(MessageSucker.java:317)
    - locked <0x00007f840dc3dbf8> (a org.jboss.messaging.core.impl.clusterconnection.MessageSucker)
    at org.jboss.messaging.core.impl.MessagingQueue.informSuckers(MessagingQueue.java:566)
    at org.jboss.messaging.core.impl.MessagingQueue.setReceiversReady(MessagingQueue.java:529)
    - locked <0x00007f840e9f29f0> (a org.jboss.messaging.core.impl.MessagingQueue)
    at org.jboss.messaging.core.impl.ChannelSupport.deliverInternal(ChannelSupport.java:667)
    at org.jboss.messaging.core.impl.MessagingQueue.deliverInternal(MessagingQueue.java:506)
    at org.jboss.messaging.core.impl.ChannelSupport$InMemoryCallback.afterCommit(ChannelSupport.java:1072)
    - locked <0x00007f840e9f3048> (a java.lang.Object)
    at org.jboss.messaging.core.impl.tx.Transaction.commit(Transaction.java:228)
    - locked <0x00007f8433fa4e20> (a org.jboss.messaging.core.impl.tx.Transaction)
    at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.sendTransaction(ServerConnectionEndpoint.java:517)

This thread is also hanging in a socketRead0() which is triggered from
org.jboss.remoting.transport.socket.MicroSocketClientInvoker.readVersion(MicroSocketClientInvoker.java:1077)
This is the point all threads are hanging even on client side. But i have no idea why the inputStream cannot be read.

You mentioned that the local message processing works, so i assume there is no issue with the database.

Regards,
Matthias
Actions
3. Re: JBM clients hangs when creating connections/sessions

danezu Mar 27, 2012 5:44 AM (in response to mgrossmann)

Hi Mathias

The issue reappeared again this morning. Later investigations led me to the conclusion that the class which does the blocking seems to be the MessageSucker, when it tries to move messages between the nodes.

I have the following thread dump:

"Thread-28596" daemon prio=10 tid=0x00007f96e3736800 nid=0x3b1c in Object.wait() [0x0000000050c28000..0x0000000050c28ba0]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.lang.Object.wait(Object.java:485)
    at org.jboss.messaging.util.Future.getResult(Future.java:51)
    - locked <0x00007f982519ef50> (a org.jboss.messaging.util.Future)
    at org.jboss.jms.client.container.ClientConsumer.waitForOnMessageToComplete(ClientConsumer.java:779)
    at org.jboss.jms.client.container.ClientConsumer.close(ClientConsumer.java:442)
    at org.jboss.jms.client.container.ConsumerAspect.handleClosing(ConsumerAspect.java:150)
    at org.jboss.aop.advice.org.jboss.jms.client.container.ConsumerAspect55.invoke(ConsumerAspect55.java)
    at org.jboss.jms.client.delegate.ClientConsumerDelegate$closing_2473194355759371067.invokeNext(ClientConsumerDelegate$closing_2473194355759371067.java)
    at org.jboss.jms.client.container.FailoverValveInterceptor.invoke(FailoverValveInterceptor.java:92)
    at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
    at org.jboss.jms.client.delegate.ClientConsumerDelegate$closing_2473194355759371067.invokeNext(ClientConsumerDelegate$closing_2473194355759371067.java)
    at org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170)
    at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
    at org.jboss.jms.client.delegate.ClientConsumerDelegate$closing_2473194355759371067.invokeNext(ClientConsumerDelegate$closing_2473194355759371067.java)
    at org.jboss.jms.client.delegate.ClientConsumerDelegate.closing(ClientConsumerDelegate.java)
    at org.jboss.messaging.core.impl.clusterconnection.MessageSucker.suspend(MessageSucker.java:217)
    - locked <0x00007f972efdd2a8> (a org.jboss.messaging.core.impl.clusterconnection.MessageSucker)
    at org.jboss.messaging.core.impl.clusterconnection.ClusterConnectionManager$ConnectionInfo.cleanupConnection(ClusterConnectionManager.java:804)
    - locked <0x00007f972efdd988> (a org.jboss.messaging.core.impl.clusterconnection.ClusterConnectionManager$ConnectionInfo)
    at org.jboss.messaging.core.impl.clusterconnection.ClusterConnectionManager$ConnectionInfo.onException(ClusterConnectionManager.java:785)
    at org.jboss.jms.client.remoting.ConsolidatedRemotingConnectionListener.handleConnectionException(ConsolidatedRemotingConnectionListener.java:120)
    at org.jboss.remoting.ConnectionValidator$1.run(ConnectionValidator.java:498)

which it correlates to the following warn inside server.log:

2012-03-27 00:47:24,258 WARN [org.jboss.messaging.core.impl.clusterconnection.ClusterConnectionManager] Connection failure detected. Clean up and retry connection. maxRetry: -1 retryInterval: 5000

It seems that the MessageSucker had problems to release the locks after a connection failure between nodes.... and from here a whole cascade of events triggered, because all the other connections that tried to access the targeted queue (which is clustered) are waiting for the instance of it to be released by MessageSucker.

Daniel
Actions

Go to original post