[JBoss JIRA] (ISPN-7489) org.jgroups.protocols.TCP emits errors when node leaves the cluster

Saturday, 18 February 2017

    [
https://issues.jboss.org/browse/ISPN-7489?page=com.atlassian.jira.plugin....
] 

Sebastian Łaskawiec commented on ISPN-7489:
-------------------------------------------

Another example:
{noformat}
[transactions-repository-2-pd4c7] 18:26:48,055 ERROR [org.jgroups.protocols.TCP]
(jgroups-22,transactions-repository-2-pd4c7) JGRP000029: transactions-repository-2-pd4c7:
failed sending message to transactions-repository-2-jms3k (104 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2415, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=7070, conn_id=1, TP: [cluster_name=cluster]
[transactions-repository-2-pd4c7] [GC (Allocation Failure)  808852K->535816K(1013632K),
0.0264148 secs]
[transactions-repository-2-1gk60] 18:26:48,384 ERROR [org.jgroups.protocols.TCP]
(jgroups-36,transactions-repository-2-1gk60) JGRP000029: transactions-repository-2-1gk60:
failed sending message to transactions-repository-2-jms3k (106 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2426, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=12125, conn_id=3, TP: [cluster_name=cluster]
[transactions-repository-2-pd4c7] [GC (Allocation Failure)  815432K->522173K(1013632K),
0.0094881 secs]
[transactions-repository-2-pd4c7] 18:26:48,857 ERROR [org.jgroups.protocols.TCP]
(jgroups-32,transactions-repository-2-pd4c7) JGRP000029: transactions-repository-2-pd4c7:
failed sending message to transactions-repository-2-jms3k (104 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2415, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=7070, conn_id=1, TP: [cluster_name=cluster]
[transactions-repository-2-pd4c7] [GC (Allocation Failure)  801789K->523993K(1013632K),
0.0111717 secs]
[transactions-repository-2-1gk60] 18:26:49,186 ERROR [org.jgroups.protocols.TCP]
(jgroups-36,transactions-repository-2-1gk60) JGRP000029: transactions-repository-2-1gk60:
failed sending message to transactions-repository-2-jms3k (106 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2426, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=12125, conn_id=3, TP: [cluster_name=cluster]
[transactions-repository-2-1gk60] 18:26:49,590 INFO  [org.infinispan.CLUSTER]
(remote-thread--p2-t18)
[Context=transactions][Context=transactions-repository-2-pd4c7]ISPN100003: Finished local
rebalance
[transactions-repository-2-pd4c7] 18:26:49,659 ERROR [org.jgroups.protocols.TCP]
(jgroups-23,transactions-repository-2-pd4c7) JGRP000029: transactions-repository-2-pd4c7:
failed sending message to transactions-repository-2-jms3k (104 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2415, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=7070, conn_id=1, TP: [cluster_name=cluster]
[transactions-repository-2-1gk60] 18:26:49,987 ERROR [org.jgroups.protocols.TCP]
(jgroups-32,transactions-repository-2-1gk60) JGRP000029: transactions-repository-2-1gk60:
failed sending message to transactions-repository-2-jms3k (106 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2426, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=12125, conn_id=3, TP: [cluster_name=cluster]
[transactions-repository-2-pd4c7] 18:26:50,461 ERROR [org.jgroups.protocols.TCP]
(jgroups-23,transactions-repository-2-pd4c7) JGRP000029: transactions-repository-2-pd4c7:
failed sending message to transactions-repository-2-jms3k (104 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2415, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=7070, conn_id=1, TP: [cluster_name=cluster]
[transactions-repository-2-1gk60] 18:26:50,789 ERROR [org.jgroups.protocols.TCP]
(jgroups-32,transactions-repository-2-1gk60) JGRP000029: transactions-repository-2-1gk60:
failed sending message to transactions-repository-2-jms3k (106 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2426, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=12125, conn_id=3, TP: [cluster_name=cluster]
[transactions-repository-2-pd4c7] 18:26:51,262 ERROR [org.jgroups.protocols.TCP]
(jgroups-23,transactions-repository-2-pd4c7) JGRP000029: transactions-repository-2-pd4c7:
failed sending message to transactions-repository-2-jms3k (104 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2415, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=7070, conn_id=1, TP: [cluster_name=cluster]
[transactions-repository-2-1gk60] [GC (Allocation Failure)  706815K->441667K(1013632K),
0.0366909 secs]
[transactions-repository-2-1gk60] 18:26:51,591 ERROR [org.jgroups.protocols.TCP]
(jgroups-32,transactions-repository-2-1gk60) JGRP000029: transactions-repository-2-1gk60:
failed sending message to transactions-repository-2-jms3k (106 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2426, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=12125, conn_id=3, TP: [cluster_name=cluster]
[transactions-repository-2-pd4c7] 18:26:52,063 ERROR [org.jgroups.protocols.TCP]
(jgroups-23,transactions-repository-2-pd4c7) JGRP000029: transactions-repository-2-pd4c7:
failed sending message to transactions-repository-2-jms3k (104 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2415, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=7070, conn_id=1, TP: [cluster_name=cluster]
[transactions-repository-2-1gk60] 18:26:52,395 ERROR [org.jgroups.protocols.TCP]
(jgroups-32,transactions-repository-2-1gk60) JGRP000029: transactions-repository-2-1gk60:
failed sending message to transactions-repository-2-jms3k (106 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2426, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=12125, conn_id=3, TP: [cluster_name=cluster]
[transactions-repository-2-pd4c7] 18:26:52,867 ERROR [org.jgroups.protocols.TCP]
(jgroups-23,transactions-repository-2-pd4c7) JGRP000029: transactions-repository-2-pd4c7:
failed sending message to transactions-repository-2-jms3k (104 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2415, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=7070, conn_id=1, TP: [cluster_name=cluster]
[transactions-repository-2-1gk60] 18:26:53,197 ERROR [org.jgroups.protocols.TCP]
(jgroups-32,transactions-repository-2-1gk60) JGRP000029: transactions-repository-2-1gk60:
failed sending message to transactions-repository-2-jms3k (106 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2426, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=12125, conn_id=3, TP: [cluster_name=cluster]
[transactions-repository-2-pd4c7] [GC (Allocation Failure)  803579K->533000K(1013632K),
0.0314847 secs]
[transactions-repository-2-pd4c7] 18:26:53,672 ERROR [org.jgroups.protocols.TCP]
(jgroups-21,transactions-repository-2-pd4c7) JGRP000029: transactions-repository-2-pd4c7:
failed sending message to transactions-repository-2-jms3k (104 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2415, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=7070, conn_id=1, TP: [cluster_name=cluster]
[transactions-repository-2-1gk60] 18:26:54,001 ERROR [org.jgroups.protocols.TCP]
(jgroups-32,transactions-repository-2-1gk60) JGRP000029: transactions-repository-2-1gk60:
failed sending message to transactions-repository-2-jms3k (106 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2426, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=12125, conn_id=3, TP: [cluster_name=cluster]
[transactions-repository-2-pd4c7] 18:26:54,474 ERROR [org.jgroups.protocols.TCP]
(jgroups-23,transactions-repository-2-pd4c7) JGRP000029: transactions-repository-2-pd4c7:
failed sending message to transactions-repository-2-jms3k (104 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2415, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=7070, conn_id=1, TP: [cluster_name=cluster]
[transactions-repository-2-1gk60] 18:26:54,803 ERROR [org.jgroups.protocols.TCP]
(jgroups-24,transactions-repository-2-1gk60) JGRP000029: transactions-repository-2-1gk60:
failed sending message to transactions-repository-2-jms3k (106 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2426, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=12125, conn_id=3, TP: [cluster_name=cluster]
[transactions-repository-2-pd4c7] 18:26:55,276 ERROR [org.jgroups.protocols.TCP]
(jgroups-23,transactions-repository-2-pd4c7) JGRP000029: transactions-repository-2-pd4c7:
failed sending message to transactions-repository-2-jms3k (104 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2415, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=7070, conn_id=1, TP: [cluster_name=cluster]
[transactions-repository-2-1gk60] 18:26:55,607 ERROR [org.jgroups.protocols.TCP]
(jgroups-24,transactions-repository-2-1gk60) JGRP000029: transactions-repository-2-1gk60:
failed sending message to transactions-repository-2-jms3k (106 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2426, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=12125, conn_id=3, TP: [cluster_name=cluster]
[transactions-repository-2-1gk60] 18:26:55,916 INFO 
[org.infinispan.remoting.transport.jgroups.JGroupsTransport]
(jgroups-32,transactions-repository-2-1gk60) ISPN000094: Received new cluster view for
channel clustered: [transactions-repository-2-1gk60|11] (4)
[transactions-repository-2-1gk60, transactions-repository-2-pd4c7,
transactions-repository-3-6mzvd, transactions-repository-3-bv2mj]
[transactions-repository-2-1gk60] 18:26:55,917 INFO  [org.infinispan.CLUSTER]
(jgroups-32,transactions-repository-2-1gk60) ISPN100000: Node
transactions-repository-3-bv2mj joined the cluster
[transactions-repository-2-pd4c7] 18:26:55,945 INFO 
[org.infinispan.remoting.transport.jgroups.JGroupsTransport]
(jgroups-23,transactions-repository-2-pd4c7) ISPN000094: Received new cluster view for
channel clustered: [transactions-repository-2-1gk60|11] (4)
[transactions-repository-2-1gk60, transactions-repository-2-pd4c7,
transactions-repository-3-6mzvd, transactions-repository-3-bv2mj]
[transactions-repository-2-pd4c7] 18:26:55,946 INFO  [org.infinispan.CLUSTER]
(jgroups-23,transactions-repository-2-pd4c7) ISPN100000: Node
transactions-repository-3-bv2mj joined the cluster
[transactions-repository-2-1gk60] 18:26:56,409 ERROR [org.jgroups.protocols.TCP]
(jgroups-24,transactions-repository-2-1gk60) JGRP000029: transactions-repository-2-1gk60:
failed sending message to transactions-repository-2-jms3k (106 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2426, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=12125, conn_id=3, TP: [cluster_name=cluster]
[transactions-repository-2-pd4c7] 18:26:56,747 ERROR [org.jgroups.protocols.TCP]
(jgroups-32,transactions-repository-2-pd4c7) JGRP000029: transactions-repository-2-pd4c7:
failed sending message to transactions-repository-2-jms3k (104 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2415, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=7070, conn_id=1, TP: [cluster_name=cluster]
[transactions-repository-2-1gk60] 18:26:57,210 ERROR [org.jgroups.protocols.TCP]
(jgroups-24,transactions-repository-2-1gk60) JGRP000029: transactions-repository-2-1gk60:
failed sending message to transactions-repository-2-jms3k (106 bytes):
java.net.SocketTimeoutException: connect timed out, headers: RequestCorrelator:
corr_id=200, type=RSP, req_id=2426, rsp_expected=true, FORK: cluster:clustered, UNICAST3:
DATA, seqno=12125, conn_id=3, TP: [cluster_name=cluster]
{noformat}

Full logs: https://gist.github.com/slaskawi/d789431ab5f16d46136dafffd7d4a89e

...
 org.jgroups.protocols.TCP emits errors when node leaves the cluster
 -------------------------------------------------------------------

                 Key: ISPN-7489
                 URL: https://issues.jboss.org/browse/ISPN-7489
             Project: Infinispan
          Issue Type: Sub-task
          Components: Cloud Integrations, Core
    Affects Versions: 9.0.0.CR1
         Environment: * OpenShift {{v1.5.0-alpha.2+e4b43ee}}
 * Custom Infinispan Server build (based on [these
instructions|https://github.com/slaskawi/infinispan-1/tree/custom_image]). SHA1
{{2b0731b21649a88a75ed71d21b9cc06ba365e947}}
            Reporter: Sebastian Łaskawiec

 When I was performing [Spring Session and Kubernetes Rolling Update
demo|https://bluejeans.com/s/pYKUg/] I encountered a couple of problems.
 One of the is this:
 {noformat}
 [transactions-repository-1-04x09] 18:09:12,193 ERROR [org.jgroups.protocols.TCP]
(jgroups-30,transactions-repository-1-04x09) JGRP000029: transactions-repository-1-04x09:
failed sending message to transactions-repository-1-4z05w (71 bytes):
java.net.SocketTimeoutException: connect timed out, headers: GMS: GmsHeader[VIEW_ACK],
UNICAST3: DATA, seqno=5262, TP: [cluster_name=cluster]
 [transactions-repository-1-1f8dx] 18:09:12,310 ERROR [org.jgroups.protocols.TCP]
(jgroups-16,transactions-repository-1-1f8dx) JGRP000029: transactions-repository-1-1f8dx:
failed sending message to transactions-repository-1-4z05w (71 bytes):
java.net.SocketTimeoutException: connect timed out, headers: GMS: GmsHeader[VIEW_ACK],
UNICAST3: DATA, seqno=6259, TP: [cluster_name=cluster]
 [transactions-repository-1-04x09] 18:09:12,997 ERROR [org.jgroups.protocols.TCP]
(jgroups-22,transactions-repository-1-04x09) JGRP000029: transactions-repository-1-04x09:
failed sending message to transactions-repository-1-4z05w (71 bytes):
java.net.SocketTimeoutException: connect timed out, headers: GMS: GmsHeader[VIEW_ACK],
UNICAST3: DATA, seqno=5262, TP: [cluster_name=cluster]
 [transactions-repository-1-1f8dx] 18:09:13,113 ERROR [org.jgroups.protocols.TCP]
(jgroups-16,transactions-repository-1-1f8dx) JGRP000029: transactions-repository-1-1f8dx:
failed sending message to transactions-repository-1-4z05w (71 bytes):
java.net.SocketTimeoutException: connect timed out, headers: GMS: GmsHeader[VIEW_ACK],
UNICAST3: DATA, seqno=6259, TP: [cluster_name=cluster]
 {noformat}
 Full logs from Rolling Update process might be found here:
https://gist.github.com/slaskawi/530241bb695f1f490bcb25eabaf9d676
 Steps to reproduce:
 * Start local OpenShift Cluster
 * invoke `./init_infrastructure.sh` from
https://github.com/slaskawi/presentations/tree/ISPN-7487-reproducer
 * invoke `cd transaction-creator && mvn fabric8:run`
 * Do the rolling update: `oc deploy transactions-repository --latest -n myproject`
 * Observe logs `kubetail -l environment=infrastructure` 

--
This message was sent by Atlassian JIRA
(v7.2.3#72005)

2026

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009