You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@zookeeper.apache.org by Jordan Zimmerman <jz...@netflix.com> on 2011/10/22 00:57:58 UTC
Node not joining ensemble
I have a node that I restarted and it's not joining the ensemble. I ask it
'stat' and it says it isn't serving any requests. Here's a snippet from
the log:
2011-10-21 22:46:23,166 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
800
2011-10-21 22:46:23,167 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 22:46:23,169 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 2 (n.sid), LOOKING (my state)
2011-10-21 22:46:23,970 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
1600
2011-10-21 22:46:23,971 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 22:46:23,973 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 2 (n.sid), LOOKING (my state)
2011-10-21 22:46:25,290 - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] -
Accepted socket connection from /127.0.0.1:44897
2011-10-21 22:46:25,574 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
3200
2011-10-21 22:46:25,575 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 22:46:25,577 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 2 (n.sid), LOOKING (my state)
2011-10-21 22:46:28,000 - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1237] -
Processing ruok command from /127.0.0.1:44897
2011-10-21 22:46:28,001 - INFO [Thread-6:NIOServerCnxn@1435] - Closed
socket connection for client /127.0.0.1:44897 (no session established for
client)
2011-10-21 22:46:28,778 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
6400
2011-10-21 22:46:28,779 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 22:46:28,781 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 2 (n.sid), LOOKING (my state)
2011-10-21 22:46:29,929 - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] -
Accepted socket connection from /127.0.0.1:44898
2011-10-21 22:46:30,871 - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1237] -
Processing stat command from /127.0.0.1:44898
2011-10-21 22:46:30,873 - INFO [Thread-7:NIOServerCnxn@1435] - Closed
socket connection for client /127.0.0.1:44898 (no session established for
client)
2011-10-21 22:46:35,182 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
12800
2011-10-21 22:46:35,183 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 22:46:35,185 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 2 (n.sid), LOOKING (my state)
2011-10-21 22:46:47,987 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
25600
2011-10-21 22:46:47,987 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 22:46:47,990 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 2 (n.sid), LOOKING (my state)
2011-10-21 22:47:13,593 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
51200
2011-10-21 22:47:13,594 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 22:47:13,596 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 2 (n.sid), LOOKING (my state)
2011-10-21 22:48:04,803 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
60000
2011-10-21 22:48:04,804 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 22:48:04,806 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 2 (n.sid), LOOKING (my state)
2011-10-21 22:48:24,886 - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] -
Accepted socket connection from /127.0.0.1:32954
2011-10-21 22:48:26,380 - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1237] -
Processing stat command from /127.0.0.1:32954
2011-10-21 22:48:26,381 - INFO [Thread-8:NIOServerCnxn@1435] - Closed
socket connection for client /127.0.0.1:32954 (no session established for
client)
2011-10-21 22:49:04,815 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
60000
2011-10-21 22:49:04,815 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 22:49:04,818 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 2 (n.sid), LOOKING (my state)
2011-10-21 22:50:04,827 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
60000
2011-10-21 22:50:04,827 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 22:50:04,829 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 2 (n.sid), LOOKING (my state)
2011-10-21 22:51:04,838 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
60000
2011-10-21 22:51:04,839 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 22:51:04,841 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 2 (n.sid), LOOKING (my state)
2011-10-21 22:51:44,890 - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] -
Accepted socket connection from /127.0.0.1:32964
2011-10-21 22:51:46,207 - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1237] -
Processing stat command from /127.0.0.1:32964
2011-10-21 22:51:46,208 - INFO [Thread-9:NIOServerCnxn@1435] - Closed
socket connection for client /127.0.0.1:32964 (no session established for
client)
2011-10-21 22:52:04,851 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
60000
2011-10-21 22:52:04,852 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 22:52:04,854 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 2 (n.sid), LOOKING (my state)
2011-10-21 22:53:04,863 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
60000
2011-10-21 22:53:04,863 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 22:53:04,866 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 2 (n.sid), LOOKING (my state)
2011-10-21 22:54:04,876 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
60000
2011-10-21 22:54:04,876 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 22:54:04,879 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 2 (n.sid), LOOKING (my state)
Re: Node not joining ensemble
Posted by Flavio Junqueira <fp...@yahoo-inc.com>.
Here is my interpretation after reading the logs:
1- Node 3 was restarted and initiated leader election for round 1;
2- Node 3 received a notification from 1 saying that it is the leader,
but it didn't get a confirmation from a quorum. Since node 3 has a
higher id and zxid, it does not change its mind about who should be
the leader: itself;
3- Node 3 didn't receive a notification from 2 showing that a quorum
supports 1, so node 3 sticks to its vote.
It sound like a bug to me, so I suggest you report it on a jira.
-Flavio
On Oct 22, 2011, at 3:13 AM, Jordan Zimmerman wrote:
> Interesting. I restarted Server 2 in the ensemble and the problem
> cleared
> itself.
>
> -JZ
>
> On 10/21/11 4:34 PM, "Jordan Zimmerman" <jz...@netflix.com>
> wrote:
>
>> FYI - I turned on DEBUG and here's more log info:
>>
>> 2011-10-21 23:33:06,732 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed
>> id: 3,
>> zxid: 12885265585, proposed zxid: 12885265585
>> 2011-10-21 23:33:06,732 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote:
>> From = 3,
>> Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
>> 2011-10-21 23:33:06,734 - DEBUG [WorkerReceiver
>> Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>> notification message. My id = 3
>> 2011-10-21 23:33:06,735 - INFO [WorkerReceiver
>> Thread:FastLeaderElection@496] - Notification: 1 (n.leader),
>> 8589935532
>> (n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my
>> state)
>> 2011-10-21 23:33:08,336 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
>> 2011-10-21 23:33:08,336 - INFO
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification
>> time out:
>> 3200
>> 2011-10-21 23:33:08,336 - DEBUG [WorkerSender
>> Thread:QuorumCnxManager@389]
>> - There is a connection already for server 1
>> 2011-10-21 23:33:08,337 - DEBUG [WorkerSender
>> Thread:QuorumCnxManager@389]
>> - There is a connection already for server 2
>> 2011-10-21 23:33:08,337 - DEBUG [WorkerReceiver
>> Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>> notification message. My id = 3
>> 2011-10-21 23:33:08,337 - INFO [WorkerReceiver
>> Thread:FastLeaderElection@496] - Notification: 3 (n.leader),
>> 12885265585
>> (n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my
>> state)
>> 2011-10-21 23:33:08,337 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed
>> id: 3,
>> zxid: 12885265585, proposed zxid: 12885265585
>> 2011-10-21 23:33:08,337 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote:
>> From = 3,
>> Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
>> 2011-10-21 23:33:08,339 - DEBUG [WorkerReceiver
>> Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>> notification message. My id = 3
>> 2011-10-21 23:33:08,339 - INFO [WorkerReceiver
>> Thread:FastLeaderElection@496] - Notification: 1 (n.leader),
>> 8589935532
>> (n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my
>> state)
>> 2011-10-21 23:33:11,540 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
>> 2011-10-21 23:33:11,540 - INFO
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification
>> time out:
>> 6400
>> 2011-10-21 23:33:11,540 - DEBUG [WorkerSender
>> Thread:QuorumCnxManager@389]
>> - There is a connection already for server 1
>> 2011-10-21 23:33:11,541 - DEBUG [WorkerSender
>> Thread:QuorumCnxManager@389]
>> - There is a connection already for server 2
>> 2011-10-21 23:33:11,541 - DEBUG [WorkerReceiver
>> Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>> notification message. My id = 3
>> 2011-10-21 23:33:11,541 - INFO [WorkerReceiver
>> Thread:FastLeaderElection@496] - Notification: 3 (n.leader),
>> 12885265585
>> (n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my
>> state)
>> 2011-10-21 23:33:11,541 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed
>> id: 3,
>> zxid: 12885265585, proposed zxid: 12885265585
>> 2011-10-21 23:33:11,541 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote:
>> From = 3,
>> Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
>> 2011-10-21 23:33:11,543 - DEBUG [WorkerReceiver
>> Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>> notification message. My id = 3
>> 2011-10-21 23:33:11,544 - INFO [WorkerReceiver
>> Thread:FastLeaderElection@496] - Notification: 1 (n.leader),
>> 8589935532
>> (n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my
>> state)
>> 2011-10-21 23:33:17,945 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
>> 2011-10-21 23:33:17,945 - INFO
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification
>> time out:
>> 12800
>> 2011-10-21 23:33:17,945 - DEBUG [WorkerSender
>> Thread:QuorumCnxManager@389]
>> - There is a connection already for server 1
>> 2011-10-21 23:33:17,946 - DEBUG [WorkerSender
>> Thread:QuorumCnxManager@389]
>> - There is a connection already for server 2
>> 2011-10-21 23:33:17,946 - DEBUG [WorkerReceiver
>> Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>> notification message. My id = 3
>> 2011-10-21 23:33:17,946 - INFO [WorkerReceiver
>> Thread:FastLeaderElection@496] - Notification: 3 (n.leader),
>> 12885265585
>> (n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my
>> state)
>> 2011-10-21 23:33:17,946 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed
>> id: 3,
>> zxid: 12885265585, proposed zxid: 12885265585
>> 2011-10-21 23:33:17,946 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote:
>> From = 3,
>> Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
>> 2011-10-21 23:33:17,948 - DEBUG [WorkerReceiver
>> Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>> notification message. My id = 3
>> 2011-10-21 23:33:17,948 - INFO [WorkerReceiver
>> Thread:FastLeaderElection@496] - Notification: 1 (n.leader),
>> 8589935532
>> (n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my
>> state)
>> 2011-10-21 23:33:30,750 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
>> 2011-10-21 23:33:30,750 - INFO
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification
>> time out:
>> 25600
>> 2011-10-21 23:33:30,750 - DEBUG [WorkerSender
>> Thread:QuorumCnxManager@389]
>> - There is a connection already for server 1
>> 2011-10-21 23:33:30,750 - DEBUG [WorkerSender
>> Thread:QuorumCnxManager@389]
>> - There is a connection already for server 2
>> 2011-10-21 23:33:30,751 - DEBUG [WorkerReceiver
>> Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>> notification message. My id = 3
>> 2011-10-21 23:33:30,751 - INFO [WorkerReceiver
>> Thread:FastLeaderElection@496] - Notification: 3 (n.leader),
>> 12885265585
>> (n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my
>> state)
>> 2011-10-21 23:33:30,751 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed
>> id: 3,
>> zxid: 12885265585, proposed zxid: 12885265585
>> 2011-10-21 23:33:30,751 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote:
>> From = 3,
>> Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
>> 2011-10-21 23:33:30,753 - DEBUG [WorkerReceiver
>> Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>> notification message. My id = 3
>> 2011-10-21 23:33:30,753 - INFO [WorkerReceiver
>> Thread:FastLeaderElection@496] - Notification: 1 (n.leader),
>> 8589935532
>> (n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my
>> state)
>> 2011-10-21 23:33:56,357 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
>> 2011-10-21 23:33:56,357 - INFO
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification
>> time out:
>> 51200
>> 2011-10-21 23:33:56,358 - DEBUG [WorkerSender
>> Thread:QuorumCnxManager@389]
>> - There is a connection already for server 1
>> 2011-10-21 23:33:56,358 - DEBUG [WorkerSender
>> Thread:QuorumCnxManager@389]
>> - There is a connection already for server 2
>> 2011-10-21 23:33:56,358 - DEBUG [WorkerReceiver
>> Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>> notification message. My id = 3
>> 2011-10-21 23:33:56,358 - INFO [WorkerReceiver
>> Thread:FastLeaderElection@496] - Notification: 3 (n.leader),
>> 12885265585
>> (n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my
>> state)
>> 2011-10-21 23:33:56,358 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed
>> id: 3,
>> zxid: 12885265585, proposed zxid: 12885265585
>> 2011-10-21 23:33:56,359 - DEBUG
>> [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote:
>> From = 3,
>> Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
>> 2011-10-21 23:33:56,360 - DEBUG [WorkerReceiver
>> Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>> notification message. My id = 3
>> 2011-10-21 23:33:56,360 - INFO [WorkerReceiver
>> Thread:FastLeaderElection@496] - Notification: 1 (n.leader),
>> 8589935532
>> (n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my
>> state)
>> (END)
>>
>>
>>
>
flavio
junqueira
research scientist
fpj@yahoo-inc.com
direct +34 93-183-8828
avinguda diagonal 177, 8th floor, barcelona, 08018, es
phone (408) 349 3300 fax (408) 349 3301
Re: Node not joining ensemble
Posted by Jordan Zimmerman <jz...@netflix.com>.
Interesting. I restarted Server 2 in the ensemble and the problem cleared
itself.
-JZ
On 10/21/11 4:34 PM, "Jordan Zimmerman" <jz...@netflix.com> wrote:
>FYI - I turned on DEBUG and here's more log info:
>
>2011-10-21 23:33:06,732 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed id: 3,
>zxid: 12885265585, proposed zxid: 12885265585
>2011-10-21 23:33:06,732 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote: From = 3,
>Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
>2011-10-21 23:33:06,734 - DEBUG [WorkerReceiver
>Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>notification message. My id = 3
>2011-10-21 23:33:06,735 - INFO [WorkerReceiver
>Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
>(n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my state)
>2011-10-21 23:33:08,336 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
>2011-10-21 23:33:08,336 - INFO
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
>3200
>2011-10-21 23:33:08,336 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
>- There is a connection already for server 1
>2011-10-21 23:33:08,337 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
>- There is a connection already for server 2
>2011-10-21 23:33:08,337 - DEBUG [WorkerReceiver
>Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>notification message. My id = 3
>2011-10-21 23:33:08,337 - INFO [WorkerReceiver
>Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
>(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
>2011-10-21 23:33:08,337 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed id: 3,
>zxid: 12885265585, proposed zxid: 12885265585
>2011-10-21 23:33:08,337 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote: From = 3,
>Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
>2011-10-21 23:33:08,339 - DEBUG [WorkerReceiver
>Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>notification message. My id = 3
>2011-10-21 23:33:08,339 - INFO [WorkerReceiver
>Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
>(n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my state)
>2011-10-21 23:33:11,540 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
>2011-10-21 23:33:11,540 - INFO
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
>6400
>2011-10-21 23:33:11,540 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
>- There is a connection already for server 1
>2011-10-21 23:33:11,541 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
>- There is a connection already for server 2
>2011-10-21 23:33:11,541 - DEBUG [WorkerReceiver
>Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>notification message. My id = 3
>2011-10-21 23:33:11,541 - INFO [WorkerReceiver
>Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
>(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
>2011-10-21 23:33:11,541 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed id: 3,
>zxid: 12885265585, proposed zxid: 12885265585
>2011-10-21 23:33:11,541 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote: From = 3,
>Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
>2011-10-21 23:33:11,543 - DEBUG [WorkerReceiver
>Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>notification message. My id = 3
>2011-10-21 23:33:11,544 - INFO [WorkerReceiver
>Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
>(n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my state)
>2011-10-21 23:33:17,945 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
>2011-10-21 23:33:17,945 - INFO
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
>12800
>2011-10-21 23:33:17,945 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
>- There is a connection already for server 1
>2011-10-21 23:33:17,946 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
>- There is a connection already for server 2
>2011-10-21 23:33:17,946 - DEBUG [WorkerReceiver
>Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>notification message. My id = 3
>2011-10-21 23:33:17,946 - INFO [WorkerReceiver
>Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
>(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
>2011-10-21 23:33:17,946 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed id: 3,
>zxid: 12885265585, proposed zxid: 12885265585
>2011-10-21 23:33:17,946 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote: From = 3,
>Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
>2011-10-21 23:33:17,948 - DEBUG [WorkerReceiver
>Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>notification message. My id = 3
>2011-10-21 23:33:17,948 - INFO [WorkerReceiver
>Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
>(n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my state)
>2011-10-21 23:33:30,750 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
>2011-10-21 23:33:30,750 - INFO
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
>25600
>2011-10-21 23:33:30,750 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
>- There is a connection already for server 1
>2011-10-21 23:33:30,750 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
>- There is a connection already for server 2
>2011-10-21 23:33:30,751 - DEBUG [WorkerReceiver
>Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>notification message. My id = 3
>2011-10-21 23:33:30,751 - INFO [WorkerReceiver
>Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
>(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
>2011-10-21 23:33:30,751 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed id: 3,
>zxid: 12885265585, proposed zxid: 12885265585
>2011-10-21 23:33:30,751 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote: From = 3,
>Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
>2011-10-21 23:33:30,753 - DEBUG [WorkerReceiver
>Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>notification message. My id = 3
>2011-10-21 23:33:30,753 - INFO [WorkerReceiver
>Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
>(n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my state)
>2011-10-21 23:33:56,357 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
>2011-10-21 23:33:56,357 - INFO
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
>51200
>2011-10-21 23:33:56,358 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
>- There is a connection already for server 1
>2011-10-21 23:33:56,358 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
>- There is a connection already for server 2
>2011-10-21 23:33:56,358 - DEBUG [WorkerReceiver
>Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>notification message. My id = 3
>2011-10-21 23:33:56,358 - INFO [WorkerReceiver
>Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
>(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
>2011-10-21 23:33:56,358 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed id: 3,
>zxid: 12885265585, proposed zxid: 12885265585
>2011-10-21 23:33:56,359 - DEBUG
>[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote: From = 3,
>Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
>2011-10-21 23:33:56,360 - DEBUG [WorkerReceiver
>Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
>notification message. My id = 3
>2011-10-21 23:33:56,360 - INFO [WorkerReceiver
>Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
>(n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my state)
>(END)
>
>
>
Re: Node not joining ensemble
Posted by Jordan Zimmerman <jz...@netflix.com>.
FYI - I turned on DEBUG and here's more log info:
2011-10-21 23:33:06,732 - DEBUG
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed id: 3,
zxid: 12885265585, proposed zxid: 12885265585
2011-10-21 23:33:06,732 - DEBUG
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote: From = 3,
Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
2011-10-21 23:33:06,734 - DEBUG [WorkerReceiver
Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
notification message. My id = 3
2011-10-21 23:33:06,735 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my state)
2011-10-21 23:33:08,336 - DEBUG
[QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
2011-10-21 23:33:08,336 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
3200
2011-10-21 23:33:08,336 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
- There is a connection already for server 1
2011-10-21 23:33:08,337 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
- There is a connection already for server 2
2011-10-21 23:33:08,337 - DEBUG [WorkerReceiver
Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
notification message. My id = 3
2011-10-21 23:33:08,337 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 23:33:08,337 - DEBUG
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed id: 3,
zxid: 12885265585, proposed zxid: 12885265585
2011-10-21 23:33:08,337 - DEBUG
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote: From = 3,
Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
2011-10-21 23:33:08,339 - DEBUG [WorkerReceiver
Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
notification message. My id = 3
2011-10-21 23:33:08,339 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my state)
2011-10-21 23:33:11,540 - DEBUG
[QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
2011-10-21 23:33:11,540 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
6400
2011-10-21 23:33:11,540 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
- There is a connection already for server 1
2011-10-21 23:33:11,541 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
- There is a connection already for server 2
2011-10-21 23:33:11,541 - DEBUG [WorkerReceiver
Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
notification message. My id = 3
2011-10-21 23:33:11,541 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 23:33:11,541 - DEBUG
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed id: 3,
zxid: 12885265585, proposed zxid: 12885265585
2011-10-21 23:33:11,541 - DEBUG
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote: From = 3,
Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
2011-10-21 23:33:11,543 - DEBUG [WorkerReceiver
Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
notification message. My id = 3
2011-10-21 23:33:11,544 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my state)
2011-10-21 23:33:17,945 - DEBUG
[QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
2011-10-21 23:33:17,945 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
12800
2011-10-21 23:33:17,945 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
- There is a connection already for server 1
2011-10-21 23:33:17,946 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
- There is a connection already for server 2
2011-10-21 23:33:17,946 - DEBUG [WorkerReceiver
Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
notification message. My id = 3
2011-10-21 23:33:17,946 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 23:33:17,946 - DEBUG
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed id: 3,
zxid: 12885265585, proposed zxid: 12885265585
2011-10-21 23:33:17,946 - DEBUG
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote: From = 3,
Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
2011-10-21 23:33:17,948 - DEBUG [WorkerReceiver
Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
notification message. My id = 3
2011-10-21 23:33:17,948 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my state)
2011-10-21 23:33:30,750 - DEBUG
[QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
2011-10-21 23:33:30,750 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
25600
2011-10-21 23:33:30,750 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
- There is a connection already for server 1
2011-10-21 23:33:30,750 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
- There is a connection already for server 2
2011-10-21 23:33:30,751 - DEBUG [WorkerReceiver
Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
notification message. My id = 3
2011-10-21 23:33:30,751 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 23:33:30,751 - DEBUG
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed id: 3,
zxid: 12885265585, proposed zxid: 12885265585
2011-10-21 23:33:30,751 - DEBUG
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote: From = 3,
Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
2011-10-21 23:33:30,753 - DEBUG [WorkerReceiver
Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
notification message. My id = 3
2011-10-21 23:33:30,753 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my state)
2011-10-21 23:33:56,357 - DEBUG
[QuorumPeer:/0.0.0.0:2181:QuorumCnxManager@414] - Queue size: 0
2011-10-21 23:33:56,357 - INFO
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@697] - Notification time out:
51200
2011-10-21 23:33:56,358 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
- There is a connection already for server 1
2011-10-21 23:33:56,358 - DEBUG [WorkerSender Thread:QuorumCnxManager@389]
- There is a connection already for server 2
2011-10-21 23:33:56,358 - DEBUG [WorkerReceiver
Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
notification message. My id = 3
2011-10-21 23:33:56,358 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 12885265585
(n.zxid), 1 (n.round), LOOKING (n.state), 3 (n.sid), LOOKING (my state)
2011-10-21 23:33:56,358 - DEBUG
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@510] - id: 3, proposed id: 3,
zxid: 12885265585, proposed zxid: 12885265585
2011-10-21 23:33:56,359 - DEBUG
[QuorumPeer:/0.0.0.0:2181:FastLeaderElection@727] - Adding vote: From = 3,
Proposed leader = 3, Porposed zxid = 12885265585, Proposed epoch = 1
2011-10-21 23:33:56,360 - DEBUG [WorkerReceiver
Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new
notification message. My id = 3
2011-10-21 23:33:56,360 - INFO [WorkerReceiver
Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589935532
(n.zxid), 3 (n.round), LEADING (n.state), 1 (n.sid), LOOKING (my state)
(END)