Have you checked that UDP traffic can get through in both directions for
those two machines?
On 8/9/18 7:04 AM, Vahram Aharonyan wrote:
Just one adjustment,
I was wrong stating that locator restart solves the issue. More
experiments show that it is not solution in this case.
Thanks,
Vahram.
*From:* Vahram Aharonyan <[email protected]>
*Sent:* Wednesday, August 8, 2018 7:41 PM
*To:* [email protected]
*Subject:* PrepareView is not reaching join initiator member
Hi All,
At some circumstances we face following scenario:
1. A new member(sc-rdops-vm07-dhcp-195-204) is trying to join
distributed system but it does not succeed – it seems due to not
receiving response on join request:
[fine 2018/08/08 15:09:16.100 UTC fc2d07ae-e61b-4c0f-b2ed-8216a326e249
< Main Thread> tid=0x11] searching for the membership coordinator
[fine 2018/08/08 15:09:16.100 UTC fc2d07ae-e61b-4c0f-b2ed-8216a326e249
< Main Thread> tid=0x11] sending
FindCoordinatorRequest(memberID=sc-rdops-vm07-dhcp-195-204(fc2d07ae-e61b-4c0f-b2ed-8216a326e249:23205)<ec>:10002,
rejected=[], lastViewId=-1) to [/10.193.40.129:6061]
[fine 2018/08/08 15:09:16.104 UTC fc2d07ae-e61b-4c0f-b2ed-8216a326e249
< Main Thread> tid=0x11] SSL Configuration:
ssl-enabled = true
[fine 2018/08/08 15:09:16.356 UTC fc2d07ae-e61b-4c0f-b2ed-8216a326e249
< Main Thread> tid=0x11] SSL Connection from peer OU=MBU, O="VMware,
Inc.", CN=vc-ops-slice-1
[fine 2018/08/08 15:09:16.369 UTC fc2d07ae-e61b-4c0f-b2ed-8216a326e249
< Main Thread> tid=0x11] TcpClient sending
FindCoordinatorRequest(memberID=sc-rdops-vm07-dhcp-195-204(fc2d07ae-e61b-4c0f-b2ed-8216a326e249:23205)<ec>:10002,
rejected=[], lastViewId=-1) to /10.193.40.129:6061
[fine 2018/08/08 15:09:16.373 UTC fc2d07ae-e61b-4c0f-b2ed-8216a326e249
< Main Thread> tid=0x11] SSL Connection from peer OU=MBU, O="VMware,
Inc.", CN=vc-ops-slice-1
[fine 2018/08/08 15:09:16.489 UTC fc2d07ae-e61b-4c0f-b2ed-8216a326e249
< Main Thread> tid=0x11] received response:
FindCoordinatorResponse(coordinator=sc2-rdops-vm09-dhcp-40-129(17201:locator)<ec><v0>:20002,
fromView=true, viewId=14299, registrants=0,
senderId=sc2-rdops-vm09-dhcp-40-129(17201:locator)<ec><v0>:20002,
network partition detection enabled=false, locators preferred as
coordinators=false)
[fine 2018/08/08 15:09:16.490 UTC fc2d07ae-e61b-4c0f-b2ed-8216a326e249
< Main Thread> tid=0x11] Locator's address indicates it is part of a
distributed system so I will not become membership coordinator on this
attempt to join
[fine 2018/08/08 15:09:16.490 UTC fc2d07ae-e61b-4c0f-b2ed-8216a326e249
< Main Thread> tid=0x11] found possible coordinator
sc2-rdops-vm09-dhcp-40-129(17201:locator)<ec><v0>:20002
[info 2018/08/08 15:09:16.490 UTC fc2d07ae-e61b-4c0f-b2ed-8216a326e249
< Main Thread> tid=0x11] Attempting to join the distributed system
through coordinator
sc2-rdops-vm09-dhcp-40-129(17201:locator)<ec><v0>:20002 using address
sc-rdops-vm07-dhcp-195-204(fc2d07ae-e61b-4c0f-b2ed-8216a326e249:23205)<ec>:10002
[fine 2018/08/08 15:09:16.491 UTC fc2d07ae-e61b-4c0f-b2ed-8216a326e249
< Main Thread> tid=0x11] sending via JGroups:
[JoinRequestMessage(sc-rdops-vm07-dhcp-195-204(fc2d07ae-e61b-4c0f-b2ed-8216a326e249:23205)<ec>:10002)
failureDetectionPort:10003] recipients:
[sc2-rdops-vm09-dhcp-40-129(17201:locator)<ec><v0>:20002]
[fine 2018/08/08 15:13:16.499 UTC fc2d07ae-e61b-4c0f-b2ed-8216a326e249
<Main Thread> tid=0x11] received no join response
[fine 2018/08/08 15:13:16.500 UTC fc2d07ae-e61b-4c0f-b2ed-8216a326e249
<Main Thread> tid=0x11] sleeping for 1000 before making another
attempt to find the coordinator
[fine 2018/08/08 15:13:17.500 UTC fc2d07ae-e61b-4c0f-b2ed-8216a326e249
<Main Thread> tid=0x11] searching for the membership coordinator
2. Snipper from Coordinator(in this case locator) is log:
[info 2018/08/08 15:09:16.498 UTC <unicast
receiver,sc2-rdops-vm09-dhcp-40-129-24030> tid=0x23] received join
request from
sc-rdops-vm07-dhcp-195-204(fc2d07ae-e61b-4c0f-b2ed-8216a326e249:23205)<ec>:10002
[info 2018/08/08 15:09:16.798 UTC <Geode Membership View Creator>
tid=0x29] preparing new view
View[sc2-rdops-vm09-dhcp-40-129(17201:locator)<ec><v0>:20002|14300]
members: [sc2-rdops-vm09-dhcp-40-129(17201:locator)<ec><v0>:20002,
sc-rdops-vm05-dhcp-130-203(dbe93506-f385-4542-9bda-55599273e96c:28849)<ec><v14279>:10002{lead},
sc2-rdops-vm09-dhcp-40-129(a3c1b724-aa54-427b-8325-20defec15b7e:482)<ec><v14291>:10002,
sc-rdops-vm07-dhcp-195-204(fc2d07ae-e61b-4c0f-b2ed-8216a326e249:23205)<ec><v14300>:10002]
failure detection ports: 20007 10002 10006 10003
[info 2018/08/08 15:09:29.800 UTC <Geode Membership View Creator>
tid=0x29] finished waiting for responses to view preparation
[warning 2018/08/08 15:09:29.800 UTC <Geode Membership View Creator>
tid=0x29] these members failed to respond to the view change:
[sc-rdops-vm07-dhcp-195-204(fc2d07ae-e61b-4c0f-b2ed-8216a326e249:23205)<ec><v14300>:10002]
[info 2018/08/08 15:09:29.800 UTC <Geode View Creator verification
thread 1> tid=0x649d] checking state of member
sc-rdops-vm07-dhcp-195-204(fc2d07ae-e61b-4c0f-b2ed-8216a326e249:23205)<ec><v14300>:10002
[info 2018/08/08 15:09:29.800 UTC <Geode View Creator verification
thread 1> tid=0x649d] member
sc-rdops-vm07-dhcp-195-204(fc2d07ae-e61b-4c0f-b2ed-8216a326e249:23205)<ec><v14300>:10002
failed availability check
[info 2018/08/08 15:09:42.238 UTC <Geode Membership View Creator>
tid=0x29] adding these unresponsive members to the crash-set for the
next view:
[sc-rdops-vm07-dhcp-195-204(fc2d07ae-e61b-4c0f-b2ed-8216a326e249:23205)<ec><v14300>:10002]
3. Snippet from other member log that is already member of
distributed system indicating that PrepareView request reaches
it(sc-rdops-vm05-dhcp-130-203) :
[fine 2018/08/08 15:09:16.802 UTC dbe93506-f385-4542-9bda-55599273e96c
<unicast receiver,sc-rdops-vm05-dhcp-130-203-36192> tid=0x2b]
processing InstallViewMessage(type=PREPARE; Current ViewID=14300;
Previous View ID=0;
View[sc2-rdops-vm09-dhcp-40-129(17201:locator)<ec><v0>:20002|14300]
members: [sc2-rdops-vm09-dhcp-40-129(17201:locator)<ec><v0>:20002,
sc-rdops-vm05-dhcp-130-203(dbe93506-f385-4542-9bda-55599273e96c:28849)<ec><v14279>:10002{lead},
sc2-rdops-vm09-dhcp-40-129(a3c1b724-aa54-427b-8325-20defec15b7e:482)<ec><v14291>:10002,
sc-rdops-vm07-dhcp-195-204(fc2d07ae-e61b-4c0f-b2ed-8216a326e249:23205)<ec><v14300>:10002];
cred=null)
So from coordinator log it is obvious that it gets join request from
member sc-rdops-vm07-dhcp-195-204, prepares new view and broadcasts
it, butsc-rdops-vm07-dhcp-195-204 member itself is not getting this
response.
Could someone have some glue on why view preparation response is not
reaching the node that has initiated join?
Please note, that we are using Geode 1.1.0 and locator restart seem to
fix this issue.
Thanks,
Vahram.
