Re: [jgroups-dev] Issue with TCPConnectionMap in jgroups 2.12.2.Final
Bela Ban <[email protected]> Thu, 28 Feb 2013 12:59:29 +0100
| Newsgroups | gmane.comp.java.javagroups.devel |
|---|---|
| Message-ID | <[email protected]> |
No, you won't lose ordering, as ordering is established higher up in the
stack; by UNICAST{2,3} or NAKACK{2} and not by the transport.
On 2/28/13 12:56 PM, Sundararajan, Mukund wrote:
> Thank you. I will disable send queues and try. If I set use_send_queues to false would I lose ordered delivery of messages? I think I won't but just want to double check. My messages need to be sent out in the same sequence in which they are produced and that has been working fine so far.
>
> Mukund
>
> On Feb 28, 2013, at 5:46 AM, "Bela Ban" <[email protected]> wrote:
>
>>
>> On 2/27/13 11:22 PM, Sundararajan, Mukund wrote:
>>>
>>> Hi Bela,
>>>
>>> I am running into an issue that is very similar to what was reported here -à https://issues.jboss.org/browse/JGRP-1157
>>
>> Actually, a more recent issue is https://issues.jboss.org/browse/JGRP-1600.
>>
>>
>>> Basically during application startup, jgroups forms a cluster with 9 other nodes. What I am seeing is sometimes all our threads get stuck in org/jgroups/blocks/TCPConnectionMap$TCPConnection$Sender.addToQueue(TCPConnectionMap.java:619). When this condition happens I have no other way out but to restart the application.
>>
>> Yes. I guess this happens when the producers (senders) use a connection entry (including the send-queue) which differs from the one the consumer (receiver thread) uses. The effect is that the consumer is waiting for work, while the producers are blocked, waiting for someone to empty the send-queue.
>>
>> I'll look into how this can happen in the 3.3 time frame, but a quick workaround should be to set use_send_queues to false in TCP.
>>
>>> I have thread dumps and have analyzed it thoroughly. What I see is there are 9 Sender threads waiting on LinkedBlockingQueue.take(). However the threads that are sending messages out are getting blocked on LinkedBlockingQueue.put() for a Connection for which the Sender thread has most probably terminated and hence there is no code waiting on take().
>>
>>
>> Terminated, or reading off of a different send-queue ? Search for "Connection.Sender". I remember a case where sender threads could terminate, but that was fixed. Don't remember the JIRA though.
>>
>>
>>> I say this because the Condition object that the 9 Sender threads are waiting on is different from the Condition object that the writers are blocked on!
>>
>>
>> You can't rely on this, as we're using a LinkedBlockingQueue, and there are 2 condition objects: notEmpty and notFull. The Connection.Sender threads are waiting on the notEmpty condition, while the producers would be waiting on the notFull condition object.
>>
>> Further comments down (look for [bela]).
>>
>>> *The nine Sender threads are the following - *
>>>
>>> "Connection.Sender [25.221.5.230:59891 - 25.221.12.6:9800],Enterprise-,ukwgc7unybcm02-41676(2)" id=14668 idx=0x6e8 tid=21005 prio=5 alive, parked, native_blocked
>>>
>>> -- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x9f88f638
>>>
>>> Connection.Sender [25.221.5.230:9800 - 25.221.13.101:35061],Enterprise-,ukwgc7unybcm02-41676(2)" id=14660 idx=0x928 tid=20997 prio=5 alive, parked, native_blocked
>>>
>>> -- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x9f7dfd80
>>>
>>> "Connection.Sender [25.221.5.230:43781 - 25.221.4.6:9800],Enterprise-,ukwgc7unybcm02-41676(2)" id=14670 idx=0x978 tid=21007 prio=5 alive, parked, native_blocked
>>>
>>> -- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x9f4cd3b0
>>>
>>> "Connection.Sender [25.221.5.230:52571 - 25.221.42.7:9800],Enterprise-,ukwgc7unybcm02-41676(2)" id=14674 idx=0x9c8 tid=21011 prio=5 alive, parked, native_blocked
>>>
>>> -- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x9f741e40
>>>
>>> "Connection.Sender [25.221.5.230:48129 - 25.221.42.6:9800],Enterprise-,ukwgc7unybcm02-41676(2)" id=14672 idx=0xa48 tid=21009 prio=5 alive, parked, native_blocked
>>>
>>> -- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x9f474138
>>>
>>> "Connection.Sender [25.221.5.230:41259 - 25.221.12.166:9800],Enterprise-,ukwgc7unybcm02-41676(2)" id=14664 idx=0xa6c tid=21001 prio=5 alive, parked, native_blocked
>>>
>>> -- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x9f772cd8
>>>
>>> "Connection.Sender [25.221.5.230:9800 - 25.221.2.5:35354],Enterprise-,ukwgc7unybcm02-41676(2)" id=14644 idx=0xa98 tid=19682 prio=5 alive, parked, native_blocked
>>>
>>> -- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x90bb3790
>>>
>>> "Connection.Sender [25.221.5.230:59870 - 25.221.13.230:9800],Enterprise-,ukwgc7unybcm02-41676(2)" id=14662 idx=0xb24 tid=20999 prio=5 alive, parked, native_blocked
>>>
>>> -- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x9f6bca10
>>>
>>> "Connection.Sender [25.221.5.230:36122 - 25.221.4.198:9800],Enterprise-,ukwgc7unybcm02-41676(2)" id=14666 idx=0xb44 tid=21003 prio=5 alive, parked, native_blocked
>>>
>>> -- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x9f5b0618
>>>
>>> *All my application threads are stuck in Sender.addToQueue() all waiting on the same Condition object *AbstractQueuedSynchronizer$ConditionObject@0x58590740. If you notice there is no Sender thread above that has a blocking take() call on this condition object.**
>>>
>>> [STUCK] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=20 idx=0x8c tid=26789 prio=1 alive, parked, native_blocked, daemon
>>>
>>> -- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x58590740
>>>
>>> [STUCK] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'" id=23 idx=0x98 tid=26792 prio=1 alive, parked, native_blocked, daemon
>>>
>>> -- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x58590740
>>>
>>> "[STUCK] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)'" id=30 idx=0xac tid=26802 prio=1 alive, parked, native_blocked, daemon
>>>
>>> -- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x58590740
>>>
>>> …..and so on. All my application threads (30 of them) are stuck in the same place.
>>
>>
>> [bela] Yes, got it. But doesn't show whether a Connection.Sender has died, or whether it uses a different connection entry.
>>
>>> *Here is the complete stack trace.*
>>>
>>> [STUCK] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=20 idx=0x8c tid=26789 prio=1 alive, parked, native_blocked, daemon
>>>
>>> -- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x58590740
>>>
>>> at jrockit/vm/Locks.park0(J)V(Native Method)
>>>
>>> at jrockit/vm/Locks.park(Locks.java:2230)[inlined]
>>>
>>> at jrockit/proxy/sun/misc/Unsafe.park(Unsafe.java:616)[inlined]
>>>
>>> at java/util/concurrent/locks/LockSupport.park(LockSupport.java:156)[inlined]
>>>
>>> at java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)[optimized]
>>>
>>> at java/util/concurrent/LinkedBlockingQueue.put(LinkedBlockingQueue.java:306)[optimized]
>>>
>>> at org/jgroups/blocks/TCPConnectionMap$TCPConnection$Sender.addToQueue(TCPConnectionMap.java:619)[inlined]
>>>
>>> at org/jgroups/blocks/TCPConnectionMap$TCPConnection.send(TCPConnectionMap.java:446)[inlined]
>>>
>>> at org/jgroups/blocks/TCPConnectionMap$TCPConnection.access$100(TCPConnectionMap.java:354)[inlined]
>>>
>>> at org/jgroups/blocks/TCPConnectionMap.send(TCPConnectionMap.java:167)[inlined]
>>>
>>> at org/jgroups/protocols/TCP.send(TCP.java:56)[optimized]
>>>
>>> at org/jgroups/protocols/BasicTCP.sendUnicast(BasicTCP.java:95)[optimized]
>>>
>>> at org/jgroups/protocols/TP.sendToSingleMember(TP.java:1214)[optimized]
>>>
>>> at org/jgroups/protocols/TP.doSend(TP.java:1198)[inlined]
>>>
>>> at org/jgroups/protocols/TP.send(TP.java:1184)[optimized]
>>>
>>> at org/jgroups/protocols/TP.down(TP.java:1041)[optimized]
>>>
>>> at org/jgroups/protocols/Discovery.down(Discovery.java:499)[inlined]
>>>
>>> at org/jgroups/protocols/TCPPING.down(TCPPING.java:149)[optimized]
>>>
>>> at org/jgroups/protocols/MERGE2.down(MERGE2.java:185)
>>>
>>> at org/jgroups/protocols/FD_SOCK.down(FD_SOCK.java:340)
>>>
>>> at org/jgroups/protocols/FD.down(FD.java:310)[optimized]
>>>
>>> at org/jgroups/protocols/VERIFY_SUSPECT.down(VERIFY_SUSPECT.java:72)[optimized]
>>>
>>> at org/jgroups/protocols/BARRIER.down(BARRIER.java:93)[optimized]
>>>
>>> at org/jgroups/protocols/pbcast/NAKACK.down(NAKACK.java:634)[optimized]
>>>
>>> at org/jgroups/protocols/UNICAST.send(UNICAST.java:450)[inlined]
>>>
>>> at org/jgroups/protocols/UNICAST.down(UNICAST.java:401)[optimized]
>>>
>>> at org/jgroups/protocols/pbcast/STABLE.down(STABLE.java:330)
>>>
>>> at org/jgroups/protocols/pbcast/GMS.down(GMS.java:977)
>>>
>>> at org/jgroups/protocols/UFC.handleDownMessage(UFC.java:123)
>>>
>>> at org/jgroups/protocols/FlowControl.down(FlowControl.java:341)
>>>
>>> at org/jgroups/protocols/FlowControl.sendCreditRequest(FlowControl.java:498)
>>>
>>> at org/jgroups/protocols/MFC.handleDownMessage(MFC.java:112)
>>>
>>> at org/jgroups/protocols/FlowControl.down(FlowControl.java:341)
>>>
>>> at org/jgroups/protocols/FRAG2.down(FRAG2.java:155)
>>>
>>> at org/jgroups/protocols/pbcast/STATE_TRANSFER.down(STATE_TRANSFER.java:214)
>>>
>>> at org/jgroups/stack/ProtocolStack.down(ProtocolStack.java:1081)
>>>
>>> at org/jgroups/JChannel.down(JChannel.java:1654)
>>>
>>> at org/jgroups/JChannel.send(JChannel.java:734)
>>>
>>> at com/ipc/ds/interzone/channel/IZChannel.sendMessage(IZChannel.java:138)
>>>
>>> at com/ipc/ds/interzone/channel/IZChannel.sendMessage(IZChannel.java:120)
>>>
>>> at com/ipc/ds/interzone/notification/LocalLineStatusNotificationListener.notify(LocalLineStatusNotificationListener.java:207)
>>>
>>> at com/ipc/ds/notification/adaptors/JNDIAdaptor.tell(Ljava/lang/String;Ljava/util/List;Lcom/ipc/ds/notification/Publishable;)V(Unknown Source)
>>>
>>> at com/ipc/ds/notification/core/NotificationEvent.fire()V(Unknown Source)
>>>
>>> at com/ipc/ds/notification/core/NotificationJob.run()V(Unknown Source)
>>>
>>> at com/ipc/ds/notification/ejb/LineStatusNotificationMDB.onMessage(Ljavax/jms/Message;)V(Unknown Source)
>>>
>>> at sun/reflect/GeneratedMethodAccessor552.invoke(Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;(Unknown Source)
>>>
>>> at sun/reflect/DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)[optimized]
>>>
>>> at java/lang/reflect/Method.invoke(Method.java:597)[optimized]
>>>
>>> at com/bea/core/repackaged/springframework/aop/support/AopUtils.invokeJoinpointUsingReflection(AopUtils.java:310)[inlined]
>>>
>>> at com/bea/core/repackaged/springframework/aop/framework/ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)[inlined]
>>>
>>> at com/bea/core/repackaged/springframework/aop/framework/ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)[optimized]
>>>
>>> at com/bea/core/repackaged/springframework/aop/support/DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
>>>
>>> at com/bea/core/repackaged/springframework/aop/support/DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
>>>
>>> at com/bea/core/repackaged/springframework/aop/framework/ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)[optimized]
>>>
>>> at com/bea/core/repackaged/springframework/aop/interceptor/ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)
>>>
>>> at com/bea/core/repackaged/springframework/aop/framework/ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)[optimized]
>>>
>>> at com/bea/core/repackaged/springframework/aop/support/DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
>>>
>>> at com/bea/core/repackaged/springframework/aop/support/DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
>>>
>>> at com/bea/core/repackaged/springframework/aop/framework/ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)[optimized]
>>>
>>> at com/bea/core/repackaged/springframework/aop/framework/JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)[optimized]
>>>
>>> at $Proxy195.onMessage(Ljavax/jms/Message;)V(Unknown Source)
>>>
>>> at weblogic/ejb/container/internal/MDListener.execute(MDListener.java:466)
>>>
>>> at weblogic/ejb/container/internal/MDListener.transactionalOnMessage(MDListener.java:371)
>>>
>>> at weblogic/ejb/container/internal/MDListener.onMessage(MDListener.java:327)
>>>
>>> at weblogic/jms/client/JMSSession.onMessage(JMSSession.java:4659)
>>>
>>> at weblogic/jms/client/JMSSession.execute(JMSSession.java:4345)[optimized]
>>>
>>> at weblogic/jms/client/JMSSession.executeMessage(JMSSession.java:3821)
>>>
>>> at weblogic/jms/client/JMSSession.access$000(JMSSession.java:115)
>>>
>>> at weblogic/jms/client/JMSSession$UseForRunnable.run(JMSSession.java:5170)
>>>
>>> at weblogic/work/SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:528)[optimized]
>>>
>>> at weblogic/work/ExecuteThread.execute(ExecuteThread.java:201)[optimized]
>>>
>>> at weblogic/work/ExecuteThread.run(ExecuteThread.java:173)
>>>
>>> at jrockit/vm/RNI.c2java(JJJJJ)V(Native Method)
>>>
>>> -- end of trace
>>>
>>> Is there a way out? This happens during application startup only under unknown circumstances. I would say 1 out of 10 times it happens.
>>
>> [bela]
>> Turn use_send_queues off. This removes the Connection.Sender threads and has the sending member send the message on its own thread.
>>
>>
>>> Our application starts sending out messages as soon as the JChannel gets connected. From netstat what I see is out of the 9 TCP connections, about 7 of them were initiated by this node to other nodes and 2 of them were initiated by other nodes. My bind port is 9800. For some connections I see the connection is from an ephemeral port on the remote side versus 9800. See example below. My server IP us 25.221.5.230. This connection was initiated by the remote side.
>>
>> [bela]
>> I recently changed concurrent connection setup: https://issues.jboss.org/browse/JGRP-1549. This might help, but is in 3.3.0.Beta1 (released today).
>>
>>
>>>
>>> I am trying to find a way out. Would setting use_send_queues to false help? At this point I have to stay with 2.12.2.Final since this code is running in the field but if an upgrade is inevitable I can look into it.
>>
>> [bela]
>> 2.12.x is unsupported, check https://community.jboss.org/wiki/Support for details.
>>
>> Once https://issues.jboss.org/browse/JGRP-1600 has been fixed, I suggest try it out. If you have comments, you can also add them to that case.
>>
>> --
>> Bela Ban, JGroups lead (http://www.jgroups.org)
>>
>
--
Bela Ban, JGroups lead (http://www.jgroups.org)
------------------------------------------------------------------------------
Everyone hates slow websites. So do we.
Make your web apps faster with AppDynamics
Download AppDynamics Lite for free today:
http://p.sf.net/sfu/appdyn_d2d_feb
_______________________________________________
Javagroups-development mailing list