zookeeper-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Adam J Shook (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (ZOOKEEPER-2938) Peer with smallest id is unable to join quorum after connection broken to other peers
Date Mon, 12 Feb 2018 17:00:00 GMT

    [ 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:6666
2018-02-12 16:29:48,440 [myid:6] - INFO  [QuorumPeer[myid=6]/0.0.0.0:4444:QuorumPeer@714]
- LOOKING
2018-02-12 16:29:48,443 [myid:6] - INFO  [QuorumPeer[myid=6]/0.0.0.0:4444: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:4444: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:4444: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:4444: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:4444: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:4444: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:4444: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:4444: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:4444: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 for client)
2018-02-12 16:30:02,449 [myid:6] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4444:NIOServerCnxnFactory@197]
- Accepted socket connection from /127.0.0.1:54611
2018-02-12 16:30:02,450 [myid:6] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4444:NIOServerCnxn@827]
- Processing ruok command from /127.0.0.1:54611
2018-02-12 16:30:02,451 [myid:6] - INFO  [Thread-3:NIOServerCnxn@1007] - Closed socket connection
for client /127.0.0.1:54611 (no session established for client)
2018-02-12 16:30:02,789 [myid:6] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4444:NIOServerCnxnFactory@197]
- Accepted socket connection from /127.0.0.1:54671
2018-02-12 16:30:02,790 [myid:6] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4444:NIOServerCnxn@827]
- Processing ruok command from /127.0.0.1:54671
2018-02-12 16:30:02,791 [myid:6] - INFO  [Thread-4:NIOServerCnxn@1007] - Closed socket connection
for client /127.0.0.1:54671 (no session established for client)
... these messages continue
{code}

> 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.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
>         at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:849)
>         at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:64)
>         at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:685)
> 2017-11-07 02:54:32,135 [myid:2] - WARN  [SendWorker:1:QuorumCnxManager$SendWorker@706]
- Send worker leaving thread
> {code}
> From the reported occurrences, it looks like this is a problem only when the node with
the smallest {{myid}} loses connection.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

Mime
View raw message