[jira] [Commented] (ZOOKEEPER-2938) Peer with smallest id is unable to join quorum after connection broken to other peers
[
https://issues.apache.org/jira/browse/ZOOKEEPER-2938?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16370875#comment-16370875
]
Abhay Bothra commented on ZOOKEEPER-2938:
-
On our other quorum peers, we see a lot of connections in CLOSE_WAIT state to
port 4181. Could these somehow prevent the quorum peer from processing leader
election messages from the affected peer?
> Peer with smallest id is unable to join quorum after connection broken to
> other peers
> -
>
> Key: ZOOKEEPER-2938
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2938
> Project: ZooKeeper
> Issue Type: Bug
>Affects Versions: 3.4.6
>Reporter: Abhay Bothra
>Priority: Major
>
> We see the following logs in the node with {{myid: 1}}
> {code}
> 2017-11-08 15:06:28,375 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (2, 1)
> 2017-11-08 15:06:28,375 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (3, 1)
> 2017-11-08 15:07:28,375 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection@597] - Notification: 1 (message
> format version), 1 (n.leader), 0x28e000a8750 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 1 (n.sid), 0x28e (n.peerEpoch) LOOKING (my state)
> 2017-11-08 15:07:28,375 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (2, 1)
> 2017-11-08 15:07:28,376 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (3, 1)
> 2017-11-08 15:08:28,375 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection@597] - Notification: 1 (message
> format version), 1 (n.leader), 0x28e000a8750 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 1 (n.sid), 0x28e (n.peerEpoch) LOOKING (my state)
> 2017-11-08 15:08:28,376 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (2, 1)
> 2017-11-08 15:08:28,376 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (3, 1)
> 2017-11-08 15:09:28,376 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection@597] - Notification: 1 (message
> format version), 1 (n.leader), 0x28e000a8750 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 1 (n.sid), 0x28e (n.peerEpoch) LOOKING (my state)
> 2017-11-08 15:09:28,376 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (2, 1)
> 2017-11-08 15:09:28,376 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (3, 1)
> 2017-11-08 15:10:28,376 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection@597] - Notification: 1 (message
> format version), 1 (n.leader), 0x28e000a8750 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 1 (n.sid), 0x28e (n.peerEpoch) LOOKING (my state)
> 2017-11-08 15:10:28,376 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (2, 1)
> 2017-11-08 15:10:28,377 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (3, 1)
> {code}
> On the nodes with {{myid: 2}} and {{myid: 3}}, we see connection broken
> events for {{myid: 1}}
> {code}
> 2017-11-07 02:54:32,135 [myid:2] - WARN
> [RecvWorker:1:QuorumCnxManager$RecvWorker@780] - Connection broken for id 1,
> my id = 2, error =
> java.net.SocketException: Connection reset
> at java.net.SocketInputStream.read(SocketInputStream.java:209)
> at java.net.SocketInputStream.read(SocketInputStream.java:141)
> at java.net.SocketInputStream.read(SocketInputStream.java:223)
> at java.io.DataInputStream.readInt(DataInputStream.java:387)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:765)
> 2017-11-07 02:54:32,135 [myid:2] - WARN
> [RecvWorker:1:QuorumCnxManager$RecvWorker@783] - Interrupting SendWorker
> 2017-11-07 02:54:32,135 [myid:2] - WARN
> [SendWorker:1:QuorumCnxManager$SendWorker@697] - Interrupted while waiting
> for message on queue
> java.lang.InterruptedException
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088)
> at
> java.util.concurrent.ArrayBl
[jira] [Commented] (ZOOKEEPER-2938) Peer with smallest id is unable to join quorum after connection broken to other peers
[
https://issues.apache.org/jira/browse/ZOOKEEPER-2938?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16361076#comment-16361076
]
Adam J Shook commented on ZOOKEEPER-2938:
-
We are experiencing this as well, but the node that continually drops the
connection does not have the smallest {{myid}} – here it is 6 but 5 is the
smallest (5, 6, 7 are the IDs). ZooKeeper 3.4.6.
{code:java}
2018-02-12 16:29:48,428 [myid:6] - INFO
[Thread-1:QuorumCnxManager$Listener@504] - My election bind port:
/10.122.11.104:
2018-02-12 16:29:48,440 [myid:6] - INFO
[QuorumPeer[myid=6]/0.0.0.0::QuorumPeer@714] - LOOKING
2018-02-12 16:29:48,443 [myid:6] - INFO
[QuorumPeer[myid=6]/0.0.0.0::FastLeaderElection@815] - New election. My id
= 6, proposed zxid=0x1b00653e67
2018-02-12 16:29:48,453 [myid:6] - INFO
[WorkerSender[myid=6]:QuorumCnxManager@193] - Have smaller server identifier,
so dropping the connection: (7, 6)
2018-02-12 16:29:48,453 [myid:6] - INFO
[WorkerReceiver[myid=6]:FastLeaderElection@597] - Notification: 1 (message
format version), 6 (n.leader), 0x1b00653e67 (n.zxid), 0x1 (n.round), LOOKING
(n.state), 6 (
n.sid), 0x1b (n.peerEpoch) LOOKING (my state)
2018-02-12 16:29:48,657 [myid:6] - INFO
[QuorumPeer[myid=6]/0.0.0.0::FastLeaderElection@849] - Notification time
out: 400
2018-02-12 16:29:48,657 [myid:6] - INFO
[WorkerReceiver[myid=6]:FastLeaderElection@597] - Notification: 1 (message
format version), 6 (n.leader), 0x1b00653e67 (n.zxid), 0x1 (n.round), LOOKING
(n.state), 6 (
n.sid), 0x1b (n.peerEpoch) LOOKING (my state)
2018-02-12 16:29:48,658 [myid:6] - INFO
[WorkerSender[myid=6]:QuorumCnxManager@193] - Have smaller server identifier,
so dropping the connection: (7, 6)
2018-02-12 16:29:49,058 [myid:6] - INFO
[QuorumPeer[myid=6]/0.0.0.0::FastLeaderElection@849] - Notification time
out: 800
2018-02-12 16:29:49,058 [myid:6] - INFO
[WorkerReceiver[myid=6]:FastLeaderElection@597] - Notification: 1 (message
format version), 6 (n.leader), 0x1b00653e67 (n.zxid), 0x1 (n.round), LOOKING
(n.state), 6 (
n.sid), 0x1b (n.peerEpoch) LOOKING (my state)
2018-02-12 16:29:49,859 [myid:6] - INFO
[QuorumPeer[myid=6]/0.0.0.0::FastLeaderElection@849] - Notification time
out: 1600
2018-02-12 16:29:50,058 [myid:6] - INFO
[WorkerSender[myid=6]:QuorumCnxManager@193] - Have smaller server identifier,
so dropping the connection: (7, 6)
2018-02-12 16:29:50,059 [myid:6] - INFO
[WorkerReceiver[myid=6]:FastLeaderElection@597] - Notification: 1 (message
format version), 6 (n.leader), 0x1b00653e67 (n.zxid), 0x1 (n.round), LOOKING
(n.state), 6 (
n.sid), 0x1b (n.peerEpoch) LOOKING (my state)
2018-02-12 16:29:50,059 [myid:6] - INFO
[WorkerSender[myid=6]:QuorumCnxManager@193] - Have smaller server identifier,
so dropping the connection: (7, 6)
2018-02-12 16:29:51,660 [myid:6] - INFO
[QuorumPeer[myid=6]/0.0.0.0::FastLeaderElection@849] - Notification time
out: 3200
2018-02-12 16:29:51,660 [myid:6] - INFO
[WorkerReceiver[myid=6]:FastLeaderElection@597] - Notification: 1 (message
format version), 6 (n.leader), 0x1b00653e67 (n.zxid), 0x1 (n.round), LOOKING
(n.state), 6 (
n.sid), 0x1b (n.peerEpoch) LOOKING (my state)
2018-02-12 16:29:51,660 [myid:6] - INFO
[WorkerSender[myid=6]:QuorumCnxManager@193] - Have smaller server identifier,
so dropping the connection: (7, 6)
2018-02-12 16:29:54,861 [myid:6] - INFO
[QuorumPeer[myid=6]/0.0.0.0::FastLeaderElection@849] - Notification time
out: 6400
2018-02-12 16:29:54,861 [myid:6] - INFO
[WorkerReceiver[myid=6]:FastLeaderElection@597] - Notification: 1 (message
format version), 6 (n.leader), 0x1b00653e67 (n.zxid), 0x1 (n.round), LOOKING
(n.state), 6 (
n.sid), 0x1b (n.peerEpoch) LOOKING (my state)
2018-02-12 16:29:54,862 [myid:6] - INFO
[WorkerSender[myid=6]:QuorumCnxManager@193] - Have smaller server identifier,
so dropping the connection: (7, 6)
2018-02-12 16:30:01,262 [myid:6] - INFO
[QuorumPeer[myid=6]/0.0.0.0::FastLeaderElection@849] - Notification time
out: 12800
2018-02-12 16:30:01,263 [myid:6] - INFO
[WorkerReceiver[myid=6]:FastLeaderElection@597] - Notification: 1 (message
format version), 6 (n.leader), 0x1b00653e67 (n.zxid), 0x1 (n.round), LOOKING
(n.state), 6 (
n.sid), 0x1b (n.peerEpoch) LOOKING (my state)
2018-02-12 16:30:01,263 [myid:6] - INFO
[WorkerSender[myid=6]:QuorumCnxManager@193] - Have smaller server identifier,
so dropping the connection: (7, 6)
2018-02-12 16:30:02,050 [myid:6] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0::NIOServerCnxnFactory@197] - Accepted
socket connection from /127.0.0.1:54541
2018-02-12 16:30:02,057 [myid:6] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0::NIOServerCnxn@827] - Processing ruok
command from /127.0.0.1:54541
2018-02-12 16:30:02,060 [myid:6] - INFO [Thread-2:NIOServerCnxn@1007] - Closed
socket connection for client /127.0.0.1:54541 (no session established
[jira] [Commented] (ZOOKEEPER-2938) Peer with smallest id is unable to join quorum after connection broken to other peers
[
https://issues.apache.org/jira/browse/ZOOKEEPER-2938?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16245047#comment-16245047
]
Abhay Bothra commented on ZOOKEEPER-2938:
-
We're also wondering if this could be related to ZOOKEEPER-1732
> Peer with smallest id is unable to join quorum after connection broken to
> other peers
> -
>
> Key: ZOOKEEPER-2938
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2938
> Project: ZooKeeper
> Issue Type: Bug
>Affects Versions: 3.4.6
>Reporter: Abhay Bothra
>
> We see the following logs in the node with {{myid: 1}}
> {code}
> 2017-11-08 15:06:28,375 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (2, 1)
> 2017-11-08 15:06:28,375 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (3, 1)
> 2017-11-08 15:07:28,375 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection@597] - Notification: 1 (message
> format version), 1 (n.leader), 0x28e000a8750 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 1 (n.sid), 0x28e (n.peerEpoch) LOOKING (my state)
> 2017-11-08 15:07:28,375 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (2, 1)
> 2017-11-08 15:07:28,376 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (3, 1)
> 2017-11-08 15:08:28,375 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection@597] - Notification: 1 (message
> format version), 1 (n.leader), 0x28e000a8750 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 1 (n.sid), 0x28e (n.peerEpoch) LOOKING (my state)
> 2017-11-08 15:08:28,376 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (2, 1)
> 2017-11-08 15:08:28,376 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (3, 1)
> 2017-11-08 15:09:28,376 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection@597] - Notification: 1 (message
> format version), 1 (n.leader), 0x28e000a8750 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 1 (n.sid), 0x28e (n.peerEpoch) LOOKING (my state)
> 2017-11-08 15:09:28,376 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (2, 1)
> 2017-11-08 15:09:28,376 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (3, 1)
> 2017-11-08 15:10:28,376 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection@597] - Notification: 1 (message
> format version), 1 (n.leader), 0x28e000a8750 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 1 (n.sid), 0x28e (n.peerEpoch) LOOKING (my state)
> 2017-11-08 15:10:28,376 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (2, 1)
> 2017-11-08 15:10:28,377 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@193] - Have smaller server identifier,
> so dropping the connection: (3, 1)
> {code}
> On the nodes with {{myid: 2}} and {{myid: 3}}, we see connection broken
> events for {{myid: 1}}
> {code}
> 2017-11-07 02:54:32,135 [myid:2] - WARN
> [RecvWorker:1:QuorumCnxManager$RecvWorker@780] - Connection broken for id 1,
> my id = 2, error =
> java.net.SocketException: Connection reset
> at java.net.SocketInputStream.read(SocketInputStream.java:209)
> at java.net.SocketInputStream.read(SocketInputStream.java:141)
> at java.net.SocketInputStream.read(SocketInputStream.java:223)
> at java.io.DataInputStream.readInt(DataInputStream.java:387)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:765)
> 2017-11-07 02:54:32,135 [myid:2] - WARN
> [RecvWorker:1:QuorumCnxManager$RecvWorker@783] - Interrupting SendWorker
> 2017-11-07 02:54:32,135 [myid:2] - WARN
> [SendWorker:1:QuorumCnxManager$SendWorker@697] - Interrupted while waiting
> for message on queue
> java.lang.InterruptedException
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088)
> at
> java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:849)
>
