Details
-
Bug
-
Status: Open
-
Critical
-
Resolution: Unresolved
-
3.10.0
-
None
-
None
Description
We encounter a strange scenario. When we set up the cluster of zookeeper(3 nodes totally), the third node is stuck in (sealStream) serializing the snapshot to the local disk. However, the leader election is executed normally. After the election, the third node is elected as the leader. The other two nodes fail to connect with the leader. Hence, the first and second nodes restart the leader election, finally the second node is elected as the leader. At this time, the third node still act as the leader. There are two leaders in the cluster. The first node can not join the cluster for 30s.
The logs of the first node are as following.
2024-07-01 02:35:28,223 [myid:] - INFO [WorkerReceiver[myid=1]:o.a.z.s.q.FastLeaderElection$Messenger$WorkerReceiver@391] - Notification: my state:LOOKING; n.sid:2, n.state:LOOKING, n.leader:2, n.round:0x2, n.peerEpoch:0x0, n.zxid:0x0, message format version:0x2, n.config version:0x02024-07-01 02:35:28,253 [myid:] - INFO [QuorumPeer[myid=1](plain=0.0.0.0:2181)(secure=disabled):o.a.z.s.q.FastLeaderElection@996] - Notification time out: 12800 ms2024-07-01 02:35:28,254 [myid:] - INFO [WorkerReceiver[myid=1]:o.a.z.s.q.FastLeaderElection$Messenger$WorkerReceiver@391] - Notification: my state:LOOKING; n.sid:1, n.state:LOOKING, n.leader:2, n.round:0x2, n.peerEpoch:0x0, n.zxid:0x0, message format version:0x2, n.config version:0x02024-07-01 02:35:28,287 [myid:] - INFO [WorkerReceiver[myid=1]:o.a.z.s.q.FastLeaderElection$Messenger$WorkerReceiver@391] - Notification: my state:LOOKING; n.sid:3, n.state:LEADING, n.leader:3, n.round:0x1, n.peerEpoch:0x0, n.zxid:0x0, message format version:0x2, n.config version:0x02024-07-01 02:35:28,288 [myid:] - INFO [QuorumPeer[myid=1](plain=0.0.0.0:2181)(secure=disabled):o.a.z.s.q.FastLeaderElection@1205] - Oracle indicates not to follow2024-07-01 02:35:29,493 [myid:] - WARN [NIOWorkerThread-20:o.a.z.s.NIOServerCnxn@397] - Close of session 0x0
During this procedure, the client can not connect with any nodes of the cluster.
Runtime logs are attached.
The root cause is the serializing the snapshot blocks the status modification of the third node?
Sometimes, this phenomenon will disappears. The configuration is the same as above. The second node is stuck in sealStream due to fail-slow disk.
// node1
2024-07-01 02:19:21,942 [myid:] - INFO [QuorumPeer[myid=1](plain=0.0.0.0:2181)(secure=disabled):o.a.z.s.q.QuorumPeer@920] - Peer state changed: looking2024-07-01 02:19:21,943 [myid:] - WARN [QuorumPeer[myid=1](plain=0.0.0.0:2181)(secure=disabled):o.a.z.s.q.QuorumPeer@1602] - PeerState set to LOOKING2024-07-01 02:19:21,943 [myid:] - INFO [QuorumPeer[myid=1](plain=0.0.0.0:2181)(secure=disabled):o.a.z.s.q.QuorumPeer@1471] - LOOKING2024-07-01 02:19:21,943 [myid:] - INFO [QuorumPeer[myid=1](plain=0.0.0.0:2181)(secure=disabled):o.a.z.s.q.FastLeaderElection@946] - New election. My id = 1, proposed zxid=0x02024-07-01 02:19:21,980 [myid:] - INFO [WorkerReceiver[myid=1]:o.a.z.s.q.FastLeaderElection$Messenger$WorkerReceiver@391] - Notification: my state:LOOKING; n.sid:1, n.state:LOOKING, n.leader:1, n.round:0x2, n.peerEpoch:0x0, n.zxid:0x0, message format version:0x2, n.config version:0x02024-07-01 02:19:22,012 [myid:] - INFO [WorkerReceiver[myid=1]:o.a.z.s.q.FastLeaderElection$Messenger$WorkerReceiver@391] - Notification: my state:LOOKING; n.sid:3, n.state:FOLLOWING, n.leader:2, n.round:0x1, n.peerEpoch:0x0, n.zxid:0x0, message format version:0x2, n.config version:0x02024-07-01 02:19:22,026 [myid:] - INFO [WorkerReceiver[myid=1]:o.a.z.s.q.FastLeaderElection$Messenger$WorkerReceiver@391] - Notification: my state:LOOKING; n.sid:2, n.state:LEADING, n.leader:2, n.round:0x1, n.peerEpoch:0x0, n.zxid:0x0, message format version:0x2, n.config version:0x02024-07-01 02:19:22,026 [myid:] - INFO [QuorumPeer[myid=1](plain=0.0.0.0:2181)(secure=disabled):o.a.z.s.q.QuorumPeer@906] - Peer state changed: following
// node3
2024-07-01 02:19:22,780 [myid:] - INFO [QuorumPeer[myid=3](plain=0.0.0.0:2181)(secure=disabled):o.a.z.s.q.QuorumPeer@920] - Peer state changed: looking2024-07-01 02:19:22,780 [myid:] - WARN [QuorumPeer[myid=3](plain=0.0.0.0:2181)(secure=disabled):o.a.z.s.q.QuorumPeer@1602] - PeerState set to LOOKING2024-07-01 02:19:22,780 [myid:] - INFO [QuorumPeer[myid=3](plain=0.0.0.0:2181)(secure=disabled):o.a.z.s.q.QuorumPeer@1471] - LOOKING2024-07-01 02:19:22,781 [myid:] - INFO [QuorumPeer[myid=3](plain=0.0.0.0:2181)(secure=disabled):o.a.z.s.q.FastLeaderElection@946] - New election. My id = 3, proposed zxid=0x02024-07-01 02:19:22,819 [myid:] - INFO [WorkerReceiver[myid=3]:o.a.z.s.q.FastLeaderElection$Messenger$WorkerReceiver@391] - Notification: my state:LOOKING; n.sid:3, n.state:LOOKING, n.leader:3, n.round:0x2, n.peerEpoch:0x0, n.zxid:0x0, message format version:0x2, n.config version:0x02024-07-01 02:19:22,838 [myid:] - INFO [WorkerReceiver[myid=3]:o.a.z.s.q.FastLeaderElection$Messenger$WorkerReceiver@391] - Notification: my state:LOOKING; n.sid:1, n.state:FOLLOWING, n.leader:2, n.round:0x1, n.peerEpoch:0x0, n.zxid:0x0, message format version:0x2, n.config version:0x02024-07-01 02:19:22,849 [myid:] - INFO [WorkerReceiver[myid=3]:o.a.z.s.q.FastLeaderElection$Messenger$WorkerReceiver@391] - Notification: my state:LOOKING; n.sid:2, n.state:LEADING, n.leader:2, n.round:0x1, n.peerEpoch:0x0, n.zxid:0x0, message format version:0x2, n.config version:0x02024-07-01 02:19:22,850 [myid:] - INFO [QuorumPeer[myid=3](plain=0.0.0.0:2181)(secure=disabled):o.a.z.s.q.QuorumPeer@906] - Peer state changed: following
But the leader election notification is strange. Node1 follows node2 since node3 follows node2. However, Node3 follows node2 since node1 follows node2. This condition cannot stand.
Moreover, this two scenarios are both stuck in sealStream. But there are different results. Is there a data race?
Are there any comments to figure out this issues？ I will very appreciate them.