[
https://issues.jboss.org/browse/JGRP-1658?page=com.atlassian.jira.plugin....
]
Bela Ban edited comment on JGRP-1658 at 7/18/13 5:23 AM:
---------------------------------------------------------
Here's the snippet from the attached log that shows this:
{noformat}
11:55:54,529 TRACE (OOB-2,NodeA-24853:) [UNICAST2] NodeA-24853 <-- DATA(NodeC-49011:
#17)
11:55:54,529 TRACE (OOB-2,NodeA-24853:) [UNICAST2] NodeA-24853 -->
SEND_FIRST_SEQNO(NodeC-49011,17)
11:55:54,529 TRACE (OOB-2,NodeA-24853:) [TCP] NodeA-24853: sending msg to NodeC-49011,
src=NodeA-24853, headers are UNICAST2: SEND_FIRST_SEQNO, seqno=17, TCP:
[channel_name=ISPN]
11:55:54,529 TRACE (TransferQueueBundler,NodeA:) [TCP] NodeA: sending 1 msgs (56 bytes
(0.09% of max_bundle_size) to 1 destination(s)
11:55:54,529 TRACE (TransferQueueBundler,NodeA:) [TCP] dest=127.0.0.1:8002 (60 bytes)
11:55:54,529 TRACE (OOB-3,NodeC:) [TCP] NodeC: received message batch of 1 messages from
NodeA
11:55:54,529 TRACE (OOB-3,NodeC:) [UNICAST2] NodeC <-- SEND_FIRST_SEQNO(NodeA,17)
11:55:54,529 TRACE (OOB-3,NodeC:) [TCP] NodeC: sending msg to NodeA, src=NodeC, headers
are GMS: GmsHeader[JOIN_REQ]: mbr=NodeC, UNICAST2: DATA, seqno=1, first, TCP:
[channel_name=ISPN]
{noformat}
was (Author: belaban):
Here's the snippet from the attached log that shows this:
{noformat}
11:55:54,529 TRACE (OOB-2,NodeA-24853:) [UNICAST2] NodeA-24853 <-- DATA(NodeC-49011:
#17)
11:55:54,529 TRACE (OOB-2,NodeA-24853:) [UNICAST2] NodeA-24853 -->
SEND_FIRST_SEQNO(NodeC-49011,17)
11:55:54,529 TRACE (OOB-2,NodeA-24853:) [TCP] NodeA-24853: sending msg to NodeC-49011,
src=NodeA-24853, headers are UNICAST2: SEND_FIRST_SEQNO, seqno=17, TCP:
[channel_name=ISPN]
11:55:54,529 TRACE (TransferQueueBundler,NodeA-24853:) [TCP] NodeA-24853: sending 1 msgs
(56 bytes (0.09% of max_bundle_size) to 1 destination(s)
11:55:54,529 TRACE (TransferQueueBundler,NodeA-24853:) [TCP] dest=127.0.0.1:8002 (60
bytes)
11:55:54,529 TRACE (OOB-3,NodeC-49011:) [TCP] NodeC-49011: received message batch of 1
messages from NodeA-24853
11:55:54,529 TRACE (OOB-3,NodeC-49011:) [UNICAST2] NodeC-49011 <--
SEND_FIRST_SEQNO(NodeA-24853,17)
11:55:54,527 DEBUG (Incoming-1,NodeD-19538:) [FD_SOCK] VIEW_CHANGE received: [NodeA-24853,
NodeB-25374, NodeD-19538]
11:55:54,527 TRACE (transport-thread-3,NodeA:___defaultcache) [TCP] dest=127.0.0.1:8001
(160 bytes)
11:55:54,529 TRACE (OOB-3,NodeC-49011:) [TCP] NodeC-49011: sending msg to NodeA-24853,
src=NodeC-49011, headers are GMS: GmsHeader[JOIN_REQ]: mbr=NodeC-49011, UNICAST2: DATA,
seqno=1, first, TCP: [channel_name=ISPN]
11:55:54,529 TRACE (OOB-4,NodeD-19538:) [TCP] NodeD-19538: received [dst: NodeD-19538,
src: NodeB-25374 (3 headers), size=127 bytes, flags=OOB|DONT_BUNDLE|NO_TOTAL_ORDER],
headers are RequestCorrelator: id=200, type=REQ, id=93582, rsp_expected=true, UNICAST2:
DATA, seqno=2, conn_id=2, TCP: [channel_name=ISPN]
{noformat}
GMS: Node re-joining the cluster during shutdown
------------------------------------------------
Key: JGRP-1658
URL:
https://issues.jboss.org/browse/JGRP-1658
Project: JGroups
Issue Type: Bug
Affects Versions: 3.3.1
Reporter: Dan Berindei
Assignee: Bela Ban
Fix For: 3.4
Attachments: pfapt.log.gz
We have RSVP in the stack, with ack_on_delivery=true.
It seems that node C receives a RSVP-flagged message just after it sent the LEAVE_REQ to
A, and immediately after sending the RSVP ACK it sends a JOIN_REQ as well.
{noformat}
11:55:54,524 DEBUG (testng:) [DefaultCacheManager] Stopping cache manager ISPN on C
11:55:54,525 DEBUG (testng:) [GMS] C: sending LEAVE request to A
11:55:54,525 TRACE (testng:) [TCP] C: sending msg to A, src=C, headers are GMS:
GmsHeader[LEAVE_REQ]: mbr=C, UNICAST2: DATA, seqno=16, TCP: [channel_name=ISPN]
11:55:54,526 TRACE (ViewHandler,A:) [GMS] A: new members=[], suspected=[], leaving=[C],
new view: [A|4] [A, B, D]
11:55:54,528 TRACE (OOB-3,C:) [TCP] C: received [dst: <null>, src: A (4 headers),
size=7469 bytes, flags=OOB|DONT_BUNDLE|NO_TOTAL_ORDER|RSVP], headers are
RequestCorrelator: id=200, type=REQ, id=93579, rsp_expected=false, exclusion_list=[A],
RSVP: REQ(7), NAKACK2: [MSG, seqno=9], TCP: [channel_name=ISPN]
11:55:54,528 TRACE (OOB-3,C:) [TCP] C: sending msg to A, src=C, headers are RSVP: RSP(7),
UNICAST2: DATA, seqno=17, TCP: [channel_name=ISPN]
11:55:54,529 TRACE (OOB-3,C:) [TCP] C: sending msg to A, src=C, headers are GMS:
GmsHeader[JOIN_REQ]: mbr=C, UNICAST2: DATA, seqno=1, first, TCP: [channel_name=ISPN]
11:55:54,613 TRACE (ViewHandler,A:) [GMS] A: new members=[C], suspected=[], leaving=[],
new view: [A|5] [A, B, D, C]
11:55:54,613 TRACE (ViewHandler,A:) [GMS] A: mcasting view [A|5] [A, B, D, C] (4 mbrs)
11:55:54,841 DEBUG (testng:) [TEST_PING] Stop discovery for C
11:55:54,841 DEBUG (testng:) [TCP] closing sockets and stopping threads
11:55:55,683 TRACE (Timer-5,A:) [TCP] A: sending msg to C, src=A, headers are GMS:
GmsHeader[JOIN_RSP]: join_rsp=view: [A|5] [A, B, D, C], digest: B: [0 (0)], D: [0 (0)], A:
[11 (11)], C: [0 (0)], UNICAST2: DATA, seqno=1, conn_id=4, first, TCP:
[channel_name=ISPN]
{noformat}
A adds C back to the view, but C shuts down and will never receive the JOIN_RSP message.
Instead, the remaining members keep logging this error message until they are shut down 3
minutes later:
{noformat}
11:59:01,346 TRACE (TransferQueueBundler,D:) [TCP] 127.0.0.1:8003: failed connecting to
127.0.0.1:8002: java.net.ConnectException: Connection refused
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see:
http://www.atlassian.com/software/jira