[infinispan-dev] [Fwd: [Fwd: Sometimes TCP responses not getting through on localhost]]

Zipped version :) -------- Original Message -------- Subject: [Fwd: Sometimes TCP responses not getting through on localhost] Date: Wed, 08 Jul 2009 17:52:14 +0200 From: Galder Zamarreno <galder.zamarreno(a)redhat.com&gt; To: infinispan-dev(a)lists.jboss.org <infinispan-dev(a)lists.jboss.org&gt; As a FYI: Not sure if you've seen similar but when running DIST tests, I randomly get stoppages like the one below. Just sending it to the rest of the team in case they have more info. Vladimir is planning to have a look to them at some point. -------- Original Message -------- Subject: Sometimes TCP responses not getting through on localhost Date: Tue, 07 Jul 2009 09:10:26 +0200 From: Galder Zamarreno <galder.zamarreno(a)redhat.com&gt; To: Vladimir Blagojevic <vladimir.blagojevic(a)jboss.com&gt; Hi Vladimir, I'm running one of the Infinispan distribution tests locally and from time to time, I'm seeing some stoppage receiving a response from one of the nodes. See attached infinispan and jgroups TRACE log. More importantly, focus on request id=1246949535122. First, 47089 sends a clustered get request: 2009-07-07 08:52:15,122 5920 TRACE [org.jgroups.protocols.TCP] (main:) sending msg to null, src=localhost.localdomain-47089, headers are MsgDisp: [Header: name=MsgDisp, type=REQ, id=1246949535122, rsp_expected=true], dest_mbrs=[localhost.localdomain-44649, localhost.localdomain-15543], NAKACK: [MSG, seqno=1], TCP: [channel_name=Infinispan-Cluster] 44649 deals with it and replies: infinispan.log:2749:2009-07-07 08:52:15,124 5922 TRACE [org.jgroups.blocks.RequestCorrelator] (Incoming-2,Infinispan-Cluster,localhost.localdomain-44649:) calling (org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher) with request 1246949535122 infinispan.log:2761:2009-07-07 08:52:15,125 5923 TRACE [org.jgroups.blocks.RequestCorrelator] (Incoming-2,Infinispan-Cluster,localhost.localdomain-44649:) sending rsp for 1246949535122 to localhost.localdomain-47089 infinispan.log:2765:2009-07-07 08:52:15,126 5924 TRACE [org.jgroups.protocols.TCP] (Incoming-2,Infinispan-Cluster,localhost.localdomain-44649:) sending msg to localhost.localdomain-47089, src=localhost.localdomain-44649, headers are MsgDisp: [Header: name=MsgDisp, type=RSP, id=1246949535122, rsp_expected=false], UNICAST: [UNICAST: DATA, seqno=1, conn_id=1246949535125, first], TCP: [channel_name=Infinispan-Cluster] 15543 deals with it too and replies: infinispan.log:2788:2009-07-07 08:52:15,129 5927 TRACE [org.jgroups.blocks.RequestCorrelator] (Incoming-1,Infinispan-Cluster,localhost.localdomain-15543:) calling (org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher) with request 1246949535122 infinispan.log:2800:2009-07-07 08:52:15,129 5927 TRACE [org.jgroups.blocks.RequestCorrelator] (Incoming-1,Infinispan-Cluster,localhost.localdomain-15543:) sending rsp for 1246949535122 to localhost.localdomain-47089 infinispan.log:2804:2009-07-07 08:52:15,130 5928 TRACE [org.jgroups.protocols.TCP] (Incoming-1,Infinispan-Cluster,localhost.localdomain-15543:) sending msg to localhost.localdomain-47089, src=localhost.localdomain-15543, headers are MsgDisp: [Header: name=MsgDisp, type=RSP, id=1246949535122, rsp_expected=false], UNICAST: [UNICAST: DATA, seqno=1, conn_id=1246949535130, first], TCP: [channel_name=Infinispan-Cluster] 47089 notes receiving it from 44649: infinispan.log:2806:2009-07-07 08:52:15,130 5928 TRACE [org.jgroups.protocols.TCP] (OOB-1,Infinispan-Cluster,localhost.localdomain-47089:) message is [dst: localhost.localdomain-47089, src: localhost.localdomain-15543 (3 headers), size=14 bytes, flags=OOB], headers are MsgDisp: [Header: name=MsgDisp, type=RSP, id=1246949535122, rsp_expected=false], UNICAST: [UNICAST: DATA, seqno=1, conn_id=1246949535130, first], TCP: [channel_name=Infinispan-Cluster] But after 15 seconds, 15543 has not been received: 2009-07-07 08:52:30,132 20930 TRACE [org.jgroups.blocks.GroupRequest] (main:) timed out waiting for responses 2009-07-07 08:52:30,133 20931 TRACE [org.jgroups.blocks.GroupRequest] (main:) call did not execute correctly, request is [req_id=1246949535122 caller=localhost.localdomain-47089 entries: localhost.localdomain-15543: sender=localhost.localdomain-15543, retval=null, received=false, suspected=false localhost.localdomain-44649: sender=localhost.localdomain-44649, retval=SuccessfulResponse, received=true, suspected=false Any idea what could be causing this? This is happening randomly, not in all runs. Is this related to that SingletonCacheStore stuff we saw last time around? Cheers, -- Galder Zamarreño Sr. Software Engineer Infinispan, JBoss Cache -- Galder Zamarreño Sr. Software Engineer Infinispan, JBoss Cache -- Galder Zamarreño Sr. Software Engineer Infinispan, JBoss Cache